RTSP output stream dies quite often:0.9.2

[bulek]

Hi,

I've compiled 0.9.2 release on Kubuntu 710 in hope that rtsp will work better, but since I get same odd behaviour as I did on stock VLC release 0.8.6c, probably I'm doing something wrong or getting into known and unsolved problems...

I have VLC 0.9.2 as VOD server on Linux machine and VLC 0.9.2 on winxp as client (I'm using RTSP streaming cause would also like to server Mythtv via Freebox plugin). It works ok for few minutes, and then picture on client freezes and it goes after timeout to next channel. STB on same streams works witout problems all the time - therefore I don't suspect problems in udp streams...

I'm running VOD server with :

Code: Select all

vlc-wrapper -vvv --color -I telnet --telnet-password toto --rtsp-host 192.168.0.1:9001 --vlm-conf /etc/vlm.conf

and have

Code: Select all

new siol_testni vod input udp://@239.255.0.200:5002 mux mp2t enabled

in /etc/vlm/conf.

Output of VLC server :

[00000522] [Media: siol_testni] main mux warning: late buffer for mux input (3684)
[00000522] [Media: siol_testni] main mux warning: late buffer for mux input (26000)
[00000416] vod_rtsp vod server debug: RtspCallback query: type=11


[00000522] [Media: siol_testni] main mux warning: late buffer for mux input (56)
[00000416] vod_rtsp vod server debug: RtspCallback query: type=11
[00000522] [Media: siol_testni] main mux warning: late buffer for mux input (28798)
[00000522] [Media: siol_testni] main mux warning: late buffer for mux input (19601)
[00000522] [Media: siol_testni] main mux warning: late buffer for mux input (9351)


[00000416] vod_rtsp vod server debug: RtspCallback query: type=12
[00000416] vod_rtsp vod server debug: HTTPD_MSG_TEARDOWN for session: 1804289383
[00000416] vod_rtsp vod server debug: closing session: 1804289383, connections: 0
[00000526] [Media: siol_testni] main access debug: waitpipe: object killed
[00000526] [Media: siol_testni] main access debug: socket 13 polling interrupted
[00000528] [Media: siol_testni] ts demux debug: eof ?
[00000517] [Media: siol_testni] main input debug: EOF reached
[00000517] [Media: siol_testni] main input debug: control type=0
[00000517] [Media: siol_testni] main input debug: control: stopping input
[00000528] [Media: siol_testni] ts demux debug: pid list:
[00000528] [Media: siol_testni] ts demux debug: - pid[0] seen
[00000528] [Media: siol_testni] ts demux debug: - pid[47] seen
[00000529] [Media: siol_testni] main packetizer debug: removing module "packetizer_mpegvideo"
[00000529] [Media: siol_testni] main packetizer debug: thread ended
[00000529] [Media: siol_testni] main packetizer debug: thread 2955705232 joined (input/decoder.c:248)
[00000529] [Media: siol_testni] main packetizer debug: killing decoder fourcc `mpgv', 0 PES in FIFO
[00000518] main stream output debug: removing a sout input (sout_input:0x8206828)
[00000522] mux_ts mux debug: removing input pid=69
[00000522] mux_ts mux debug: new PCR PID is 68
[00000528] [Media: siol_testni] ts demux debug: - pid[218] seen
[00000530] [Media: siol_testni] main packetizer debug: removing module "mpeg_audio"
[00000530] [Media: siol_testni] main packetizer debug: thread ended
[00000530] [Media: siol_testni] main packetizer debug: thread 2947312528 joined (input/decoder.c:248)
[00000530] [Media: siol_testni] main packetizer debug: killing decoder fourcc `mpga', 0 PES in FIFO
[00000518] main stream output debug: removing a sout input (sout_input:0x8207b38)
[00000522] mux_ts mux debug: removing input pid=68
[00000522] mux_ts mux debug: new PCR PID is 8191
[00000522] main mux warning: no more input streams for this mux
[00000517] [Media: siol_testni] main input debug: Program doesn't contain anymore ES
[00000528] [Media: siol_testni] ts demux debug: - pid[219] seen
[00000528] [Media: siol_testni] ts demux debug: - pid[8191] seen
[00000528] [Media: siol_testni] main demux debug: removing module "ts"
[00000526] [Media: siol_testni] main access debug: removing module "access_udp"
[00000517] [Media: siol_testni] main input debug: thread ended
[00000517] [Media: siol_testni] main input debug: thread 2972490640 joined (input/vlm.c:776)
[00000517] [Media: siol_testni] main input debug: TIMER input launching for '(null)' : 83.045 ms - Total 83.045 ms / 1 intvls (Avg 83.045 ms)
[00000519] main stream out debug: destroying chain... (name=rtp)
[00000524] main generic debug: thread ended
[00000524] main generic debug: thread 2964097936 joined (rtp.c:1273)
[00000522] main mux debug: removing module "mux_ts"
[00000519] main stream out debug: removing module "stream_out_rtp"
[00000519] main stream out debug: destroying chain done

Output of vlc client:

main debug: decoded 103/105 pictures
main warning: buffer is 41492 late, triggering upsampling
main warning: resampling stopped after 21903000 usec (drift: 13878)
main warning: buffer is 40499 late, triggering upsampling
main warning: resampling stopped after 15611000 usec (drift: 3952)
live555 debug: reset the timeout timer
main warning: buffer is 40134 late, triggering upsampling
main warning: resampling stopped after 12810000 usec (drift: 1890)
main warning: buffer is 40033 late, triggering upsampling
live555 debug: reset the timeout timer
main warning: resampling stopped after 11101000 usec (drift: 1411)
live555 warning: no data received in 10s, eof ?
main debug: EOF reached
main debug: finished input
main debug: dying input
qt4 debug: Updating the stream status: 8
main debug: dying input
ts debug: eof ?
main debug: thread ended
main debug: thread times: real 2m49.984375s, kernel 0m0.328125s, user 0m0.546875s
main debug: thread 6696 joined (input/demux.c:385)
ts debug: pid list:
ts debug: - pid[0] seen
ts debug: - pid[66] seen
main debug: removing module "mpeg_audio"
main debug: thread ended
main debug: dying input
main debug: thread times: real 2m48.203125s, kernel 0m0.000000s, user 0m2.125000s
main debug: thread 6616 joined (input/decoder.c:248)
main debug: killing decoder fourcc `mpga', 0 PES in FIFO
main debug: removing module "mpgatofixed32"
main debug: removing module "bandlimited_resampler"
aout_directx debug: closing audio device
main debug: thread ended
aout_directx debug: DirectSoundThread exiting
main debug: thread ended
main debug: thread times: real 2m48.234375s, kernel 0m0.000000s, user 0m0.000000s
main debug: thread 7336 joined (directx.c:664)
main debug: removing module "aout_directx"
main debug: removing module "converter_float"
main debug: removing module "float32_mixer"
ts debug: - pid[68] seen
main debug: removing module "libmpeg2"
main debug: thread ended
main debug: thread times: real 2m48.250000s, kernel 0m0.203125s, user 0m4.234375s
main debug: thread 6572 joined (input/decoder.c:248)
main debug: killing decoder fourcc `mpgv', 0 PES in FIFO
vout_directx debug: DirectXCloseSurface
main debug: dying input
vout_directx debug: DirectXCloseDisplay
vout_directx debug: DirectXCloseDisplay clipper
vout_directx debug: DirectXCloseDisplay display
main debug: dying input
vout_directx debug: DirectXCloseDDraw
main debug: removing module "blend"
main debug: thread times: real 0m0.000000s, kernel 0m0.000000s, user 0m0.000000s
main debug: thread 7452 joined (freetype.c:511)
main debug: removing module "freetype"
main debug: thread ended
main debug: thread times: real 2m48.187500s, kernel 0m0.203125s, user 0m3.218750s
main debug: thread 7400 joined (video_output/video_output.c:536)
vout_directx debug: CloseVideo
vout_directx debug: DirectXEventThread terminating
vout_directx debug: DirectXCloseWindow
vout_directx debug: WinProc WM_DESTROY
main debug: removing module "qt4"
qt4 debug: Video is not needed anymore
main debug: thread ended
main debug: thread times: real 2m48.312500s, kernel 0m0.015625s, user 0m0.015625s
main debug: thread 7248 joined (directx.c:507)
main debug: removing module "vout_directx"
main debug: Program doesn't contain anymore ES
ts debug: - pid[69] seen
ts debug: - pid[8191] seen
main debug: removing module "ts"
qt4 debug: Updating the geometry
main debug: thread times: real 2m49.984375s, kernel 0m0.000000s, user 0m0.000000s
main debug: thread 6668 joined (live555.cpp:459)
main debug: removing module "live555"
main debug: thread ended
main debug: dead input
main debug: thread times: real 2m50.390625s, kernel 0m1.281250s, user 0m0.796875s
main debug: thread 6784 joined (playlist/engine.c:244)
main debug: TIMER input launching for 'SIOL TESTNI KANAL' : 318.000 ms - Total 318.000 ms / 1 intvls (Avg 318.000 ms)
main debug: starting new item
main debug: changing item without a request (current 36/38)
main debug: using item 37
main debug: creating new input thread
main debug: Creating an input for 'MPEG TESTNI KANAL'
main debug: waiting for thread initialization
main debug: thread started
main debug: thread 6872 (input) created at priority 1 (input/input.c:368)
qt4 debug: Updating the stream status: 3
main debug: `rtsp://192.168.0.1:9001/test ' gives access `rtsp' demux `' path `192.168.0.1:9001/test '
main debug: creating demux: access='rtsp' demux='' path='192.168.0.1:9001/test '
main debug: looking for access_demux module: 1 candidate
live555 debug: DESCRIBE failed with 404: cannot handle DESCRIBE response: RTSP/1.0 404 Not found
live555 debug: connection timeout, retrying
live555 debug: DESCRIBE failed with 404: cannot handle DESCRIBE response: RTSP/1.0 404 Not found
live555 debug: we will now try HTTP tunneling mode
live555 debug: DESCRIBE failed with 404: cannot handle HTTP GET response: HTTP/1.1 404 Not Found
live555 debug: connection timeout, retrying
live555 error: Failed to connect with rtsp://192.168.0.1:9001/test+
main warning: no access_demux module matching "rtsp" could be loaded
main debug: TIMER module_Need() : 126.000 ms - Total 126.000 ms / 1 intvls (Avg 126.000 ms)
main debug: creating access 'rtsp' path='192.168.0.1:9001/test '
qt4 debug: New Event: type 1103
qt4 debug: Updating the stream status: 1
main debug: looking for access module: 1 candidate
main debug: net: connecting to 192.168.0.1 port 9001
main debug: connection: Resource temporarily unavailable
main debug: connection succeeded (socket = 6680)
access_realrtsp debug: rtsp connected
access_realrtsp warning: only real/helix rtsp servers supported for now
main warning: no access module matching "rtsp" could be loaded
main debug: TIMER module_Need() : 23.000 ms - Total 23.000 ms / 1 intvls (Avg 23.000 ms)
main debug: waitpipe: object killed
main error: open of `rtsp://192.168.0.1:9001/test ' failed: could not create access
qt4 debug: Destroy the Interaction Dialog
qt4 debug: Hide the Interaction Dialog
qt4 debug: New Event: type 1103
qt4 debug: Updating the stream status: 9
qt4 debug: New Event: type 1103
qt4 debug: New Event: type 1103
main debug: finished input
main debug: dying input
main debug: thread ended
main debug: dead input
main debug: thread times: real 0m0.250000s, kernel 0m0.015625s, user 0m0.000000s
main debug: thread 6872 joined (playlist/engine.c:244)
qt4 debug: Updating the stream status: 8
main debug: TIMER input launching for 'MPEG TESTNI KANAL' : 269.000 ms - Total 269.000 ms / 1 intvls (Avg 269.000 ms)
main debug: starting new item
main debug: changing item without a request (current 37/38)
main debug: nothing to play

I'd kindly ask if more experienced users can give me some guidance, what is wrong in that case...

Is VLC as RTSP streamer stable enough for production use ?

Thanks in advance,

regards,

Bulek.

[bulek]

Hi,

I+m still banging my head with this problem. I tried to eliminate streaming scenario and used vlc only to receive original udp mpeg2 stream and show it on desktop and exactly same thing happens (as I described above when using one vlc as rtsp server (transcodes udp streams to rtsp) and other vlc as client....

There seems nothing usefull in messages about that behaviour. It just freezes fairly quickly (up to few minutes)...

Anyone has idea what might be going on ? If I connect winxp laptop on same ethernet network with vlc it works ok, without interruptions...

Thanks in advance,

regards,

Bulek.

[bulek]

Hi,

after some time I maybe got to the right track to solution...

My ISP confirmed that death after 5 mins is cause by their servers, cause my system doesn't response to IGMP queries. They send each query every minute and when they get no response to 5 of them, they cut the stream. Now my system has to rejoin stream for another 5 mins..

The main question is what to do know, to respond to those igmp queries ?
Is it enough to replace udp with igmp in play URLs ?
How to solve it ?

Interesting fact: if i put Winxp with vlc on same network, it won't die, my linux vlc viewer dies after 5mins. What is the difference between Winxp and linux regarding igmp (vlc versions are the same 0.9.4 if I remember right)...

Thanks in advance,

regards,

Bulek.

[Rémi Denis-Courmont]

IGMP is handled by the operating system, not VLC. Check that your firewall, routing and interface settings are correct.

[bulek]

IGMP is handled by the operating system, not VLC. Check that your firewall, routing and interface settings are correct.

Hi,

everything seems ok, only potential problem is that I have several network cards and I'm receiving IPTV stream on one of them.

My ISP confirmed that my streams die after determined time cause I don't reply to IGMP queries. Now I'd like to find the reason. I'd kindly ask if anyone more experienced can help me with following questions:
- OS: I'm using KUbuntu 710. Is this OS considered or generaly present Linux OSes) as proper handling of IGMP packets ?

I have done some sniffing with tcpdump -i eth3 -x -v igmp

and I got following. I'm not an network expert, but it seems that at the start my system reports joining to group and when the stream dies it sends leave IGMP packet. What is the problem is that it doesn't responsd to IGMP in the mean time - my ISP waits for 5 unsucessful IGMP queries and then aborts stream....

How can I fix that behaviour ?
I'm aware that this is probably more OS problem, but VLC obviously tells OS to report and leave on stream start and end, so maybe also VLC should tell it to respond to queries ?

Got this with tcpdump (XXX.XXX.XXX.XXX is my ip of network interface for IPTV):

11:09:36.603980 IP (tos 0xc0, ttl 1, id 0, offset 0, flags [DF], proto IGMP (2), length 32, options (RA)) 10.134.127.235 > 239.255.0.124: igmp v2 report 239.255.0.124
0x0000: 46c0 0020 0000 4000 0102 692b 0a86 7feb
0x0010: efff 007c 9404 0000 1600 f983 efff 007c
11:09:37.383951 IP (tos 0xc0, ttl 1, id 0, offset 0, flags [DF], proto IGMP (2), length 32, options (RA)) 10.134.127.235 > 239.255.0.124: igmp v2 report 239.255.0.124
0x0000: 46c0 0020 0000 4000 0102 692b 0a86 7feb
0x0010: efff 007c 9404 0000 1600 f983 efff 007c
11:09:42.171937 IP (tos 0xc0, ttl 1, id 0, offset 0, flags [DF], proto IGMP (2), length 32, options (RA)) 10.134.127.235 > 239.255.0.124: igmp v2 report 239.255.0.124
0x0000: 46c0 0020 0000 4000 0102 692b 0a86 7feb
0x0010: efff 007c 9404 0000 1600 f983 efff 007c
11:09:50.687119 IP (tos 0x0, ttl 1, id 60806, offset 0, flags [none], proto IGMP (2), length 28) 10.134.64.1 > ALL-SYSTEMS.MCAST.NET: igmp query v2
0x0000: 4500 001c ed86 0000 0102 a1d1 0a86 4001
0x0010: e000 0001 1164 ee9b 0000 0000 0000 0000
0x0020: 0000 0000 0000 0000 0000 0000 0000
11:10:51.228286 IP (tos 0x0, ttl 1, id 61324, offset 0, flags [none], proto IGMP (2), length 28) 10.134.64.1 > ALL-SYSTEMS.MCAST.NET: igmp query v2
0x0000: 4500 001c ef8c 0000 0102 9fcb 0a86 4001
0x0010: e000 0001 1164 ee9b 0000 0000 0000 0000
0x0020: 0000 0000 0000 0000 0000 0000 0000
11:11:51.665890 IP (tos 0x0, ttl 1, id 61742, offset 0, flags [none], proto IGMP (2), length 28) 10.134.64.1 > ALL-SYSTEMS.MCAST.NET: igmp query v2
0x0000: 4500 001c f12e 0000 0102 9e29 0a86 4001
0x0010: e000 0001 1164 ee9b 0000 0000 0000 0000
0x0020: 0000 0000 0000 0000 0000 0000 0000
11:12:52.253514 IP (tos 0x0, ttl 1, id 62239, offset 0, flags [none], proto IGMP (2), length 28) 10.134.64.1 > ALL-SYSTEMS.MCAST.NET: igmp query v2
0x0000: 4500 001c f31f 0000 0102 9c38 0a86 4001
0x0010: e000 0001 1164 ee9b 0000 0000 0000 0000
0x0020: 0000 0000 0000 0000 0000 0000 0000
11:13:52.515966 IP (tos 0x0, ttl 1, id 62775, offset 0, flags [none], proto IGMP (2), length 28) 10.134.64.1 > ALL-SYSTEMS.MCAST.NET: igmp query v2
0x0000: 4500 001c f537 0000 0102 9a20 0a86 4001
0x0010: e000 0001 1164 ee9b 0000 0000 0000 0000
0x0020: 0000 0000 0000 0000 0000 0000 0000
11:14:53.446270 IP (tos 0x0, ttl 1, id 63185, offset 0, flags [none], proto IGMP (2), length 28) 10.134.64.1 > ALL-SYSTEMS.MCAST.NET: igmp query v2
0x0000: 4500 001c f6d1 0000 0102 9886 0a86 4001
0x0010: e000 0001 1164 ee9b 0000 0000 0000 0000
0x0020: 0000 0000 0000 0000 0000 0000 0000
11:14:54.373948 IP (tos 0xc0, ttl 1, id 0, offset 0, flags [DF], proto IGMP (2), length 32, options (RA)) 10.134.127.235 > ALL-ROUTERS.MCAST.NET: igmp leave 239.255.0.124
0x0000: 46c0 0020 0000 4000 0102 79a4 0a86 7feb
0x0010: e000 0002 9404 0000 1700 f883 efff 007c
11:14:54.389898 IP (tos 0x0, ttl 1, id 63193, offset 0, flags [none], proto IGMP (2), length 28) 10.134.64.1 > 239.255.0.124: igmp query v2 [max resp time 10] [gaddr 239.255.0.124]
0x0000: 4500 001c f6d9 0000 0102 8804 0a86 4001
0x0010: efff 007c 110a fe79 efff 007c 0000 0000
0x0020: 0000 0000 0000 0000 0000 0000 0000

Thanks in advance,

regards,

Bulek.

[bulek]

Hi,

I found out with some help of other users that firewall caused problems. Those two working packets were only send in one way, while IGMP snooping packets showed on tcpdump, but didn't get to kernel...

Thanks in advance,

regards,

Bulek.