RTSP over UDP fails

Thu Jun 2 17:20:13 UTC 2022

Le vendredi 03 juin 2022 à 01:53 +1000, John McDermott a écrit :
> I’ve also attached the GST_DEBUG=rtspsrc:5 log around the first TEARDOWN
> message below. It seems that the client wasn’t able to send a message to the
> server after the first TEARDOWN:

TEARDOWN is happening exactly 5s letter, which matches the timeout. I don't
think its relevant information.

> 
> 0:00:06.111330827 ESC[34m662997ESC[00m 0x5574ed0a91e0 ESC[37mDEBUG ESC[00m
> ESC[00m rtspsrc
> gstrtspsrc.c:5315:gst_rtspsrc_connection_flush:<rtspsrc0>ESC[00m set flushing
> 0
> 0:00:06.111333975 ESC[34m662997ESC[00m 0x5574ed0a91e0 ESC[37mDEBUG ESC[00m
> ESC[00m rtspsrc
> gstrtspsrc.c:5318:gst_rtspsrc_connection_flush:<rtspsrc0>ESC[00m connection
> flush
> 0:00:06.111340293 ESC[34m662997ESC[00m 0x5574ed0a91e0 ESC[37mDEBUG ESC[00m
> ESC[00m rtspsrc gstrtspsrc.c:5969:gst_rtspsrc_reconnect:<rtspsrc0>ESC[00m
> doing reconnect
> 0:00:06.111343811 ESC[34m662997ESC[00m 0x5574ed0a91e0 ESC[37mDEBUG ESC[00m
> ESC[00m rtspsrc gstrtspsrc.c:8275:gst_rtspsrc_close:<rtspsrc0>ESC[00m
> TEARDOWN...
> 0:00:06.112321648 ESC[34m662997ESC[00m 0x5574ed0a91e0 ESC[37mDEBUG ESC[00m
> ESC[00m rtspsrc gstrtspsrc.c:560:default_before_send:<rtspsrc0>ESC[00m default
> handler
> 0:00:06.112336119 ESC[34m662997ESC[00m 0x5574ed0a91e0 ESC[37mDEBUG ESC[00m
> ESC[00m rtspsrc gstrtspsrc.c:6602:gst_rtspsrc_try_send:<rtspsrc0>ESC[00m
> sending message
> 0:00:06.193865221 ESC[34m662997ESC[00m 0x5574ed0a91e0 ESC[33;01mWARN ESC[00m
> ESC[00m rtspsrc gstrtspsrc.c:6616:gst_rtspsrc_try_send:<rtspsrc0>ESC[00m
> server closed connection
> 0:00:06.193894801 ESC[34m662997ESC[00m 0x5574ed0a91e0 ESC[37mDEBUG ESC[00m
> ESC[00m rtspsrc
> gstrtspsrc.c:5303:gst_rtsp_conninfo_reconnect:<rtspsrc0>ESC[00m reconnecting
> connection...
> 0:00:06.193901152 ESC[34m662997ESC[00m 0x5574ed0a91e0 ESC[37mDEBUG ESC[00m
> ESC[00m rtspsrc gstrtspsrc.c:5282:gst_rtsp_conninfo_close:<rtspsrc0>ESC[00m
> closing connection...
> 0:00:06.193961725 ESC[34m662997ESC[00m 0x5574ed0a91e0 ESC[37mDEBUG ESC[00m
> ESC[00m rtspsrc gstrtspsrc.c:5226:gst_rtsp_conninfo_connect:<rtspsrc0>ESC[00m
> connecting (rtsp://admin:password@192.168.100.124:554/onvif1)...
> 0:00:06.199456481 ESC[34m662997ESC[00m 0x5574ed0a91e0 ESC[37mDEBUG ESC[00m
> ESC[00m rtspsrc gstrtspsrc.c:560:default_before_send:<rtspsrc0>ESC[00m default
> handler
> 0:00:06.199486993 ESC[34m662997ESC[00m 0x5574ed0a91e0 ESC[37mDEBUG ESC[00m
> ESC[00m rtspsrc gstrtspsrc.c:6602:gst_rtspsrc_try_send:<rtspsrc0>ESC[00m
> sending message
> 0:00:08.653795233 ESC[34m662997ESC[00m 0x5574ed0a91e0 ESC[33;01mWARN ESC[00m
> ESC[00m rtspsrc
> gstrtspsrc.c:6554:gst_rtsp_src_receive_response:<rtspsrc0>ESC[00m error: Could
> not receive message. (Parse error)
> 
> I’ve now tried RTSPT and force TCP instead, but I noticed that it tries to
> send a “dummy packet” after the PLAY message:
> 
> 0:00:00.215559150 ESC[32m664387ESC[00m 0x55af8a7c91e0 ESC[37mDEBUG ESC[00m
> ESC[00m rtspsrc gstrtspsrc.c:9180:gst_rtspsrc_thread:<rtspsrc0>ESC[00m got
> command PLAY
> 0:00:00.215570442 ESC[32m664387ESC[00m 0x55af8a7c91e0 ESC[37mDEBUG ESC[00m
> ESC[00m rtspsrc
> gstrtspsrc.c:5315:gst_rtspsrc_connection_flush:<rtspsrc0>ESC[00m set flushing
> 0
> 0:00:00.215574075 ESC[32m664387ESC[00m 0x55af8a7c91e0 ESC[37mDEBUG ESC[00m
> ESC[00m rtspsrc
> gstrtspsrc.c:5318:gst_rtspsrc_connection_flush:<rtspsrc0>ESC[00m connection
> flush
> 0:00:00.215580153 ESC[32m664387ESC[00m 0x55af8a7c91e0 ESC[37mDEBUG ESC[00m
> ESC[00m rtspsrc gstrtspsrc.c:8652:gst_rtspsrc_play:<rtspsrc0>ESC[00m PLAY...
> 0:00:00.215583697 ESC[32m664387ESC[00m 0x55af8a7c91e0 ESC[37mDEBUG ESC[00m
> ESC[00m rtspsrc
> gstrtspsrc.c:4908:gst_rtspsrc_send_dummy_packets:<rtspsrc0>ESC[00m sending
> dummy packet to stream 0x7ffb40019fa0
> 0:00:00.215712385 ESC[32m664387ESC[00m 0x55af8a7c91e0 ESC[37mDEBUG ESC[00m
> ESC[00m rtspsrc gstrtspsrc.c:560:default_before_send:<rtspsrc0>ESC[00m default
> handler
> 0:00:00.215720537 ESC[32m664387ESC[00m 0x55af8a7c91e0 ESC[37mDEBUG ESC[00m
> ESC[00m rtspsrc gstrtspsrc.c:6602:gst_rtspsrc_try_send:<rtspsrc0>ESC[00m
> sending message
> 0:00:00.847878037 ESC[32m664387ESC[00m 0x55af8a7c91e0 ESC[33;01mWARN ESC[00m
> ESC[00m rtspsrc
> gstrtspsrc.c:6554:gst_rtsp_src_receive_response:<rtspsrc0>ESC[00m error: Could
> not receive message. (Parse error)
> ERROR: from element /GstPipeline:pipeline0/GstRTSPSrc:rtspsrc0: Could not read
> from resource.
> 
> It doesn’t send a dummy packet to my other camera though.
> 
> Cheers,
> 
> John
> 
> On 3 Jun 2022, 1:31 AM +1000, John McDermott <egglue at gmail.com>, wrote:
> > Hi
> > 
> > I’ve just tried timeout=0, but it become stuck. I then used the GST_DEBUG=2
> > flag but it’s not clear if it actually tried TCP after UDP:
> > 
> > Progress: (request) SETUP stream 1
> > Progress: (open) Opened Stream
> > Setting pipeline to PLAYING ...
> > New clock: GstSystemClock
> > Progress: (request) Sending PLAY request
> > Redistribute latency...
> > Redistribute latency...
> > Progress: (request) Sending PLAY request
> > Redistribute latency...
> > Redistribute latency...
> > Progress: (request) Sent PLAY request
> > 0:00:06.145175115 658948 0x55dc226b85e0 WARN rtspsrc
> > gstrtspsrc.c:6616:gst_rtspsrc_try_send:<rtspsrc0> server closed connection
> > 0:00:08.651279028 658948 0x55dc226b85e0 WARN rtspsrc
> > gstrtspsrc.c:6554:gst_rtsp_src_receive_response:<rtspsrc0> error: Could not
> > receive message. (Parse error)
> > ERROR: from element /GstPipeline:pipeline0/GstRTSPSrc:rtspsrc0: Could not
> > read from resource.
> > Additional debug info:
> > ../subprojects/gst-plugins-good/gst/rtsp/gstrtspsrc.c(6554):
> > gst_rtsp_src_receive_response ():
> > /GstPipeline:pipeline0/GstRTSPSrc:rtspsrc0:
> > Could not receive message. (Parse error)
> > 
> > The connection seems to be closed right after when UDP fails. Here’s the
> > Wireshark capture:
> > 
> > No.	Time	Source	Destination	Protocol	Length	Info
> > 10	0.681943	192.168.100.55	192.168.100.124	RTSP	522
> > 	OPTIONS rtsp://192.168.100.124:554/onvif1 RTSP/1.0
> > 14	0.860696	192.168.100.124	192.168.100.55	RTSP	194
> > 	Reply: RTSP/1.0 200 OK
> > 16	0.861292	192.168.100.55	192.168.100.124	RTSP	224
> > 	DESCRIBE rtsp://192.168.100.124:554/onvif1 RTSP/1.0
> > 18	0.871429	192.168.100.124	192.168.100.55	RTSP	190
> > 	Reply: RTSP/1.0 401 Unauthorized
> > 20	0.871877	192.168.100.55	192.168.100.124	RTSP	412
> > 	DESCRIBE rtsp://192.168.100.124:554/onvif1 RTSP/1.0
> > 21	0.885671	192.168.100.124	192.168.100.55	RTSP/SDP
> > 	570	Reply: RTSP/1.0 200 OK
> > 23	0.887486	192.168.100.55	192.168.100.124	RTSP	450
> > 	SETUP rtsp://192.168.100.124:554/onvif1/track1 RTSP/1.0
> > 24	0.895097	192.168.100.124	192.168.100.55	RTSP	248
> > 	Reply: RTSP/1.0 200 OK
> > 26	0.897494	192.168.100.55	192.168.100.124	RTSP	468
> > 	SETUP rtsp://192.168.100.124:554/onvif1/track2 RTSP/1.0
> > 27	0.903456	192.168.100.124	192.168.100.55	RTSP	248
> > 	Reply: RTSP/1.0 200 OK
> > 29	0.905120	192.168.100.55	192.168.100.124	RTSP	416
> > 	PLAY rtsp://192.168.100.124:554/onvif1 RTSP/1.0
> > 148	1.839500	192.168.100.124	192.168.100.55	RTSP	268
> > 	Reply: RTSP/1.0 200 OK
> > 1277	6.849112	192.168.100.55	192.168.100.124	RTSP	405
> > 	TEARDOWN rtsp://192.168.100.124:554/onvif1 RTSP/1.0
> > 1286	6.862540	192.168.100.55	192.168.100.124	RTSP	405
> > 	TEARDOWN rtsp://192.168.100.124:554/onvif1 RTSP/1.0
> > 1388	9.399490	192.168.100.124	192.168.100.55	RTSP	193
> > 	Reply: RTSP/1.0 400 Bad Request
> > 1401	9.411456	192.168.100.55	192.168.100.124	RTSP	522
> > 	OPTIONS rtsp://192.168.100.124:554/onvif1 RTSP/1.0
> > 1408	9.620161	192.168.100.124	192.168.100.55	RTSP	194
> > 	Reply: RTSP/1.0 200 OK
> > 
> > 
> > Considering the following Wireshark capture when FFMPEG is used, I now
> > believe my camera indeed uses TCP (as well):
> > 
> > No.	Time	Source	Destination	Protocol	Length	Info
> > 4344	40.005447	192.168.100.55	192.168.100.124	TCP	78
> > 	53760 → 554 [SYN] Seq=0 Win=65535 Len=0 MSS=1460 WS=64 TSval=64110566
> > TSecr=0 SACK_PERM=1
> > 4345	40.011522	192.168.100.124	192.168.100.55	TCP	74
> > 	554 → 53760 [SYN, ACK] Seq=0 Ack=1 Win=14480 Len=0 MSS=1460 SACK_PERM=1
> > TSval=25698694 TSecr=64110566 WS=4
> > 4346	40.011634	192.168.100.55	192.168.100.124	TCP	66
> > 	53760 → 554 [ACK] Seq=1 Ack=1 Win=131712 Len=0 TSval=64110572
> > TSecr=25698694
> > 4347	40.011723	192.168.100.55	192.168.100.124	RTSP	156
> > 	OPTIONS rtsp://192.168.100.124:554/onvif1 RTSP/1.0
> > 4348	40.017358	192.168.100.124	192.168.100.55	TCP	66
> > 	554 → 53760 [ACK] Seq=1 Ack=91 Win=14480 Len=0 TSval=25698694
> > TSecr=64110572
> > 4350	40.100464	192.168.100.124	192.168.100.55	RTSP	194
> > 	Reply: RTSP/1.0 200 OK
> > 4351	40.100524	192.168.100.55	192.168.100.124	TCP	66
> > 	53760 → 554 [ACK] Seq=91 Ack=129 Win=131584 Len=0 TSval=64110659
> > TSecr=25698703
> > 4352	40.101137	192.168.100.55	192.168.100.124	RTSP	182
> > 	DESCRIBE rtsp://192.168.100.124:554/onvif1 RTSP/1.0
> > 4353	40.105133	192.168.100.124	192.168.100.55	TCP	66
> > 	554 → 53760 [ACK] Seq=129 Ack=207 Win=14480 Len=0 TSval=25698703
> > TSecr=64110659
> > 4354	40.105964	192.168.100.124	192.168.100.55	RTSP	190
> > 	Reply: RTSP/1.0 401 Unauthorized
> > 4355	40.106004	192.168.100.55	192.168.100.124	TCP	66
> > 	53760 → 554 [ACK] Seq=207 Ack=253 Win=131456 Len=0 TSval=64110663
> > TSecr=25698703
> > 4356	40.106597	192.168.100.55	192.168.100.124	RTSP	370
> > 	DESCRIBE rtsp://192.168.100.124:554/onvif1 RTSP/1.0
> > 4357	40.112124	192.168.100.124	192.168.100.55	RTSP/SDP
> > 	570	Reply: RTSP/1.0 200 OK
> > 4358	40.112167	192.168.100.55	192.168.100.124	TCP	66
> > 	53760 → 554 [ACK] Seq=511 Ack=757 Win=131008 Len=0 TSval=64110669
> > TSecr=25698704
> > 4359	40.113296	192.168.100.55	192.168.100.124	RTSP	412
> > 	SETUP rtsp://192.168.100.124:554/onvif1/track1 RTSP/1.0
> > 4360	40.120319	192.168.100.124	192.168.100.55	RTSP	248
> > 	Reply: RTSP/1.0 200 OK
> > 4361	40.120366	192.168.100.55	192.168.100.124	TCP	66
> > 	53760 → 554 [ACK] Seq=857 Ack=939 Win=130880 Len=0 TSval=64110678
> > TSecr=25698705
> > 4362	40.121836	192.168.100.55	192.168.100.124	RTSP	431
> > 	SETUP rtsp://192.168.100.124:554/onvif1/track2 RTSP/1.0
> > 4363	40.128754	192.168.100.124	192.168.100.55	RTSP	248
> > 	Reply: RTSP/1.0 200 OK
> > 4364	40.128855	192.168.100.55	192.168.100.124	TCP	66
> > 	53760 → 554 [ACK] Seq=1222 Ack=1121 Win=130880 Len=0 TSval=64110685
> > TSecr=25698705
> > 4365	40.129964	192.168.100.55	192.168.100.124	RTSP	379
> > 	PLAY rtsp://192.168.100.124:554/onvif1 RTSP/1.0
> > 4366	40.131391	192.168.100.55	192.168.100.124	RTP	54
> > 	PT=ITU-T G.711 PCMU, SSRC=0x0, Seq=0, Time=0
> > 4367	40.131998	192.168.100.55	192.168.100.124	RTCP	50
> > 	Receiver Report 
> > 4368	40.132773	192.168.100.55	192.168.100.124	RTP	54
> > 	PT=ITU-T G.711 PCMU, SSRC=0x0, Seq=0, Time=0
> > 4369	40.133311	192.168.100.55	192.168.100.124	RTCP	50
> > 	Receiver Report 
> > 4370	40.137885	192.168.100.124	192.168.100.55	ICMP	78
> > 	Destination unreachable (Port unreachable)
> > 4371	40.139424	192.168.100.124	192.168.100.55	ICMP	78
> > 	Destination unreachable (Port unreachable)
> > 4372	40.170640	192.168.100.124	192.168.100.55	TCP	66
> > 	554 → 53760 [ACK] Seq=1121 Ack=1535 Win=15552 Len=0 TSval=25698710
> > TSecr=64110686
> > 4378	40.763363	192.168.100.124	192.168.100.55	RTP	77
> > 	PT=DynamicRTP-Type-96, SSRC=0x39867684, Seq=49079, Time=2712090874, Mark
> > 
> > Hopefully this sheds new light on the issue.
> > 
> > Cheers,
> > 
> > John
> > On 2 Jun 2022, 2:02 AM +1000, Nicolas Dufresne <nicolas at ndufresne.ca>,
> > wrote:
> > > Le mercredi 01 juin 2022 à 03:46 +1000, John McDermott via gstreamer-devel
> > > a
> > > écrit :
> > > > Hi all
> > > > 
> > > > I have a camera that possibly has an unstable connection. FFMPEG can
> > > > read the
> > > > stream fine over UDP but not TCP. It takes a few second to setup, but it
> > > > works
> > > > fine over UDP nonetheless. The camera probably supports only UDP.
> > > > However, the
> > > > standard command:
> > > > 
> > > > gst-launch-1.0 rtspsrc location=rtsp://ip/stream ! queue ! rtph264depay
> > > > !
> > > > h264parse ! fakesink
> > > > 
> > > > fails with the following:
> > > > 
> > > > Progress: (open) Retrieving media info
> > > > Progress: (request) SETUP stream 0
> > > > Progress: (request) SETUP stream 1
> > > > Progress: (open) Opened Stream
> > > > Setting pipeline to PLAYING ...
> > > > New clock: GstSystemClock
> > > > Progress: (request) Sending PLAY request
> > > > Redistribute latency...
> > > > Redistribute latency...
> > > > Progress: (request) Sending PLAY request
> > > > Redistribute latency...
> > > > Redistribute latency...
> > > > Progress: (request) Sent PLAY request
> > > > ERROR: from element /GstPipeline:pipeline0/GstRTSPSrc:rtspsrc0: Could
> > > > not read
> > > > from resource.
> > > > Additional debug info:
> > > > ../subprojects/gst-plugins-good/gst/rtsp/gstrtspsrc.c(6554):
> > > > gst_rtsp_src_receive_response ():
> > > > /GstPipeline:pipeline0/GstRTSPSrc:rtspsrc0:
> > > > Could not receive message. (Parse error)
> > > > ERROR: from element /GstPipeline:pipeline0/GstRTSPSrc:rtspsrc0: Could
> > > > not read
> > > > from resource.
> > > > 
> > > > Is there a way to allow make Gstreamer to be as “resilient” as FFMPEG?
> > > > My
> > > > guess is that if GST could spend a few more seconds establishing the
> > > > connection and/or reading the stream, it should work.
> > > 
> > > Try with a little more logs to understand what is going on, e.g. set the
> > > env
> > > GST_DEBUG="2" . What may happen is that it takes over 5s for UDP packets
> > > to
> > > arrive and gstreamer fallbacks to TCP and fails. You can disable the the
> > > timeout
> > > , rtspsrc timeout=0, this will prevent the fallback from happening.
> > > 
> > > Nicolas