After an evaluation, GNOME has moved from Bugzilla to GitLab. Learn more about GitLab.
No new issues can be reported in GNOME Bugzilla anymore.
To report an issue in a GNOME project, go to GNOME GitLab.
Do not go to GNOME Gitlab for: Bluefish, Doxygen, GnuCash, GStreamer, java-gnome, LDTP, NetworkManager, Tomboy.
Bug 654464 - udpsrc conflict with rtsp and multicast due to two-phase setup
udpsrc conflict with rtsp and multicast due to two-phase setup
Status: RESOLVED OBSOLETE
Product: GStreamer
Classification: Platform
Component: gst-plugins-good
0.10.29
Other Linux
: Normal normal
: git master
Assigned To: GStreamer Maintainers
GStreamer Maintainers
Depends on:
Blocks:
 
 
Reported: 2011-07-12 11:45 UTC by Marc Leeman
Modified: 2013-06-25 12:26 UTC
See Also:
GNOME target: ---
GNOME version: ---



Description Marc Leeman 2011-07-12 11:45:23 UTC
This setup is about two RTSP enabled cameras; but they do not allow any port negociation.

We access two identical encoders via RTSP; that have the same settings:
uri-in=rtsp://10.3.0.48:7070 protocols=2
uri-in=rtsp://10.3.0.171:7070 protocols=2

When the first camera is accessed; the RTSP negociation finally lands on the correct combination when fixing the port-range on the decoder side.

The second encoder poses a problem due to the RTSP setup process.
The RTSP session is started in two phases.

In a first phase; the unicast UDP ports are opened (shared=0) which fails because these ports are already in use by the first client.
The second phase; where the multicast sockets are opened (udpsrc shared=1) is never executed since the result of the first setup is a range of ports incompatible with what the encoder is willing to provide; while technically there should not be an issue.
Comment 1 Marc Leeman 2011-07-12 11:46:12 UTC
Starting client 1 with:
GST_DEBUG_NO_COLOR=1 GST_DEBUG=*udp*:5 gst-launch rtspsrc location=rtsp://10.3.0.48:7070 protocols=2 port-range=5000-5005 debug=1 ! fakesink

Setting pipeline to PAUSED ...
RTSP request message 0x7fff2cff9290
 request line:
   method: 'OPTIONS'
   uri: 'rtsp://10.3.0.48:7070/'
   version: '1.0'
 headers:
   key: 'User-Agent', value: 'RealMedia Player Version 6.0.9.1235 (linux-2.0-libc6-i386-gcc2.95)'
   key: 'ClientChallenge', value: '9e26d33f2984236010ef6253fb1887f7'
   key: 'CompanyID', value: 'KnKV4M4I/B2FjJ1TToLycw=='
   key: 'GUID', value: '00000000-0000-0000-0000-000000000000'
   key: 'RegionData', value: '0'
   key: 'PlayerStarttime', value: '[28/03/2003:22:50:23 00:00]'
   key: 'ClientID', value: 'Linux_2.4_6.0.9.1235_play32_RN01_EN_586'
 body:
RTSP response message 0x7fff2cff9250
 status line:
   code: '200'
   reason: 'OK'
   version: '1.0'
 headers:
   key: 'CSeq', value: '1'
   key: 'Date', value: 'Thu, Mar 22 2007 17:22:19 GMT'
   key: 'Public', value: 'OPTIONS'
   key: 'Public', value: 'DESCRIBE'
   key: 'Public', value: 'SETUP'
   key: 'Public', value: 'TEARDOWN'
   key: 'Public', value: 'PLAY'
   key: 'Public', value: 'SET_PARAMETER'
 body: length 0
RTSP request message 0x7fff2cff9290
 request line:
   method: 'DESCRIBE'
   uri: 'rtsp://10.3.0.48:7070/'
   version: '1.0'
 headers:
   key: 'Accept', value: 'application/sdp'
 body:
RTSP response message 0x7fff2cff9250
 status line:
   code: '200'
   reason: 'OK'
   version: '1.0'
 headers:
   key: 'CSeq', value: '2'
   key: 'Date', value: 'Thu, Mar 22 2007 17:22:19 GMT'
   key: 'Content-Base', value: 'rtsp://10.3.0.48:7070//'
   key: 'Content-Type', value: 'application/sdp'
   key: 'Content-Length', value: '604'
 body: length 605
00000000 (0x1933b40): 76 3d 30 0d 0a 6f 3d 2d 20 31 31 37 34 35 37 39 v=0..o=- 1174579
00000010 (0x1933b50): 39 39 39 34 38 30 30 30 30 20 31 20 49 4e 20 49 999480000 1 IN I
00000020 (0x1933b60): 50 34 20 31 30 2e 33 2e 30 2e 34 38 0d 0a 73 3d P4 10.3.0.48..s=
00000030 (0x1933b70): 53 65 73 73 69 6f 6e 20 73 74 72 65 61 6d 65 64 Session streamed
00000040 (0x1933b80): 20 62 79 20 52 54 50 2f 52 54 53 50 20 73 65 72 by RTP/RTSP ser
00000050 (0x1933b90): 76 65 72 0d 0a 69 3d 41 43 54 49 2e 43 4f 4d 20 ver..i=ACTI.COM
00000060 (0x1933ba0): 53 74 72 65 61 6d 69 6e 67 20 4d 65 64 69 61 20 Streaming Media
00000070 (0x1933bb0): 76 0d 0a 74 3d 30 20 30 0d 0a 61 3d 74 6f 6f 6c v..t=0 0..a=tool
00000080 (0x1933bc0): 3a 41 43 54 49 2e 43 4f 4d 20 53 74 72 65 61 6d :ACTI.COM Stream
00000090 (0x1933bd0): 69 6e 67 20 4d 65 64 69 61 20 76 32 30 30 35 2e ing Media v2005.
000000a0 (0x1933be0): 30 33 2e 33 31 0d 0a 61 3d 74 79 70 65 3a 62 72 03.31..a=type:br
000000b0 (0x1933bf0): 6f 61 64 63 61 73 74 0d 0a 61 3d 63 6f 6e 74 72 oadcast..a=contr
000000c0 (0x1933c00): 6f 6c 3a 2a 0d 0a 61 3d 72 61 6e 67 65 3a 6e 70 ol:*..a=range:np
000000d0 (0x1933c10): 74 3d 30 2d 0d 0a 61 3d 78 2d 71 74 2d 74 65 78 t=0-..a=x-qt-tex
000000e0 (0x1933c20): 74 2d 6e 61 6d 3a 53 65 73 73 69 6f 6e 20 73 74 t-nam:Session st
000000f0 (0x1933c30): 72 65 61 6d 65 64 20 62 79 20 52 54 50 2f 52 54 reamed by RTP/RT
00000100 (0x1933c40): 53 50 20 73 65 72 76 65 72 0d 0a 61 3d 78 2d 71 SP server..a=x-q
00000110 (0x1933c50): 74 2d 74 65 78 74 2d 69 6e 66 3a 41 43 54 49 2e t-text-inf:ACTI.
00000120 (0x1933c60): 43 4f 4d 20 53 74 72 65 61 6d 69 6e 67 20 4d 65 COM Streaming Me
00000130 (0x1933c70): 64 69 61 20 76 0d 0a 6d 3d 76 69 64 65 6f 20 35 dia v..m=video 5
00000140 (0x1933c80): 30 30 30 20 52 54 50 2f 41 56 50 20 39 36 0d 0a 000 RTP/AVP 96..
00000150 (0x1933c90): 63 3d 49 4e 20 49 50 34 20 32 32 36 2e 32 35 35 c=IN IP4 226.255
00000160 (0x1933ca0): 2e 30 2e 34 38 2f 32 35 35 0d 0a 61 3d 72 74 70 .0.48/255..a=rtp
00000170 (0x1933cb0): 6d 61 70 3a 39 36 20 4d 50 34 56 2d 45 53 2f 39 map:96 MP4V-ES/9
00000180 (0x1933cc0): 30 30 30 30 0d 0a 61 3d 66 6d 74 70 3a 39 36 20 0000..a=fmtp:96
00000190 (0x1933cd0): 70 72 6f 66 69 6c 65 2d 6c 65 76 65 6c 2d 69 64 profile-level-id
000001a0 (0x1933ce0): 3d 32 34 35 3b 63 6f 6e 66 69 67 3d 30 30 30 30 =245;config=0000
000001b0 (0x1933cf0): 30 31 42 30 46 35 30 30 30 30 30 31 42 35 30 39 01B0F5000001B509
000001c0 (0x1933d00): 30 30 30 30 30 31 30 30 30 30 30 30 30 31 32 30 0000010000000120
000001d0 (0x1933d10): 30 30 43 38 38 38 42 30 45 30 45 30 46 41 36 32 00C888B0E0E0FA62
000001e0 (0x1933d20): 44 30 38 39 30 32 38 33 30 37 0d 0a 61 3d 63 6f D089028307..a=co
000001f0 (0x1933d30): 6e 74 72 6f 6c 3a 74 72 61 63 6b 31 0d 0a 6d 3d ntrol:track1..m=
00000200 (0x1933d40): 61 75 64 69 6f 20 35 30 30 32 20 52 54 50 2f 41 audio 5002 RTP/A
00000210 (0x1933d50): 56 50 20 31 31 31 0d 0a 63 3d 49 4e 20 49 50 34 VP 111..c=IN IP4
00000220 (0x1933d60): 20 32 32 36 2e 32 35 35 2e 30 2e 34 38 2f 32 35 226.255.0.48/25
00000230 (0x1933d70): 35 0d 0a 61 3d 72 74 70 6d 61 70 3a 31 31 31 20 5..a=rtpmap:111
00000240 (0x1933d80): 4c 31 36 2f 38 30 30 30 0d 0a 61 3d 63 6f 6e 74 L16/8000..a=cont
00000250 (0x1933d90): 72 6f 6c 3a 74 72 61 63 6b 32 0d 0a 00 rol:track2...
sdp packet 0x1936c80:
 version: '0'
 origin:
  username: '-'
  sess_id: '1174579999480000'
  sess_version: '1'
  nettype: 'IN'
  addrtype: 'IP4'
  addr: '10.3.0.48'
 session_name: 'Session streamed by RTP/RTSP server'
 information: 'ACTI.COM Streaming Media v'
 uri: '(NULL)'
 connection:
  nettype: '(NULL)'
  addrtype: '(NULL)'
  address: '(NULL)'
  ttl: '0'
  addr_number: '0'
 key:
  type: '(NULL)'
  data: '(NULL)'
 attributes:
  attribute 'tool' : 'ACTI.COM Streaming Media v2005.03.31'
  attribute 'type' : 'broadcast'
  attribute 'control' : '*'
  attribute 'range' : 'npt=0-'
  attribute 'x-qt-text-nam' : 'Session streamed by RTP/RTSP server'
  attribute 'x-qt-text-inf' : 'ACTI.COM Streaming Media v'
 medias:
  media 0:
   media: 'video'
   port: '5000'
   num_ports: '4294967295'
   proto: 'RTP/AVP'
   formats:
    format '96'
   information: '(NULL)'
   connections:
    nettype: 'IN'
    addrtype: 'IP4'
    address: '226.255.0.48'
    ttl: '255'
    addr_number: '0'
   key:
    type: '(NULL)'
    data: '(NULL)'
   attributes:
    attribute 'rtpmap' : '96 MP4V-ES/90000'
    attribute 'fmtp' : '96 profile-level-id=245;config=000001B0F5000001B509000001000000012000C888B0E0E0FA62D089028307'
    attribute 'control' : 'track1'
  media 1:
   media: 'audio'
   port: '5002'
   num_ports: '4294967295'
   proto: 'RTP/AVP'
   formats:
    format '111'
   information: '(NULL)'
   connections:
    nettype: 'IN'
    addrtype: 'IP4'
    address: '226.255.0.48'
    ttl: '255'
    addr_number: '0'
   key:
    type: '(NULL)'
    data: '(NULL)'
   attributes:
    attribute 'rtpmap' : '111 L16/8000'
    attribute 'control' : 'track2'
0:00:00.112222761 24172 0x174b080 DEBUG udpsrc gstudpsrc.c:784:gst_udpsrc_start:<udpsrc0> allocating socket for 0.0.0.0:5000
0:00:00.112502138 24172 0x174b080 DEBUG udpsrc gstudpsrc.c:795:gst_udpsrc_start:<udpsrc0> got socket 8
0:00:00.112541408 24172 0x174b080 DEBUG udpsrc gstudpsrc.c:797:gst_udpsrc_start:<udpsrc0> setting reuse 0
0:00:00.112578854 24172 0x174b080 DEBUG udpsrc gstudpsrc.c:804:gst_udpsrc_start:<udpsrc0> binding on port 5000
0:00:00.112622144 24172 0x174b080 DEBUG udpsrc gstudpsrc.c:853:gst_udpsrc_start:<udpsrc0> setting udp buffer of 524288 bytes
0:00:00.112661870 24172 0x174b080 DEBUG udpsrc gstudpsrc.c:873:gst_udpsrc_start:<udpsrc0> have udp buffer of 262142 bytes
0:00:00.112700270 24172 0x174b080 DEBUG udpsrc gstudpsrc.c:906:gst_udpsrc_start:<udpsrc0> bound, on port 5000
0:00:00.112805643 24172 0x174b080 LOG udpsrc gstudpsrc.c:992:gst_udpsrc_unlock_stop:<udpsrc0> No longer flushing
0:00:00.114082966 24172 0x174b080 DEBUG udpsrc gstudpsrc.c:784:gst_udpsrc_start:<udpsrc1> allocating socket for 0.0.0.0:5001
0:00:00.114328954 24172 0x174b080 DEBUG udpsrc gstudpsrc.c:795:gst_udpsrc_start:<udpsrc1> got socket 11
0:00:00.114367758 24172 0x174b080 DEBUG udpsrc gstudpsrc.c:797:gst_udpsrc_start:<udpsrc1> setting reuse 0
0:00:00.114458296 24172 0x174b080 DEBUG udpsrc gstudpsrc.c:804:gst_udpsrc_start:<udpsrc1> binding on port 5001
0:00:00.114505358 24172 0x174b080 DEBUG udpsrc gstudpsrc.c:873:gst_udpsrc_start:<udpsrc1> have udp buffer of 126976 bytes
0:00:00.114546165 24172 0x174b080 DEBUG udpsrc gstudpsrc.c:906:gst_udpsrc_start:<udpsrc1> bound, on port 5001
0:00:00.114633778 24172 0x174b080 LOG udpsrc gstudpsrc.c:992:gst_udpsrc_unlock_stop:<udpsrc1> No longer flushing
RTSP request message 0x7fff2cff90c0
 request line:
   method: 'SETUP'
   uri: 'rtsp://10.3.0.48:7070//track1'
   version: '1.0'
 headers:
   key: 'Transport', value: 'RTP/AVP;multicast;client_port=5000-5001'
 body:
RTSP response message 0x7fff2cff9080
 status line:
   code: '200'
   reason: 'OK'
   version: '1.0'
 headers:
   key: 'CSeq', value: '3'
   key: 'Date', value: 'Thu, Mar 22 2007 17:22:19 GMT'
   key: 'Transport', value: 'RTP/AVP;multicast;destination=226.255.0.48;port=5000;ttl=255'
   key: 'Session', value: '70'
 body: length 0
0:00:00.127266086 24172 0x174b080 LOG udpsrc gstudpsrc.c:979:gst_udpsrc_unlock:<udpsrc0> Flushing
0:00:00.127369127 24172 0x174b080 LOG udpsrc gstudpsrc.c:992:gst_udpsrc_unlock_stop:<udpsrc0> No longer flushing
0:00:00.127561738 24172 0x174b080 DEBUG udpsrc gstudpsrc.c:1005:gst_udpsrc_stop: stopping, closing sockets
0:00:00.127881225 24172 0x174b080 LOG udpsrc gstudpsrc.c:979:gst_udpsrc_unlock:<udpsrc1> Flushing
0:00:00.127927709 24172 0x174b080 LOG udpsrc gstudpsrc.c:992:gst_udpsrc_unlock_stop:<udpsrc1> No longer flushing
0:00:00.128068444 24172 0x174b080 DEBUG udpsrc gstudpsrc.c:1005:gst_udpsrc_stop: stopping, closing sockets
0:00:00.128977696 24172 0x174b080 DEBUG udpsrc gstudpsrc.c:784:gst_udpsrc_start:<udpsrc2> allocating socket for 226.255.0.48:5000
0:00:00.129219514 24172 0x174b080 DEBUG udpsrc gstudpsrc.c:795:gst_udpsrc_start:<udpsrc2> got socket 8
0:00:00.129257771 24172 0x174b080 DEBUG udpsrc gstudpsrc.c:797:gst_udpsrc_start:<udpsrc2> setting reuse 1
0:00:00.129295795 24172 0x174b080 DEBUG udpsrc gstudpsrc.c:804:gst_udpsrc_start:<udpsrc2> binding on port 5000
0:00:00.129340757 24172 0x174b080 DEBUG udpsrc gstudpsrc.c:873:gst_udpsrc_start:<udpsrc2> have udp buffer of 126976 bytes
0:00:00.129381481 24172 0x174b080 DEBUG udpsrc gstudpsrc.c:897:gst_udpsrc_start:<udpsrc2> joining multicast group 226.255.0.48
0:00:00.130398049 24172 0x174b080 DEBUG udpsrc gstudpsrc.c:906:gst_udpsrc_start:<udpsrc2> bound, on port 5000
0:00:00.130562409 24172 0x174b080 LOG udpsrc gstudpsrc.c:992:gst_udpsrc_unlock_stop:<udpsrc2> No longer flushing
0:00:00.132317722 24172 0x174b080 DEBUG multiudpsink gstmultiudpsink.c:1056:gst_multiudpsink_add_internal:<GstUDPSink@0x195d800> adding client on host localhost, port 4951
0:00:00.133110361 24172 0x174b080 DEBUG multiudpsink gstmultiudpsink.c:1084:gst_multiudpsink_add_internal:<GstUDPSink@0x195d800> add client with host localhost, port 4951
0:00:00.133177732 24172 0x174b080 DEBUG multiudpsink gstmultiudpsink.c:1094:gst_multiudpsink_add_internal:<GstUDPSink@0x195d800> added client on host localhost, port 4951
0:00:00.133276693 24172 0x174b080 DEBUG multiudpsink gstmultiudpsink.c:1136:gst_multiudpsink_remove:<udpsink0> found 1 clients with host localhost, port 4951
0:00:00.133313674 24172 0x174b080 DEBUG multiudpsink gstmultiudpsink.c:1140:gst_multiudpsink_remove:<udpsink0> remove client with host localhost, port 4951
0:00:00.133362041 24172 0x174b080 DEBUG multiudpsink gstmultiudpsink.c:1056:gst_multiudpsink_add_internal:<udpsink0> adding client on host 226.255.0.48, port 5000
0:00:00.133575209 24172 0x174b080 DEBUG multiudpsink gstmultiudpsink.c:1084:gst_multiudpsink_add_internal:<udpsink0> add client with host 226.255.0.48, port 5000
0:00:00.133617816 24172 0x174b080 DEBUG multiudpsink gstmultiudpsink.c:1094:gst_multiudpsink_add_internal:<udpsink0> added client on host 226.255.0.48, port 5000
0:00:00.133739696 24172 0x174b080 DEBUG multiudpsink gstmultiudpsink.c:768:gst_multiudpsink_set_property:<udpsink0> setting SOCKFD to 8
0:00:00.135285807 24172 0x174b080 DEBUG udpsrc gstudpsrc.c:784:gst_udpsrc_start:<udpsrc3> allocating socket for 0.0.0.0:5002
0:00:00.135532432 24172 0x174b080 DEBUG udpsrc gstudpsrc.c:795:gst_udpsrc_start:<udpsrc3> got socket 11
0:00:00.135570899 24172 0x174b080 DEBUG udpsrc gstudpsrc.c:797:gst_udpsrc_start:<udpsrc3> setting reuse 0
0:00:00.135609448 24172 0x174b080 DEBUG udpsrc gstudpsrc.c:804:gst_udpsrc_start:<udpsrc3> binding on port 5002
0:00:00.135653465 24172 0x174b080 DEBUG udpsrc gstudpsrc.c:853:gst_udpsrc_start:<udpsrc3> setting udp buffer of 524288 bytes
0:00:00.135693874 24172 0x174b080 DEBUG udpsrc gstudpsrc.c:873:gst_udpsrc_start:<udpsrc3> have udp buffer of 262142 bytes
0:00:00.135733541 24172 0x174b080 DEBUG udpsrc gstudpsrc.c:906:gst_udpsrc_start:<udpsrc3> bound, on port 5002
0:00:00.135820502 24172 0x174b080 LOG udpsrc gstudpsrc.c:992:gst_udpsrc_unlock_stop:<udpsrc3> No longer flushing
0:00:00.136744132 24172 0x174b080 DEBUG udpsrc gstudpsrc.c:784:gst_udpsrc_start:<udpsrc4> allocating socket for 0.0.0.0:5003
0:00:00.137033371 24172 0x174b080 DEBUG udpsrc gstudpsrc.c:795:gst_udpsrc_start:<udpsrc4> got socket 16
0:00:00.137075161 24172 0x174b080 DEBUG udpsrc gstudpsrc.c:797:gst_udpsrc_start:<udpsrc4> setting reuse 0
0:00:00.137113470 24172 0x174b080 DEBUG udpsrc gstudpsrc.c:804:gst_udpsrc_start:<udpsrc4> binding on port 5003
0:00:00.137159391 24172 0x174b080 DEBUG udpsrc gstudpsrc.c:873:gst_udpsrc_start:<udpsrc4> have udp buffer of 126976 bytes
0:00:00.137200116 24172 0x174b080 DEBUG udpsrc gstudpsrc.c:906:gst_udpsrc_start:<udpsrc4> bound, on port 5003
0:00:00.137288801 24172 0x174b080 LOG udpsrc gstudpsrc.c:992:gst_udpsrc_unlock_stop:<udpsrc4> No longer flushing
RTSP request message 0x7fff2cff90c0
 request line:
   method: 'SETUP'
   uri: 'rtsp://10.3.0.48:7070//track2'
   version: '1.0'
 headers:
   key: 'Transport', value: 'RTP/AVP;multicast;client_port=5002-5003'
 body:
RTSP response message 0x7fff2cff9080
 status line:
   code: '200'
   reason: 'OK'
   version: '1.0'
 headers:
   key: 'CSeq', value: '4'
   key: 'Date', value: 'Thu, Mar 22 2007 17:22:19 GMT'
   key: 'Transport', value: 'RTP/AVP;multicast;destination=226.255.0.48;port=5002;ttl=255'
   key: 'Session', value: '70'
 body: length 0
0:00:00.146186958 24172 0x174b080 LOG udpsrc gstudpsrc.c:979:gst_udpsrc_unlock:<udpsrc3> Flushing
0:00:00.146268144 24172 0x174b080 LOG udpsrc gstudpsrc.c:992:gst_udpsrc_unlock_stop:<udpsrc3> No longer flushing
0:00:00.146446738 24172 0x174b080 DEBUG udpsrc gstudpsrc.c:1005:gst_udpsrc_stop: stopping, closing sockets
0:00:00.146683396 24172 0x174b080 LOG udpsrc gstudpsrc.c:979:gst_udpsrc_unlock:<udpsrc4> Flushing
0:00:00.146724188 24172 0x174b080 LOG udpsrc gstudpsrc.c:992:gst_udpsrc_unlock_stop:<udpsrc4> No longer flushing
0:00:00.146909690 24172 0x174b080 DEBUG udpsrc gstudpsrc.c:1005:gst_udpsrc_stop: stopping, closing sockets
0:00:00.148001948 24172 0x174b080 DEBUG udpsrc gstudpsrc.c:784:gst_udpsrc_start:<udpsrc5> allocating socket for 226.255.0.48:5002
0:00:00.148255548 24172 0x174b080 DEBUG udpsrc gstudpsrc.c:795:gst_udpsrc_start:<udpsrc5> got socket 11
0:00:00.148341729 24172 0x174b080 DEBUG udpsrc gstudpsrc.c:797:gst_udpsrc_start:<udpsrc5> setting reuse 1
0:00:00.148380091 24172 0x174b080 DEBUG udpsrc gstudpsrc.c:804:gst_udpsrc_start:<udpsrc5> binding on port 5002
0:00:00.148424730 24172 0x174b080 DEBUG udpsrc gstudpsrc.c:873:gst_udpsrc_start:<udpsrc5> have udp buffer of 126976 bytes
0:00:00.148465522 24172 0x174b080 DEBUG udpsrc gstudpsrc.c:897:gst_udpsrc_start:<udpsrc5> joining multicast group 226.255.0.48
0:00:00.148528348 24172 0x174b080 DEBUG udpsrc gstudpsrc.c:906:gst_udpsrc_start:<udpsrc5> bound, on port 5002
0:00:00.148617289 24172 0x174b080 LOG udpsrc gstudpsrc.c:992:gst_udpsrc_unlock_stop:<udpsrc5> No longer flushing
0:00:00.149759443 24172 0x174b080 DEBUG multiudpsink gstmultiudpsink.c:1056:gst_multiudpsink_add_internal:<GstUDPSink@0x196d070> adding client on host localhost, port 4951
0:00:00.150289165 24172 0x174b080 DEBUG multiudpsink gstmultiudpsink.c:1084:gst_multiudpsink_add_internal:<GstUDPSink@0x196d070> add client with host localhost, port 4951
0:00:00.150350417 24172 0x174b080 DEBUG multiudpsink gstmultiudpsink.c:1094:gst_multiudpsink_add_internal:<GstUDPSink@0x196d070> added client on host localhost, port 4951
0:00:00.150445162 24172 0x174b080 DEBUG multiudpsink gstmultiudpsink.c:1136:gst_multiudpsink_remove:<udpsink1> found 1 clients with host localhost, port 4951
0:00:00.150483959 24172 0x174b080 DEBUG multiudpsink gstmultiudpsink.c:1140:gst_multiudpsink_remove:<udpsink1> remove client with host localhost, port 4951
0:00:00.150532498 24172 0x174b080 DEBUG multiudpsink gstmultiudpsink.c:1056:gst_multiudpsink_add_internal:<udpsink1> adding client on host 226.255.0.48, port 5002
0:00:00.150679458 24172 0x174b080 DEBUG multiudpsink gstmultiudpsink.c:1084:gst_multiudpsink_add_internal:<udpsink1> add client with host 226.255.0.48, port 5002
0:00:00.150719987 24172 0x174b080 DEBUG multiudpsink gstmultiudpsink.c:1094:gst_multiudpsink_add_internal:<udpsink1> added client on host 226.255.0.48, port 5002
0:00:00.150865844 24172 0x174b080 DEBUG multiudpsink gstmultiudpsink.c:768:gst_multiudpsink_set_property:<udpsink1> setting SOCKFD to 11
Pipeline is live and does not need PREROLL ...
Setting pipeline to PLAYING ...
Comment 2 Marc Leeman 2011-07-12 11:46:51 UTC
When the second encoder is started with:
GST_DEBUG_NO_COLOR=1 GST_DEBUG=*udpsrc*:5 gst-launch rtspsrc location=rtsp://10.3.0.171:7070 protocols=2 port-range=5000-5005 debug=1 ! fakesink

Setting pipeline to PAUSED ...
RTSP request message 0x7fff90c75de0
 request line:
   method: 'OPTIONS'
   uri: 'rtsp://10.3.0.171:7070/'
   version: '1.0'
 headers:
   key: 'User-Agent', value: 'RealMedia Player Version 6.0.9.1235 (linux-2.0-libc6-i386-gcc2.95)'
   key: 'ClientChallenge', value: '9e26d33f2984236010ef6253fb1887f7'
   key: 'CompanyID', value: 'KnKV4M4I/B2FjJ1TToLycw=='
   key: 'GUID', value: '00000000-0000-0000-0000-000000000000'
   key: 'RegionData', value: '0'
   key: 'PlayerStarttime', value: '[28/03/2003:22:50:23 00:00]'
   key: 'ClientID', value: 'Linux_2.4_6.0.9.1235_play32_RN01_EN_586'
 body:
RTSP response message 0x7fff90c75da0
 status line:
   code: '200'
   reason: 'OK'
   version: '1.0'
 headers:
   key: 'CSeq', value: '1'
   key: 'Date', value: 'Tue, Jul 12 2011 11:13:43 GMT'
   key: 'Public', value: 'OPTIONS'
   key: 'Public', value: 'DESCRIBE'
   key: 'Public', value: 'SETUP'
   key: 'Public', value: 'PLAY'
   key: 'Public', value: 'TEARDOWN'
 body: length 0
RTSP request message 0x7fff90c75de0
 request line:
   method: 'DESCRIBE'
   uri: 'rtsp://10.3.0.171:7070/'
   version: '1.0'
 headers:
   key: 'Accept', value: 'application/sdp'
 body:
RTSP response message 0x7fff90c75da0
 status line:
   code: '200'
   reason: 'OK'
   version: '1.0'
 headers:
   key: 'CSeq', value: '2'
   key: 'Date', value: 'Tue, Jul 12 2011 11:13:43 GMT'
   key: 'Content-Base', value: 'rtsp://10.3.0.171:7070/'
   key: 'Content-Type', value: 'application/sdp'
   key: 'Content-Length', value: '436'
 body: length 437
00000000 (0x2675b40): 76 3d 30 0d 0a 6f 3d 2d 20 31 33 31 30 34 36 39 v=0..o=- 1310469
00000010 (0x2675b50): 32 32 33 30 30 39 36 33 35 35 36 20 31 20 49 4e 22300963556 1 IN
00000020 (0x2675b60): 20 49 50 34 20 32 32 36 2e 32 35 35 2e 30 2e 31 IP4 226.255.0.1
00000030 (0x2675b70): 37 31 0d 0a 73 3d 53 65 73 73 69 6f 6e 20 73 74 71..s=Session st
00000040 (0x2675b80): 72 65 61 6d 65 64 20 62 79 20 52 54 50 2f 52 54 reamed by RTP/RT
00000050 (0x2675b90): 53 50 20 73 65 72 76 65 72 0d 0a 69 3d 41 43 54 SP server..i=ACT
00000060 (0x2675ba0): 69 2e 43 4f 4d 20 53 74 72 65 61 6d 69 6e 67 20 i.COM Streaming
00000070 (0x2675bb0): 4d 65 64 69 61 20 76 0d 0a 74 3d 30 20 30 0d 0a Media v..t=0 0..
00000080 (0x2675bc0): 61 3d 74 6f 6f 6c 3a 41 43 54 69 2e 43 4f 4d 20 a=tool:ACTi.COM
00000090 (0x2675bd0): 53 74 72 65 61 6d 69 6e 67 20 4d 65 64 69 61 20 Streaming Media
000000a0 (0x2675be0): 76 32 30 30 36 2e 31 30 2e 32 32 0d 0a 61 3d 74 v2006.10.22..a=t
000000b0 (0x2675bf0): 79 70 65 3a 62 72 6f 61 64 63 61 73 74 0d 0a 61 ype:broadcast..a
000000c0 (0x2675c00): 3d 63 6f 6e 74 72 6f 6c 3a 2a 0d 0a 61 3d 72 61 =control:*..a=ra
000000d0 (0x2675c10): 6e 67 65 3a 6e 74 70 3d 30 2d 0d 0a 6d 3d 76 69 nge:ntp=0-..m=vi
000000e0 (0x2675c20): 64 65 6f 20 35 30 30 30 20 52 54 50 2f 41 56 50 deo 5000 RTP/AVP
000000f0 (0x2675c30): 20 39 36 0d 0a 63 3d 49 4e 20 49 50 34 20 32 32 96..c=IN IP4 22
00000100 (0x2675c40): 36 2e 32 35 35 2e 30 2e 31 37 31 0d 0a 61 3d 72 6.255.0.171..a=r
00000110 (0x2675c50): 74 70 6d 61 70 3a 39 36 20 4d 50 34 56 2d 45 53 tpmap:96 MP4V-ES
00000120 (0x2675c60): 2f 39 30 30 30 30 0d 0a 61 3d 66 6d 74 70 3a 39 /90000..a=fmtp:9
00000130 (0x2675c70): 36 20 70 72 6f 66 69 6c 65 2d 6c 65 76 65 6c 2d 6 profile-level-
00000140 (0x2675c80): 69 64 3d 32 34 35 3b 63 6f 6e 66 69 67 3d 30 30 id=245;config=00
00000150 (0x2675c90): 30 30 30 31 42 30 30 33 30 30 30 30 30 31 42 35 0001B003000001B5
00000160 (0x2675ca0): 30 39 30 30 30 30 30 31 30 30 30 30 30 30 30 31 0900000100000001
00000170 (0x2675cb0): 32 30 30 30 38 36 43 34 30 30 36 37 30 43 35 41 200086C400670C5A
00000180 (0x2675cc0): 31 31 32 30 35 31 38 46 30 30 30 30 30 31 42 33 1120518F000001B3
00000190 (0x2675cd0): 30 30 31 30 30 37 30 30 30 30 30 31 42 36 0d 0a 001007000001B6..
000001a0 (0x2675ce0): 61 3d 63 6f 6e 74 72 6f 6c 3a 74 72 61 63 6b 31 a=control:track1
000001b0 (0x2675cf0): 0d 0a 0d 0a 00 .....
sdp packet 0x2675f30:
 version: '0'
 origin:
  username: '-'
  sess_id: '131046922300963556'
  sess_version: '1'
  nettype: 'IN'
  addrtype: 'IP4'
  addr: '226.255.0.171'
 session_name: 'Session streamed by RTP/RTSP server'
 information: 'ACTi.COM Streaming Media v'
 uri: '(NULL)'
 connection:
  nettype: '(NULL)'
  addrtype: '(NULL)'
  address: '(NULL)'
  ttl: '0'
  addr_number: '0'
 key:
  type: '(NULL)'
  data: '(NULL)'
 attributes:
  attribute 'tool' : 'ACTi.COM Streaming Media v2006.10.22'
  attribute 'type' : 'broadcast'
  attribute 'control' : '*'
  attribute 'range' : 'ntp=0-'
 medias:
  media 0:
   media: 'video'
   port: '5000'
   num_ports: '4294967295'
   proto: 'RTP/AVP'
   formats:
    format '96'
   information: '(NULL)'
   connections:
    nettype: 'IN'
    addrtype: 'IP4'
    address: '226.255.0.171'
    ttl: '0'
    addr_number: '0'
   key:
    type: '(NULL)'
    data: '(NULL)'
   attributes:
    attribute 'rtpmap' : '96 MP4V-ES/90000'
    attribute 'fmtp' : '96 profile-level-id=245;config=000001B003000001B50900000100000001200086C400670C5A1120518F000001B3001007000001B6'
    attribute 'control' : 'track1'
0:00:00.127953443 24468 0x248d080 DEBUG udpsrc gstudpsrc.c:784:gst_udpsrc_start:<udpsrc0> allocating socket for 0.0.0.0:5000
0:00:00.128229858 24468 0x248d080 DEBUG udpsrc gstudpsrc.c:795:gst_udpsrc_start:<udpsrc0> got socket 8
0:00:00.128269443 24468 0x248d080 DEBUG udpsrc gstudpsrc.c:797:gst_udpsrc_start:<udpsrc0> setting reuse 0
0:00:00.128306492 24468 0x248d080 DEBUG udpsrc gstudpsrc.c:804:gst_udpsrc_start:<udpsrc0> binding on port 5000
0:00:00.128387183 24468 0x248d080 WARN udpsrc gstudpsrc.c:945:gst_udpsrc_start:<udpsrc0> error: bind failed -1: Address already in use (98)
0:00:00.129343393 24468 0x248d080 DEBUG udpsrc gstudpsrc.c:784:gst_udpsrc_start:<udpsrc1> allocating socket for 0.0.0.0:5002
0:00:00.129582886 24468 0x248d080 DEBUG udpsrc gstudpsrc.c:795:gst_udpsrc_start:<udpsrc1> got socket 8
0:00:00.129687817 24468 0x248d080 DEBUG udpsrc gstudpsrc.c:797:gst_udpsrc_start:<udpsrc1> setting reuse 0
0:00:00.129725407 24468 0x248d080 DEBUG udpsrc gstudpsrc.c:804:gst_udpsrc_start:<udpsrc1> binding on port 5002
0:00:00.129807395 24468 0x248d080 WARN udpsrc gstudpsrc.c:945:gst_udpsrc_start:<udpsrc1> error: bind failed -1: Address already in use (98)
0:00:00.130703703 24468 0x248d080 DEBUG udpsrc gstudpsrc.c:784:gst_udpsrc_start:<udpsrc2> allocating socket for 0.0.0.0:5004
0:00:00.130932081 24468 0x248d080 DEBUG udpsrc gstudpsrc.c:795:gst_udpsrc_start:<udpsrc2> got socket 8
0:00:00.130969783 24468 0x248d080 DEBUG udpsrc gstudpsrc.c:797:gst_udpsrc_start:<udpsrc2> setting reuse 0
0:00:00.131005947 24468 0x248d080 DEBUG udpsrc gstudpsrc.c:804:gst_udpsrc_start:<udpsrc2> binding on port 5004
0:00:00.131047886 24468 0x248d080 DEBUG udpsrc gstudpsrc.c:853:gst_udpsrc_start:<udpsrc2> setting udp buffer of 524288 bytes
0:00:00.131086503 24468 0x248d080 DEBUG udpsrc gstudpsrc.c:873:gst_udpsrc_start:<udpsrc2> have udp buffer of 262142 bytes
0:00:00.131125052 24468 0x248d080 DEBUG udpsrc gstudpsrc.c:906:gst_udpsrc_start:<udpsrc2> bound, on port 5004
0:00:00.131232645 24468 0x248d080 LOG udpsrc gstudpsrc.c:992:gst_udpsrc_unlock_stop:<udpsrc2> No longer flushing
0:00:00.132447495 24468 0x248d080 DEBUG udpsrc gstudpsrc.c:784:gst_udpsrc_start:<udpsrc3> allocating socket for 0.0.0.0:5005
0:00:00.132750114 24468 0x248d080 DEBUG udpsrc gstudpsrc.c:795:gst_udpsrc_start:<udpsrc3> got socket 11
0:00:00.132790861 24468 0x248d080 DEBUG udpsrc gstudpsrc.c:797:gst_udpsrc_start:<udpsrc3> setting reuse 0
0:00:00.132828855 24468 0x248d080 DEBUG udpsrc gstudpsrc.c:804:gst_udpsrc_start:<udpsrc3> binding on port 5005
0:00:00.132931236 24468 0x248d080 DEBUG udpsrc gstudpsrc.c:873:gst_udpsrc_start:<udpsrc3> have udp buffer of 126976 bytes
0:00:00.132972890 24468 0x248d080 DEBUG udpsrc gstudpsrc.c:906:gst_udpsrc_start:<udpsrc3> bound, on port 5005
0:00:00.133060121 24468 0x248d080 LOG udpsrc gstudpsrc.c:992:gst_udpsrc_unlock_stop:<udpsrc3> No longer flushing
RTSP request message 0x7fff90c75c10
 request line:
   method: 'SETUP'
   uri: 'rtsp://10.3.0.171:7070/track1'
   version: '1.0'
 headers:
   key: 'Transport', value: 'RTP/AVP;multicast;client_port=5004-5005'
 body:
RTSP response message 0x7fff90c75bd0
 status line:
   code: '404'
   reason: 'Stream Not Found'
   version: '1.0'
 headers:
   key: 'CSeq', value: '3'
   key: 'Date', value: 'Tue, Jul 12 2011 11:13:43 GMT'
 body: length 0
0:00:00.155046443 24468 0x248d080 LOG udpsrc gstudpsrc.c:979:gst_udpsrc_unlock:<udpsrc2> Flushing
0:00:00.155091225 24468 0x248d080 LOG udpsrc gstudpsrc.c:992:gst_udpsrc_unlock_stop:<udpsrc2> No longer flushing
0:00:00.155266107 24468 0x248d080 DEBUG udpsrc gstudpsrc.c:1005:gst_udpsrc_stop: stopping, closing sockets
0:00:00.155543287 24468 0x248d080 LOG udpsrc gstudpsrc.c:979:gst_udpsrc_unlock:<udpsrc3> Flushing
0:00:00.155586179 24468 0x248d080 LOG udpsrc gstudpsrc.c:992:gst_udpsrc_unlock_stop:<udpsrc3> No longer flushing
0:00:00.155774606 24468 0x248d080 DEBUG udpsrc gstudpsrc.c:1005:gst_udpsrc_stop: stopping, closing sockets
ERROR: Pipeline doesn't want to pause.
ERROR: from element /GstPipeline:pipeline0/GstRTSPSrc:rtspsrc0: Could not write to resource.
Additional debug info:
gstrtspsrc.c(5184): gst_rtspsrc_setup_streams (): /GstPipeline:pipeline0/GstRTSPSrc:rtspsrc0:
Error (404): Not Found
Setting pipeline to NULL ...
Freeing pipeline ...
Comment 3 David Schleef 2011-07-13 05:55:53 UTC
Why are you using port-range=...?
Comment 4 Marc Leeman 2011-07-13 12:04:03 UTC
You are right; the port range is not really needed; the problem still remains.

In essence; I think that the encoder is doing something wrong in the SETUP phase (not suggesting the correct ports, but just replying with Not Found); but we get there due to attempt to setup unicast ports on our side; while we know it should be multicast since the SDP told us already.

I have two encoders of the same make; encoder A and encoder B. Encoder A seems to be a slightly more recent version wrt to encoder B. Starting A before B triggers the issue; while starting B before A does not (encoder A corrects the ports in the SETUP reply).

No doubt that this is wrong by the encoder B; this is what encoder B sends me after I started encoder A:

RTSP request message 0x7fffbe970ab0
 request line:
   method: 'SETUP'
   uri:    'rtsp://10.3.0.171:7070/track1'
   version: '1.0'
 headers:
   key: 'Transport', value: 'RTP/AVP;multicast;client_port=5004-5005'
 body:
RTSP response message 0x7fffbe970a70
 status line:
   code:   '404'
   reason: 'Stream Not Found'
   version: '1.0'
 headers:
   key: 'CSeq', value: '3'
   key: 'Date', value: 'Wed, Jul 13 2011 11:40:27 GMT'
 body: length 0


This is what another encoder (more recent of the same make) sends me after I started encoder A before B.

RTSP request message 0x7fffc6c518d0
 request line:
   method: 'SETUP'
   uri:    'rtsp://10.3.0.48:7070//track1'
   version: '1.0'
 headers:
   key: 'Transport', value: 'RTP/AVP;multicast;client_port=5002-5003'
 body:
RTSP response message 0x7fffc6c51890
 status line:
   code:   '200'
   reason: 'OK'
   version: '1.0'
 headers:
   key: 'CSeq', value: '3'
   key: 'Date', value: 'Fri, Mar 23 2007 18:02:31 GMT'
   key: 'Transport', value: 'RTP/AVP;multicast;destination=226.255.0.48;port=5000;ttl=255'
   key: 'Session', value: '163'
 body: length 0

The major issue is that encoder B just fails if it gets the SETUP with the wrong port combination; while encoder A accepts the setup but corrects the port in the reply. udpsrc is then able to bind on the port since it opens on multicast (shared=0).

BUT, we only got there due to this phase in the negociation:
0:00:00.369336740 19720      0x25be0c0 DEBUG                 udpsrc gstudpsrc.c:784:gst_udpsrc_start:<udpsrc0> allocating socket for 0.0.0.0:5000
0:00:00.369624127 19720      0x25be0c0 DEBUG                 udpsrc gstudpsrc.c:795:gst_udpsrc_start:<udpsrc0> got socket 10
0:00:00.369665497 19720      0x25be0c0 DEBUG                 udpsrc gstudpsrc.c:797:gst_udpsrc_start:<udpsrc0> setting reuse 0
0:00:00.369704946 19720      0x25be0c0 DEBUG                 udpsrc gstudpsrc.c:804:gst_udpsrc_start:<udpsrc0> binding on port 5000
0:00:00.369789664 19720      0x25be0c0 WARN                  udpsrc gstudpsrc.c:945:gst_udpsrc_start:<udpsrc0> error: bind failed -1: Address already in use (98)
0:00:00.370732089 19720      0x25be0c0 DEBUG                 udpsrc gstudpsrc.c:784:gst_udpsrc_start:<udpsrc1> allocating socket for 0.0.0.0:5002
0:00:00.370974259 19720      0x25be0c0 DEBUG                 udpsrc gstudpsrc.c:795:gst_udpsrc_start:<udpsrc1> got socket 10
0:00:00.371013078 19720      0x25be0c0 DEBUG                 udpsrc gstudpsrc.c:797:gst_udpsrc_start:<udpsrc1> setting reuse 0
0:00:00.371052355 19720      0x25be0c0 DEBUG                 udpsrc gstudpsrc.c:804:gst_udpsrc_start:<udpsrc1> binding on port 5002
0:00:00.371096882 19720      0x25be0c0 DEBUG                 udpsrc gstudpsrc.c:853:gst_udpsrc_start:<udpsrc1> setting udp buffer of 524288 bytes
0:00:00.371137838 19720      0x25be0c0 DEBUG                 udpsrc gstudpsrc.c:873:gst_udpsrc_start:<udpsrc1> have udp buffer of 262142 bytes
0:00:00.371295943 19720      0x25be0c0 DEBUG                 udpsrc gstudpsrc.c:906:gst_udpsrc_start:<udpsrc1> bound, on port 5002
0:00:00.371423726 19720      0x25be0c0 LOG                   udpsrc gstudpsrc.c:992:gst_udpsrc_unlock_stop:<udpsrc1> No longer flushing
0:00:00.372628098 19720      0x25be0c0 DEBUG                 udpsrc gstudpsrc.c:784:gst_udpsrc_start:<udpsrc2> allocating socket for 0.0.0.0:5003
0:00:00.372879650 19720      0x25be0c0 DEBUG                 udpsrc gstudpsrc.c:795:gst_udpsrc_start:<udpsrc2> got socket 13
0:00:00.372918492 19720      0x25be0c0 DEBUG                 udpsrc gstudpsrc.c:797:gst_udpsrc_start:<udpsrc2> setting reuse 0
0:00:00.372957596 19720      0x25be0c0 DEBUG                 udpsrc gstudpsrc.c:804:gst_udpsrc_start:<udpsrc2> binding on port 5003
0:00:00.373004080 19720      0x25be0c0 DEBUG                 udpsrc gstudpsrc.c:873:gst_udpsrc_start:<udpsrc2> have udp buffer of 126976 bytes
0:00:00.373045067 19720      0x25be0c0 DEBUG                 udpsrc gstudpsrc.c:906:gst_udpsrc_start:<udpsrc2> bound, on port 5003
0:00:00.373131960 19720      0x25be0c0 LOG                   udpsrc gstudpsrc.c:992:gst_udpsrc_unlock_stop:<udpsrc2> No longer flushing

If this unicast setup could be skipped once we know it is multicast (cf. SDP); this problem could be avoided.

It seems to be a poor reaction of the encoder based on something we should not do...
Comment 5 Marc Leeman 2011-07-13 12:21:09 UTC
  reuse               : Enable reuse of the port
                        flags: readable, writable
                        Boolean. Default: true Current: true
Comment 6 David Schleef 2011-07-13 23:12:12 UTC
It's sort of questionable why we're binding to 0.0.0.0:${port}.  That is just asking for port collisions.
Comment 7 Wim Taymans 2012-11-16 11:36:42 UTC
Can you check if this is fixed with #639420?
Comment 8 Wim Taymans 2012-11-16 11:37:51 UTC
The reason why I think it's probably fixed is because we don't actually allocate the ports in multicast anymore.