websocketd icon indicating copy to clipboard operation
websocketd copied to clipboard
verified publisher icon joewalnes

mosquitto_sub as command throwing error "Received message of type that we did not expect..."

Open JeffRossMT opened this issue 4 years ago • 1 comments

Using this command to start websocketd to collect weewx weather information from mosquitto:

websocketd --port=8080 --address=127.0.0.1 --loglevel=debug mosquitto_sub -h 10.2.6.1 -p 1883 -t weather/loop -u weewx -P weewx --pretty 2>&1

I get the following:

Fri, 11 Feb 2022 14:26:46 -0700 | INFO   | server     |  | Serving using application   : /usr/local/bin/mosquitto_sub -h 10.2.6.1 -p 1883 -t weather/loop -u weewx -P weewx --pretty
Fri, 11 Feb 2022 14:26:46 -0700 | INFO   | server     |  | Starting WebSocket server   : ws://127.0.0.1:8080/
Fri, 11 Feb 2022 14:29:40 -0700 | DEBUG  | env        | url:'http://127.0.0.1:8080/mqtt' id:'1644614980348914118' remote:'127.0.0.1' command:'/usr/local/bin/mosquitto_sub' | Std. variable: SERVER_SOFTWARE=websocketd/v0.3.1 (go1.15.2 openbsd-amd64) --
Fri, 11 Feb 2022 14:29:40 -0700 | DEBUG  | env        | url:'http://127.0.0.1:8080/mqtt' id:'1644614980348914118' remote:'127.0.0.1' command:'/usr/local/bin/mosquitto_sub' | Parent envvar: PATH=/home/jross/bin:/bin:/sbin:/usr/bin:/usr/sbin:/usr/local/bin:/usr/local/sbin:/etc/scripts/.
Fri, 11 Feb 2022 14:29:40 -0700 | DEBUG  | env        | url:'http://127.0.0.1:8080/mqtt' id:'1644614980348914118' remote:'127.0.0.1' command:'/usr/local/bin/mosquitto_sub' | Std. variable: REMOTE_ADDR=127.0.0.1
Fri, 11 Feb 2022 14:29:40 -0700 | DEBUG  | env        | url:'http://127.0.0.1:8080/mqtt' id:'1644614980348914118' remote:'127.0.0.1' command:'/usr/local/bin/mosquitto_sub' | Std. variable: REMOTE_HOST=127.0.0.1
Fri, 11 Feb 2022 14:29:40 -0700 | DEBUG  | env        | url:'http://127.0.0.1:8080/mqtt' id:'1644614980348914118' remote:'127.0.0.1' command:'/usr/local/bin/mosquitto_sub' | Std. variable: SERVER_NAME=127.0.0.1
Fri, 11 Feb 2022 14:29:40 -0700 | DEBUG  | env        | url:'http://127.0.0.1:8080/mqtt' id:'1644614980348914118' remote:'127.0.0.1' command:'/usr/local/bin/mosquitto_sub' | Std. variable: SERVER_PORT=8080
Fri, 11 Feb 2022 14:29:40 -0700 | DEBUG  | env        | url:'http://127.0.0.1:8080/mqtt' id:'1644614980348914118' remote:'127.0.0.1' command:'/usr/local/bin/mosquitto_sub' | Std. variable: SERVER_PROTOCOL=HTTP/1.1
Fri, 11 Feb 2022 14:29:40 -0700 | DEBUG  | env        | url:'http://127.0.0.1:8080/mqtt' id:'1644614980348914118' remote:'127.0.0.1' command:'/usr/local/bin/mosquitto_sub' | Std. variable: GATEWAY_INTERFACE=websocketd-CGI/0.1
Fri, 11 Feb 2022 14:29:40 -0700 | DEBUG  | env        | url:'http://127.0.0.1:8080/mqtt' id:'1644614980348914118' remote:'127.0.0.1' command:'/usr/local/bin/mosquitto_sub' | Std. variable: REQUEST_METHOD=GET
Fri, 11 Feb 2022 14:29:40 -0700 | DEBUG  | env        | url:'http://127.0.0.1:8080/mqtt' id:'1644614980348914118' remote:'127.0.0.1' command:'/usr/local/bin/mosquitto_sub' | Std. variable: SCRIPT_NAME=/
Fri, 11 Feb 2022 14:29:40 -0700 | DEBUG  | env        | url:'http://127.0.0.1:8080/mqtt' id:'1644614980348914118' remote:'127.0.0.1' command:'/usr/local/bin/mosquitto_sub' | Std. variable: PATH_INFO=/mqtt
Fri, 11 Feb 2022 14:29:40 -0700 | DEBUG  | env        | url:'http://127.0.0.1:8080/mqtt' id:'1644614980348914118' remote:'127.0.0.1' command:'/usr/local/bin/mosquitto_sub' | Std. variable: PATH_TRANSLATED=/mqtt
Fri, 11 Feb 2022 14:29:40 -0700 | DEBUG  | env        | url:'http://127.0.0.1:8080/mqtt' id:'1644614980348914118' remote:'127.0.0.1' command:'/usr/local/bin/mosquitto_sub' | Std. variable: QUERY_STRING=
Fri, 11 Feb 2022 14:29:40 -0700 | DEBUG  | env        | url:'http://127.0.0.1:8080/mqtt' id:'1644614980348914118' remote:'127.0.0.1' command:'/usr/local/bin/mosquitto_sub' | Std. variable: AUTH_TYPE=
Fri, 11 Feb 2022 14:29:40 -0700 | DEBUG  | env        | url:'http://127.0.0.1:8080/mqtt' id:'1644614980348914118' remote:'127.0.0.1' command:'/usr/local/bin/mosquitto_sub' | Std. variable: CONTENT_LENGTH=
Fri, 11 Feb 2022 14:29:40 -0700 | DEBUG  | env        | url:'http://127.0.0.1:8080/mqtt' id:'1644614980348914118' remote:'127.0.0.1' command:'/usr/local/bin/mosquitto_sub' | Std. variable: CONTENT_TYPE=
Fri, 11 Feb 2022 14:29:40 -0700 | DEBUG  | env        | url:'http://127.0.0.1:8080/mqtt' id:'1644614980348914118' remote:'127.0.0.1' command:'/usr/local/bin/mosquitto_sub' | Std. variable: REMOTE_IDENT=
Fri, 11 Feb 2022 14:29:40 -0700 | DEBUG  | env        | url:'http://127.0.0.1:8080/mqtt' id:'1644614980348914118' remote:'127.0.0.1' command:'/usr/local/bin/mosquitto_sub' | Std. variable: REMOTE_USER=
Fri, 11 Feb 2022 14:29:40 -0700 | DEBUG  | env        | url:'http://127.0.0.1:8080/mqtt' id:'1644614980348914118' remote:'127.0.0.1' command:'/usr/local/bin/mosquitto_sub' | Std. variable: UNIQUE_ID=1644614980348914118
Fri, 11 Feb 2022 14:29:40 -0700 | DEBUG  | env        | url:'http://127.0.0.1:8080/mqtt' id:'1644614980348914118' remote:'127.0.0.1' command:'/usr/local/bin/mosquitto_sub' | Std. variable: REMOTE_PORT=9220
Fri, 11 Feb 2022 14:29:40 -0700 | DEBUG  | env        | url:'http://127.0.0.1:8080/mqtt' id:'1644614980348914118' remote:'127.0.0.1' command:'/usr/local/bin/mosquitto_sub' | Std. variable: REQUEST_URI=/mqtt
Fri, 11 Feb 2022 14:29:40 -0700 | DEBUG  | env        | url:'http://127.0.0.1:8080/mqtt' id:'1644614980348914118' remote:'127.0.0.1' command:'/usr/local/bin/mosquitto_sub' | Header variable HTTP_ORIGIN=https://127.0.0.1:8080
Fri, 11 Feb 2022 14:29:40 -0700 | DEBUG  | env        | url:'http://127.0.0.1:8080/mqtt' id:'1644614980348914118' remote:'127.0.0.1' command:'/usr/local/bin/mosquitto_sub' | Header variable HTTP_SEC_WEBSOCKET_KEY=oVHTNFxGTQa/0zZtr/uPIQ==
Fri, 11 Feb 2022 14:29:40 -0700 | DEBUG  | env        | url:'http://127.0.0.1:8080/mqtt' id:'1644614980348914118' remote:'127.0.0.1' command:'/usr/local/bin/mosquitto_sub' | Header variable HTTP_SEC_WEBSOCKET_VERSION=13
Fri, 11 Feb 2022 14:29:40 -0700 | DEBUG  | env        | url:'http://127.0.0.1:8080/mqtt' id:'1644614980348914118' remote:'127.0.0.1' command:'/usr/local/bin/mosquitto_sub' | Header variable HTTP_SEC_WEBSOCKET_PROTOCOL=mqtt
Fri, 11 Feb 2022 14:29:40 -0700 | DEBUG  | env        | url:'http://127.0.0.1:8080/mqtt' id:'1644614980348914118' remote:'127.0.0.1' command:'/usr/local/bin/mosquitto_sub' | Header variable HTTP_UPGRADE=websocket
Fri, 11 Feb 2022 14:29:40 -0700 | DEBUG  | env        | url:'http://127.0.0.1:8080/mqtt' id:'1644614980348914118' remote:'127.0.0.1' command:'/usr/local/bin/mosquitto_sub' | Header variable HTTP_CONNECTION=Upgrade
Fri, 11 Feb 2022 14:29:40 -0700 | ACCESS | session    | url:'http://127.0.0.1:8080/mqtt' id:'1644614980348914118' remote:'127.0.0.1' command:'/usr/local/bin/mosquitto_sub' origin:'https://127.0.0.1:8080' | CONNECT
Fri, 11 Feb 2022 14:29:40 -0700 | DEBUG  | websocket  | url:'http://127.0.0.1:8080/mqtt' id:'1644614980348914118' remote:'127.0.0.1' command:'/usr/local/bin/mosquitto_sub' origin:'https://127.0.0.1:8080' pid:'7870' | Received message of type that we did not expect... Ignoring...
Fri, 11 Feb 2022 14:29:40 -0700 | DEBUG  | websocket  | url:'http://127.0.0.1:8080/mqtt' id:'1644614980348914118' remote:'127.0.0.1' command:'/usr/local/bin/mosquitto_sub' origin:'https://127.0.0.1:8080' pid:'7870' | Received message of type that we did not expect... Ignoring...
Fri, 11 Feb 2022 14:29:43 -0700 | DEBUG  | websocket  | url:'http://127.0.0.1:8080/mqtt' id:'1644614980348914118' remote:'127.0.0.1' command:'/usr/local/bin/mosquitto_sub' origin:'https://127.0.0.1:8080' pid:'7870' | Received message of type that we did not expect... Ignoring...
Fri, 11 Feb 2022 14:29:47 -0700 | DEBUG  | websocket  | url:'http://127.0.0.1:8080/mqtt' id:'1644614980348914118' remote:'127.0.0.1' command:'/usr/local/bin/mosquitto_sub' origin:'https://127.0.0.1:8080' pid:'7870' | Cannot receive: websocket: close 1006 (abnormal closure): unexpected EOF
Fri, 11 Feb 2022 14:29:47 -0700 | TRACE  | websocket  | url:'http://127.0.0.1:8080/mqtt' id:'1644614980348914118' remote:'127.0.0.1' command:'/usr/local/bin/mosquitto_sub' origin:'https://127.0.0.1:8080' pid:'7870' | Terminated websocket connection
Fri, 11 Feb 2022 14:29:47 -0700 | DEBUG  | process    | url:'http://127.0.0.1:8080/mqtt' id:'1644614980348914118' remote:'127.0.0.1' command:'/usr/local/bin/mosquitto_sub' origin:'https://127.0.0.1:8080' pid:'7870' | Process STDOUT closed
Fri, 11 Feb 2022 14:29:47 -0700 | DEBUG  | process    | url:'http://127.0.0.1:8080/mqtt' id:'1644614980348914118' remote:'127.0.0.1' command:'/usr/local/bin/mosquitto_sub' origin:'https://127.0.0.1:8080' pid:'7870' | Process STDERR closed
Fri, 11 Feb 2022 14:29:47 -0700 | DEBUG  | process    | url:'http://127.0.0.1:8080/mqtt' id:'1644614980348914118' remote:'127.0.0.1' command:'/usr/local/bin/mosquitto_sub' origin:'https://127.0.0.1:8080' pid:'7870' | Process 7870 terminated after SIGINT
Fri, 11 Feb 2022 14:29:47 -0700 | ACCESS | session    | url:'http://127.0.0.1:8080/mqtt' id:'1644614980348914118' remote:'127.0.0.1' command:'/usr/local/bin/mosquitto_sub' origin:'https://127.0.0.1:8080' pid:'7870' | DISCONNECT

But when I add ktrace to the mix to see what's really going on I see that, indeed, the MQTT subscription is working and delivering results:

 76907 websocketd GIO   fd 8 read 664 bytes
       "{"rain24_in": "0.0", "barometer_inHg": "26.232", "outHumidity": "43.0", "altimeter_inHg": "30.5278323602", "maxSolarRad": "226.15267305", "dewpoint_F": "11.5", "rain_in": "0.0", "cloudbase_foot": "8680.33295427", "heatindex_F": "31.5", "inDewpoint_F": "36.9602\
	980922", "dayRain_in": "0.0", "outTemp_F": "31.5", "appTemp_F": "22.2795534307", "windchill_F": "25.5", "hourRain_in": "0.0", "humidex_F": "31.5", "rainRate_inch_per_hour": "0.0", "windGust_mph": "10.3", "pressure_inHg": "26.232", "inTemp_F": "69.8", "usUnits"\
	: "1.0", "windSpeed_mph": "6.3", "UV": "2.0", "dateTime": "1644619189.0", "windDir": "321.0", "inHumidity": "30.0", "radiation_Wpm2": "224.61"}
       "
 76907 websocketd RET   clock_gettime 0
 76907 websocketd RET   read 664/0x298
 76907 websocketd CALL  clock_gettime(CLOCK_MONOTONIC,0x207f359f0)
 76907 websocketd STRU  struct timespec { 26380030.652492712 }
 76907 websocketd RET   clock_gettime 0
 76907 websocketd CALL  nanosleep(0x207f359f0,0)
 76907 websocketd STRU  struct timespec { 0.000020000 }
 76907 websocketd CALL  __thrwakeup(0xc000034f38,1)
 76907 websocketd RET   __thrwakeup 0
 76907 websocketd CALL  read(8,0xc000163000,0x1000)
 76907 websocketd RET   __thrsleep 0
 76907 websocketd RET   read -1 errno 35 Resource temporarily unavailable
 76907 websocketd CALL  kevent(4,0,0,0x20d8f8748,64,0x20d8f8720)
 76907 websocketd STRU  struct timespec { 0 }
 76907 websocketd RET   kevent 0
 76907 websocketd CALL  kevent(4,0,0,0x20d8f8748,64,0)
 76907 websocketd CALL  write(7,0xc00013f00a,0x29b)
 76907 websocketd GIO   fd 7 wrote 667 bytes
       "\M^A~\^B\M^W{"rain24_in": "0.0", "barometer_inHg": "26.232", "outHumidity": "43.0", "altimeter_inHg": "30.5278323602", "maxSolarRad": "226.15267305", "dewpoint_F": "11.5", "rain_in": "0.0", "cloudbase_foot": "8680.33295427", "heatindex_F": "31.5", "inDewpoint_\
	F": "36.9602980922", "dayRain_in": "0.0", "outTemp_F": "31.5", "appTemp_F": "22.2795534307", "windchill_F": "25.5", "hourRain_in": "0.0", "humidex_F": "31.5", "rainRate_inch_per_hour": "0.0", "windGust_mph": "10.3", "pressure_inHg": "26.232", "inTemp_F": "69.8\
	", "usUnits": "1.0", "windSpeed_mph": "6.3", "UV": "2.0", "dateTime": "1644619189.0", "windDir": "321.0", "inHumidity": "30.0", "radiation_Wpm2": "224.61"}"
 76907 websocketd RET   write 667/0x29b
 76907 websocketd CALL  __thrsleep(0xc000034b38,CLOCK_MONOTONIC,0,0,0xc000034b38)
 76907 websocketd STRU  struct kevent { ident=7, filter=EVFILT_WRITE, flags=0x21<EV_ADD|EV_CLEAR>, fflags=0<>, data=32744, udata=0x2e593fec8 }
 76907 websocketd RET   kevent 1
 76907 websocketd CALL  clock_gettime(CLOCK_MONOTONIC,0x20d8f8f38)
 76907 websocketd STRU  struct timespec { 26380030.652658095 }
 76907 websocketd RET   clock_gettime 0
 76907 websocketd CALL  kevent(4,0,0,0x20d8f8748,64,0x20d8f8720)
 76907 websocketd STRU  struct timespec { 0 }
 76907 websocketd RET   kevent 0
 76907 websocketd CALL  kevent(4,0,0,0x20d8f8748,64,0)
 76907 websocketd RET   nanosleep 0
 76907 websocketd CALL  clock_gettime(CLOCK_MONOTONIC,0x207f359f0)
 76907 websocketd STRU  struct timespec { 26380030.670468801 }
 76907 websocketd RET   clock_gettime 0
 76907 websocketd CALL  clock_gettime(CLOCK_MONOTONIC,0x207f35988)
 76907 websocketd STRU  struct timespec { 26380030.670490871 }
 76907 websocketd RET   clock_gettime 0
 76907 websocketd CALL  clock_gettime(CLOCK_MONOTONIC,0x207f35920)
 76907 websocketd STRU  struct timespec { 26380030.670504979 }
 76907 websocketd RET   clock_gettime 0
 76907 websocketd CALL  __thrsleep(0xc000034738,CLOCK_MONOTONIC,0x207f35970,0,0xc000034738)
 76907 websocketd STRU  struct timespec { 26380090.670504979 }
 76907 websocketd STRU  struct kevent { ident=7, filter=EVFILT_READ, flags=0x21<EV_ADD|EV_CLEAR>, fflags=0<>, data=29, udata=0x2e593fec8 }
 76907 websocketd RET   kevent 1
 76907 websocketd CALL  clock_gettime(CLOCK_MONOTONIC,0x20d8f8f38)
 76907 websocketd STRU  struct timespec { 26380033.644427078 }
 76907 websocketd RET   clock_gettime 0
 76907 websocketd CALL  __thrwakeup(0xc000034738,1)
 76907 websocketd RET   __thrwakeup 0
 76907 websocketd CALL  read(7,0xc000118000,0x1000)
 76907 websocketd RET   __thrsleep 0
 76907 websocketd GIO   fd 7 read 29 bytes
       "\M^B\M^W\^R\^_\M^J\M-2"
	\M^J\M->ez\M-k\M-Fzz\M-x\M^]~p\M-e\M-B}q\M-*\M^J"'\M-:"
 76907 websocketd RET   read 29/0x1d
 76907 websocketd CALL  clock_gettime(CLOCK_MONOTONIC,0x207f359f0)
 76907 websocketd STRU  struct timespec { 26380033.644497477 }
 76907 websocketd RET   clock_gettime 0
 76907 websocketd CALL  clock_gettime(CLOCK_MONOTONIC,0x207f359f0)
 76907 websocketd STRU  struct timespec { 26380033.644516335 }
 76907 websocketd RET   clock_gettime 0
 76907 websocketd CALL  nanosleep(0x207f359f0,0)
 76907 websocketd STRU  struct timespec { 0.000020000 }
 76907 websocketd CALL  clock_gettime(CLOCK_REALTIME,0xc00003ecd8)
 76907 websocketd STRU  struct timespec { 1644619236<"Feb 11 15:40:09 2022">.433036102 }
 76907 websocketd RET   clock_gettime 0
 76907 websocketd CALL  clock_gettime(CLOCK_MONOTONIC,0xc00003ece0)
 76907 websocketd STRU  struct timespec { 26380033.644620956 }
 76907 websocketd RET   clock_gettime 0
 76907 websocketd CALL  write(1,0xc0000d8000,0x119)
 76907 websocketd GIO   fd 1 wrote 281 bytes
       "Fri, 11 Feb 2022 15:40:36 -0700 | DEBUG  | websocket  | url:'http://127.0.0.1:8080/mqtt' id:'1644619233427533642' remote:'127.0.0.1' command:'/usr/local/bin/mosquitto_sub' origin:'https://127.0.0.1:8080' pid:'37169' | Received message of type that we did not e\
	xpect... Ignoring...
       "
 76907 websocketd RET   write 281/0x119

What might be wrong with the mosquitto text as received so I can get this to work?

Thanks! Jeff Ross

JeffRossMT avatar Feb 11 '22 22:02 JeffRossMT

I added a smidgen of debugging with the following patch:

--- libwebsocketd/websocket_endpoint.go	Mon Feb 21 12:54:44 2022
+++ libwebsocketd/websocket_endpoint.go.mod	Mon Feb 21 13:14:14 2022
@@ -71,7 +71,8 @@
 			break
 		}
 		if mtype != we.mtype {
-			we.log.Debug("websocket", "Received message of type that we did not expect... Ignoring...")
+			we.log.Debug("websocket", "Received message of type %d that we did not expect instead of %d... Ignoring...",mtype,we.mtype)
+			we.log.Debug("websocket", "Received message of unknown type: %d", mtype)
 		}

 		p, err := ioutil.ReadAll(rd)

Didn't help a lot, though--here's what I get from the debug log after the patch:

Mon, 21 Feb 2022 13:32:58 -0700 | DEBUG  | env        | url:'https://starhouse-observatory.org:9001/mqtt' id:'1645475578197867527' remote:'154.27.106.60' command:'./mosquitto_sub.sh' | Std. variable: SERVER_SOFTWARE=websocketd/v0.3.1 (go1.15.2 openbsd-amd64) --
Mon, 21 Feb 2022 13:32:58 -0700 | DEBUG  | env        | url:'https://starhouse-observatory.org:9001/mqtt' id:'1645475578197867527' remote:'154.27.106.60' command:'./mosquitto_sub.sh' | Parent envvar: PATH=/home/jross/bin:/bin:/sbin:/usr/bin:/usr/sbin:/usr/local/bin:/usr/local/sbin:/etc/scripts/.
Mon, 21 Feb 2022 13:32:58 -0700 | DEBUG  | env        | url:'https://starhouse-observatory.org:9001/mqtt' id:'1645475578197867527' remote:'154.27.106.60' command:'./mosquitto_sub.sh' | Std. variable: REMOTE_ADDR=154.27.106.60
Mon, 21 Feb 2022 13:32:58 -0700 | DEBUG  | env        | url:'https://starhouse-observatory.org:9001/mqtt' id:'1645475578197867527' remote:'154.27.106.60' command:'./mosquitto_sub.sh' | Std. variable: REMOTE_HOST=154.27.106.60
Mon, 21 Feb 2022 13:32:58 -0700 | DEBUG  | env        | url:'https://starhouse-observatory.org:9001/mqtt' id:'1645475578197867527' remote:'154.27.106.60' command:'./mosquitto_sub.sh' | Std. variable: SERVER_NAME=starhouse-observatory.org
Mon, 21 Feb 2022 13:32:58 -0700 | DEBUG  | env        | url:'https://starhouse-observatory.org:9001/mqtt' id:'1645475578197867527' remote:'154.27.106.60' command:'./mosquitto_sub.sh' | Std. variable: SERVER_PORT=9001
Mon, 21 Feb 2022 13:32:58 -0700 | DEBUG  | env        | url:'https://starhouse-observatory.org:9001/mqtt' id:'1645475578197867527' remote:'154.27.106.60' command:'./mosquitto_sub.sh' | Std. variable: SERVER_PROTOCOL=HTTP/1.1
Mon, 21 Feb 2022 13:32:58 -0700 | DEBUG  | env        | url:'https://starhouse-observatory.org:9001/mqtt' id:'1645475578197867527' remote:'154.27.106.60' command:'./mosquitto_sub.sh' | Std. variable: GATEWAY_INTERFACE=websocketd-CGI/0.1
Mon, 21 Feb 2022 13:32:58 -0700 | DEBUG  | env        | url:'https://starhouse-observatory.org:9001/mqtt' id:'1645475578197867527' remote:'154.27.106.60' command:'./mosquitto_sub.sh' | Std. variable: REQUEST_METHOD=GET
Mon, 21 Feb 2022 13:32:58 -0700 | DEBUG  | env        | url:'https://starhouse-observatory.org:9001/mqtt' id:'1645475578197867527' remote:'154.27.106.60' command:'./mosquitto_sub.sh' | Std. variable: SCRIPT_NAME=/
Mon, 21 Feb 2022 13:32:58 -0700 | DEBUG  | env        | url:'https://starhouse-observatory.org:9001/mqtt' id:'1645475578197867527' remote:'154.27.106.60' command:'./mosquitto_sub.sh' | Std. variable: PATH_INFO=/mqtt
Mon, 21 Feb 2022 13:32:58 -0700 | DEBUG  | env        | url:'https://starhouse-observatory.org:9001/mqtt' id:'1645475578197867527' remote:'154.27.106.60' command:'./mosquitto_sub.sh' | Std. variable: PATH_TRANSLATED=/mqtt
Mon, 21 Feb 2022 13:32:58 -0700 | DEBUG  | env        | url:'https://starhouse-observatory.org:9001/mqtt' id:'1645475578197867527' remote:'154.27.106.60' command:'./mosquitto_sub.sh' | Std. variable: QUERY_STRING=
Mon, 21 Feb 2022 13:32:58 -0700 | DEBUG  | env        | url:'https://starhouse-observatory.org:9001/mqtt' id:'1645475578197867527' remote:'154.27.106.60' command:'./mosquitto_sub.sh' | Std. variable: AUTH_TYPE=
Mon, 21 Feb 2022 13:32:58 -0700 | DEBUG  | env        | url:'https://starhouse-observatory.org:9001/mqtt' id:'1645475578197867527' remote:'154.27.106.60' command:'./mosquitto_sub.sh' | Std. variable: CONTENT_LENGTH=
Mon, 21 Feb 2022 13:32:58 -0700 | DEBUG  | env        | url:'https://starhouse-observatory.org:9001/mqtt' id:'1645475578197867527' remote:'154.27.106.60' command:'./mosquitto_sub.sh' | Std. variable: CONTENT_TYPE=
Mon, 21 Feb 2022 13:32:58 -0700 | DEBUG  | env        | url:'https://starhouse-observatory.org:9001/mqtt' id:'1645475578197867527' remote:'154.27.106.60' command:'./mosquitto_sub.sh' | Std. variable: REMOTE_IDENT=
Mon, 21 Feb 2022 13:32:58 -0700 | DEBUG  | env        | url:'https://starhouse-observatory.org:9001/mqtt' id:'1645475578197867527' remote:'154.27.106.60' command:'./mosquitto_sub.sh' | Std. variable: REMOTE_USER=
Mon, 21 Feb 2022 13:32:58 -0700 | DEBUG  | env        | url:'https://starhouse-observatory.org:9001/mqtt' id:'1645475578197867527' remote:'154.27.106.60' command:'./mosquitto_sub.sh' | Std. variable: UNIQUE_ID=1645475578197867527
Mon, 21 Feb 2022 13:32:58 -0700 | DEBUG  | env        | url:'https://starhouse-observatory.org:9001/mqtt' id:'1645475578197867527' remote:'154.27.106.60' command:'./mosquitto_sub.sh' | Std. variable: REMOTE_PORT=58338
Mon, 21 Feb 2022 13:32:58 -0700 | DEBUG  | env        | url:'https://starhouse-observatory.org:9001/mqtt' id:'1645475578197867527' remote:'154.27.106.60' command:'./mosquitto_sub.sh' | Std. variable: REQUEST_URI=/mqtt
Mon, 21 Feb 2022 13:32:58 -0700 | DEBUG  | env        | url:'https://starhouse-observatory.org:9001/mqtt' id:'1645475578197867527' remote:'154.27.106.60' command:'./mosquitto_sub.sh' | Std. variable: HTTPS=on
Mon, 21 Feb 2022 13:32:58 -0700 | DEBUG  | env        | url:'https://starhouse-observatory.org:9001/mqtt' id:'1645475578197867527' remote:'154.27.106.60' command:'./mosquitto_sub.sh' | Header variable HTTP_ACCEPT=*/*
Mon, 21 Feb 2022 13:32:58 -0700 | DEBUG  | env        | url:'https://starhouse-observatory.org:9001/mqtt' id:'1645475578197867527' remote:'154.27.106.60' command:'./mosquitto_sub.sh' | Header variable HTTP_SEC_WEBSOCKET_PROTOCOL=mqttv3.1
Mon, 21 Feb 2022 13:32:58 -0700 | DEBUG  | env        | url:'https://starhouse-observatory.org:9001/mqtt' id:'1645475578197867527' remote:'154.27.106.60' command:'./mosquitto_sub.sh' | Header variable HTTP_SEC_WEBSOCKET_EXTENSIONS=permessage-deflate
Mon, 21 Feb 2022 13:32:58 -0700 | DEBUG  | env        | url:'https://starhouse-observatory.org:9001/mqtt' id:'1645475578197867527' remote:'154.27.106.60' command:'./mosquitto_sub.sh' | Header variable HTTP_SEC_FETCH_SITE=same-site
Mon, 21 Feb 2022 13:32:58 -0700 | DEBUG  | env        | url:'https://starhouse-observatory.org:9001/mqtt' id:'1645475578197867527' remote:'154.27.106.60' command:'./mosquitto_sub.sh' | Header variable HTTP_ACCEPT_LANGUAGE=en-US,en;q=0.5
Mon, 21 Feb 2022 13:32:58 -0700 | DEBUG  | env        | url:'https://starhouse-observatory.org:9001/mqtt' id:'1645475578197867527' remote:'154.27.106.60' command:'./mosquitto_sub.sh' | Header variable HTTP_ACCEPT_ENCODING=gzip, deflate, br
Mon, 21 Feb 2022 13:32:58 -0700 | DEBUG  | env        | url:'https://starhouse-observatory.org:9001/mqtt' id:'1645475578197867527' remote:'154.27.106.60' command:'./mosquitto_sub.sh' | Header variable HTTP_SEC_WEBSOCKET_VERSION=13
Mon, 21 Feb 2022 13:32:58 -0700 | DEBUG  | env        | url:'https://starhouse-observatory.org:9001/mqtt' id:'1645475578197867527' remote:'154.27.106.60' command:'./mosquitto_sub.sh' | Header variable HTTP_DNT=1
Mon, 21 Feb 2022 13:32:58 -0700 | DEBUG  | env        | url:'https://starhouse-observatory.org:9001/mqtt' id:'1645475578197867527' remote:'154.27.106.60' command:'./mosquitto_sub.sh' | Header variable HTTP_CONNECTION=keep-alive, Upgrade
Mon, 21 Feb 2022 13:32:58 -0700 | DEBUG  | env        | url:'https://starhouse-observatory.org:9001/mqtt' id:'1645475578197867527' remote:'154.27.106.60' command:'./mosquitto_sub.sh' | Header variable HTTP_SEC_FETCH_MODE=websocket
Mon, 21 Feb 2022 13:32:58 -0700 | DEBUG  | env        | url:'https://starhouse-observatory.org:9001/mqtt' id:'1645475578197867527' remote:'154.27.106.60' command:'./mosquitto_sub.sh' | Header variable HTTP_USER_AGENT=Mozilla/5.0 (Macintosh; Intel Mac OS X 10.15; rv:97.0) Gecko/20100101 Firefox/97.0
Mon, 21 Feb 2022 13:32:58 -0700 | DEBUG  | env        | url:'https://starhouse-observatory.org:9001/mqtt' id:'1645475578197867527' remote:'154.27.106.60' command:'./mosquitto_sub.sh' | Header variable HTTP_ORIGIN=https://www.starhouse-observatory.org
Mon, 21 Feb 2022 13:32:58 -0700 | DEBUG  | env        | url:'https://starhouse-observatory.org:9001/mqtt' id:'1645475578197867527' remote:'154.27.106.60' command:'./mosquitto_sub.sh' | Header variable HTTP_PRAGMA=no-cache
Mon, 21 Feb 2022 13:32:58 -0700 | DEBUG  | env        | url:'https://starhouse-observatory.org:9001/mqtt' id:'1645475578197867527' remote:'154.27.106.60' command:'./mosquitto_sub.sh' | Header variable HTTP_SEC_WEBSOCKET_KEY=Attp86tOm6Hlp8foZrxI2A==
Mon, 21 Feb 2022 13:32:58 -0700 | DEBUG  | env        | url:'https://starhouse-observatory.org:9001/mqtt' id:'1645475578197867527' remote:'154.27.106.60' command:'./mosquitto_sub.sh' | Header variable HTTP_SEC_FETCH_DEST=websocket
Mon, 21 Feb 2022 13:32:58 -0700 | DEBUG  | env        | url:'https://starhouse-observatory.org:9001/mqtt' id:'1645475578197867527' remote:'154.27.106.60' command:'./mosquitto_sub.sh' | Header variable HTTP_SEC_GPC=1
Mon, 21 Feb 2022 13:32:58 -0700 | DEBUG  | env        | url:'https://starhouse-observatory.org:9001/mqtt' id:'1645475578197867527' remote:'154.27.106.60' command:'./mosquitto_sub.sh' | Header variable HTTP_CACHE_CONTROL=no-cache
Mon, 21 Feb 2022 13:32:58 -0700 | DEBUG  | env        | url:'https://starhouse-observatory.org:9001/mqtt' id:'1645475578197867527' remote:'154.27.106.60' command:'./mosquitto_sub.sh' | Header variable HTTP_UPGRADE=websocket
Mon, 21 Feb 2022 13:32:58 -0700 | ACCESS | session    | url:'https://starhouse-observatory.org:9001/mqtt' id:'1645475578197867527' remote:'154.27.106.60' command:'./mosquitto_sub.sh' origin:'https://www.starhouse-observatory.org' | CONNECT
Mon, 21 Feb 2022 13:32:58 -0700 | DEBUG  | websocket  | url:'https://starhouse-observatory.org:9001/mqtt' id:'1645475578197867527' remote:'154.27.106.60' command:'./mosquitto_sub.sh' origin:'https://www.starhouse-observatory.org' pid:'30738' | Received message of type 2 that we did not expect instead of 1... Ignoring...
Mon, 21 Feb 2022 13:32:58 -0700 | DEBUG  | websocket  | url:'https://starhouse-observatory.org:9001/mqtt' id:'1645475578197867527' remote:'154.27.106.60' command:'./mosquitto_sub.sh' origin:'https://www.starhouse-observatory.org' pid:'30738' | Received message of unknown type: 2
Mon, 21 Feb 2022 13:32:58 -0700 | ERROR  | process    | url:'https://starhouse-observatory.org:9001/mqtt' id:'1645475548662208639' remote:'154.27.106.60' command:'./mosquitto_sub.sh' origin:'https://www.starhouse-observatory.org' pid:'84317' | Unexpected error while reading STDOUT from process: read |0: file already closed
Mon, 21 Feb 2022 13:32:58 -0700 | ERROR  | process    | url:'https://starhouse-observatory.org:9001/mqtt' id:'1645475548662208639' remote:'154.27.106.60' command:'./mosquitto_sub.sh' origin:'https://www.starhouse-observatory.org' pid:'84317' | Unexpected error while reading STDERR from process: read |0: file already closed
Mon, 21 Feb 2022 13:32:58 -0700 | DEBUG  | process    | url:'https://starhouse-observatory.org:9001/mqtt' id:'1645475548662208639' remote:'154.27.106.60' command:'./mosquitto_sub.sh' origin:'https://www.starhouse-observatory.org' pid:'84317' | Process 84317 terminated after SIGKILL
Mon, 21 Feb 2022 13:32:58 -0700 | ACCESS | session    | url:'https://starhouse-observatory.org:9001/mqtt' id:'1645475548662208639' remote:'154.27.106.60' command:'./mosquitto_sub.sh' origin:'https://www.starhouse-observatory.org' pid:'84317' | DISCONNECT
Mon, 21 Feb 2022 13:33:27 -0700 | DEBUG  | websocket  | url:'https://starhouse-observatory.org:9001/mqtt' id:'1645475578197867527' remote:'154.27.106.60' command:'./mosquitto_sub.sh' origin:'https://www.starhouse-observatory.org' pid:'30738' | Cannot receive: websocket: close 1005 (no status)
Mon, 21 Feb 2022 13:33:27 -0700

What I don't know is what a message of type 2 is and how do I convert the output of mosquitto_sub to a message of type 1? I did try piping the output of mosquitto_sub through strings but that made no change.

Jeff

JeffRossMT avatar Feb 21 '22 20:02 JeffRossMT