VLC hangs with 100% CPU-usage when streaming
Posted: 15 Feb 2006 11:02
Hello,
I've got a PC with two TV-cards installed with devices connected two the composite input. With the help of VLM I start two MMS-streams. These streams are working properly.
But I want to save these streams into files on demand with the help of VLM.
This is also working, but not every time.
I recognised that when I stop saving one stream to a file and start this process (with another file to save to) again, it sometimes hangs the whole VLC.exe. VLC.exe then has 100% CPU-usage. The mms-streams are still accesible, for example with windows media player over the network, and it tries to save the stream into a file, but i fails.
Here is the log what happens, when VLC.exe has 100% cpu-usage:
I use VLM because I can access VLC that way from my VB.NET program.
Here is an example of how that looks like:
And then I run a test programm which starts and stops saving this stream into a file every 60 seconds:
The file name is always a new one.
Sometimes its the second stream-saving when VLC.exe crashes (100% load), sometimes its the 3rd or 4th.
So my guess would be, that VLC has a problem opening a Direct-Show device (Capture1, which is a TV-card) when it has been in use by VLC some seconds before.
In my VB.NET programm I have many waits after every row I transmit over the VLM-interface, and after stopping (control xyz stop) or deleting (del xyz) I have even longer waits (some seconds)
The versions I tried was the 0.8.4a and today nightly built (15th Feb.)
Perhaps somebody has the same problems and could verify this?!
I've got a PC with two TV-cards installed with devices connected two the composite input. With the help of VLM I start two MMS-streams. These streams are working properly.
But I want to save these streams into files on demand with the help of VLM.
This is also working, but not every time.
I recognised that when I stop saving one stream to a file and start this process (with another file to save to) again, it sometimes hangs the whole VLC.exe. VLC.exe then has 100% CPU-usage. The mms-streams are still accesible, for example with windows media player over the network, and it tries to save the stream into a file, but i fails.
Here is the log what happens, when VLC.exe has 100% cpu-usage:
Code: Select all
dshow error: can't use device: none, unsupported device type
dshow error: can't open audio
dshow error: can't use device: none, unsupported device type
dshow error: can't open audio
access_mms error: cannot read data
access_mms error: cannot read data
main debug: control type=0
main debug: control: stopping input
main debug: closing input
asf debug: free asf object 0x8cabdca1-0xa947-0x11cf-0x8ee400c00c205365
asf debug: free asf object 0xc5f8cbea-0x5baf-0x4877-0x8467aa8c44fa4cca
asf debug: free asf object 0x5fbf03b5-0xa92e-0x11cf-0x8ee300c00c205365
asf debug: free asf object 0xb7dc0791-0xa9b7-0x11cf-0x8ee600c00c205365
asf debug: free asf object 0x86d15240-0x311d-0x11d0-0xa3a400a0c90348f6
asf debug: free asf object 0x75b22630-0x668e-0x11cf-0xa6d900aa0062ce6c
asf debug: free asf object 0x75b22636-0x668e-0x11cf-0xa6d900aa0062ce6c
main debug: removing module "packetizer_copy"
main debug: killing decoder fourcc `WMV2', 0 PES in FIFO
main debug: removing an input
ffmpeg debug: ffmpeg codec (Windows Media Video 2) stopped
main debug: removing module "ffmpeg"
main debug: removing module "ffmpeg"
mux_asf debug: removing input
main warning: no more input stream for this mux
main debug: Program doesn't contain anymore ES
main debug: removing module "asf"
access_mms debug: closing stream
main debug: removing module "access_mms"
main debug: destroying sout
main debug: destroying chain... (name=transcode)
main debug: destroying chain... (name=duplicate)
stream_out_duplicate debug: closing a duplication
main debug: destroying chain... (name=std)
mux_asf debug: Asf muxer closed
mux_asf debug: Asf muxer creating header
mux_asf debug: pixel aspect-ratio: 1/1
main debug: removing module "mux_asf"
access_output_file debug: file access output closed
main debug: removing module "access_output_file"
main debug: removing module "stream_out_standard"
main debug: destroying chain done
main debug: removing module "stream_out_duplicate"
main debug: destroying chain done
main debug: removing module "stream_out_transcode"
main debug: destroying chain done
main debug: thread times: real 1m0.578125s, kernel 0m0.125000s, user 0m4.046875s
main debug: thread 5272 joined (src/input/input.c:402)
stream_out_transcode debug: late picture skipped (205020)
stream_out_transcode debug: late picture skipped (190140)
stream_out_transcode debug: late picture skipped (165408)
stream_out_transcode debug: late picture skipped (150494)
stream_out_transcode debug: late picture skipped (125735)
stream_out_transcode debug: late picture skipped (110811)
stream_out_transcode debug: late picture skipped (86079)
stream_out_transcode debug: late picture skipped (71157)
stream_out_transcode debug: late picture skipped (46433)
stream_out_transcode debug: late picture skipped (31332)
stream_out_transcode debug: late picture skipped (192896)
stream_out_transcode debug: late picture skipped (178116)
stream_out_transcode debug: late picture skipped (145955)
stream_out_transcode debug: late picture skipped (131899)
stream_out_transcode debug: late picture skipped (106936)
stream_out_transcode debug: late picture skipped (92382)
stream_out_transcode debug: late picture skipped (12847)
stream_out_transcode debug: late picture skipped (17624)
stream_out_transcode debug: late picture skipped (10804)
stream_out_transcode debug: late picture skipped (15462)
stream_out_transcode debug: late picture skipped (287)
main debug: waiting for thread completion
main debug: thread 5368 (input) created at priority 1 (src/input/input.c:260)
main debug: stream=`transcode'
main debug: looking for sout stream module: 1 candidate
main debug: stream=`duplicate'
main debug: looking for sout stream module: 1 candidate
stream_out_duplicate debug: creating 'duplicate'
stream_out_duplicate debug: * adding `std{access=file,mux=asf,url="c:\Video\Calltest2.wmv"}'
main debug: stream=`std'
main debug: looking for sout stream module: 1 candidate
stream_out_transcode debug: late picture skipped (150609)
stream_out_transcode debug: late picture skipped (168291)
stream_out_transcode debug: late picture skipped (111065)
stream_out_transcode debug: late picture skipped (130315)
stream_out_transcode debug: late picture skipped (91030)
stream_out_transcode debug: late picture skipped (73737)
stream_out_transcode debug: late picture skipped (51373)
stream_out_transcode debug: late picture skipped (34041)
stream_out_transcode debug: late picture skipped (11687)
main debug: set sout option: sout-standard-access to file
main debug: set sout option: sout-standard-mux to asf
main warning: Option sout-standard-url is deprecated. You should use sout-standard-dst instead.
main debug: set sout option: sout-standard-dst to c:\Video\Calltest2.wmv
stream_out_standard debug: creating `file/asf://c:\Video\Calltest2.wmv'
stream_out_standard debug: extention is wmv
stream_out_standard debug: extention -> mux=asf
stream_out_standard debug: using `file/asf://c:\Video\Calltest2.wmv'
main debug: looking for sout access module: 1 candidate
access_output_file debug: file access output opened (`c:\Video\Calltest2.wmv')
main debug: using sout access module "access_output_file"
stream_out_standard debug: access opened
main debug: looking for sout mux module: 1 candidate
mux_asf debug: Asf muxer opened
mux_asf debug: Packet size 4096
mux_asf debug: meta data: title='' author='' copyright='' comment='' rating=''
main debug: using sout mux module "mux_asf"
stream_out_standard debug: mux opened
main debug: using sout stream module "stream_out_standard"
main debug: using sout stream module "stream_out_duplicate"
main debug: set sout option: sout-transcode-vcodec to WMV2
main debug: set sout option: sout-transcode-vb to 512
main debug: set sout option: sout-transcode-scale to 1
stream_out_transcode debug: codec video=WMV2 0x0 scaling: 1.000000 512kb/s
main debug: using sout stream module "stream_out_transcode"
main debug: `mmsh://212.63.65.137:1235' gives access `mmsh' demux `' path `212.63.65.137:1235'
main debug: creating demux: access='mmsh' demux='' path='212.63.65.137:1235'
main debug: looking for access_demux module: 0 candidates
main warning: no access_demux module matched "mmsh"
main debug: creating access 'mmsh' path='212.63.65.137:1235'
main debug: looking for access2 module: 6 candidates
main debug: net: connecting to 212.63.65.137 port 1235
main: Accepting
main debug: connection in progress
access_mms debug: HTTP reply 'HTTP/1.0 200 OK'
access_mms debug: stream type = broadcast
access_mms error: cannot read data
access_mms debug: complete header size=573
access_mms debug: packet count=4294967295 packet size=4096
stream_out_transcode debug: late picture skipped (19846)
access_mms debug: starting stream
main debug: net: connecting to 212.63.65.137 port 1235
main: Accepting
main debug: connection in progress
access_mms debug: HTTP reply 'HTTP/1.0 200 OK'
access_mms debug: Content-type: application/octet-stream
access_mms debug: Server: Cougar 4.1.0.3921
access_mms debug: Pragma: no-cache
access_mms debug: Pragma: client-id=11478
access_mms debug: Pragma: features="broadcast"
access_mms debug: Cache-Control: no-cache
main debug: using access2 module "access_mms"
main debug: pre buffering
access_mms warning: packet lost ? (0 != 1)
access_mms warning: packet lost ? (1448 != 1)
main debug: received first data for our buffer
stream_out_transcode debug: late picture skipped (8339)
main debug: prebuffering done 24576 bytes in 0s - 39 kbytes/s
stream_out_transcode debug: late picture skipped (6065)
main debug: creating demux: access='mmsh' demux='' path='212.63.65.137:1235'
main debug: looking for demux2 module: 42 candidates
asf debug: found object guid: 0x75b22630-0x668e-0x11cf-0xa6d900aa0062ce6c size:523
asf debug: read "header object" subobj:4, reserved1:1, reserved2:2
asf debug: found object guid: 0x8cabdca1-0xa947-0x11cf-0x8ee400c00c205365 size:104
asf debug: read "file properties object" file_id:0xbabac001-0x26a2-0xa57f-0x6cf833da78a44c92 file_size:573 creation_date:0 data_packets_count:4294967295 play_duration:0 send_duration:0 preroll:2000 flags:1 min_data_packet_size:4096 max_data_packet_size:4096 max_bitrate:512000
asf debug: found object guid: 0x5fbf03b5-0xa92e-0x11cf-0x8ee300c00c205365 size:156
asf debug: read "header extension object" reserved1:0xabd3d211-0xa9ba-0x11cf-0x8ee600c00c205365 reserved2:6 header_extension_size:110
asf debug: found object guid: 0xc5f8cbea-0x5baf-0x4877-0x8467aa8c44fa4cca size:110
asf debug: read "metadata object" 2 entries
asf debug: - AspectRatioX=1
asf debug: - AspectRatioY=1
asf debug: found object guid: 0xb7dc0791-0xa9b7-0x11cf-0x8ee600c00c205365 size:133
asf debug: read "stream Properties object" stream_type:0xbc19efc0-0x5b4d-0x11cf-0xa8fd00805f5c442b error_correction_type:0x20fb5700-0x5b55-0x11cf-0xa8fd00805f5c442b time_offset:0 type_specific_data_length:55 error_correction_data_length:0 flags:0x1 stream_number:1
asf debug: found object guid: 0x86d15240-0x311d-0x11d0-0xa3a400a0c90348f6 size:100
asf debug: read "codec list object" reserved_guid:0x86d15241-0x311d-0x11d0-0xa3a400a0c90348f6 codec_entries_count:1
asf debug: - codec[0] video name:"Windows Media Video 8" description:"" information_length:4
asf debug: found object guid: 0x75b22636-0x668e-0x11cf-0xa6d900aa0062ce6c size:50
asf debug: read "data object" file_id:0xbabac001-0x26a2-0xa57f-0x6cf833da78a44c92 total data packet:0 reserved:257
asf debug: + 'Unknown' GUID 0x0-0x0-0x0-0x0000000000000000 size:0pos:0
asf debug: + 'Header' GUID 0x75b22630-0x668e-0x11cf-0xa6d900aa0062ce6c size:523pos:0
asf debug: | + 'File Properties' GUID 0x8cabdca1-0xa947-0x11cf-0x8ee400c00c205365 size:104pos:30
asf debug: | + 'Header Extention' GUID 0x5fbf03b5-0xa92e-0x11cf-0x8ee300c00c205365 size:156pos:134
asf debug: | | + 'Metadata' GUID 0xc5f8cbea-0x5baf-0x4877-0x8467aa8c44fa4cca size:110pos:180
asf debug: | + 'Stream Properties' GUID 0xb7dc0791-0xa9b7-0x11cf-0x8ee600c00c205365 size:133pos:290
asf debug: | + 'Codec List' GUID 0x86d15240-0x311d-0x11d0-0xa3a400a0c90348f6 size:100pos:423
asf debug: + 'Data' GUID 0x75b22636-0x668e-0x11cf-0xa6d900aa0062ce6c size:50pos:523
asf debug: found 1 streams
main debug: selecting program id=0
asf debug: added new video stream(ID:1)
main debug: using demux2 module "asf"
main debug: looking for packetizer module: 17 candidates
main debug: using packetizer module "packetizer_copy"
main debug: stream out mode -> no decoder thread
main debug: starting in asynch mode
access_mms warning: unimplemented query in control
main debug: `mmsh://212.63.65.137:1235' successfully opened
packetizer_copy debug: need dts > 0
packetizer_copy debug: need dts > 0
packetizer_copy debug: need dts > 0
stream_out_transcode debug: late picture skipped (6063)
packetizer_copy debug: need dts > 0
packetizer_copy debug: need dts > 0
stream_out_transcode debug: late picture skipped (7828)
packetizer_copy debug: need dts > 0
main debug: adding a new input
stream_out_transcode debug: creating video transcoding from fcc=`WMV2' to fcc=`WMV2'
stream_out_transcode debug: late picture skipped (125389)
stream_out_transcode debug: late picture skipped (22134)
stream_out_transcode debug: late picture skipped (86118)
stream_out_transcode debug: late picture skipped (46638)
stream_out_transcode debug: late picture skipped (9459)
stream_out_transcode debug: late picture skipped (449)
stream_out_transcode debug: late picture skipped (4417)
stream_out_transcode debug: late picture skipped (96569)
stream_out_transcode debug: late picture skipped (78116)
stream_out_transcode debug: late picture skipped (58351)
stream_out_transcode debug: late picture skipped (39796)
stream_out_transcode debug: late picture skipped (19109)
stream_out_transcode debug: late picture skipped (522)
main debug: looking for decoder module: 26 candidates
stream_out_transcode debug: late picture skipped (75115)
stream_out_transcode debug: late picture skipped (54641)
stream_out_transcode debug: late picture skipped (35478)
stream_out_transcode debug: late picture skipped (15245)
stream_out_transcode debug: late picture skipped (80218)
stream_out_transcode debug: late picture skipped (61424)
stream_out_transcode debug: late picture skipped (40633)
stream_out_transcode debug: late picture skipped (22103)
stream_out_transcode debug: late picture skipped (1541)
ffmpeg debug: libavcodec already initialized
stream_out_transcode debug: late picture skipped (66557)
stream_out_transcode debug: late picture skipped (50340)
stream_out_transcode debug: late picture skipped (27396)
stream_out_transcode debug: late picture skipped (11428)
stream_out_transcode debug: late picture skipped (51080)
stream_out_transcode debug: late picture skipped (35470)
stream_out_transcode debug: late picture skipped (11931)
stream_out_transcode debug: late picture skipped (52272)
stream_out_transcode debug: late picture skipped (30209)
stream_out_transcode debug: late picture skipped (13080)
stream_out_transcode debug: late picture skipped (44200)
stream_out_transcode debug: late picture skipped (25986)
stream_out_transcode debug: late picture skipped (4543)
stream_out_transcode debug: late picture skipped (45154)
stream_out_transcode debug: late picture skipped (27780)
stream_out_transcode debug: late picture skipped (5983)
stream_out_transcode debug: late picture skipped (31179)
stream_out_transcode debug: late picture skipped (10526)
stream_out_transcode debug: late picture skipped (30213)
stream_out_transcode debug: late picture skipped (12168)
stream_out_transcode debug: late picture skipped (41442)
stream_out_transcode debug: late picture skipped (25332)
stream_out_transcode debug: late picture skipped (2347)
stream_out_transcode debug: late picture skipped (21974)
stream_out_transcode debug: late picture skipped (4939)
stream_out_transcode debug: late picture skipped (34622)
stream_out_transcode debug: late picture skipped (15600)
stream_out_transcode debug: late picture skipped (30527)
stream_out_transcode debug: late picture skipped (12796)
stream_out_transcode debug: late picture skipped (11751)
stream_out_transcode debug: late picture skipped (31263)
stream_out_transcode debug: late picture skipped (10186)
stream_out_transcode debug: late picture skipped (30878)
stream_out_transcode debug: late picture skipped (12276)
stream_out_transcode debug: late picture skipped (39256)
stream_out_transcode debug: late picture skipped (24816)
stream_out_transcode debug: late picture skipped (131)
stream_out_transcode debug: late picture skipped (45120)
stream_out_transcode debug: late picture skipped (33334)
stream_out_transcode debug: late picture skipped (5549)
stream_out_transcode debug: late picture skipped (27291)
stream_out_transcode debug: late picture skipped (1462)
stream_out_transcode debug: late picture skipped (19143)
stream_out_transcode debug: late picture skipped (6678)
ffmpeg debug: postprocessing disabled
ffmpeg debug: using direct rendering
ffmpeg debug: ffmpeg codec (Windows Media Video 2) started
main debug: using decoder module "ffmpeg"
main debug: looking for encoder module: 10 candidates
ffmpeg debug: libavcodec already initialized
stream_out_transcode debug: late picture skipped (22281)
stream_out_transcode debug: late picture skipped (15995)
stream_out_transcode debug: late picture skipped (22987)
stream_out_transcode debug: late picture skipped (12119)
stream_out_transcode debug: late picture skipped (1439)
stream_out_transcode debug: late picture skipped (2736)
stream_out_transcode debug: late picture skipped (5200)
stream_out_transcode debug: late picture skipped (22709)
stream_out_transcode debug: late picture skipped (47093)
stream_out_transcode debug: late picture skipped (24312)
stream_out_transcode debug: late picture skipped (7497)
stream_out_transcode debug: late picture skipped (104158)
stream_out_transcode debug: late picture skipped (69588)
stream_out_transcode debug: late picture skipped (30112)
stream_out_transcode debug: late picture skipped (147301)
stream_out_transcode debug: late picture skipped (103760)
stream_out_transcode debug: late picture skipped (64137)
stream_out_transcode debug: late picture skipped (24482)
stream_out_transcode debug: late picture skipped (9052)
stream_out_transcode debug: late picture skipped (22450)
stream_out_transcode debug: late picture skipped (1542)
stream_out_transcode debug: late picture skipped (12874)
stream_out_transcode debug: late picture skipped (24001)
stream_out_transcode debug: late picture skipped (2401)
stream_out_transcode debug: late picture skipped (3474)
ffmpeg debug: found encoder Windows Media Video 2
main debug: using encoder module "ffmpeg"
main debug: removing module "ffmpeg"
ffmpeg warning: warning: first frame is no keyframe
(wmv2@04C71B40)
stream_out_transcode debug: scaling to 320x240
main debug: looking for encoder module: 10 candidates
ffmpeg debug: libavcodec already initialized
ffmpeg debug: found encoder Windows Media Video 2
main debug: using encoder module "ffmpeg"
stream_out_duplicate debug: duplicated a new stream codec=WMV2 (es=0 group=0)
main debug: adding a new input
mux_asf debug: adding input
stream_out_duplicate debug: - added for output 0
main debug: control type=0
main debug: control: stopping input
main debug: closing input
asf debug: free asf object 0x8cabdca1-0xa947-0x11cf-0x8ee400c00c205365
asf debug: free asf object 0xc5f8cbea-0x5baf-0x4877-0x8467aa8c44fa4cca
asf debug: free asf object 0x5fbf03b5-0xa92e-0x11cf-0x8ee300c00c205365
asf debug: free asf object 0xb7dc0791-0xa9b7-0x11cf-0x8ee600c00c205365
asf debug: free asf object 0x86d15240-0x311d-0x11d0-0xa3a400a0c90348f6
asf debug: free asf object 0x75b22630-0x668e-0x11cf-0xa6d900aa0062ce6c
asf debug: free asf object 0x75b22636-0x668e-0x11cf-0xa6d900aa0062ce6c
main debug: removing module "packetizer_copy"
main debug: killing decoder fourcc `WMV2', 0 PES in FIFO
main debug: removing an input
ffmpeg debug: ffmpeg codec (Windows Media Video 2) stopped
main debug: removing module "ffmpeg"
main debug: removing module "ffmpeg"
mux_asf debug: Asf muxer creating header
mux_asf debug: pixel aspect-ratio: 1/1
mux_asf debug: removing input
main warning: no more input stream for this mux
main debug: Program doesn't contain anymore ES
main debug: removing module "asf"
access_mms debug: closing stream
main debug: removing module "access_mms"
main debug: destroying sout
main debug: destroying chain... (name=transcode)
main debug: destroying chain... (name=duplicate)
stream_out_duplicate debug: closing a duplication
main debug: destroying chain... (name=std)
mux_asf debug: Asf muxer closed
mux_asf debug: Asf muxer creating header
mux_asf debug: pixel aspect-ratio: 1/1
main debug: removing module "mux_asf"
access_output_file debug: file access output closed
main debug: removing module "access_output_file"
main debug: removing module "stream_out_standard"
main debug: destroying chain done
main debug: removing module "stream_out_duplicate"
main debug: destroying chain done
main debug: removing module "stream_out_transcode"
main debug: destroying chain done
main debug: thread times: real 1m0.328125s, kernel 0m0.078125s, user 0m0.046875s
main debug: thread 5368 joined (src/input/input.c:402)
I use VLM because I can access VLC that way from my VB.NET program.
Here is an example of how that looks like:
Code: Select all
new mainstream broadcast
setup mainstream input dshow://
setup mainstream option dshow-vdev=Capture1
setup mainstream option dshow-adev=none
setup mainstream option dshow-size=
setup mainstream output #transcode{vcodec=WMV2,vb=512,scale=1}:duplicate{dst=std{access=mmsh,mux=asfh,url=:1234}}
setup mainstream enabled
control mainstream play
Code: Select all
new callaufnahme broadcast
setup callaufnahme input mmsh://192.168.1.1:1235
setup callaufnahme output #transcode{vcodec=WMV2,vb=512,scale=1}:duplicate{dst=std{access=file,mux=asf,url=""c:\Video\file.wmv""}}
setup callaufnahme enabled
control callaufnahme play
Sometimes its the second stream-saving when VLC.exe crashes (100% load), sometimes its the 3rd or 4th.
So my guess would be, that VLC has a problem opening a Direct-Show device (Capture1, which is a TV-card) when it has been in use by VLC some seconds before.
In my VB.NET programm I have many waits after every row I transmit over the VLM-interface, and after stopping (control xyz stop) or deleting (del xyz) I have even longer waits (some seconds)
The versions I tried was the 0.8.4a and today nightly built (15th Feb.)
Perhaps somebody has the same problems and could verify this?!