search

goodrobots / maverick

UAV Autonomous Systems Management
https://goodrobots.github.io/maverick/
MIT License
167 stars 60 forks source link

webrtc/visiond not connecting #1012

Closed fnoop closed 2 years ago

fnoop commented 2 years ago 
Sep 17 14:43:58 maverick-raspberry janus[9353]: [WARN] [rtsp-stream] Reconnection of the RTSP stream failed, trying again in a few seconds...
Sep 17 14:44:03 maverick-raspberry janus[9353]: [WARN] [rtsp-stream] 5s passed with no media, trying to reconnect the RTSP stream
Sep 17 14:44:13 maverick-raspberry janus[9353]: [ERR] [plugins/janus_streaming.c:janus_streaming_rtsp_connect_to_server:6442] Couldn't send DESCRIBE request: Timeout was reached
Sep 17 14:44:13 maverick-raspberry janus[9353]: [WARN] [rtsp-stream] Reconnection of the RTSP stream failed, trying again in a few seconds...

visiond looks like it starts up ok

Sep 17 14:43:17 maverick-raspberry python3[22434]: 2021-09-17 14:43:17,215 - visiond.modules.streamer - INFO - RTSP stream running at rtsp://0.0.0.0:6010/video
Sep 17 14:43:17 maverick-raspberry python3[22434]: 2021-09-17 14:43:17,222 - visiond.modules.streamer - INFO - Pipeline: "v4l2-source /dev/video0 ! capsfilter 'video/x-raw, format=(string)YUY2, width=(int)640, height=(int)480, framerate=(fraction)30/1' ! queue ! autovideoconvert ! omx-h264-encode ! h264capsfilter ! h264parse ! pay0"
Sep 17 14:43:17 maverick-raspberry python3[22434]: 2021-09-17 14:43:17,258 - visiond.modules.streamer - INFO - Starting camera stream
Sep 17 14:43:17 maverick-raspberry python3[22434]: 2021-09-17 14:43:17,262 - visiond.modules.app - INFO - Notifying systemd of startup completion
Sep 17 14:43:17 maverick-raspberry systemd[1]: Started Maverick Vision Daemon.
Sep 17 14:43:17 maverick-raspberry python3[22434]: 2021-09-17 14:43:17,389 - visiond.modules.rtspfactory - INFO - Creating RTSP factory element: /video
Sep 17 14:43:17 maverick-raspberry python3[22434]: 2021-09-17 14:43:17,399 - visiond.modules.streamer - INFO - RTSPMedia constructed: reusable: True, shared: True, stopondisconnect: True, latency: 0
Sep 17 14:43:17 maverick-raspberry python3[22434]: 2021-09-17 14:43:17,417 - visiond.modules.rtspfactory - DEBUG - Configuring RTSPMedia: <GstRtspServer.RTSPMedia object at 0xb1837508 (GstRTSPMedia at 0xb0c121b0)>
Sep 17 14:43:19 maverick-raspberry python3[22434]: 2021-09-17 14:43:19,972 - tornado.access - INFO - 101 GET / (127.0.0.1) 3.53ms
Sep 17 14:43:19 maverick-raspberry python3[22434]: 2021-09-17 14:43:19,973 - visiond.janushandler - INFO - Opening JanusHandler websocket connection
fnoop commented 2 years ago 
Sep 17 23:08:09 maverick-raspberry janus[4243]: [WARN] libnice version outdated: 0.1.14 installed, at least 0.1.16 recommended. Notice the installed version was checked at build time: if you updated libnice in the meanwhile, re-configure and recompile to get rid of this warning
fnoop commented 2 years ago

Changing janus build to install custom libnice, to see if that helps - #1009

fnoop commented 2 years ago

Updated libnice, still same problem. Grr.

Sep 18 12:29:14 maverick-raspberry python3[27414]: 2021-09-18 12:29:14,516 - visiond.janushandler - DEBUG - got message '{"emitter":"Maverick","type":16,"subtype":1,"timestamp":1631964554513946,"session_id":2556123236931274,"handle_id":2150927340422795,"opaque_id":"d60a9d8f-9e31-428d-8a34-5522ba7c9760","event":{"ice":"failed","stream_id":1,"component_id":1}}'
Sep 18 12:29:19 maverick-raspberry python3[27414]: 2021-09-18 12:29:19,524 - visiond.janushandler - DEBUG - got message '{"emitter":"Maverick","type":16,"subtype":6,"timestamp":1631964559519461,"session_id":2556123236931274,"handle_id":2150927340422795,"opaque_id":"d60a9d8f-9e31-428d-8a34-5522ba7c9760","event":{"connection":"hangup","reason":"ICE failed"}}'
fnoop commented 2 years ago

Different errors now. webrtc end:

Sep 18 18:02:14 maverick-raspberry janus[5196]: [WARN] [3583220383012737] ICE failed for component 1 in stream 1, but let's give it some time... (trickle received, answer received, alert not set)
Sep 18 18:02:19 maverick-raspberry janus[5196]: [ERR] [ice.c:janus_ice_check_failed:1876] [3583220383012737] ICE failed for component 1 in stream 1...

visiond end:

Sep 18 18:02:06 maverick-raspberry python3[27414]: 2021-09-18 18:02:06,997 - visiond.janushandler - DEBUG - got message '{"emitter":"Maverick","type":128,"timestamp":1631984526994081,"event":{"transport":"janus.transport.websockets","id":"10429799154540685426","data":{"event":"connected","admin_api":false,"ip":"192.168.1.181"}}}'
Sep 18 18:02:07 maverick-raspberry python3[27414]: 2021-09-18 18:02:07,014 - visiond.janushandler - DEBUG - got message '{"emitter":"Maverick","type":1,"timestamp":1631984527012562,"session_id":6981104294043625,"event":{"name":"created","transport":{"transport":"janus.transport.websockets","id":"10429799154540685426"}}}'
Sep 18 18:02:07 maverick-raspberry python3[27414]: 2021-09-18 18:02:07,025 - visiond.janushandler - DEBUG - got message '{"emitter":"Maverick","type":2,"timestamp":1631984527023340,"session_id":6981104294043625,"handle_id":3583220383012737,"opaque_id":"06947036-f2da-47ea-ab4f-6f1042201cbf","event":{"name":"attached","plugin":"janus.plugin.streaming","opaque_id":"06947036-f2da-47ea-ab4f-6f1042201cbf"}}'
Sep 18 18:02:07 maverick-raspberry python3[27414]: 2021-09-18 18:02:07,059 - visiond.janushandler - DEBUG - got message '{"emitter":"Maverick","type":16,"subtype":2,"timestamp":1631984527056235,"session_id":6981104294043625,"handle_id":3583220383012737,"opaque_id":"06947036-f2da-47ea-ab4f-6f1042201cbf","event":{"local-candidate":"1 1 udp 2015363327 192.168.1.208 48976 typ host","stream_id":1,"component_id":1}}'
Sep 18 18:02:07 maverick-raspberry python3[27414]: 2021-09-18 18:02:07,061 - visiond.janushandler - DEBUG - got message '{"emitter":"Maverick","type":8,"timestamp":1631984527057179,"session_id":6981104294043625,"handle_id":3583220383012737,"opaque_id":"06947036-f2da-47ea-ab4f-6f1042201cbf","event":{"owner":"local","jsep":{"type":"offer","sdp":"v=0\\r\\no=- 1631984527048302 1 IN IP4 192.168.1.208\\r\\ns=Mountpoint 1\\r\\nt=0 0\\r\\na=group:BUNDLE video\\r\\na=msid-semantic: WMS janus\\r\\nm=video 9 UDP/TLS/RTP/SAVPF 96 97\\r\\nc=IN IP4 192.168.1.208\\r\\na=sendonly\\r\\na=mid:video\\r\\na=rtcp-mux\\r\\na=ice-ufrag:2Y4G\\r\\na=ice-pwd:fBiZaCiLQ9zEgPvYBJ02QO\\r\\na=ice-options:trickle\\r\\na=fingerprint:sha-256 96:C9:36:24:1B:90:0F:BD:8A:C0:C8:44:71:AC:25:06:CC:F8:BB:01:4A:4C:FD:91:3A:E3:3E:56:3C:57:F5:79\\r\\na=setup:actpass\\r\\na=rtpmap:96 H264/90000\\r\\na=fmtp:96 profile-level-id=42e028;packetization-mode=1\\r\\na=rtcp-fb:96 nack\\r\\na=rtcp-fb:96 nack pli\\r\\na=rtcp-fb:96 goog-remb\\r\\na=extmap:1 urn:ietf:params:rtp-hdrext:sdes:mid\\r\\na=extmap:2 http://www.webrtc.org/experiments/rtp-hdrext/abs-send-time\\r\\na=rtpmap:97 rtx/90000\\r\\na=fmtp:97 apt=96\\r\\na=ssrc-group:FID 3501457789 3760106365\\r\\na=msid:janus janusv0\\r\\na=ssrc:3501457789 cname:janus\\r\\na=ssrc:3501457789 msid:janus janusv0\\r\\na=ssrc:3501457789 mslabel:janus\\r\\na=ssrc:3501457789 label:janusv0\\r\\na=ssrc:3760106365 cname:janus\\r\\na=ssrc:3760106365 msid:janus janusv0\\r\\na=ssrc:3760106365 mslabel:janus\\r\\na=ssrc:3760106365 label:janusv0\\r\\na=candidate:1 1 udp 2015363327 192.168.1.208 48976 typ host\\r\\na=end-of-candidates\\r\\n"}}}'
Sep 18 18:02:07 maverick-raspberry python3[27414]: 2021-09-18 18:02:07,077 - visiond.janushandler - DEBUG - got message '{"emitter":"Maverick","type":8,"timestamp":1631984527073858,"session_id":6981104294043625,"handle_id":3583220383012737,"opaque_id":"06947036-f2da-47ea-ab4f-6f1042201cbf","event":{"owner":"remote","jsep":{"type":"answer","sdp":"v=0\\r\\no=- 4854788741059518197 2 IN IP4 127.0.0.1\\r\\ns=-\\r\\nt=0 0\\r\\na=group:BUNDLE video\\r\\na=msid-semantic: WMS\\r\\nm=video 9 UDP/TLS/RTP/SAVPF 96 97\\r\\nc=IN IP4 0.0.0.0\\r\\na=rtcp:9 IN IP4 0.0.0.0\\r\\na=ice-ufrag:ikBg\\r\\na=ice-pwd:ah08TtEuQL66IAX5XL5NPXOV\\r\\na=ice-options:trickle\\r\\na=fingerprint:sha-256 36:71:00:61:D2:DB:75:E3:D0:B6:0E:DD:21:9F:98:05:51:0C:4E:EC:36:E7:F3:E2:EE:AE:2E:6A:6F:00:C2:E8\\r\\na=setup:active\\r\\na=mid:video\\r\\na=extmap:2 http://www.webrtc.org/experiments/rtp-hdrext/abs-send-time\\r\\na=extmap:1 urn:ietf:params:rtp-hdrext:sdes:mid\\r\\na=recvonly\\r\\na=rtcp-mux\\r\\na=rtpmap:96 H264/90000\\r\\na=rtcp-fb:96 goog-remb\\r\\na=rtcp-fb:96 nack\\r\\na=rtcp-fb:96 nack pli\\r\\na=fmtp:96 level-asymmetry-allowed=1;packetization-mode=1;profile-level-id=42e01f\\r\\na=rtpmap:97 rtx/90000\\r\\na=fmtp:97 apt=96\\r\\n"}}}'
Sep 18 18:02:07 maverick-raspberry python3[27414]: 2021-09-18 18:02:07,082 - visiond.janushandler - DEBUG - got message '{"emitter":"Maverick","type":64,"timestamp":1631984527074568,"session_id":6981104294043625,"handle_id":3583220383012737,"opaque_id":"06947036-f2da-47ea-ab4f-6f1042201cbf","event":{"plugin":"janus.plugin.streaming","data":{"status":"starting","id":1}}}'
Sep 18 18:02:07 maverick-raspberry python3[27414]: 2021-09-18 18:02:07,110 - visiond.janushandler - DEBUG - got message '{"emitter":"Maverick","type":16,"subtype":3,"timestamp":1631984527107827,"session_id":6981104294043625,"handle_id":3583220383012737,"opaque_id":"06947036-f2da-47ea-ab4f-6f1042201cbf","event":{"remote-candidate":"965449285 1 udp 2113937151 172.16.0.2 53397 typ host generation 0 ufrag ikBg network-cost 999","stream_id":1,"component_id":1}}'
Sep 18 18:02:07 maverick-raspberry python3[27414]: 2021-09-18 18:02:07,114 - visiond.janushandler - DEBUG - got message '{"emitter":"Maverick","type":16,"subtype":1,"timestamp":1631984527109147,"session_id":6981104294043625,"handle_id":3583220383012737,"opaque_id":"06947036-f2da-47ea-ab4f-6f1042201cbf","event":{"ice":"connecting","stream_id":1,"component_id":1}}'
Sep 18 18:02:14 maverick-raspberry python3[27414]: 2021-09-18 18:02:14,181 - visiond.janushandler - DEBUG - got message '{"emitter":"Maverick","type":16,"subtype":1,"timestamp":1631984534179413,"session_id":6981104294043625,"handle_id":3583220383012737,"opaque_id":"06947036-f2da-47ea-ab4f-6f1042201cbf","event":{"ice":"failed","stream_id":1,"component_id":1}}'
Sep 18 18:02:19 maverick-raspberry python3[27414]: 2021-09-18 18:02:19,188 - visiond.janushandler - DEBUG - got message '{"emitter":"Maverick","type":16,"subtype":6,"timestamp":1631984539185894,"session_id":6981104294043625,"handle_id":3583220383012737,"opaque_id":"06947036-f2da-47ea-ab4f-6f1042201cbf","event":{"connection":"hangup","reason":"ICE failed"}}'
fnoop commented 2 years ago

Aargh simple as a firewall issue. Looks like stun/ice trying to connect to itself over high udp ports which we block in firewall by default. Need to either specify a small range in janus config and open that up, or open up a large high udp range - preferably the former.

fnoop commented 2 years ago

Fixed firewall in #1013