Some MKV's don't stream with 1.03 (resolved)

For help and support with PS3 Media Server in general
Forum rules
Please make sure you follow the Problem Reporting Guidelines before posting if you want a reply.

Some MKV's don't stream with 1.03 (resolved)

Postby PS4 » Mon Jan 19, 2009 10:37 pm

Strange problem.

I've got some mkv's that don't want to stream under 1.03. In fact, the problem started with 1.02, I was just too lazy to report it. The same mkv works fine in 0.99. All testing using mencode with default settings.

PMS starts up fine. I see the mkv thumbnail in the ps3. I select it to play with mencode. The screen goes black, and stays black. The on screen display show dts and mpeg2 (with no bitrate), the total length of the film, but the timer just sits at 00:00:00.

I look at the pms gui and I see that it's transcoding away, filling up the buffer, but it's not streaming.
If I select avisynth/mencode, it works (but I get 2 ch sound). See debug log snippet below.

Oh well, back to 0.99.

[Thread-45] DEBUG 16:07:13.785 Opened handler on socket Socket[addr=/192.168.0.98,port=65247,localport=5001]
[Thread-45] DEBUG 16:07:13.785 Received on socket: POST /upnp/control/content_directory HTTP/1.1
[Thread-45] DEBUG 16:07:13.785 Received on socket: X-AV-Client-Info: av=5.0; cn="Sony Computer Entertainment Inc."; mn="PLAYSTATION 3"; mv="1.0";
[Thread-45] DEBUG 16:07:13.785 Received on socket: Host: 192.168.0.7:5001
[Thread-45] DEBUG 16:07:13.785 Received on socket: User-Agent: UPnP/1.0 DLNADOC/1.00
[Thread-45] DEBUG 16:07:13.785 Received on socket: Content-Length: 903
[Thread-45] DEBUG 16:07:13.785 Received on socket: Content-Type: text/xml; charset="utf-8"
[Thread-45] DEBUG 16:07:13.785 Received on socket: SOAPACTION: "urn:schemas-upnp-org:service:ContentDirectory:1#Browse"
[Thread-45] INFO 16:07:13.987 HTTP: upnp/control/content_directory / 0-0
[Thread-45] DEBUG 16:07:13.987 Wrote on socket: HTTP/1.1 200 OK
[Thread-45] DEBUG 16:07:13.987 Wrote on socket: CONTENT-TYPE: text/xml; charset="utf-8"
[Thread-45] DEBUG 16:07:13.987 Searching for objectId: 0$0 with children option: false
[Thread-45] DEBUG 16:07:13.987 Search extension for list1.txt
[Thread-45] DEBUG 16:07:13.987 Wrote on socket: Server: Windows Vista-x86-6.0 UPnP/1.0, PMS
[Thread-45] DEBUG 16:07:13.987 Wrote on socket: Content-Length: 1022
[Thread-45] DEBUG 16:07:13.987 Wrote on socket:
[Thread-45] DEBUG 16:07:13.987 Close Connection
[Thread-46] DEBUG 16:07:19.697 Opened handler on socket Socket[addr=/192.168.0.98,port=65246,localport=5001]
[Thread-46] DEBUG 16:07:19.697 Received on socket: GET /get/0$0$5/Test1.mkv HTTP/1.1
[Thread-46] DEBUG 16:07:19.697 Received on socket: Host: 192.168.0.7:5001
[Thread-46] DEBUG 16:07:19.697 Received on socket: User-Agent: PLAYSTATION 3
[Thread-46] DEBUG 16:07:19.713 Received on socket: Connection: Keep-Alive
[Thread-46] DEBUG 16:07:19.713 Received on socket: Accept-Encoding: identity
[Thread-46] INFO 16:07:19.713 HTTP: get/0$0$5/Test1.mkv / 0-0
[Thread-46] DEBUG 16:07:19.713 Wrote on socket: HTTP/1.1 200 OK
[Thread-46] DEBUG 16:07:19.713 Searching for objectId: 0$0$5 with children option: false
[Thread-46] DEBUG 16:07:19.713 Asked stream chunk [0-0] timeseek: 0.0 of Test1.mkv and player MEncoder
[Thread-46] TRACE 16:07:19.713 Starting transcode of Test1.mkv
[Thread-46] INFO 16:07:19.713 Creating pipe \\.\pipe\mencoder1232399239713
[Thread-47] INFO 16:07:19.853 Waiting for pipe connection \\.\pipe\mencoder1232399239713
[Timer-1] DEBUG 16:07:19.853 Buffered Space: 0 bytes
[win32/mencoder.exe] INFO 16:07:19.947 Starting C:\Program Files\PS3 Media Server\win32\mencoder.exe -ss 0 -quiet E:\TVersity-E\Test1.mkv -quiet -quiet -oac lavc -of mpeg -mpegopts format=mpeg2:muxrate=500000:vbuf_size=1194:abuf_size=64 -ovc lavc -channels 6 -lavdopts debug=0:threads=2 -lavcopts autoaspect=1:vcodec=mpeg2video:acodec=ac3:abitrate=384:threads=2:keyint=1:vqscale=1:vqmin=2 -ass -nofontconfig -subcp cp1252 -alang eng,fre,jpn,ger -ass-color ffffff00 -ass-border-color 00000000 -ass-font-scale 1.0 -ass-force-style FontName=Arial,Outline=1,Shadow=1,MarginV=10 -slang eng,fre,jpn,ger -quiet -quiet -quiet -quiet -ofps 24000/1001 -quiet -quiet -af lavcresample=48000 -srate 48000 -o \\.\pipe\mencoder1232399239713
[win32/mencoder.exe] INFO 16:07:19.978 Reading pipe: \\.\pipe\mencoder1232399239713
[win32/mencoder.exe] INFO 16:07:19.978 Attaching thread: win32/mencoder.exe
[Thread-51] DEBUG 16:07:19.993 MEncoder Sherpya-SVN-r28126-4.2.5 (C) 2000-2008 MPlayer Team
[Thread-51] DEBUG 16:07:19.993 CPU: Intel(R) Core(TM)2 Duo CPU E8400 @ 3.00GHz (Family: 6, Model: 23, Stepping: 6)
[Thread-51] DEBUG 16:07:19.993 CPUflags: Type: 6 MMX: 1 MMX2: 1 3DNow: 0 3DNow2: 0 SSE: 1 SSE2: 1
[Thread-51] DEBUG 16:07:19.993 Compiled with runtime CPU detection.
[Thread-51] DEBUG 16:07:20.009 success: format: 0 data: 0x0 - 0x17dd5374
[Thread-51] DEBUG 16:07:20.009 [mkv] Track ID 1: video (V_MPEG4/ISO/AVC), -vid 0
[Thread-51] DEBUG 16:07:20.009 [mkv] Track ID 2: audio (A_DTS), -aid 0, -alang eng
[Thread-51] DEBUG 16:07:20.009 [mkv] Track ID 3: subtitles (S_TEXT/UTF8), -sid 0, -slang eng
[Thread-51] DEBUG 16:07:20.009 [mkv] Will play video track 1.
[Thread-51] DEBUG 16:07:20.009 Matroska file format detected.
[Thread-51] DEBUG 16:07:20.009 VIDEO: [avc1] 1280x544 24bpp 23.976 fps 0.0 kbps ( 0.0 kbyte/s)
[Thread-51] DEBUG 16:07:20.009 [V] filefmt:31 fourcc:0x31637661 size:1280x544 fps:23.976 ftime:=0.0417
[Thread-51] DEBUG 16:07:20.009 ==========================================================================
[Thread-51] DEBUG 16:07:20.009 Opening audio decoder: [libdca] DTS decoding with libdca
[Thread-51] DEBUG 16:07:20.009 AUDIO: 48000 Hz, 6 ch, s16le, 1536.0 kbit/33.33% (ratio: 192000->576000)
[Thread-51] DEBUG 16:07:20.009 Selected audio codec: [dts] afm: libdca (DTS-libdca)
[Thread-51] DEBUG 16:07:20.009 ==========================================================================
[Thread-47] INFO 16:07:20.009 Result of \\.\pipe\mencoder1232399239713 : true
[Thread-51] DEBUG 16:07:20.009 PACKET SIZE: 2048 bytes, deltascr: 884
[Thread-51] DEBUG 16:07:20.009 [ass] auto-open
[Thread-51] DEBUG 16:07:20.009 [ass] Init
[Thread-51] DEBUG 16:07:20.009 ==========================================================================
[Thread-51] DEBUG 16:07:20.009 Opening video decoder: [ffmpeg] FFmpeg's libavcodec codec family
[Thread-50] DEBUG 16:07:20.009 Stream with high frequencies VQ coding
[Thread-50] DEBUG 16:07:20.009 Warning: -ass implies -keep-pts, which may cause "badly interleaved" files.
[Thread-50] DEBUG 16:07:20.009 [ass] Fontconfig disabled, only default font will be used.
[Thread-51] DEBUG 16:07:20.009 Selected video codec: [ffh264] vfm: ffmpeg (FFmpeg H.264)
[Thread-51] DEBUG 16:07:20.009 ==========================================================================
[Thread-50] DEBUG 16:07:20.009 Limiting audio preload to 0.4s.
[Thread-50] DEBUG 16:07:20.009 Increasing audio density to 4.
[Thread-51] DEBUG 16:07:20.040 Writing header...
[Thread-51] DEBUG 16:07:20.040 VDec: vo config request - 1280 x 544 (preferred colorspace: Planar YV12)
[Thread-51] DEBUG 16:07:20.040 VDec: using Planar YV12 as output csp (no 0)
[Thread-51] DEBUG 16:07:20.040 Movie-Aspect is 2.35:1 - prescaling to correct movie aspect.
[Thread-51] DEBUG 16:07:20.040 videocodec: libavcodec (1280x544 fourcc=3267706d [mpg2])
[Thread-51] DEBUG 16:07:20.040 [VE_LAVC] Using constant qscale = 1.000000 (VBR).
[Timer-1] DEBUG 16:07:20.867 Buffered Space: 2205696 bytes
[Timer-1] DEBUG 16:07:21.881 Buffered Space: 6412288 bytes
[Thread-37] INFO 16:07:22.349 Stopping process: win32/ffmpeg.exe
[Thread-37] INFO 16:07:22.349 Destroying buffer
[Timer-1] DEBUG 16:07:22.895 Buffered Space: 13381632 bytes
[Timer-1] DEBUG 16:07:23.909 Buffered Space: 19650560 bytes
[Timer-1] DEBUG 16:07:24.923 Buffered Space: 25124864 bytes
[Timer-1] DEBUG 16:07:25.937 Buffered Space: 30982144 bytes
[Thread-46] DEBUG 16:07:26.015 Wrote on socket: Content-Type: video/mpeg
[Thread-46] DEBUG 16:07:26.015 Wrote on socket: Connection: keep-alive
[Thread-46] DEBUG 16:07:26.015 Wrote on socket: Server: Windows Vista-x86-6.0 UPnP/1.0, PMS
[Thread-46] DEBUG 16:07:26.015 Wrote on socket:
[Thread-52] DEBUG 16:07:26.109 Opened handler on socket Socket[addr=/192.168.0.98,port=65245,localport=5001]
[Thread-52] DEBUG 16:07:26.109 Received on socket: GET /get/0$0$5/Test1.mkv HTTP/1.1
[Thread-52] DEBUG 16:07:26.109 Received on socket: Host: 192.168.0.7:5001
[Thread-52] DEBUG 16:07:26.109 Received on socket: User-Agent: PLAYSTATION 3
[Thread-52] DEBUG 16:07:26.109 Received on socket: Connection: Keep-Alive
[Thread-52] DEBUG 16:07:26.124 Received on socket: Accept-Encoding: identity
[Thread-52] INFO 16:07:26.124 HTTP: get/0$0$5/Test1.mkv / 0-0
[Thread-52] DEBUG 16:07:26.124 Wrote on socket: HTTP/1.1 200 OK
[Thread-52] DEBUG 16:07:26.124 Searching for objectId: 0$0$5 with children option: false
[Thread-52] DEBUG 16:07:26.124 Asked stream chunk [0-0] timeseek: 0.0 of Test1.mkv and player MEncoder
[Thread-52] DEBUG 16:07:26.124 Wrote on socket: Content-Type: video/mpeg
[Thread-52] DEBUG 16:07:26.124 Wrote on socket: Connection: keep-alive
[Thread-52] DEBUG 16:07:26.124 Wrote on socket: Server: Windows Vista-x86-6.0 UPnP/1.0, PMS
[Thread-52] DEBUG 16:07:26.124 Wrote on socket:
[Thread-52] DEBUG 16:07:26.202 Sending stream with premature end : 1114112 bytes of get/0$0$5/Test1.mkv. Reason: An existing connection was forcibly closed by the remote host
[Thread-52] DEBUG 16:07:26.202 Ready to Stop: true
[Thread-52] DEBUG 16:07:26.202 Sending stream: 1114112 bytes of get/0$0$5/Test1.mkv
[Thread-52] DEBUG 16:07:26.202 Close Connection
[Thread-53] INFO 16:07:26.904 Stopping process: win32/mencoder.exe
[Thread-53] INFO 16:07:26.904 Destroying buffer
[Thread-54] INFO 16:07:26.935 Destroying buffer
[Thread-47] DEBUG 16:07:26.935 EOF
[win32/mencoder.exe] DEBUG 16:07:26.935 EOF
[Thread-47] INFO 16:07:26.935 Disconnected pipe
[Thread-46] DEBUG 16:07:28.324 Sending stream with premature end : 1245184 bytes of get/0$0$5/Test1.mkv. Reason: An existing connection was forcibly closed by the remote host
[Thread-46] DEBUG 16:07:28.324 Sending stream: 1245184 bytes of get/0$0$5/Test1.mkv
[Thread-46] DEBUG 16:07:28.324 Close Connection
[Thread-57] DEBUG 16:07:28.324 Opened handler on socket Socket[addr=/192.168.0.98,port=65244,localport=5001]
[Thread-57] DEBUG 16:07:28.324 Received on socket: GET /get/0$0$5/Test1.mkv HTTP/1.1
[Thread-57] DEBUG 16:07:28.324 Received on socket: Host: 192.168.0.7:5001
[Thread-57] DEBUG 16:07:28.324 Received on socket: User-Agent: PLAYSTATION 3
[Thread-57] DEBUG 16:07:28.339 Received on socket: Connection: Keep-Alive
[Thread-57] DEBUG 16:07:28.339 Received on socket: Accept-Encoding: identity
[Thread-57] DEBUG 16:07:28.339 Received on socket: TimeSeekRange.dlna.org : npt=0.000-
[Thread-57] INFO 16:07:28.339 HTTP: get/0$0$5/Test1.mkv / 0-0
[Thread-57] DEBUG 16:07:28.339 Wrote on socket: HTTP/1.1 200 OK
[Thread-57] DEBUG 16:07:28.339 Searching for objectId: 0$0$5 with children option: false
[Thread-57] DEBUG 16:07:28.339 Asked stream chunk [0-0] timeseek: 0.0 of Test1.mkv and player MEncoder
[Thread-57] TRACE 16:07:28.339 Starting transcode of Test1.mkv
[Thread-57] INFO 16:07:28.339 Creating pipe \\.\pipe\mencoder1232399248339
[Thread-58] INFO 16:07:28.355 Waiting for pipe connection \\.\pipe\mencoder1232399248339
[Timer-2] DEBUG 16:07:28.355 Buffered Space: 0 bytes
[win32/mencoder.exe] INFO 16:07:28.417 Starting C:\Program Files\PS3 Media Server\win32\mencoder.exe -ss 0 -quiet E:\TVersity-E\Test1.mkv -quiet -quiet -oac lavc -of mpeg -mpegopts format=mpeg2:muxrate=500000:vbuf_size=1194:abuf_size=64 -ovc lavc -channels 6 -lavdopts debug=0:threads=2 -lavcopts autoaspect=1:vcodec=mpeg2video:acodec=ac3:abitrate=384:threads=2:keyint=1:vqscale=1:vqmin=2 -ass -nofontconfig -subcp cp1252 -alang eng,fre,jpn,ger -ass-color ffffff00 -ass-border-color 00000000 -ass-font-scale 1.0 -ass-force-style FontName=Arial,Outline=1,Shadow=1,MarginV=10 -slang eng,fre,jpn,ger -quiet -quiet -quiet -quiet -ofps 24000/1001 -quiet -quiet -af lavcresample=48000 -srate 48000 -o \\.\pipe\mencoder1232399248339
[win32/mencoder.exe] INFO 16:07:28.417 Reading pipe: \\.\pipe\mencoder1232399248339
[win32/mencoder.exe] INFO 16:07:28.417 Attaching thread: win32/mencoder.exe
[Thread-61] DEBUG 16:07:28.433 MEncoder Sherpya-SVN-r28126-4.2.5 (C) 2000-2008 MPlayer Team
[Thread-61] DEBUG 16:07:28.433 CPU: Intel(R) Core(TM)2 Duo CPU E8400 @ 3.00GHz (Family: 6, Model: 23, Stepping: 6)
[Thread-61] DEBUG 16:07:28.433 CPUflags: Type: 6 MMX: 1 MMX2: 1 3DNow: 0 3DNow2: 0 SSE: 1 SSE2: 1
[Thread-61] DEBUG 16:07:28.433 Compiled with runtime CPU detection.
[Thread-61] DEBUG 16:07:28.449 success: format: 0 data: 0x0 - 0x17dd5374
[Thread-61] DEBUG 16:07:28.449 [mkv] Track ID 1: video (V_MPEG4/ISO/AVC), -vid 0
[Thread-61] DEBUG 16:07:28.449 [mkv] Track ID 2: audio (A_DTS), -aid 0, -alang eng
[Thread-61] DEBUG 16:07:28.449 [mkv] Track ID 3: subtitles (S_TEXT/UTF8), -sid 0, -slang eng
[Thread-61] DEBUG 16:07:28.449 [mkv] Will play video track 1.
[Thread-61] DEBUG 16:07:28.449 Matroska file format detected.
[Thread-61] DEBUG 16:07:28.449 VIDEO: [avc1] 1280x544 24bpp 23.976 fps 0.0 kbps ( 0.0 kbyte/s)
[Thread-61] DEBUG 16:07:28.449 [V] filefmt:31 fourcc:0x31637661 size:1280x544 fps:23.976 ftime:=0.0417
[Thread-61] DEBUG 16:07:28.449 ==========================================================================
[Thread-61] DEBUG 16:07:28.449 Opening audio decoder: [libdca] DTS decoding with libdca
[Thread-61] DEBUG 16:07:28.449 AUDIO: 48000 Hz, 6 ch, s16le, 1536.0 kbit/33.33% (ratio: 192000->576000)
[Thread-61] DEBUG 16:07:28.449 Selected audio codec: [dts] afm: libdca (DTS-libdca)
[Thread-61] DEBUG 16:07:28.449 ==========================================================================
[Thread-61] DEBUG 16:07:28.449 PACKET SIZE: 2048 bytes, deltascr: 884
[Thread-58] INFO 16:07:28.449 Result of \\.\pipe\mencoder1232399248339 : true
[Thread-61] DEBUG 16:07:28.449 [ass] auto-open
[Thread-60] DEBUG 16:07:28.449 Stream with high frequencies VQ coding
[Thread-60] DEBUG 16:07:28.449 Warning: -ass implies -keep-pts, which may cause "badly interleaved" files.
[Thread-61] DEBUG 16:07:28.449 [ass] Init
[Thread-61] DEBUG 16:07:28.449 ==========================================================================
[Thread-60] DEBUG 16:07:28.449 [ass] Fontconfig disabled, only default font will be used.
[Thread-61] DEBUG 16:07:28.449 Opening video decoder: [ffmpeg] FFmpeg's libavcodec codec family
[Thread-61] DEBUG 16:07:28.449 Selected video codec: [ffh264] vfm: ffmpeg (FFmpeg H.264)
[Thread-61] DEBUG 16:07:28.449 ==========================================================================
[Thread-60] DEBUG 16:07:28.449 Limiting audio preload to 0.4s.
[Thread-60] DEBUG 16:07:28.449 Increasing audio density to 4.
[Thread-61] DEBUG 16:07:28.495 Writing header...
[Thread-61] DEBUG 16:07:28.495 VDec: vo config request - 1280 x 544 (preferred colorspace: Planar YV12)
[Thread-61] DEBUG 16:07:28.495 VDec: using Planar YV12 as output csp (no 0)
[Thread-61] DEBUG 16:07:28.495 Movie-Aspect is 2.35:1 - prescaling to correct movie aspect.
[Thread-61] DEBUG 16:07:28.495 videocodec: libavcodec (1280x544 fourcc=3267706d [mpg2])
[Thread-61] DEBUG 16:07:28.495 [VE_LAVC] Using constant qscale = 1.000000 (VBR).
[Thread-56] INFO 16:07:29.026 Destroying buffer
[Thread-55] INFO 16:07:29.057 Destroying buffer
[Timer-2] DEBUG 16:07:29.369 Buffered Space: 2045952 bytes
[Timer-2] DEBUG 16:07:30.383 Buffered Space: 6148096 bytes
[Timer-2] DEBUG 16:07:31.397 Buffered Space: 13381632 bytes
[Timer-2] DEBUG 16:07:32.411 Buffered Space: 19652608 bytes
[Timer-2] DEBUG 16:07:33.425 Buffered Space: 25376768 bytes
[Timer-2] DEBUG 16:07:34.439 Buffered Space: 31567872 bytes
[Thread-57] DEBUG 16:07:34.486 Wrote on socket: Content-Type: video/mpeg
[Thread-57] DEBUG 16:07:34.486 Wrote on socket: Connection: keep-alive
[Thread-57] DEBUG 16:07:34.486 Wrote on socket: Server: Windows Vista-x86-6.0 UPnP/1.0, PMS
[Thread-57] DEBUG 16:07:34.486 Wrote on socket:
[Timer-2] DEBUG 16:07:35.453 Buffered Space: 27850752 bytes
[Timer-2] DEBUG 16:07:36.467 Buffered Space: 19972096 bytes
[Thread-60] DEBUG 16:07:36.857 [h264 @ 01C22830]Cannot parallelize deblocking type 1, decoding such frames in sequential order
[Thread-60] DEBUG 16:07:36.857 [ass] PlayResX undefined, setting 678.
[Timer-2] DEBUG 16:07:37.481 Buffered Space: 10743808 bytes
[Timer-2] DEBUG 16:07:38.495 Buffered Space: 2859008 bytes
[Thread-57] DEBUG 16:07:38.729 Suspend Read: readCount=48824320 / writeCount=49776640
[Thread-58] DEBUG 16:07:38.791 freeMemory: 41470784
[Thread-58] DEBUG 16:07:38.791 totalMemory: 96235520
[Thread-58] DEBUG 16:07:38.791 maxMemory: 799145984
[Thread-58] DEBUG 16:07:38.791 Extending buffer to 419430400
[Thread-58] DEBUG 16:07:39.150 Done extending
[Thread-57] DEBUG 16:07:39.244 Resume Read: readCount=48824320 / writeCount=50757632
[Thread-57] DEBUG 16:07:39.353 Suspend Read: readCount=50266112 / writeCount=51204096
[Timer-2] DEBUG 16:07:39.509 Buffered Space: 1521664 bytes
[Thread-57] DEBUG 16:07:39.868 Resume Read: readCount=50266112 / writeCount=53084160
[Thread-57] DEBUG 16:07:40.102 Suspend Read: readCount=53084160 / writeCount=54020096
[Timer-2] DEBUG 16:07:40.523 Buffered Space: 2459648 bytes
[Thread-57] DEBUG 16:07:40.617 Resume Read: readCount=53084160 / writeCount=55924736
[Thread-57] DEBUG 16:07:40.851 Suspend Read: readCount=55836672 / writeCount=56817664
[Thread-57] DEBUG 16:07:41.365 Resume Read: readCount=55836672 / writeCount=58912768
[Timer-2] DEBUG 16:07:41.537 Buffered Space: 1617920 bytes
[Thread-57] DEBUG 16:07:41.615 Suspend Read: readCount=58851328 / writeCount=59834368
[Thread-57] DEBUG 16:07:42.130 Resume Read: readCount=58851328 / writeCount=61804544
[Thread-57] DEBUG 16:07:42.379 Suspend Read: readCount=61931520 / writeCount=62894080
[Timer-2] DEBUG 16:07:42.551 Buffered Space: 1566720 bytes
[Thread-57] DEBUG 16:07:42.894 Resume Read: readCount=61931520 / writeCount=65114112
[Thread-57] DEBUG 16:07:43.175 Suspend Read: readCount=65208320 / writeCount=66181120
[Timer-2] DEBUG 16:07:43.565 Buffered Space: 2762752 bytes
[Thread-57] DEBUG 16:07:43.690 Resume Read: readCount=65208320 / writeCount=68679680
[Thread-57] DEBUG 16:07:44.064 Suspend Read: readCount=69533696 / writeCount=70479872
[Thread-57] DEBUG 16:07:44.579 Resume Read: readCount=69533696 / writeCount=73592832
[Timer-2] DEBUG 16:07:44.579 Buffered Space: 3928064 bytes
[Thread-57] DEBUG 16:07:45.063 Suspend Read: readCount=75104256 / writeCount=76066816
[Thread-57] DEBUG 16:07:45.577 Resume Read: readCount=75104256 / writeCount=78555136
[Timer-2] DEBUG 16:07:45.593 Buffered Space: 3252224 bytes
[Thread-57] DEBUG 16:07:45.952 Suspend Read: readCount=79560704 / writeCount=80541696
[Thread-57] DEBUG 16:07:46.467 Resume Read: readCount=79560704 / writeCount=82952192
[Timer-2] DEBUG 16:07:46.607 Buffered Space: 2445312 bytes
[Thread-57] DEBUG 16:07:46.810 Suspend Read: readCount=83558400 / writeCount=84516864
[Thread-57] DEBUG 16:07:47.325 Resume Read: readCount=83558400 / writeCount=87009280
[Timer-2] DEBUG 16:07:47.621 Buffered Space: 1748992 bytes
[Thread-57] DEBUG 16:07:47.730 Suspend Read: readCount=88342528 / writeCount=89327616
[Thread-57] DEBUG 16:07:48.245 Resume Read: readCount=88342528 / writeCount=93349888
[Timer-2] DEBUG 16:07:48.635 Buffered Space: 3743744 bytes
[Thread-57] DEBUG 16:07:49.290 Suspend Read: readCount=100335616 / writeCount=101292032
[Timer-2] DEBUG 16:07:49.649 Buffered Space: 3293184 bytes
[Thread-57] DEBUG 16:07:49.805 Resume Read: readCount=100335616 / writeCount=104515584
[Thread-57] DEBUG 16:07:50.460 Suspend Read: readCount=107937792 / writeCount=108904448
[Timer-2] DEBUG 16:07:50.663 Buffered Space: 2387968 bytes
[Thread-57] DEBUG 16:07:50.975 Resume Read: readCount=107937792 / writeCount=112795648
[Timer-2] DEBUG 16:07:51.677 Buffered Space: 1200128 bytes
[Thread-57] DEBUG 16:07:51.693 Suspend Read: readCount=116326400 / writeCount=117264384
[Thread-57] DEBUG 16:07:52.207 Resume Read: readCount=116326400 / writeCount=120571904
[Timer-2] DEBUG 16:07:52.691 Buffered Space: 1789952 bytes
[Thread-57] DEBUG 16:07:52.831 Suspend Read: readCount=123600896 / writeCount=124598272
[Thread-57] DEBUG 16:07:53.346 Resume Read: readCount=123600896 / writeCount=127670272
[Timer-2] DEBUG 16:07:53.705 Buffered Space: 1495040 bytes
[Thread-57] DEBUG 16:07:53.767 Suspend Read: readCount=128647168 / writeCount=129628160
[Thread-57] DEBUG 16:07:54.282 Resume Read: readCount=128647168 / writeCount=132030464
[Thread-57] DEBUG 16:07:54.594 Suspend Read: readCount=132317184 / writeCount=133302272
[Timer-2] DEBUG 16:07:54.719 Buffered Space: 1503232 bytes
[Thread-57] DEBUG 16:07:55.109 Resume Read: readCount=132317184 / writeCount=135378944
[Thread-57] DEBUG 16:07:55.359 Suspend Read: readCount=135266304 / writeCount=136208384
[Timer-2] DEBUG 16:07:55.733 Buffered Space: 2420736 bytes
[Thread-57] DEBUG 16:07:55.873 Resume Read: readCount=135266304 / writeCount=138297344
[Thread-57] DEBUG 16:07:56.139 Suspend Read: readCount=138477568 / writeCount=139458560
[Thread-57] DEBUG 16:07:56.653 Resume Read: readCount=138477568 / writeCount=141672448
[Timer-2] DEBUG 16:07:56.747 Buffered Space: 2570240 bytes
[Thread-57] DEBUG 16:07:56.965 Suspend Read: readCount=142278656 / writeCount=143257600
[Thread-57] DEBUG 16:07:57.480 Resume Read: readCount=142278656 / writeCount=145367040
[Timer-2] DEBUG 16:07:57.761 Buffered Space: 1030144 bytes
[Thread-57] DEBUG 16:07:57.761 Suspend Read: readCount=145620992 / writeCount=146585600
[Thread-57] DEBUG 16:07:58.276 Resume Read: readCount=145620992 / writeCount=148731904
[Thread-57] DEBUG 16:07:58.525 Suspend Read: readCount=148635648 / writeCount=149633024
[Timer-2] DEBUG 16:07:58.775 Buffered Space: 2037760 bytes
[Thread-57] DEBUG 16:07:59.040 Resume Read: readCount=148635648 / writeCount=151908352
[Thread-57] DEBUG 16:07:59.321 Suspend Read: readCount=152043520 / writeCount=153006080
[Timer-2] DEBUG 16:07:59.789 Buffered Space: 2748416 bytes
[Thread-57] DEBUG 16:07:59.836 Resume Read: readCount=152043520 / writeCount=154892288
[Thread-57] DEBUG 16:08:00.023 Suspend Read: readCount=154337280 / writeCount=155328512
[Thread-57] DEBUG 16:08:00.538 Resume Read: readCount=154337280 / writeCount=156516352
[Thread-57] DEBUG 16:08:00.678 Suspend Read: readCount=156041216 / writeCount=156993536
[Timer-2] DEBUG 16:08:00.803 Buffered Space: 1306624 bytes
[Thread-57] DEBUG 16:08:01.193 Resume Read: readCount=156041216 / writeCount=158789632
[Thread-57] DEBUG 16:08:01.427 Suspend Read: readCount=158793728 / writeCount=159778816
[Timer-2] DEBUG 16:08:01.817 Buffered Space: 2807808 bytes
[Thread-57] DEBUG 16:08:01.942 Resume Read: readCount=158793728 / writeCount=162295808
[Thread-57] DEBUG 16:08:02.316 Suspend Read: readCount=163184640 / writeCount=164134912
[Timer-2] DEBUG 16:08:02.831 Buffered Space: 3375104 bytes
[Thread-57] DEBUG 16:08:02.831 Resume Read: readCount=163184640 / writeCount=166559744
[Thread-57] DEBUG 16:08:03.112 Suspend Read: readCount=166592512 / writeCount=167550976
[Thread-57] DEBUG 16:08:03.627 Resume Read: readCount=166592512 / writeCount=168742912
[Thread-57] DEBUG 16:08:03.736 Suspend Read: readCount=168034304 / writeCount=169029632
[Timer-2] DEBUG 16:08:03.845 Buffered Space: 1253376 bytes
[Thread-57] DEBUG 16:08:04.251 Resume Read: readCount=168034304 / writeCount=170575872
[Thread-57] DEBUG 16:08:04.422 Suspend Read: readCount=170131456 / writeCount=171102208
[Timer-2] DEBUG 16:08:04.859 Buffered Space: 2709504 bytes
[Thread-57] DEBUG 16:08:04.937 Resume Read: readCount=170131456 / writeCount=173197312
[Thread-57] DEBUG 16:08:05.218 Suspend Read: readCount=173473792 / writeCount=174444544
[Thread-57] DEBUG 16:08:05.733 Resume Read: readCount=173473792 / writeCount=176695296
[Timer-2] DEBUG 16:08:05.873 Buffered Space: 1923072 bytes
[Thread-57] DEBUG 16:08:05.982 Suspend Read: readCount=176422912 / writeCount=177393664
[Thread-57] DEBUG 16:08:06.497 Resume Read: readCount=176422912 / writeCount=179642368
[Thread-57] DEBUG 16:08:06.825 Suspend Read: readCount=180355072 / writeCount=181293056
[Timer-2] DEBUG 16:08:06.887 Buffered Space: 1239040 bytes
[Thread-57] DEBUG 16:08:07.339 Resume Read: readCount=180355072 / writeCount=184244224
[Thread-57] DEBUG 16:08:07.807 Suspend Read: readCount=185794560 / writeCount=186771456
[Timer-2] DEBUG 16:08:07.901 Buffered Space: 1492992 bytes
[Thread-57] DEBUG 16:08:08.322 Resume Read: readCount=185794560 / writeCount=189634560
[Thread-57] DEBUG 16:08:08.712 Suspend Read: readCount=190447616 / writeCount=191447040
[Timer-2] DEBUG 16:08:08.915 Buffered Space: 1898496 bytes
[Thread-57] DEBUG 16:08:09.227 Resume Read: readCount=190447616 / writeCount=193763328
[Thread-57] DEBUG 16:08:09.523 Suspend Read: readCount=194052096 / writeCount=195004416
[Timer-2] DEBUG 16:08:09.929 Buffered Space: 2734080 bytes
[Thread-57] DEBUG 16:08:10.038 Resume Read: readCount=194052096 / writeCount=197257216
[Thread-57] DEBUG 16:08:10.350 Suspend Read: readCount=197787648 / writeCount=198780928
[Thread-57] DEBUG 16:08:10.865 Resume Read: readCount=197787648 / writeCount=201365504
[Timer-2] DEBUG 16:08:10.943 Buffered Space: 2942976 bytes
[Thread-57] DEBUG 16:08:11.286 Suspend Read: readCount=202768384 / writeCount=203753472
[Thread-57] DEBUG 16:08:11.801 Resume Read: readCount=202768384 / writeCount=206692352
[Timer-2] DEBUG 16:08:11.957 Buffered Space: 2537472 bytes
[Thread-57] DEBUG 16:08:12.160 Suspend Read: readCount=206962688 / writeCount=207921152
[Thread-57] DEBUG 16:08:12.675 Resume Read: readCount=206962688 / writeCount=210612224
[Timer-2] DEBUG 16:08:12.971 Buffered Space: 2586624 bytes
[Thread-57] DEBUG 16:08:13.517 Suspend Read: readCount=216793088 / writeCount=217786368
[Timer-2] DEBUG 16:08:13.985 Buffered Space: 5277696 bytes
[Thread-57] DEBUG 16:08:14.032 Resume Read: readCount=216793088 / writeCount=222216192
[Thread-57] DEBUG 16:08:14.547 Suspend Read: readCount=222822400 / writeCount=223801344
[Timer-2] DEBUG 16:08:14.999 Buffered Space: 2803712 bytes
[Thread-57] DEBUG 16:08:15.061 Resume Read: readCount=222822400 / writeCount=225976320
[Thread-57] DEBUG 16:08:15.311 Suspend Read: readCount=225837056 / writeCount=226772992
[Thread-57] DEBUG 16:08:15.826 Resume Read: readCount=225837056 / writeCount=229179392
[Timer-2] DEBUG 16:08:16.013 Buffered Space: 2603008 bytes
[Thread-57] DEBUG 16:08:16.419 Suspend Read: readCount=232652800 / writeCount=233611264
[Thread-57] DEBUG 16:08:16.933 Resume Read: readCount=232652800 / writeCount=238389248
[Timer-2] DEBUG 16:08:17.027 Buffered Space: 5130240 bytes
[Timer-2] DEBUG 16:08:18.041 Buffered Space: 1560576 bytes
[Thread-57] DEBUG 16:08:18.181 Suspend Read: readCount=246939648 / writeCount=247926784
[Thread-57] DEBUG 16:08:18.696 Resume Read: readCount=246939648 / writeCount=251815936
[Timer-2] DEBUG 16:08:19.055 Buffered Space: 3328000 bytes
[Thread-57] DEBUG 16:08:19.570 Suspend Read: readCount=257032192 / writeCount=258031616
[Timer-2] DEBUG 16:08:20.069 Buffered Space: 3575808 bytes
[Thread-57] DEBUG 16:08:20.085 Resume Read: readCount=257032192 / writeCount=260610048
[Thread-57] DEBUG 16:08:20.397 Suspend Read: readCount=260702208 / writeCount=261691392
[Thread-57] DEBUG 16:08:20.911 Resume Read: readCount=260702208 / writeCount=263438336
[Timer-2] DEBUG 16:08:21.083 Buffered Space: 1234944 bytes
[Thread-57] DEBUG 16:08:21.099 Suspend Read: readCount=263061504 / writeCount=264022016
[Thread-57] DEBUG 16:08:21.613 Resume Read: readCount=263061504 / writeCount=265639936
[Thread-57] DEBUG 16:08:21.785 Suspend Read: readCount=265158656 / writeCount=266110976
[Timer-2] DEBUG 16:08:22.097 Buffered Space: 1949696 bytes
[Thread-57] DEBUG 16:08:22.300 Resume Read: readCount=265158656 / writeCount=267741184
[Thread-57] DEBUG 16:08:22.471 Suspend Read: readCount=267321344 / writeCount=268310528
[Thread-57] DEBUG 16:08:22.986 Resume Read: readCount=267321344 / writeCount=269752320
[Timer-2] DEBUG 16:08:23.111 Buffered Space: 1298432 bytes
[Thread-57] DEBUG 16:08:23.142 Suspend Read: readCount=269221888 / writeCount=270182400
[Thread-57] DEBUG 16:08:23.657 Resume Read: readCount=269221888 / writeCount=271929344
[Thread-57] DEBUG 16:08:23.875 Suspend Read: readCount=271777792 / writeCount=272728064
[Timer-2] DEBUG 16:08:24.125 Buffered Space: 2072576 bytes
[Thread-57] DEBUG 16:08:24.390 Resume Read: readCount=271777792 / writeCount=275007488
[Thread-57] DEBUG 16:08:24.671 Suspend Read: readCount=275251200 / writeCount=276226048
[Timer-2] DEBUG 16:08:25.139 Buffered Space: 3184640 bytes
[Thread-57] DEBUG 16:08:25.186 Resume Read: readCount=275251200 / writeCount=278626304
[Thread-57] DEBUG 16:08:25.513 Suspend Read: readCount=279117824 / writeCount=280068096
[Thread-57] DEBUG 16:08:26.028 Resume Read: readCount=279117824 / writeCount=282365952
[Timer-2] DEBUG 16:08:26.153 Buffered Space: 2074624 bytes
[Thread-57] DEBUG 16:08:26.278 Suspend Read: readCount=282132480 / writeCount=283131904
[Thread-57] DEBUG 16:08:26.793 Resume Read: readCount=282132480 / writeCount=284917760
[Thread-57] DEBUG 16:08:26.995 Suspend Read: readCount=284688384 / writeCount=285634560
[Timer-2] DEBUG 16:08:27.167 Buffered Space: 1533952 bytes
[Thread-57] DEBUG 16:08:27.510 Resume Read: readCount=284688384 / writeCount=287604736
[Timer-2] DEBUG 16:08:28.181 Buffered Space: 3831808 bytes
[Timer-2] DEBUG 16:08:29.195 Buffered Space: 7737344 bytes
[Timer-2] DEBUG 16:08:30.209 Buffered Space: 13047808 bytes
[Timer-2] DEBUG 16:08:31.223 Buffered Space: 19372032 bytes
[Timer-2] DEBUG 16:08:32.237 Buffered Space: 25581568 bytes
[Timer-2] DEBUG 16:08:33.251 Buffered Space: 31811584 bytes
[Timer-2] DEBUG 16:08:34.265 Buffered Space: 37806080 bytes
[Timer-2] DEBUG 16:08:35.279 Buffered Space: 43907072 bytes
[Timer-2] DEBUG 16:08:36.293 Buffered Space: 49790976 bytes
[Timer-2] DEBUG 16:08:37.307 Buffered Space: 55535616 bytes
Last edited by PS4 on Fri Jan 23, 2009 10:13 pm, edited 1 time in total.
PS4
 
Posts: 21
Joined: Mon Jan 19, 2009 4:11 pm

Re: Some MKV's don't stream with 1.03

Postby shagrath » Mon Jan 19, 2009 10:41 pm

well the same debug.log snippet from the 0.99 could help
shagrath
Project Lead
 
Posts: 2668
Joined: Wed Jan 14, 2009 1:39 pm

Re: Some MKV's don't stream with 1.03

Postby PS4 » Mon Jan 19, 2009 10:52 pm

From 0.99, same file worked perfectly.
Thanks

------------------------------------

[Thread-40] DEBUG 16:48:13.565 Wrote on socket: HTTP/1.1 200 OK
[Thread-40] DEBUG 16:48:13.565 Wrote on socket: CONTENT-TYPE: text/xml; charset="utf-8"
[Thread-40] DEBUG 16:48:13.565 Searching for objectId: 0$0 with children option: false
[Thread-40] DEBUG 16:48:13.565 Wrote on socket: Server: Windows Vista-x86-6.0 UPnP/1.0, PMS
[Thread-40] DEBUG 16:48:13.565 Wrote on socket: Content-Length: 999
[Thread-40] DEBUG 16:48:13.565 Wrote on socket:
[Thread-40] DEBUG 16:48:13.565 Close Connection
[Thread-41] DEBUG 16:48:13.565 Opened handler on socket Socket[addr=/192.168.0.98,port=60380,localport=4999]
[Thread-41] DEBUG 16:48:13.565 Received on socket: POST /upnp/control/content_directory HTTP/1.1
[Thread-41] DEBUG 16:48:13.565 Received on socket: X-AV-Client-Info: av=5.0; cn="Sony Computer Entertainment Inc."; mn="PLAYSTATION 3"; mv="1.0";
[Thread-41] DEBUG 16:48:13.581 Received on socket: Host: 192.168.0.7:4999
[Thread-41] DEBUG 16:48:13.581 Received on socket: User-Agent: UPnP/1.0 DLNADOC/1.00
[Thread-41] DEBUG 16:48:13.581 Received on socket: Content-Length: 910
[Thread-41] DEBUG 16:48:13.581 Received on socket: Content-Type: text/xml; charset="utf-8"
[Thread-41] DEBUG 16:48:13.581 Received on socket: SOAPACTION: "urn:schemas-upnp-org:service:ContentDirectory:1#Browse"
[Thread-41] INFO 16:48:13.768 HTTP: upnp/control/content_directory / 0-0
[Thread-41] DEBUG 16:48:13.768 Wrote on socket: HTTP/1.1 200 OK
[Thread-41] DEBUG 16:48:13.768 Wrote on socket: CONTENT-TYPE: text/xml; charset="utf-8"
[Thread-41] DEBUG 16:48:13.768 Searching for objectId: 0$0 with children option: true
[Thread-41] DEBUG 16:48:13.768 Search extension for E:\TVersity-E\AVI
[Thread-41] INFO 16:48:13.768 Adding AVI / class: net.pms.dlna.RealFile
[Thread-41] DEBUG 16:48:13.768 Search extension for E:\TVersity-E\Documentaries
[Thread-41] INFO 16:48:13.799 Adding Documentaries / class: net.pms.dlna.RealFile
[Thread-41] DEBUG 16:48:13.799 Search extension for E:\TVersity-E\DVD
[Thread-41] INFO 16:48:13.799 Adding DVD / class: net.pms.dlna.RealFile
[Thread-41] DEBUG 16:48:13.799 Search extension for E:\TVersity-E\M2TS
[Thread-41] INFO 16:48:13.799 Adding M2TS / class: net.pms.dlna.RealFile
[Thread-41] DEBUG 16:48:13.799 Search extension for E:\TVersity-E\MKV
[Thread-41] INFO 16:48:13.799 Adding MKV / class: net.pms.dlna.RealFile
[Thread-41] DEBUG 16:48:13.799 Search extension for E:\TVersity-E\list1.txt
[Thread-41] DEBUG 16:48:13.799 Search extension for E:\TVersity-E\Test1.mkv
[Thread-41] DEBUG 16:48:13.799 Found 1! net.pms.formats.MKV
[Thread-41] INFO 16:48:13.799 Adding Test1.mkv / class: net.pms.dlna.RealFile
[Thread-41] INFO 16:48:13.799 Switching Test1.mkv to player: MEncoder
[Thread-41] INFO 16:48:13.799 Duplicate Test1.mkv with player: MEncoder
[Thread-41] INFO 16:48:13.799 Adding Test1.mkv / class: net.pms.dlna.FileTranscodeVirtualFolder
[Thread-41] DEBUG 16:48:13.799 Setting DLNA id 0$0$0 to AVI
[Thread-41] DEBUG 16:48:13.799 Setting DLNA id 0$0$1 to Documentaries
[Thread-41] DEBUG 16:48:13.799 Setting DLNA id 0$0$2 to DVD
[Thread-41] DEBUG 16:48:13.799 Setting DLNA id 0$0$3 to M2TS
[Thread-41] DEBUG 16:48:13.799 Setting DLNA id 0$0$4 to MKV
[Thread-41] DEBUG 16:48:13.799 Setting DLNA id 0$0$5 to Test1.mkv
[Thread-41] DEBUG 16:48:13.799 Setting DLNA id 0$0$6 to #--TRANSCODED--#
[Thread-41] DEBUG 16:48:13.799 Setting DLNA id 0$0$6$0 to Test1.mkv
[Thread-41] DEBUG 16:48:13.799 Setting DLNA id 0$0$6$0$0 to Test1.mkv
[pool-2-thread-1] INFO 16:48:13.799 Starting C:\pms-win32-0.99\pms-win32-0.99\win32\ffmpeg.exe -ss 120 -i E:\TVersity-E\Test1.mkv -an -an -s 320x180 -vframes 1 -f image2 pipe:
[pool-2-thread-1] INFO 16:48:13.815 Attaching thread: win32/ffmpeg.exe
[Thread-43] DEBUG 16:48:14.033 FFmpeg version Sherpya-r15666, Copyright (c) 2000-2008 Fabrice Bellard, et al.
[Thread-43] DEBUG 16:48:14.033 libavutil 49.12. 0 / 49.12. 0
[Thread-43] DEBUG 16:48:14.033 libavcodec 52. 0. 0 / 52. 0. 0
[Thread-43] DEBUG 16:48:14.033 libavformat 52.22. 1 / 52.22. 1
[Thread-43] DEBUG 16:48:14.033 libavdevice 52. 1. 0 / 52. 1. 0
[Thread-43] DEBUG 16:48:14.033 libswscale 0. 6. 1 / 0. 6. 1
[Thread-43] DEBUG 16:48:14.033 libpostproc 51. 2. 0 / 51. 2. 0
[Thread-43] DEBUG 16:48:14.033 built on Oct 22 2008 23:37:16, gcc: 4.2.5 20080919 (prerelease) [Sherpya]
[Thread-43] DEBUG 16:48:14.033 Input #0, matroska, from 'E:\TVersity-E\Test1.mkv':
[Thread-43] DEBUG 16:48:14.033 Duration: 01:40:58.14, start: 0.000000, bitrate: N/A
[Thread-43] DEBUG 16:48:14.033 Stream #0.0(eng): Video: h264, yuv420p, 1280x544, 23.98 tb(r)
[Thread-43] DEBUG 16:48:14.033 Stream #0.1(eng): Audio: dca, 48000 Hz, 5:1, s16
[Thread-43] DEBUG 16:48:14.033 Stream #0.2(eng): Subtitle: 0x0000
[Thread-43] DEBUG 16:48:14.033 Output #0, image2, to 'pipe:':
[Thread-43] DEBUG 16:48:14.033 Stream #0.0(eng): Video: mjpeg, yuvj420p, 320x180 [PAR 45:34 DAR 40:17], q=2-31, 200 kb/s, 23.98 tb(c)
[Thread-43] DEBUG 16:48:14.033 Stream mapping:
[Thread-43] DEBUG 16:48:14.033 Stream #0.0 -> #0.0
[Thread-43] DEBUG 16:48:14.033 Press [q] to stop encoding
[Thread-43] DEBUG 16:48:14.033 video:14kB audio:0kB global headers:0kB muxing overhead -100.156807%
[pool-2-thread-1] DEBUG 16:48:14.033 EOF
[pool-2-thread-1] DEBUG 16:48:14.033 Ready to Stop: true
[pool-2-thread-1] DEBUG 16:48:14.064 Media info: mimeType: video/mp4 / container: matroska / bitrate: 0 / size: 4695348084 / codecV: h264 / duration: 01:40:58.140 / resolution: 1280x544 / frameRate: 23.98 / codecA: dca / sampleFrequency: 48000 / nrAudioChannels: 6
[Thread-41] DEBUG 16:48:14.064 End of analysis
[Thread-41] DEBUG 16:48:14.064 Wrote on socket: Server: Windows Vista-x86-6.0 UPnP/1.0, PMS
[Thread-41] DEBUG 16:48:14.064 Wrote on socket: Content-Length: 3683
[Thread-41] DEBUG 16:48:14.064 Wrote on socket:
[Thread-41] DEBUG 16:48:14.064 Close Connection
[Thread-47] DEBUG 16:48:14.345 Opened handler on socket Socket[addr=/192.168.0.98,port=60379,localport=4999]
[Thread-47] DEBUG 16:48:14.345 Received on socket: POST /upnp/control/content_directory HTTP/1.1
[Thread-47] DEBUG 16:48:14.345 Received on socket: X-AV-Client-Info: av=5.0; cn="Sony Computer Entertainment Inc."; mn="PLAYSTATION 3"; mv="1.0";
[Thread-47] DEBUG 16:48:14.361 Received on socket: Host: 192.168.0.7:4999
[Thread-47] DEBUG 16:48:14.361 Received on socket: User-Agent: UPnP/1.0 DLNADOC/1.00
[Thread-47] DEBUG 16:48:14.361 Received on socket: Content-Length: 276
[Thread-47] DEBUG 16:48:14.361 Received on socket: Content-Type: text/xml; charset="utf-8"
[Thread-47] DEBUG 16:48:14.361 Received on socket: SOAPACTION: "urn:schemas-upnp-org:service:ContentDirectory:1#GetSystemUpdateID"
[Thread-48] DEBUG 16:48:14.407 Opened handler on socket Socket[addr=/192.168.0.98,port=60378,localport=4999]
[Thread-48] DEBUG 16:48:14.407 Received on socket: GET /get/0$0$5/thumbnail0000Test1.mkv HTTP/1.0
[Thread-48] DEBUG 16:48:14.407 Received on socket: Host: 192.168.0.7:4999
[Thread-48] DEBUG 16:48:14.407 Received on socket: User-Agent: PLAYSTATION 3
[Thread-48] DEBUG 16:48:14.423 Received on socket: Connection: close
[Thread-48] DEBUG 16:48:14.423 Received on socket: Accept-Encoding: identity
[Thread-48] DEBUG 16:48:14.423 Received on socket: Cache-Control: no-cache
[Thread-48] INFO 16:48:14.423 HTTP: get/0$0$5/thumbnail0000Test1.mkv / 0-0
[Thread-48] DEBUG 16:48:14.423 Wrote on socket: HTTP/1.0 200 OK
[Thread-48] DEBUG 16:48:14.423 Searching for objectId: 0$0$5 with children option: false
[Thread-48] DEBUG 16:48:14.423 Wrote on socket: Content-Type: image/png
[Thread-48] DEBUG 16:48:14.423 Wrote on socket: Accept-Ranges: bytes
[Thread-48] DEBUG 16:48:14.423 Wrote on socket: Expires: Fri, 15 May 2009 15:34:54 GMT
[Thread-48] DEBUG 16:48:14.423 Wrote on socket: Connection: keep-alive
[Thread-48] DEBUG 16:48:14.423 Wrote on socket: Server: Windows Vista-x86-6.0 UPnP/1.0, PMS
[Thread-48] DEBUG 16:48:14.423 Available Content-Length: 13288
[Thread-48] DEBUG 16:48:14.423 Wrote on socket: Content-Length: 13288
[Thread-48] DEBUG 16:48:14.423 Wrote on socket:
[Thread-48] DEBUG 16:48:14.470 Sending stream: 13288 bytes of get/0$0$5/thumbnail0000Test1.mkv
[Thread-48] DEBUG 16:48:14.470 Close Connection
[Thread-49] DEBUG 16:48:14.485 Opened handler on socket Socket[addr=/192.168.0.98,port=60377,localport=4999]
[Thread-49] DEBUG 16:48:14.485 Received on socket: GET /get/0$0$5/thumbnail0000Test1.mkv HTTP/1.1
[Thread-49] DEBUG 16:48:14.485 Received on socket: Host: 192.168.0.7:4999
[Thread-49] DEBUG 16:48:14.485 Received on socket: User-Agent: PLAYSTATION 3
[Thread-49] DEBUG 16:48:14.501 Received on socket: Connection: Keep-Alive
[Thread-49] DEBUG 16:48:14.501 Received on socket: Accept-Encoding: identity
[Thread-49] INFO 16:48:14.501 HTTP: get/0$0$5/thumbnail0000Test1.mkv / 0-0
[Thread-49] DEBUG 16:48:14.501 Wrote on socket: HTTP/1.1 200 OK
[Thread-49] DEBUG 16:48:14.501 Searching for objectId: 0$0$5 with children option: false
[Thread-49] DEBUG 16:48:14.501 Wrote on socket: Content-Type: image/png
[Thread-49] DEBUG 16:48:14.501 Wrote on socket: Accept-Ranges: bytes
[Thread-49] DEBUG 16:48:14.501 Wrote on socket: Expires: Fri, 15 May 2009 15:34:54 GMT
[Thread-49] DEBUG 16:48:14.501 Wrote on socket: Connection: keep-alive
[Thread-49] DEBUG 16:48:14.501 Wrote on socket: Server: Windows Vista-x86-6.0 UPnP/1.0, PMS
[Thread-49] DEBUG 16:48:14.501 Available Content-Length: 13288
[Thread-49] DEBUG 16:48:14.501 Wrote on socket: Content-Length: 13288
[Thread-49] DEBUG 16:48:14.501 Wrote on socket:
[Thread-49] DEBUG 16:48:14.501 Sending stream: 13288 bytes of get/0$0$5/thumbnail0000Test1.mkv
[Thread-49] DEBUG 16:48:14.501 Close Connection
[Thread-47] INFO 16:48:14.548 HTTP: upnp/control/content_directory / 0-0
[Thread-47] DEBUG 16:48:14.548 Wrote on socket: HTTP/1.1 200 OK
[Thread-47] DEBUG 16:48:14.548 Wrote on socket: CONTENT-TYPE: text/xml; charset="utf-8"
[Thread-47] DEBUG 16:48:14.548 Wrote on socket: Server: Windows Vista-x86-6.0 UPnP/1.0, PMS
[Thread-47] DEBUG 16:48:14.548 Wrote on socket: Content-Length: 332
[Thread-47] DEBUG 16:48:14.548 Wrote on socket:
[Thread-47] DEBUG 16:48:14.548 Close Connection
[Thread-50] DEBUG 16:48:14.548 Opened handler on socket Socket[addr=/192.168.0.98,port=60376,localport=4999]
[Thread-50] DEBUG 16:48:14.548 Received on socket: POST /upnp/control/content_directory HTTP/1.1
[Thread-50] DEBUG 16:48:14.548 Received on socket: X-AV-Client-Info: av=5.0; cn="Sony Computer Entertainment Inc."; mn="PLAYSTATION 3"; mv="1.0";
[Thread-50] DEBUG 16:48:14.563 Received on socket: Host: 192.168.0.7:4999
[Thread-50] DEBUG 16:48:14.563 Received on socket: User-Agent: UPnP/1.0 DLNADOC/1.00
[Thread-50] DEBUG 16:48:14.563 Received on socket: Content-Length: 903
[Thread-50] DEBUG 16:48:14.563 Received on socket: Content-Type: text/xml; charset="utf-8"
[Thread-50] DEBUG 16:48:14.563 Received on socket: SOAPACTION: "urn:schemas-upnp-org:service:ContentDirectory:1#Browse"
[Thread-46] INFO 16:48:14.751 Stopping process: win32/ffmpeg.exe
[Thread-46] INFO 16:48:14.751 Destroying buffer
[Thread-50] INFO 16:48:14.782 HTTP: upnp/control/content_directory / 0-0
[Thread-46] INFO 16:48:14.782 Destroying buffer
[Thread-50] DEBUG 16:48:14.813 Wrote on socket: HTTP/1.1 200 OK
[Thread-50] DEBUG 16:48:14.813 Wrote on socket: CONTENT-TYPE: text/xml; charset="utf-8"
[Thread-50] DEBUG 16:48:14.813 Searching for objectId: 0$0 with children option: false
[Thread-50] DEBUG 16:48:14.813 Search extension for list1.txt
[Thread-50] DEBUG 16:48:14.813 Wrote on socket: Server: Windows Vista-x86-6.0 UPnP/1.0, PMS
[Thread-50] DEBUG 16:48:14.813 Wrote on socket: Content-Length: 999
[Thread-50] DEBUG 16:48:14.813 Wrote on socket:
[Thread-50] DEBUG 16:48:14.813 Close Connection
[Thread-42] INFO 16:48:16.810 Stopping process: win32/ffmpeg.exe
[Thread-42] INFO 16:48:16.810 Destroying buffer
[Thread-51] DEBUG 16:48:18.744 Opened handler on socket Socket[addr=/192.168.0.98,port=60375,localport=4999]
[Thread-51] DEBUG 16:48:18.744 Received on socket: GET /get/0$0$5/Test1.mkv HTTP/1.1
[Thread-51] DEBUG 16:48:18.744 Received on socket: Host: 192.168.0.7:4999
[Thread-51] DEBUG 16:48:18.744 Received on socket: User-Agent: PLAYSTATION 3
[Thread-51] DEBUG 16:48:18.760 Received on socket: Connection: Keep-Alive
[Thread-51] DEBUG 16:48:18.760 Received on socket: Accept-Encoding: identity
[Thread-51] INFO 16:48:18.760 HTTP: get/0$0$5/Test1.mkv / 0-0
[Thread-51] DEBUG 16:48:18.760 Wrote on socket: HTTP/1.1 200 OK
[Thread-51] DEBUG 16:48:18.760 Searching for objectId: 0$0$5 with children option: false
[Thread-51] DEBUG 16:48:18.760 Asked stream chunk [0-0] timeseek: 0.0 of Test1.mkv and player MEncoder
[Thread-51] TRACE 16:48:18.760 Starting transcode of Test1.mkv
[Thread-51] INFO 16:48:18.760 Creating pipe \\.\pipe\mencoder1232401698760
[Thread-52] INFO 16:48:19.087 Waiting for pipe connection \\.\pipe\mencoder1232401698760
[win32/mencoder.exe] INFO 16:48:19.150 Starting C:\pms-win32-0.99\pms-win32-0.99\win32\mencoder.exe -ss 0 -quiet E:\TVersity-E\Test1.mkv -quiet -quiet -oac lavc -of mpeg -mpegopts format=mpeg2:muxrate=500000:vbuf_size=1194:abuf_size=64 -ovc lavc -channels 6 -lavdopts debug=0:threads=2 -lavcopts vcodec=mpeg2video:acodec=ac3:abitrate=384:threads=2:keyint=1:vqscale=1:vqmin=2:vrc_maxrate=25000:vrc_buf_size=7000 -ass -nofontconfig -subcp cp1252 -alang eng -ass-color ffffff00 -ass-font-scale 1.0 -ass-force-style FontName=Arial,Outline=1,Shadow=1,MarginV=1 -slang eng -quiet -quiet -fps 24000/1001 -ofps 24000/1001 -quiet -quiet -o \\.\pipe\mencoder1232401698760
[win32/mencoder.exe] INFO 16:48:19.150 Reading pipe: \\.\pipe\mencoder1232401698760
[win32/mencoder.exe] INFO 16:48:19.228 Attaching thread: win32/mencoder.exe
[Timer-1] DEBUG 16:48:19.228 Buffered Space: 0 bytes
[Thread-57] DEBUG 16:48:19.228 MEncoder Sherpya-SVN-r27811-4.2.5 (C) 2000-2008 MPlayer Team
[Thread-57] DEBUG 16:48:19.228 CPU: Intel(R) Core(TM)2 Duo CPU E8400 @ 3.00GHz (Family: 6, Model: 23, Stepping: 6)
[Thread-57] DEBUG 16:48:19.228 CPUflags: Type: 6 MMX: 1 MMX2: 1 3DNow: 0 3DNow2: 0 SSE: 1 SSE2: 1
[Thread-57] DEBUG 16:48:19.228 Compiled with runtime CPU detection.
[Thread-57] DEBUG 16:48:19.228 success: format: 0 data: 0x0 - 0x17dd5374
[Thread-57] DEBUG 16:48:19.228 [mkv] Track ID 1: video (V_MPEG4/ISO/AVC), -vid 0
[Thread-57] DEBUG 16:48:19.228 [mkv] Track ID 2: audio (A_DTS), -aid 0, -alang eng
[Thread-57] DEBUG 16:48:19.228 [mkv] Track ID 3: subtitles (S_TEXT/UTF8), -sid 0, -slang eng
[Thread-57] DEBUG 16:48:19.228 [mkv] Will play video track 1.
[Thread-57] DEBUG 16:48:19.228 Matroska file format detected.
[Thread-57] DEBUG 16:48:19.228 VIDEO: [avc1] 1280x544 24bpp 23.976 fps 0.0 kbps ( 0.0 kbyte/s)
[Thread-57] DEBUG 16:48:19.228 [V] filefmt:31 fourcc:0x31637661 size:1280x544 fps:23.976 ftime:=0.0417
[Thread-57] DEBUG 16:48:19.228 Input fps will be interpreted as 23.976 instead.
[Thread-57] DEBUG 16:48:19.228 ==========================================================================
[Thread-52] INFO 16:48:19.228 Result of \\.\pipe\mencoder1232401698760 : true
[Thread-57] DEBUG 16:48:19.228 Opening audio decoder: [libdca] DTS decoding with libdca
[Thread-57] DEBUG 16:48:19.228 AUDIO: 48000 Hz, 6 ch, s16le, 1536.0 kbit/33.33% (ratio: 192000->576000)
[Thread-57] DEBUG 16:48:19.228 Selected audio codec: [dts] afm: libdca (DTS-libdca)
[Thread-57] DEBUG 16:48:19.228 ==========================================================================
[Thread-57] DEBUG 16:48:19.228 PACKET SIZE: 2048 bytes, deltascr: 884
[Thread-54] DEBUG 16:48:19.228 Stream with high frequencies VQ coding
[Thread-54] DEBUG 16:48:19.228 Warning: -ass implies -keep-pts, which may cause "badly interleaved" files.
[Thread-57] DEBUG 16:48:19.228 [ass] auto-open
[Thread-54] DEBUG 16:48:19.228 [ass] Fontconfig disabled, only default font will be used.
[Thread-57] DEBUG 16:48:19.228 [ass] Init
[Thread-57] DEBUG 16:48:19.228 ==========================================================================
[Thread-57] DEBUG 16:48:19.243 Opening video decoder: [ffmpeg] FFmpeg's libavcodec codec family
[Thread-57] DEBUG 16:48:19.243 Selected video codec: [ffh264] vfm: ffmpeg (FFmpeg H.264)
[Thread-57] DEBUG 16:48:19.243 ==========================================================================
[Thread-54] DEBUG 16:48:19.243 Limiting audio preload to 0.4s.
[Thread-54] DEBUG 16:48:19.243 Increasing audio density to 4.
[Thread-57] DEBUG 16:48:19.275 VDec: vo config request - 1280 x 544 (preferred colorspace: Planar YV12)
[Thread-57] DEBUG 16:48:19.275 VDec: using Planar YV12 as output csp (no 0)
[Thread-57] DEBUG 16:48:19.275 Movie-Aspect is 2.35:1 - prescaling to correct movie aspect.
[Thread-57] DEBUG 16:48:19.275 videocodec: libavcodec (1280x544 fourcc=3267706d [mpg2])
[Thread-57] DEBUG 16:48:19.275 [VE_LAVC] Using constant qscale = 1.000000 (VBR).
[Thread-57] DEBUG 16:48:19.290 Writing header...
[Timer-1] DEBUG 16:48:20.242 Buffered Space: 2000000 bytes
[Timer-1] DEBUG 16:48:21.256 Buffered Space: 7000000 bytes
[Timer-1] DEBUG 16:48:22.270 Buffered Space: 14000000 bytes
[Timer-1] DEBUG 16:48:23.284 Buffered Space: 20000000 bytes
[Timer-1] DEBUG 16:48:24.298 Buffered Space: 25000000 bytes
[Thread-51] DEBUG 16:48:25.218 Wrote on socket: Content-Type: video/mpeg
[Thread-51] DEBUG 16:48:25.218 Wrote on socket: Connection: keep-alive
[Thread-51] DEBUG 16:48:25.218 Wrote on socket: Server: Windows Vista-x86-6.0 UPnP/1.0, PMS
[Thread-51] DEBUG 16:48:25.218 Wrote on socket:
[Timer-1] DEBUG 16:48:25.312 Buffered Space: 30754816 bytes
[Thread-58] DEBUG 16:48:25.312 Opened handler on socket Socket[addr=/192.168.0.98,port=60374,localport=4999]
[Thread-58] DEBUG 16:48:25.312 Received on socket: GET /get/0$0$5/Test1.mkv HTTP/1.1
[Thread-58] DEBUG 16:48:25.312 Received on socket: Host: 192.168.0.7:4999
[Thread-58] DEBUG 16:48:25.312 Received on socket: User-Agent: PLAYSTATION 3
[Thread-58] DEBUG 16:48:25.327 Received on socket: Connection: Keep-Alive
[Thread-58] DEBUG 16:48:25.327 Received on socket: Accept-Encoding: identity
[Thread-58] INFO 16:48:25.327 HTTP: get/0$0$5/Test1.mkv / 0-0
[Thread-58] DEBUG 16:48:25.327 Wrote on socket: HTTP/1.1 200 OK
[Thread-58] DEBUG 16:48:25.327 Searching for objectId: 0$0$5 with children option: false
[Thread-58] DEBUG 16:48:25.327 Asked stream chunk [0-0] timeseek: 0.0 of Test1.mkv and player MEncoder
[Thread-58] DEBUG 16:48:25.327 Wrote on socket: Content-Type: video/mpeg
[Thread-58] DEBUG 16:48:25.327 Wrote on socket: Connection: keep-alive
[Thread-58] DEBUG 16:48:25.327 Wrote on socket: Server: Windows Vista-x86-6.0 UPnP/1.0, PMS
[Thread-58] DEBUG 16:48:25.327 Wrote on socket:
[Thread-58] DEBUG 16:48:25.421 Sending stream with premature end : 1114112 bytes of get/0$0$5/Test1.mkv. Reason: An existing connection was forcibly closed by the remote host
[Thread-58] DEBUG 16:48:25.421 Ready to Stop: true
[Thread-58] DEBUG 16:48:25.421 Sending stream: 1114112 bytes of get/0$0$5/Test1.mkv
[Thread-58] DEBUG 16:48:25.421 Close Connection
[Thread-51] DEBUG 16:48:25.499 Ready to Stop: false
[Timer-1] DEBUG 16:48:26.326 Buffered Space: 39000000 bytes
[Timer-1] DEBUG 16:48:27.340 Buffered Space: 43000000 bytes
[Thread-54] DEBUG 16:48:27.527 [h264 @ 025AE8F0]Cannot parallelize deblocking type 1, decoding such frames in sequential order
[Thread-54] DEBUG 16:48:27.527 [ass] PlayResX undefined, setting 678.
[Thread-51] DEBUG 16:48:27.527 Sending stream with premature end : 1245184 bytes of get/0$0$5/Test1.mkv. Reason: An existing connection was forcibly closed by the remote host
[Thread-51] DEBUG 16:48:27.527 Ready to Stop: true
[Thread-51] DEBUG 16:48:27.527 Sending stream: 1245184 bytes of get/0$0$5/Test1.mkv
[Thread-51] DEBUG 16:48:27.527 Close Connection
[Thread-63] DEBUG 16:48:27.527 Opened handler on socket Socket[addr=/192.168.0.98,port=60373,localport=4999]
[Thread-63] DEBUG 16:48:27.543 Received on socket: GET /get/0$0$5/Test1.mkv HTTP/1.1
[Thread-63] DEBUG 16:48:27.543 Received on socket: Host: 192.168.0.7:4999
[Thread-63] DEBUG 16:48:27.543 Received on socket: User-Agent: PLAYSTATION 3
[Thread-63] DEBUG 16:48:27.543 Received on socket: Connection: Keep-Alive
[Thread-63] DEBUG 16:48:27.543 Received on socket: Accept-Encoding: identity
[Thread-63] DEBUG 16:48:27.543 Received on socket: TimeSeekRange.dlna.org : npt=0.000-
[Thread-63] INFO 16:48:27.543 HTTP: get/0$0$5/Test1.mkv / 0-0
[Thread-63] DEBUG 16:48:27.543 Wrote on socket: HTTP/1.1 200 OK
[Thread-63] DEBUG 16:48:27.543 Searching for objectId: 0$0$5 with children option: false
[Thread-63] DEBUG 16:48:27.543 Asked stream chunk [0-0] timeseek: 0.0 of Test1.mkv and player MEncoder
[Thread-63] DEBUG 16:48:27.543 Ready to Stop: false
[Thread-63] DEBUG 16:48:27.543 Wrote on socket: Content-Type: video/mpeg
[Thread-63] DEBUG 16:48:27.543 Wrote on socket: Connection: keep-alive
[Thread-63] DEBUG 16:48:27.543 Wrote on socket: Server: Windows Vista-x86-6.0 UPnP/1.0, PMS
[Thread-63] DEBUG 16:48:27.543 Wrote on socket:
[Timer-1] DEBUG 16:48:28.354 Buffered Space: 37463360 bytes
[Timer-1] DEBUG 16:48:29.368 Buffered Space: 40349248 bytes
[Thread-55] DEBUG 16:48:29.383 freeMemory: 3223576
[Thread-55] DEBUG 16:48:29.383 totalMemory: 60764160
[Thread-55] DEBUG 16:48:29.383 maxMemory: 799145984
[Thread-55] DEBUG 16:48:29.383 Extending buffer to 681574400
[Thread-55] DEBUG 16:48:29.945 Done extending
[Timer-1] DEBUG 16:48:30.382 Buffered Space: 42300672 bytes
[Timer-1] DEBUG 16:48:31.396 Buffered Space: 45252096 bytes
[Timer-1] DEBUG 16:48:32.410 Buffered Space: 47154944 bytes
[Timer-1] DEBUG 16:48:33.424 Buffered Space: 48009216 bytes
[Timer-1] DEBUG 16:48:34.438 Buffered Space: 48929024 bytes
[Timer-1] DEBUG 16:48:35.452 Buffered Space: 52766336 bytes
[Timer-1] DEBUG 16:48:36.466 Buffered Space: 55669184 bytes
[Timer-1] DEBUG 16:48:37.480 Buffered Space: 58572032 bytes
[Timer-1] DEBUG 16:48:38.494 Buffered Space: 61474880 bytes
[Timer-1] DEBUG 16:48:39.508 Buffered Space: 64443264 bytes
[Timer-1] DEBUG 16:48:40.522 Buffered Space: 69346112 bytes
[Timer-1] DEBUG 16:48:41.536 Buffered Space: 73248960 bytes
[Timer-1] DEBUG 16:48:42.550 Buffered Space: 78151808 bytes
[Timer-1] DEBUG 16:48:43.564 Buffered Space: 83054656 bytes
[Timer-1] DEBUG 16:48:44.578 Buffered Space: 86957504 bytes
[Timer-1] DEBUG 16:48:45.592 Buffered Space: 88860352 bytes
[Timer-1] DEBUG 16:48:46.606 Buffered Space: 89714624 bytes
[Timer-1] DEBUG 16:48:47.620 Buffered Space: 92617472 bytes
[Timer-1] DEBUG 16:48:48.634 Buffered Space: 95568896 bytes
[Timer-1] DEBUG 16:48:49.648 Buffered Space: 99437824 bytes
[Timer-1] DEBUG 16:48:50.662 Buffered Space: 102520320 bytes
[Timer-1] DEBUG 16:48:51.676 Buffered Space: 105520320 bytes
[Timer-1] DEBUG 16:48:52.690 Buffered Space: 109520320 bytes
[Timer-1] DEBUG 16:48:53.704 Buffered Space: 113471744 bytes
[Timer-1] DEBUG 16:48:54.718 Buffered Space: 116471744 bytes
[Timer-1] DEBUG 16:48:55.732 Buffered Space: 119471744 bytes
[Timer-1] DEBUG 16:48:56.746 Buffered Space: 123423168 bytes
[Timer-1] DEBUG 16:48:57.760 Buffered Space: 126046912 bytes
[Timer-1] DEBUG 16:48:58.774 Buffered Space: 130277440 bytes
[Timer-1] DEBUG 16:48:59.788 Buffered Space: 134228864 bytes
[Timer-1] DEBUG 16:49:00.802 Buffered Space: 136131712 bytes
[Timer-1] DEBUG 16:49:01.816 Buffered Space: 140083136 bytes
[Timer-1] DEBUG 16:49:02.830 Buffered Space: 145034560 bytes
[Timer-1] DEBUG 16:49:03.844 Buffered Space: 145937408 bytes
[Timer-1] DEBUG 16:49:04.858 Buffered Space: 150888832 bytes
[Timer-1] DEBUG 16:49:05.872 Buffered Space: 154857216 bytes
[Thread-63] DEBUG 16:49:06.121 Sending stream with premature end : 65142784 bytes of get/0$0$5/Test1.mkv. Reason: An existing connection was forcibly closed by the remote host
[Thread-63] DEBUG 16:49:06.121 Ready to Stop: true
[Thread-63] DEBUG 16:49:06.121 Sending stream: 65142784 bytes of get/0$0$5/Test1.mkv
[Thread-63] DEBUG 16:49:06.121 Close Connection
[Thread-66] DEBUG 16:49:06.184 Opened handler on socket Socket[addr=/192.168.0.98,port=60372,localport=4999]
[Thread-66] DEBUG 16:49:06.184 Received on socket: GET /get/0$0$5/thumbnail0000Test1.mkv HTTP/1.0
[Thread-66] DEBUG 16:49:06.184 Received on socket: Host: 192.168.0.7:4999
[Thread-66] DEBUG 16:49:06.184 Received on socket: User-Agent: PLAYSTATION 3
[Thread-66] DEBUG 16:49:06.199 Received on socket: Connection: close
[Thread-66] DEBUG 16:49:06.199 Received on socket: Accept-Encoding: identity
[Thread-66] DEBUG 16:49:06.199 Received on socket: Cache-Control: no-cache
[Thread-66] INFO 16:49:06.199 HTTP: get/0$0$5/thumbnail0000Test1.mkv / 0-0
[Thread-66] DEBUG 16:49:06.199 Wrote on socket: HTTP/1.0 200 OK
[Thread-66] DEBUG 16:49:06.199 Searching for objectId: 0$0$5 with children option: false
[Thread-66] DEBUG 16:49:06.199 Wrote on socket: Content-Type: image/png
[Thread-66] DEBUG 16:49:06.199 Wrote on socket: Accept-Ranges: bytes
[Thread-66] DEBUG 16:49:06.199 Wrote on socket: Expires: Fri, 15 May 2009 15:35:46 GMT
[Thread-66] DEBUG 16:49:06.199 Wrote on socket: Connection: keep-alive
[Thread-66] DEBUG 16:49:06.199 Wrote on socket: Server: Windows Vista-x86-6.0 UPnP/1.0, PMS
[Thread-66] DEBUG 16:49:06.199 Available Content-Length: 13288
[Thread-66] DEBUG 16:49:06.199 Wrote on socket: Content-Length: 13288
[Thread-66] DEBUG 16:49:06.199 Wrote on socket:
[Thread-66] DEBUG 16:49:06.199 Sending stream: 13288 bytes of get/0$0$5/thumbnail0000Test1.mkv
[Thread-66] DEBUG 16:49:06.199 Close Connection
[Thread-67] DEBUG 16:49:06.199 Opened handler on socket Socket[addr=/192.168.0.98,port=60371,localport=4999]
[Thread-67] DEBUG 16:49:06.199 Received on socket: GET /get/0$0$5/thumbnail0000Test1.mkv HTTP/1.1
[Thread-67] DEBUG 16:49:06.199 Received on socket: Host: 192.168.0.7:4999
[Thread-67] DEBUG 16:49:06.199 Received on socket: User-Agent: PLAYSTATION 3
[Thread-67] DEBUG 16:49:06.215 Received on socket: Connection: Keep-Alive
[Thread-67] DEBUG 16:49:06.215 Received on socket: Accept-Encoding: identity
[Thread-67] INFO 16:49:06.215 HTTP: get/0$0$5/thumbnail0000Test1.mkv / 0-0
[Thread-67] DEBUG 16:49:06.215 Wrote on socket: HTTP/1.1 200 OK
[Thread-67] DEBUG 16:49:06.215 Searching for objectId: 0$0$5 with children option: false
[Thread-67] DEBUG 16:49:06.215 Wrote on socket: Content-Type: image/png
[Thread-67] DEBUG 16:49:06.215 Wrote on socket: Accept-Ranges: bytes
[Thread-67] DEBUG 16:49:06.215 Wrote on socket: Expires: Fri, 15 May 2009 15:35:46 GMT
[Thread-67] DEBUG 16:49:06.215 Wrote on socket: Connection: keep-alive
[Thread-67] DEBUG 16:49:06.215 Wrote on socket: Server: Windows Vista-x86-6.0 UPnP/1.0, PMS
[Thread-67] DEBUG 16:49:06.215 Available Content-Length: 13288
[Thread-67] DEBUG 16:49:06.215 Wrote on socket: Content-Length: 13288
[Thread-67] DEBUG 16:49:06.215 Wrote on socket:
[Thread-67] DEBUG 16:49:06.215 Sending stream: 13288 bytes of get/0$0$5/thumbnail0000Test1.mkv
[Thread-67] DEBUG 16:49:06.215 Close Connection
[Thread-64] INFO 16:49:06.823 Stopping process: win32/mencoder.exe
[Thread-65] INFO 16:49:06.823 Stopping process: win32/mencoder.exe
[Thread-64] INFO 16:49:06.823 Destroying buffer
[Thread-65] INFO 16:49:06.839 Destroying buffer
[win32/mencoder.exe] DEBUG 16:49:06.839 EOF
[Thread-52] INFO 16:49:06.839 Disconnected pipe
[Thread-64] INFO 16:49:06.886 Destroying buffer
[Thread-65] INFO 16:49:06.886 Destroying buffer
[Thread-16] INFO 16:49:51.564 Sending BYEBYE...
[Thread-16] DEBUG 16:49:51.564 Setting multicast network interface: name:eth2 (Marvell Yukon 88E8056 PCI-E Gigabit Ethernet Controller) index: 8 addresses:
/192.168.0.7;

[Thread-16] DEBUG 16:49:51.595 Sending message from multicast socket on network interface: name:eth2 (Marvell Yukon 88E8056 PCI-E Gigabit Ethernet Controller) index: 8 addresses:
/192.168.0.7;

[Thread-16] DEBUG 16:49:51.595 Multicast socket is on interface: /192.168.0.7
[Thread-16] DEBUG 16:49:51.595 Socket Timeout: 0
[Thread-16] DEBUG 16:49:51.595 Socket TTL: 32
[Thread-16] DEBUG 16:49:51.595 Sending this SSDP packet: NOTIFY * HTTP/1.1<CRLF>HOST: 239.255.255.250:1900<CRLF>NT: upnp:rootdevice<CRLF>NTS: ssdp:byebye<CRLF>USN: uuid:1234567890TOTO::upnp:rootdevice<CRLF><CRLF>
[Thread-16] DEBUG 16:49:51.658 Sending this SSDP packet: NOTIFY * HTTP/1.1<CRLF>HOST: 239.255.255.250:1900<CRLF>NT: uuid:1234567890TOTO::<CRLF>NTS: ssdp:byebye<CRLF>USN: uuid:1234567890TOTO::<CRLF><CRLF>
[Thread-16] DEBUG 16:49:51.720 Sending this SSDP packet: NOTIFY * HTTP/1.1<CRLF>HOST: 239.255.255.250:1900<CRLF>NT: urn:schemas-upnp-org:device:MediaServer:1<CRLF>NTS: ssdp:byebye<CRLF>USN: uuid:1234567890TOTO::urn:schemas-upnp-org:device:MediaServer:1<CRLF><CRLF>
[Thread-16] DEBUG 16:49:51.783 Sending this SSDP packet: NOTIFY * HTTP/1.1<CRLF>HOST: 239.255.255.250:1900<CRLF>NT: urn:schemas-upnp-org:service:ContentDirectory:1<CRLF>NTS: ssdp:byebye<CRLF>USN: uuid:1234567890TOTO::urn:schemas-upnp-org:service:ContentDirectory:1<CRLF><CRLF>
[Thread-16] DEBUG 16:49:51.845 Sending this SSDP packet: NOTIFY * HTTP/1.1<CRLF>HOST: 239.255.255.250:1900<CRLF>CACHE-CONTROL: max-age=1800<CRLF>LOCATION: http://192.168.0.7:4999/description/fetch<CRLF>NT: urn:schemas-upnp-org:service:ConnectionManager:1<CRLF>NTS: ssdp:alive<CRLF>Server: Windows Vista-x86-6.0 UPnP/1.0, PMS<CRLF>USN: uuid:1234567890TOTO::urn:schemas-upnp-org:service:ConnectionManager:1<CRLF><CRLF>
[Thread-16] INFO 16:49:51.907 Forcing shutdown of all active processes
[Thread-16] INFO 16:49:51.907 Stopping server on host 192.168.0.7 and port 4999...
PS4
 
Posts: 21
Joined: Mon Jan 19, 2009 4:11 pm

Re: Some MKV's don't stream with 1.03

Postby shagrath » Mon Jan 19, 2009 11:01 pm

Ok thanks

here's 3 differences I'm seeing, so you can try some changes:

- in your 0.99 version, you have limited the bandwidth to 25 mbits, and not in the 1.03
- you are using the "force framerate parsed from ffmpeg" option in 0.99 (don't know if the option was there already, btw, maybe it's automatic), not in 1.03
- ultimately, that's not the same mencoder build between those two versions, so maybe just swapping the mencoder.exe could change something
shagrath
Project Lead
 
Posts: 2668
Joined: Wed Jan 14, 2009 1:39 pm

Re: Some MKV's don't stream with 1.03

Postby PS4 » Mon Jan 19, 2009 11:30 pm

U DA MAN!!!

It was "force framerate parsed from ffmpeg". As soon as I checked that, 1.03 started to work. Not sure what it meant and why I need it only for certain movies. It must have been on (by default and hidden) in 0.99.

But, there's a new problem. Sorry. :)

If I check multi-core support in mencode, I get the black screen again (with force framerate checked).

Debug log below.

[Thread-36] DEBUG 17:21:22.367 Opened handler on socket Socket[addr=/192.168.0.98,port=64913,localport=5001]
[Thread-36] DEBUG 17:21:22.367 Received on socket: POST /upnp/control/content_directory HTTP/1.1
[Thread-36] DEBUG 17:21:22.367 Received on socket: X-AV-Client-Info: av=5.0; cn="Sony Computer Entertainment Inc."; mn="PLAYSTATION 3"; mv="1.0";
[Thread-36] DEBUG 17:21:22.379 Received on socket: Host: 192.168.0.7:5001
[Thread-36] DEBUG 17:21:22.379 Received on socket: User-Agent: UPnP/1.0 DLNADOC/1.00
[Thread-36] DEBUG 17:21:22.379 Received on socket: Content-Length: 910
[Thread-36] DEBUG 17:21:22.380 Received on socket: Content-Type: text/xml; charset="utf-8"
[Thread-36] DEBUG 17:21:22.380 Received on socket: SOAPACTION: "urn:schemas-upnp-org:service:ContentDirectory:1#Browse"
[Thread-36] INFO 17:21:22.560 HTTP: upnp/control/content_directory / 0-0
[Thread-36] DEBUG 17:21:22.560 Wrote on socket: HTTP/1.1 200 OK
[Thread-36] DEBUG 17:21:22.560 Wrote on socket: CONTENT-TYPE: text/xml; charset="utf-8"
[Thread-36] DEBUG 17:21:22.560 Searching for objectId: 0$0 with children option: true
[Thread-36] DEBUG 17:21:22.561 Search extension for E:\TVersity-E\AVI
[Thread-36] INFO 17:21:22.561 Adding AVI / class: net.pms.dlna.RealFile
[Thread-36] DEBUG 17:21:22.562 Search extension for E:\TVersity-E\Documentaries
[Thread-36] INFO 17:21:22.562 Adding Documentaries / class: net.pms.dlna.RealFile
[Thread-36] DEBUG 17:21:22.562 Search extension for E:\TVersity-E\DVD
[Thread-36] INFO 17:21:22.562 Adding DVD / class: net.pms.dlna.RealFile
[Thread-36] DEBUG 17:21:22.562 Search extension for E:\TVersity-E\M2TS
[Thread-36] INFO 17:21:22.563 Adding M2TS / class: net.pms.dlna.RealFile
[Thread-36] DEBUG 17:21:22.563 Search extension for E:\TVersity-E\MKV
[Thread-36] INFO 17:21:22.563 Adding MKV / class: net.pms.dlna.RealFile
[Thread-36] DEBUG 17:21:22.564 Search extension for E:\TVersity-E\list1.txt
[Thread-36] DEBUG 17:21:22.564 Search extension for E:\TVersity-E\Test1.mkv
[Thread-36] DEBUG 17:21:22.564 Found 1! net.pms.formats.MKV
[Thread-36] INFO 17:21:22.565 Adding Test1.mkv / class: net.pms.dlna.RealFile
[Thread-36] INFO 17:21:22.567 Switching Test1.mkv to player: MEncoder
[Thread-36] INFO 17:21:22.567 Duplicate Test1.mkv with player: MEncoder
[Thread-36] INFO 17:21:22.567 Adding Test1.mkv / class: net.pms.dlna.FileTranscodeVirtualFolder
[Thread-36] DEBUG 17:21:22.567 Setting DLNA id 0$0$0 to AVI
[Thread-36] DEBUG 17:21:22.567 Setting DLNA id 0$0$1 to Documentaries
[Thread-36] DEBUG 17:21:22.567 Setting DLNA id 0$0$2 to DVD
[Thread-36] DEBUG 17:21:22.567 Setting DLNA id 0$0$3 to M2TS
[Thread-36] DEBUG 17:21:22.567 Setting DLNA id 0$0$4 to MKV
[Thread-36] DEBUG 17:21:22.567 Setting DLNA id 0$0$5 to Test1.mkv
[Thread-36] DEBUG 17:21:22.567 Setting DLNA id 0$0$6 to #--TRANSCODED--#
[Thread-36] DEBUG 17:21:22.567 Setting DLNA id 0$0$6$0 to Test1.mkv
[Thread-36] DEBUG 17:21:22.567 Setting DLNA id 0$0$6$0$0 to Test1.mkv
[pool-3-thread-1] INFO 17:21:22.572 Starting C:\Program Files\PS3 Media Server\win32\ffmpeg.exe -ss 120 -i E:\TVersity-E\Test1.mkv -an -an -s 320x180 -vframes 1 -f image2 pipe:
[pool-3-thread-1] INFO 17:21:22.578 Attaching thread: win32/ffmpeg.exe
[Thread-38] DEBUG 17:21:22.809 FFmpeg version SVN-r16043-Sherpya, Copyright (c) 2000-2008 Fabrice Bellard, et al.
[Thread-38] DEBUG 17:21:22.809 libavutil 49.12. 0 / 49.12. 0
[Thread-38] DEBUG 17:21:22.809 libavcodec 52. 6. 1 / 52. 6. 1
[Thread-38] DEBUG 17:21:22.809 libavformat 52.23. 1 / 52.23. 1
[Thread-38] DEBUG 17:21:22.809 libavdevice 52. 1. 0 / 52. 1. 0
[Thread-38] DEBUG 17:21:22.809 libavfilter 0. 1. 0 / 0. 1. 0
[Thread-38] DEBUG 17:21:22.809 libswscale 0. 6. 1 / 0. 6. 1
[Thread-38] DEBUG 17:21:22.809 libpostproc 51. 2. 0 / 51. 2. 0
[Thread-38] DEBUG 17:21:22.809 built on Dec 10 2008 18:25:26, gcc: 4.2.5 20080919 (prerelease) [Sherpya]
[Thread-38] DEBUG 17:21:22.810 Input #0, matroska, from 'E:\TVersity-E\Test1.mkv':
[Thread-38] DEBUG 17:21:22.810 Duration: 01:40:58.14, start: 0.000000, bitrate: N/A
[Thread-38] DEBUG 17:21:22.810 Stream #0.0(eng): Video: h264, yuv420p, 1280x544, 23.98 tb(r)
[Thread-38] DEBUG 17:21:22.810 Stream #0.1(eng): Audio: dca, 48000 Hz, 5.1, s16
[Thread-38] DEBUG 17:21:22.810 Stream #0.2(eng): Subtitle: 0x0000
[Thread-38] DEBUG 17:21:22.810 Output #0, image2, to 'pipe:':
[Thread-38] DEBUG 17:21:22.810 Stream #0.0(eng): Video: mjpeg, yuvj420p, 320x180 [PAR 45:34 DAR 40:17], q=2-31, 200 kb/s, 23.98 tb(c)
[Thread-38] DEBUG 17:21:22.810 Stream mapping:
[Thread-38] DEBUG 17:21:22.810 Stream #0.0 -> #0.0
[Thread-38] DEBUG 17:21:22.810 Press [q] to stop encoding
[Thread-38] DEBUG 17:21:22.810 video:14kB audio:0kB global headers:0kB muxing overhead -100.156807%
[pool-3-thread-1] DEBUG 17:21:22.814 EOF
[pool-3-thread-1] DEBUG 17:21:22.815 Ready to Stop: true
[pool-3-thread-1] DEBUG 17:21:22.844 Media info: mimeType: video/mp4 / container: matroska / bitrate: 0 / size: 4695348084 / codecV: h264 / duration: 01:40:58.140 / width: 1280 / height: 544 / frameRate: 23.98 / codecA: dca / sampleFrequency: 48000 / nrAudioChannels: 0
[Thread-36] DEBUG 17:21:22.844 End of analysis
[Thread-36] DEBUG 17:21:22.846 Wrote on socket: Server: Windows Vista-x86-6.0 UPnP/1.0, PMS
[Thread-36] DEBUG 17:21:22.846 Wrote on socket: Content-Length: 3801
[Thread-36] DEBUG 17:21:22.846 Wrote on socket:
[Thread-36] DEBUG 17:21:22.846 Close Connection
[Thread-42] DEBUG 17:21:23.413 Opened handler on socket Socket[addr=/192.168.0.98,port=64912,localport=5001]
[Thread-42] DEBUG 17:21:23.413 Received on socket: POST /upnp/control/content_directory HTTP/1.1
[Thread-42] DEBUG 17:21:23.413 Received on socket: X-AV-Client-Info: av=5.0; cn="Sony Computer Entertainment Inc."; mn="PLAYSTATION 3"; mv="1.0";
[Thread-42] DEBUG 17:21:23.426 Received on socket: Host: 192.168.0.7:5001
[Thread-42] DEBUG 17:21:23.426 Received on socket: User-Agent: UPnP/1.0 DLNADOC/1.00
[Thread-42] DEBUG 17:21:23.426 Received on socket: Content-Length: 276
[Thread-42] DEBUG 17:21:23.426 Received on socket: Content-Type: text/xml; charset="utf-8"
[Thread-42] DEBUG 17:21:23.426 Received on socket: SOAPACTION: "urn:schemas-upnp-org:service:ContentDirectory:1#GetSystemUpdateID"
[Thread-43] DEBUG 17:21:23.493 Opened handler on socket Socket[addr=/192.168.0.98,port=64911,localport=5001]
[Thread-43] DEBUG 17:21:23.493 Received on socket: GET /get/0$0$5/thumbnail0000Test1.mkv HTTP/1.0
[Thread-43] DEBUG 17:21:23.493 Received on socket: Host: 192.168.0.7:5001
[Thread-43] DEBUG 17:21:23.493 Received on socket: User-Agent: PLAYSTATION 3
[Thread-43] DEBUG 17:21:23.505 Received on socket: Connection: close
[Thread-43] DEBUG 17:21:23.505 Received on socket: Accept-Encoding: identity
[Thread-43] DEBUG 17:21:23.505 Received on socket: Cache-Control: no-cache
[Thread-43] INFO 17:21:23.505 HTTP: get/0$0$5/thumbnail0000Test1.mkv / 0-0
[Thread-43] DEBUG 17:21:23.505 Wrote on socket: HTTP/1.0 200 OK
[Thread-43] DEBUG 17:21:23.505 Searching for objectId: 0$0$5 with children option: false
[Thread-43] DEBUG 17:21:23.505 Wrote on socket: Content-Type: image/png
[Thread-43] DEBUG 17:21:23.505 Wrote on socket: Accept-Ranges: bytes
[Thread-43] DEBUG 17:21:23.506 Wrote on socket: Expires: Fri, 15 May 2009 16:08:03 GMT
[Thread-43] DEBUG 17:21:23.506 Wrote on socket: Connection: keep-alive
[Thread-43] DEBUG 17:21:23.506 Wrote on socket: Server: Windows Vista-x86-6.0 UPnP/1.0, PMS
[Thread-43] DEBUG 17:21:23.506 Available Content-Length: 12841
[Thread-43] DEBUG 17:21:23.506 Wrote on socket: Content-Length: 12841
[Thread-43] DEBUG 17:21:23.506 Wrote on socket:
[Thread-43] DEBUG 17:21:23.508 Sending stream: 12841 bytes of get/0$0$5/thumbnail0000Test1.mkv
[Thread-43] DEBUG 17:21:23.508 Close Connection
[Thread-41] INFO 17:21:23.516 Stopping process: win32/ffmpeg.exe
[Thread-41] INFO 17:21:23.516 Destroying buffer
[Thread-41] INFO 17:21:23.561 Destroying buffer
[Thread-44] DEBUG 17:21:23.605 Opened handler on socket Socket[addr=/192.168.0.98,port=64910,localport=5001]
[Thread-44] DEBUG 17:21:23.606 Received on socket: GET /get/0$0$5/thumbnail0000Test1.mkv HTTP/1.1
[Thread-44] DEBUG 17:21:23.606 Received on socket: Host: 192.168.0.7:5001
[Thread-44] DEBUG 17:21:23.606 Received on socket: User-Agent: PLAYSTATION 3
[Thread-42] INFO 17:21:23.610 HTTP: upnp/control/content_directory / 0-0
[Thread-42] DEBUG 17:21:23.610 Wrote on socket: HTTP/1.1 200 OK
[Thread-42] DEBUG 17:21:23.610 Wrote on socket: CONTENT-TYPE: text/xml; charset="utf-8"
[Thread-42] DEBUG 17:21:23.610 Wrote on socket: Server: Windows Vista-x86-6.0 UPnP/1.0, PMS
[Thread-42] DEBUG 17:21:23.610 Wrote on socket: Content-Length: 332
[Thread-42] DEBUG 17:21:23.610 Wrote on socket:
[Thread-42] DEBUG 17:21:23.611 Close Connection
[Thread-45] DEBUG 17:21:23.619 Opened handler on socket Socket[addr=/192.168.0.98,port=64909,localport=5001]
[Thread-45] DEBUG 17:21:23.619 Received on socket: POST /upnp/control/content_directory HTTP/1.1
[Thread-45] DEBUG 17:21:23.619 Received on socket: X-AV-Client-Info: av=5.0; cn="Sony Computer Entertainment Inc."; mn="PLAYSTATION 3"; mv="1.0";
[Thread-45] DEBUG 17:21:23.630 Received on socket: Host: 192.168.0.7:5001
[Thread-45] DEBUG 17:21:23.630 Received on socket: User-Agent: UPnP/1.0 DLNADOC/1.00
[Thread-45] DEBUG 17:21:23.630 Received on socket: Content-Length: 903
[Thread-45] DEBUG 17:21:23.630 Received on socket: Content-Type: text/xml; charset="utf-8"
[Thread-45] DEBUG 17:21:23.630 Received on socket: SOAPACTION: "urn:schemas-upnp-org:service:ContentDirectory:1#Browse"
[Thread-44] DEBUG 17:21:23.631 Received on socket: Connection: Keep-Alive
[Thread-44] DEBUG 17:21:23.631 Received on socket: Accept-Encoding: identity
[Thread-44] INFO 17:21:23.631 HTTP: get/0$0$5/thumbnail0000Test1.mkv / 0-0
[Thread-44] DEBUG 17:21:23.631 Wrote on socket: HTTP/1.1 200 OK
[Thread-44] DEBUG 17:21:23.631 Searching for objectId: 0$0$5 with children option: false
[Thread-44] DEBUG 17:21:23.631 Wrote on socket: Content-Type: image/png
[Thread-44] DEBUG 17:21:23.631 Wrote on socket: Accept-Ranges: bytes
[Thread-44] DEBUG 17:21:23.631 Wrote on socket: Expires: Fri, 15 May 2009 16:08:03 GMT
[Thread-44] DEBUG 17:21:23.631 Wrote on socket: Connection: keep-alive
[Thread-44] DEBUG 17:21:23.631 Wrote on socket: Server: Windows Vista-x86-6.0 UPnP/1.0, PMS
[Thread-44] DEBUG 17:21:23.632 Available Content-Length: 12841
[Thread-44] DEBUG 17:21:23.632 Wrote on socket: Content-Length: 12841
[Thread-44] DEBUG 17:21:23.632 Wrote on socket:
[Thread-44] DEBUG 17:21:23.632 Sending stream: 12841 bytes of get/0$0$5/thumbnail0000Test1.mkv
[Thread-44] DEBUG 17:21:23.632 Close Connection
[Thread-45] INFO 17:21:23.810 HTTP: upnp/control/content_directory / 0-0
[Thread-45] DEBUG 17:21:23.810 Wrote on socket: HTTP/1.1 200 OK
[Thread-45] DEBUG 17:21:23.810 Wrote on socket: CONTENT-TYPE: text/xml; charset="utf-8"
[Thread-45] DEBUG 17:21:23.810 Searching for objectId: 0$0 with children option: false
[Thread-45] DEBUG 17:21:23.811 Search extension for list1.txt
[Thread-45] DEBUG 17:21:23.813 Wrote on socket: Server: Windows Vista-x86-6.0 UPnP/1.0, PMS
[Thread-45] DEBUG 17:21:23.813 Wrote on socket: Content-Length: 1022
[Thread-45] DEBUG 17:21:23.813 Wrote on socket:
[Thread-45] DEBUG 17:21:23.813 Close Connection
[Thread-46] DEBUG 17:21:27.295 Opened handler on socket Socket[addr=/192.168.0.98,port=64908,localport=5001]
[Thread-46] DEBUG 17:21:27.295 Received on socket: GET /get/0$0$5/Test1.mkv HTTP/1.1
[Thread-46] DEBUG 17:21:27.296 Received on socket: Host: 192.168.0.7:5001
[Thread-46] DEBUG 17:21:27.296 Received on socket: User-Agent: PLAYSTATION 3
[Thread-46] DEBUG 17:21:27.308 Received on socket: Connection: Keep-Alive
[Thread-46] DEBUG 17:21:27.308 Received on socket: Accept-Encoding: identity
[Thread-46] INFO 17:21:27.308 HTTP: get/0$0$5/Test1.mkv / 0-0
[Thread-46] DEBUG 17:21:27.308 Wrote on socket: HTTP/1.1 200 OK
[Thread-46] DEBUG 17:21:27.308 Searching for objectId: 0$0$5 with children option: false
[Thread-46] DEBUG 17:21:27.308 Asked stream chunk [0-0] timeseek: 0.0 of Test1.mkv and player MEncoder
[Thread-46] TRACE 17:21:27.308 Starting transcode of Test1.mkv
[Thread-46] INFO 17:21:27.311 Creating pipe \\.\pipe\mencoder1232403687309
[Timer-1] DEBUG 17:21:27.428 Buffered Space: 0 bytes
[Thread-47] INFO 17:21:27.428 Waiting for pipe connection \\.\pipe\mencoder1232403687309
[win32/mencoder_mt.exe] INFO 17:21:27.513 Starting C:\Program Files\PS3 Media Server\win32\mencoder_mt.exe -ss 0 -quiet E:\TVersity-E\Test1.mkv -quiet -quiet -oac lavc -of mpeg -mpegopts format=mpeg2:muxrate=500000:vbuf_size=1194:abuf_size=64 -ovc lavc -channels 6 -lavdopts debug=0:threads=2 -lavcopts autoaspect=1:vcodec=mpeg2video:acodec=ac3:abitrate=384:threads=2:keyint=1:vqscale=1:vqmin=2 -ass -nofontconfig -subcp cp1252 -alang eng,fre,jpn,ger -ass-color ffffff00 -ass-border-color 00000000 -ass-font-scale 1.0 -ass-force-style FontName=Arial,Outline=1,Shadow=1,MarginV=10 -slang eng,fre,jpn,ger -quiet -quiet -fps 24000/1001 -ofps 24000/1001 -quiet -quiet -lavdopts fast -af lavcresample=48000 -srate 48000 -o \\.\pipe\mencoder1232403687309
[win32/mencoder_mt.exe] INFO 17:21:27.515 Reading pipe: \\.\pipe\mencoder1232403687309
[win32/mencoder_mt.exe] INFO 17:21:27.515 Attaching thread: win32/mencoder_mt.exe
[Thread-51] DEBUG 17:21:27.526 MEncoder MT-SVN-r28126-Build-from-Sherpya-4.2.4 (C) 2000-2008 MPlayer Team
[Thread-51] DEBUG 17:21:27.526 CPU: Intel(R) Core(TM)2 Duo CPU E8400 @ 3.00GHz (Family: 6, Model: 23, Stepping: 6)
[Thread-51] DEBUG 17:21:27.526 CPUflags: Type: 6 MMX: 1 MMX2: 1 3DNow: 0 3DNow2: 0 SSE: 1 SSE2: 1
[Thread-51] DEBUG 17:21:27.526 Compiled for x86 CPU with extensions: MMX MMX2 SSE SSE2
[Thread-51] DEBUG 17:21:27.540 success: format: 0 data: 0x0 - 0x17dd5374
[Thread-51] DEBUG 17:21:27.542 [mkv] Track ID 1: video (V_MPEG4/ISO/AVC), -vid 0
[Thread-51] DEBUG 17:21:27.542 [mkv] Track ID 2: audio (A_DTS), -aid 0, -alang eng
[Thread-51] DEBUG 17:21:27.542 [mkv] Track ID 3: subtitles (S_TEXT/UTF8), -sid 0, -slang eng
[Thread-51] DEBUG 17:21:27.542 [mkv] Will play video track 1.
[Thread-51] DEBUG 17:21:27.542 Matroska file format detected.
[Thread-51] DEBUG 17:21:27.542 VIDEO: [avc1] 1280x544 24bpp 23.976 fps 0.0 kbps ( 0.0 kbyte/s)
[Thread-51] DEBUG 17:21:27.542 [V] filefmt:31 fourcc:0x31637661 size:1280x544 fps:23.976 ftime:=0.0417
[Thread-51] DEBUG 17:21:27.542 Input fps will be interpreted as 23.976 instead.
[Thread-51] DEBUG 17:21:27.542 ==========================================================================
[Thread-51] DEBUG 17:21:27.542 Opening audio decoder: [libdca] DTS decoding with libdca
[Thread-51] DEBUG 17:21:27.543 AUDIO: 48000 Hz, 6 ch, s16le, 1536.0 kbit/33.33% (ratio: 192000->576000)
[Thread-51] DEBUG 17:21:27.543 Selected audio codec: [dts] afm: libdca (DTS-libdca)
[Thread-51] DEBUG 17:21:27.543 ==========================================================================
[Thread-51] DEBUG 17:21:27.543 PACKET SIZE: 2048 bytes, deltascr: 884
[Thread-50] DEBUG 17:21:27.543 Stream with high frequencies VQ coding
[Thread-51] DEBUG 17:21:27.544 [ass] auto-open
[Thread-50] DEBUG 17:21:27.544 Warning: -ass implies -keep-pts, which may cause "badly interleaved" files.
[Thread-47] INFO 17:21:27.544 Result of \\.\pipe\mencoder1232403687309 : true
[Thread-50] DEBUG 17:21:27.544 [ass] Fontconfig disabled, only default font will be used.
[Thread-51] DEBUG 17:21:27.544 [ass] Init
[Thread-51] DEBUG 17:21:27.544 ==========================================================================
[Thread-51] DEBUG 17:21:27.545 Opening video decoder: [ffmpeg] FFmpeg's libavcodec codec family
[Thread-51] DEBUG 17:21:27.545 Selected video codec: [ffh264] vfm: ffmpeg (FFmpeg H.264)
[Thread-51] DEBUG 17:21:27.545 ==========================================================================
[Thread-50] DEBUG 17:21:27.545 Limiting audio preload to 0.4s.
[Thread-50] DEBUG 17:21:27.545 Increasing audio density to 4.
[Thread-51] DEBUG 17:21:27.568 Writing header...
[Thread-51] DEBUG 17:21:27.584 VDec: vo config request - 1280 x 544 (preferred colorspace: Planar YV12)
[Thread-51] DEBUG 17:21:27.584 VDec: using Planar YV12 as output csp (no 0)
[Thread-51] DEBUG 17:21:27.584 Movie-Aspect is 2.35:1 - prescaling to correct movie aspect.
[Thread-51] DEBUG 17:21:27.584 videocodec: libavcodec (1280x544 fourcc=3267706d [mpg2])
[Thread-51] DEBUG 17:21:27.584 [VE_LAVC] Using constant qscale = 1.000000 (VBR).
[Timer-1] DEBUG 17:21:28.429 Buffered Space: 3815424 bytes
[Timer-1] DEBUG 17:21:29.430 Buffered Space: 14032896 bytes
[Timer-1] DEBUG 17:21:30.429 Buffered Space: 23588864 bytes
[Timer-1] DEBUG 17:21:31.429 Buffered Space: 33095680 bytes
[Timer-1] DEBUG 17:21:32.429 Buffered Space: 41734144 bytes
[Thread-37] INFO 17:21:32.572 Stopping process: win32/ffmpeg.exe
[Thread-37] INFO 17:21:32.572 Destroying buffer
[Thread-50] DEBUG 17:21:32.993 [ass] PlayResX undefined, setting 678.
[Timer-1] DEBUG 17:21:33.429 Buffered Space: 44906496 bytes
[Thread-46] DEBUG 17:21:33.563 Wrote on socket: Content-Type: video/mpeg
[Thread-46] DEBUG 17:21:33.563 Wrote on socket: Connection: keep-alive
[Thread-46] DEBUG 17:21:33.563 Wrote on socket: Server: Windows Vista-x86-6.0 UPnP/1.0, PMS
[Thread-46] DEBUG 17:21:33.563 Wrote on socket:
[Thread-52] DEBUG 17:21:33.674 Opened handler on socket Socket[addr=/192.168.0.98,port=64907,localport=5001]
[Thread-52] DEBUG 17:21:33.675 Received on socket: GET /get/0$0$5/Test1.mkv HTTP/1.1
[Thread-52] DEBUG 17:21:33.675 Received on socket: Host: 192.168.0.7:5001
[Thread-52] DEBUG 17:21:33.675 Received on socket: User-Agent: PLAYSTATION 3
[Thread-52] DEBUG 17:21:33.688 Received on socket: Connection: Keep-Alive
[Thread-52] DEBUG 17:21:33.688 Received on socket: Accept-Encoding: identity
[Thread-52] INFO 17:21:33.688 HTTP: get/0$0$5/Test1.mkv / 0-0
[Thread-52] DEBUG 17:21:33.688 Wrote on socket: HTTP/1.1 200 OK
[Thread-52] DEBUG 17:21:33.688 Searching for objectId: 0$0$5 with children option: false
[Thread-52] DEBUG 17:21:33.688 Asked stream chunk [0-0] timeseek: 0.0 of Test1.mkv and player MEncoder
[Thread-52] DEBUG 17:21:33.688 Wrote on socket: Content-Type: video/mpeg
[Thread-52] DEBUG 17:21:33.688 Wrote on socket: Connection: keep-alive
[Thread-52] DEBUG 17:21:33.688 Wrote on socket: Server: Windows Vista-x86-6.0 UPnP/1.0, PMS
[Thread-52] DEBUG 17:21:33.688 Wrote on socket:
[Thread-52] DEBUG 17:21:33.779 Sending stream with premature end : 1114112 bytes of get/0$0$5/Test1.mkv. Reason: An existing connection was forcibly closed by the remote host
[Thread-52] DEBUG 17:21:33.779 Ready to Stop: true
[Thread-52] DEBUG 17:21:33.779 Sending stream: 1114112 bytes of get/0$0$5/Test1.mkv
[Thread-52] DEBUG 17:21:33.780 Close Connection
[Thread-47] DEBUG 17:21:34.232 freeMemory: 38783848
[Thread-47] DEBUG 17:21:34.233 totalMemory: 94982144
[Thread-47] DEBUG 17:21:34.233 maxMemory: 799145984
[Thread-47] DEBUG 17:21:34.233 Extending buffer to 419430400
[Timer-1] DEBUG 17:21:34.429 Buffered Space: 49991680 bytes
[Thread-54] INFO 17:21:34.491 Stopping process: win32/mencoder_mt.exe
[Thread-54] INFO 17:21:34.491 Destroying buffer
[win32/mencoder_mt.exe] DEBUG 17:21:34.813 EOF
[Thread-53] INFO 17:21:34.813 Destroying buffer
[Thread-47] DEBUG 17:21:34.848 EOF
[Thread-47] INFO 17:21:34.848 Disconnected pipe
[Thread-46] DEBUG 17:21:35.904 Sending stream with premature end : 1245184 bytes of get/0$0$5/Test1.mkv. Reason: An existing connection was forcibly closed by the remote host
[Thread-46] DEBUG 17:21:35.905 Sending stream: 1245184 bytes of get/0$0$5/Test1.mkv
[Thread-46] DEBUG 17:21:35.905 Close Connection
[Thread-57] DEBUG 17:21:35.906 Opened handler on socket Socket[addr=/192.168.0.98,port=64906,localport=5001]
[Thread-57] DEBUG 17:21:35.906 Received on socket: GET /get/0$0$5/Test1.mkv HTTP/1.1
[Thread-57] DEBUG 17:21:35.906 Received on socket: Host: 192.168.0.7:5001
[Thread-57] DEBUG 17:21:35.906 Received on socket: User-Agent: PLAYSTATION 3
[Thread-57] DEBUG 17:21:35.920 Received on socket: Connection: Keep-Alive
[Thread-57] DEBUG 17:21:35.920 Received on socket: Accept-Encoding: identity
[Thread-57] DEBUG 17:21:35.920 Received on socket: TimeSeekRange.dlna.org : npt=0.000-
[Thread-57] INFO 17:21:35.920 HTTP: get/0$0$5/Test1.mkv / 0-0
[Thread-57] DEBUG 17:21:35.920 Wrote on socket: HTTP/1.1 200 OK
[Thread-57] DEBUG 17:21:35.921 Searching for objectId: 0$0$5 with children option: false
[Thread-57] DEBUG 17:21:35.921 Asked stream chunk [0-0] timeseek: 0.0 of Test1.mkv and player MEncoder
[Thread-57] TRACE 17:21:35.921 Starting transcode of Test1.mkv
[Thread-57] INFO 17:21:35.921 Creating pipe \\.\pipe\mencoder1232403695921
[Timer-2] DEBUG 17:21:35.936 Buffered Space: 0 bytes
[Thread-58] INFO 17:21:35.941 Waiting for pipe connection \\.\pipe\mencoder1232403695921
[win32/mencoder_mt.exe] INFO 17:21:35.991 Starting C:\Program Files\PS3 Media Server\win32\mencoder_mt.exe -ss 0 -quiet E:\TVersity-E\Test1.mkv -quiet -quiet -oac lavc -of mpeg -mpegopts format=mpeg2:muxrate=500000:vbuf_size=1194:abuf_size=64 -ovc lavc -channels 6 -lavdopts debug=0:threads=2 -lavcopts autoaspect=1:vcodec=mpeg2video:acodec=ac3:abitrate=384:threads=2:keyint=1:vqscale=1:vqmin=2 -ass -nofontconfig -subcp cp1252 -alang eng,fre,jpn,ger -ass-color ffffff00 -ass-border-color 00000000 -ass-font-scale 1.0 -ass-force-style FontName=Arial,Outline=1,Shadow=1,MarginV=10 -slang eng,fre,jpn,ger -quiet -quiet -fps 24000/1001 -ofps 24000/1001 -quiet -quiet -lavdopts fast -af lavcresample=48000 -srate 48000 -o \\.\pipe\mencoder1232403695921
[win32/mencoder_mt.exe] INFO 17:21:35.993 Reading pipe: \\.\pipe\mencoder1232403695921
[win32/mencoder_mt.exe] INFO 17:21:35.993 Attaching thread: win32/mencoder_mt.exe
[Thread-61] DEBUG 17:21:36.009 MEncoder MT-SVN-r28126-Build-from-Sherpya-4.2.4 (C) 2000-2008 MPlayer Team
[Thread-61] DEBUG 17:21:36.009 CPU: Intel(R) Core(TM)2 Duo CPU E8400 @ 3.00GHz (Family: 6, Model: 23, Stepping: 6)
[Thread-61] DEBUG 17:21:36.009 CPUflags: Type: 6 MMX: 1 MMX2: 1 3DNow: 0 3DNow2: 0 SSE: 1 SSE2: 1
[Thread-61] DEBUG 17:21:36.010 Compiled for x86 CPU with extensions: MMX MMX2 SSE SSE2
[Thread-61] DEBUG 17:21:36.030 success: format: 0 data: 0x0 - 0x17dd5374
[Thread-61] DEBUG 17:21:36.032 [mkv] Track ID 1: video (V_MPEG4/ISO/AVC), -vid 0
[Thread-61] DEBUG 17:21:36.033 [mkv] Track ID 2: audio (A_DTS), -aid 0, -alang eng
[Thread-61] DEBUG 17:21:36.033 [mkv] Track ID 3: subtitles (S_TEXT/UTF8), -sid 0, -slang eng
[Thread-61] DEBUG 17:21:36.033 [mkv] Will play video track 1.
[Thread-61] DEBUG 17:21:36.033 Matroska file format detected.
[Thread-61] DEBUG 17:21:36.033 VIDEO: [avc1] 1280x544 24bpp 23.976 fps 0.0 kbps ( 0.0 kbyte/s)
[Thread-61] DEBUG 17:21:36.033 [V] filefmt:31 fourcc:0x31637661 size:1280x544 fps:23.976 ftime:=0.0417
[Thread-61] DEBUG 17:21:36.033 Input fps will be interpreted as 23.976 instead.
[Thread-61] DEBUG 17:21:36.033 ==========================================================================
[Thread-61] DEBUG 17:21:36.034 Opening audio decoder: [libdca] DTS decoding with libdca
[Thread-61] DEBUG 17:21:36.034 AUDIO: 48000 Hz, 6 ch, s16le, 1536.0 kbit/33.33% (ratio: 192000->576000)
[Thread-61] DEBUG 17:21:36.034 Selected audio codec: [dts] afm: libdca (DTS-libdca)
[Thread-61] DEBUG 17:21:36.034 ==========================================================================
[Thread-61] DEBUG 17:21:36.034 PACKET SIZE: 2048 bytes, deltascr: 884
[Thread-58] INFO 17:21:36.034 Result of \\.\pipe\mencoder1232403695921 : true
[Thread-61] DEBUG 17:21:36.035 [ass] auto-open
[Thread-60] DEBUG 17:21:36.035 Stream with high frequencies VQ coding
[Thread-60] DEBUG 17:21:36.035 Warning: -ass implies -keep-pts, which may cause "badly interleaved" files.
[Thread-61] DEBUG 17:21:36.036 [ass] Init
[Thread-60] DEBUG 17:21:36.036 [ass] Fontconfig disabled, only default font will be used.
[Thread-61] DEBUG 17:21:36.036 ==========================================================================
[Thread-61] DEBUG 17:21:36.037 Opening video decoder: [ffmpeg] FFmpeg's libavcodec codec family
[Thread-61] DEBUG 17:21:36.038 Selected video codec: [ffh264] vfm: ffmpeg (FFmpeg H.264)
[Thread-61] DEBUG 17:21:36.038 ==========================================================================
[Thread-60] DEBUG 17:21:36.039 Limiting audio preload to 0.4s.
[Thread-60] DEBUG 17:21:36.039 Increasing audio density to 4.
[Thread-61] DEBUG 17:21:36.076 Writing header...
[Thread-61] DEBUG 17:21:36.097 VDec: vo config request - 1280 x 544 (preferred colorspace: Planar YV12)
[Thread-61] DEBUG 17:21:36.098 VDec: using Planar YV12 as output csp (no 0)
[Thread-61] DEBUG 17:21:36.098 Movie-Aspect is 2.35:1 - prescaling to correct movie aspect.
[Thread-61] DEBUG 17:21:36.098 videocodec: libavcodec (1280x544 fourcc=3267706d [mpg2])
[Thread-61] DEBUG 17:21:36.098 [VE_LAVC] Using constant qscale = 1.000000 (VBR).
[Thread-56] INFO 17:21:36.605 Destroying buffer
[Thread-55] INFO 17:21:36.674 Destroying buffer
[Timer-2] DEBUG 17:21:36.936 Buffered Space: 3244032 bytes
[Timer-2] DEBUG 17:21:37.937 Buffered Space: 12240896 bytes
[Timer-2] DEBUG 17:21:38.937 Buffered Space: 21774336 bytes
[Timer-2] DEBUG 17:21:39.937 Buffered Space: 29464576 bytes
[Timer-2] DEBUG 17:21:40.940 Buffered Space: 39622656 bytes
[Thread-60] DEBUG 17:21:41.901 [ass] PlayResX undefined, setting 678.
[Timer-2] DEBUG 17:21:41.940 Buffered Space: 43182080 bytes
[Thread-57] DEBUG 17:21:42.043 Wrote on socket: Content-Type: video/mpeg
[Thread-57] DEBUG 17:21:42.043 Wrote on socket: Connection: keep-alive
[Thread-57] DEBUG 17:21:42.043 Wrote on socket: Server: Windows Vista-x86-6.0 UPnP/1.0, PMS
[Thread-57] DEBUG 17:21:42.043 Wrote on socket:
[Timer-2] DEBUG 17:21:42.940 Buffered Space: 37969920 bytes
[Thread-58] DEBUG 17:21:43.216 freeMemory: 423825064
[Thread-58] DEBUG 17:21:43.216 totalMemory: 496361472
[Thread-58] DEBUG 17:21:43.216 maxMemory: 799145984
[Thread-58] DEBUG 17:21:43.216 Extending buffer to 419430400
[Thread-58] DEBUG 17:21:43.567 Done extending
[Timer-2] DEBUG 17:21:43.941 Buffered Space: 31649792 bytes
[Timer-2] DEBUG 17:21:44.944 Buffered Space: 25958400 bytes
[Timer-2] DEBUG 17:21:45.944 Buffered Space: 20416512 bytes
[Timer-2] DEBUG 17:21:46.948 Buffered Space: 16693248 bytes
[Timer-2] DEBUG 17:21:47.948 Buffered Space: 12976128 bytes
[Timer-2] DEBUG 17:21:48.949 Buffered Space: 9246720 bytes
[Timer-2] DEBUG 17:21:49.950 Buffered Space: 9654272 bytes
[Timer-2] DEBUG 17:21:50.951 Buffered Space: 8677376 bytes
[Timer-2] DEBUG 17:21:51.952 Buffered Space: 7559168 bytes
[Timer-2] DEBUG 17:21:52.953 Buffered Space: 4999168 bytes
[Thread-57] DEBUG 17:21:53.729 Suspend Read: readCount=133038080 / writeCount=134004736
[Timer-2] DEBUG 17:21:53.956 Buffered Space: 2617344 bytes
[Thread-57] DEBUG 17:21:54.229 Resume Read: readCount=133038080 / writeCount=137652224
[Timer-2] DEBUG 17:21:54.958 Buffered Space: 1136640 bytes
[Thread-57] DEBUG 17:21:55.029 Suspend Read: readCount=142278656 / writeCount=143276032
[Thread-57] DEBUG 17:21:55.529 Resume Read: readCount=142278656 / writeCount=146890752
[Timer-2] DEBUG 17:21:55.959 Buffered Space: 2478080 bytes
[Thread-57] DEBUG 17:21:56.249 Suspend Read: readCount=150536192 / writeCount=151535616
[Thread-57] DEBUG 17:21:56.749 Resume Read: readCount=150536192 / writeCount=153569280
[Timer-2] DEBUG 17:21:56.958 Buffered Space: 1138688 bytes
[Thread-57] DEBUG 17:21:56.986 Suspend Read: readCount=153288704 / writeCount=154286080
[Thread-57] DEBUG 17:21:57.486 Resume Read: readCount=153288704 / writeCount=156973056
[Timer-2] DEBUG 17:21:57.958 Buffered Space: 1638400 bytes
[Thread-57] DEBUG 17:21:58.190 Suspend Read: readCount=161415168 / writeCount=162398208
[Thread-57] DEBUG 17:21:58.690 Resume Read: readCount=161415168 / writeCount=165715968
[Timer-2] DEBUG 17:21:58.960 Buffered Space: 1966080 bytes
[Thread-57] DEBUG 17:21:59.108 Suspend Read: readCount=166264832 / writeCount=167219200
[Thread-57] DEBUG 17:21:59.608 Resume Read: readCount=166264832 / writeCount=170139648
[Timer-2] DEBUG 17:21:59.960 Buffered Space: 2228224 bytes
[Thread-57] DEBUG 17:22:00.193 Suspend Read: readCount=173015040 / writeCount=174014464
[Thread-57] DEBUG 17:22:00.693 Resume Read: readCount=173015040 / writeCount=177197056
[Timer-2] DEBUG 17:22:00.963 Buffered Space: 3061760 bytes
[Thread-57] DEBUG 17:22:01.665 Suspend Read: readCount=184221696 / writeCount=185200640
[Timer-2] DEBUG 17:22:01.966 Buffered Space: 3510272 bytes
[Thread-57] DEBUG 17:22:02.165 Resume Read: readCount=184221696 / writeCount=189331456
[Timer-2] DEBUG 17:22:02.966 Buffered Space: 1409024 bytes
[Thread-57] DEBUG 17:22:03.069 Suspend Read: readCount=194641920 / writeCount=195610624
[Thread-57] DEBUG 17:22:03.569 Resume Read: readCount=194641920 / writeCount=199993344
[Timer-2] DEBUG 17:22:03.969 Buffered Space: 4495360 bytes
[Timer-2] DEBUG 17:22:04.968 Buffered Space: 1673216 bytes
[Thread-57] DEBUG 17:22:05.796 Suspend Read: readCount=220200960 / writeCount=221171712
[Timer-2] DEBUG 17:22:05.968 Buffered Space: 1994752 bytes
[Thread-57] DEBUG 17:22:06.296 Resume Read: readCount=220200960 / writeCount=224276480
[Timer-2] DEBUG 17:22:06.969 Buffered Space: 2467840 bytes
[Timer-2] DEBUG 17:22:07.971 Buffered Space: 2930688 bytes
[Timer-2] DEBUG 17:22:08.973 Buffered Space: 2603008 bytes
[Thread-57] DEBUG 17:22:09.503 Suspend Read: readCount=256901120 / writeCount=257878016
[Timer-2] DEBUG 17:22:09.974 Buffered Space: 3569664 bytes
[Thread-57] DEBUG 17:22:10.004 Resume Read: readCount=256901120 / writeCount=260628480
[Thread-57] DEBUG 17:22:10.397 Suspend Read: readCount=261488640 / writeCount=262463488
[Thread-57] DEBUG 17:22:10.897 Resume Read: readCount=261488640 / writeCount=265156608
[Timer-2] DEBUG 17:22:10.976 Buffered Space: 2945024 bytes
[Thread-57] DEBUG 17:22:11.264 Suspend Read: readCount=265682944 / writeCount=266651648
[Thread-57] DEBUG 17:22:11.764 Resume Read: readCount=265682944 / writeCount=269430784
[Timer-2] DEBUG 17:22:11.979 Buffered Space: 2494464 bytes
[Timer-2] DEBUG 17:22:12.983 Buffered Space: 8474624 bytes
[Timer-2] DEBUG 17:22:13.985 Buffered Space: 14637056 bytes
[Timer-2] DEBUG 17:22:14.985 Buffered Space: 20971520 bytes
[Timer-2] DEBUG 17:22:15.985 Buffered Space: 29804544 bytes
[Timer-2] DEBUG 17:22:16.987 Buffered Space: 40198144 bytes
[Timer-2] DEBUG 17:22:17.986 Buffered Space: 49967104 bytes
[Timer-2] DEBUG 17:22:18.986 Buffered Space: 60157952 bytes
[Timer-2] DEBUG 17:22:19.986 Buffered Space: 69623808 bytes
[Timer-2] DEBUG 17:22:20.986 Buffered Space: 79921152 bytes
[Timer-2] DEBUG 17:22:21.988 Buffered Space: 89448448 bytes
[Timer-2] DEBUG 17:22:22.989 Buffered Space: 98566144 bytes
[Timer-2] DEBUG 17:22:23.991 Buffered Space: 105142272 bytes
[Timer-2] DEBUG 17:22:24.991 Buffered Space: 111601664 bytes
[Timer-2] DEBUG 17:22:25.996 Buffered Space: 119361536 bytes
[Thread-57] DEBUG 17:22:26.984 Sending stream with premature end : 269615104 bytes of get/0$0$5/Test1.mkv. Reason: An existing connection was forcibly closed by the remote host
[Thread-57] DEBUG 17:22:26.984 Ready to Stop: true
[Thread-57] DEBUG 17:22:26.984 Sending stream: 269615104 bytes of get/0$0$5/Test1.mkv
[Thread-57] DEBUG 17:22:26.984 Close Connection
[Timer-2] DEBUG 17:22:26.998 Buffered Space: 397019136 bytes
[Thread-64] DEBUG 17:22:27.058 Opened handler on socket Socket[addr=/192.168.0.98,port=64905,localport=5001]
[Thread-64] DEBUG 17:22:27.058 Received on socket: GET /get/0$0$5/thumbnail0000Test1.mkv HTTP/1.0
[Thread-64] DEBUG 17:22:27.058 Received on socket: Host: 192.168.0.7:5001
[Thread-64] DEBUG 17:22:27.058 Received on socket: User-Agent: PLAYSTATION 3
[Thread-64] DEBUG 17:22:27.071 Received on socket: Connection: close
[Thread-64] DEBUG 17:22:27.071 Received on socket: Accept-Encoding: identity
[Thread-64] DEBUG 17:22:27.071 Received on socket: Cache-Control: no-cache
[Thread-64] INFO 17:22:27.071 HTTP: get/0$0$5/thumbnail0000Test1.mkv / 0-0
[Thread-64] DEBUG 17:22:27.071 Wrote on socket: HTTP/1.0 200 OK
[Thread-64] DEBUG 17:22:27.071 Searching for objectId: 0$0$5 with children option: false
[Thread-64] DEBUG 17:22:27.071 Wrote on socket: Content-Type: image/png
[Thread-64] DEBUG 17:22:27.071 Wrote on socket: Accept-Ranges: bytes
[Thread-64] DEBUG 17:22:27.071 Wrote on socket: Expires: Fri, 15 May 2009 16:09:07 GMT
[Thread-64] DEBUG 17:22:27.071 Wrote on socket: Connection: keep-alive
[Thread-64] DEBUG 17:22:27.071 Wrote on socket: Server: Windows Vista-x86-6.0 UPnP/1.0, PMS
[Thread-64] DEBUG 17:22:27.071 Available Content-Length: 12841
[Thread-64] DEBUG 17:22:27.071 Wrote on socket: Content-Length: 12841
[Thread-64] DEBUG 17:22:27.071 Wrote on socket:
[Thread-64] DEBUG 17:22:27.071 Sending stream: 12841 bytes of get/0$0$5/thumbnail0000Test1.mkv
[Thread-64] DEBUG 17:22:27.071 Close Connection
[Thread-65] DEBUG 17:22:27.091 Opened handler on socket Socket[addr=/192.168.0.98,port=64904,localport=5001]
[Thread-65] DEBUG 17:22:27.091 Received on socket: GET /get/0$0$5/thumbnail0000Test1.mkv HTTP/1.1
[Thread-65] DEBUG 17:22:27.091 Received on socket: Host: 192.168.0.7:5001
[Thread-65] DEBUG 17:22:27.091 Received on socket: User-Agent: PLAYSTATION 3
[Thread-65] DEBUG 17:22:27.102 Received on socket: Connection: Keep-Alive
[Thread-65] DEBUG 17:22:27.102 Received on socket: Accept-Encoding: identity
[Thread-65] INFO 17:22:27.102 HTTP: get/0$0$5/thumbnail0000Test1.mkv / 0-0
[Thread-65] DEBUG 17:22:27.102 Wrote on socket: HTTP/1.1 200 OK
[Thread-65] DEBUG 17:22:27.102 Searching for objectId: 0$0$5 with children option: false
[Thread-65] DEBUG 17:22:27.102 Wrote on socket: Content-Type: image/png
[Thread-65] DEBUG 17:22:27.102 Wrote on socket: Accept-Ranges: bytes
[Thread-65] DEBUG 17:22:27.102 Wrote on socket: Expires: Fri, 15 May 2009 16:09:07 GMT
[Thread-65] DEBUG 17:22:27.102 Wrote on socket: Connection: keep-alive
[Thread-65] DEBUG 17:22:27.102 Wrote on socket: Server: Windows Vista-x86-6.0 UPnP/1.0, PMS
[Thread-65] DEBUG 17:22:27.102 Available Content-Length: 12841
[Thread-65] DEBUG 17:22:27.102 Wrote on socket: Content-Length: 12841
[Thread-65] DEBUG 17:22:27.102 Wrote on socket:
[Thread-65] DEBUG 17:22:27.102 Sending stream: 12841 bytes of get/0$0$5/thumbnail0000Test1.mkv
[Thread-65] DEBUG 17:22:27.103 Close Connection
[Thread-62] INFO 17:22:27.691 Stopping process: win32/mencoder_mt.exe
[Thread-62] INFO 17:22:27.694 Destroying buffer
[Thread-58] DEBUG 17:22:27.755 EOF
[Thread-58] INFO 17:22:27.755 Disconnected pipe
[win32/mencoder_mt.exe] DEBUG 17:22:27.755 EOF
[Thread-63] INFO 17:22:27.755 Destroying buffer
[Thread-15] INFO 17:22:44.599 Sending ALIVE...
[Thread-15] DEBUG 17:22:44.599 Setting multicast network interface: name:eth2 (Marvell Yukon 88E8056 PCI-E Gigabit Ethernet Controller) index: 8 addresses:
/192.168.0.7;

[Thread-15] DEBUG 17:22:44.628 Sending message from multicast socket on network interface: name:eth2 (Marvell Yukon 88E8056 PCI-E Gigabit Ethernet Controller) index: 8 addresses:
/192.168.0.7;

[Thread-15] DEBUG 17:22:44.628 Multicast socket is on interface: /192.168.0.7
[Thread-15] DEBUG 17:22:44.628 Socket Timeout: 0
[Thread-15] DEBUG 17:22:44.628 Socket TTL: 32
[Thread-15] DEBUG 17:22:44.628 Sending this SSDP packet: NOTIFY * HTTP/1.1<CRLF>HOST: 239.255.255.250:1900<CRLF>CACHE-CONTROL: max-age=1800<CRLF>LOCATION: http://192.168.0.7:5001/description/fetch<CRLF>NT: upnp:rootdevice<CRLF>NTS: ssdp:alive<CRLF>Server: Windows Vista-x86-6.0 UPnP/1.0, PMS<CRLF>USN: uuid:6437d48e-3a0d-37f5-b4f0-6e11fbe6359e::upnp:rootdevice<CRLF><CRLF>
[Thread-16] DEBUG 17:22:44.628 Setting multicast network interface: name:eth2 (Marvell Yukon 88E8056 PCI-E Gigabit Ethernet Controller) index: 8 addresses:
/192.168.0.7;

[Thread-16] DEBUG 17:22:44.658 Setting multicast network interface: name:eth2 (Marvell Yukon 88E8056 PCI-E Gigabit Ethernet Controller) index: 8 addresses:
/192.168.0.7;

[Thread-15] DEBUG 17:22:44.688 Sending this SSDP packet: NOTIFY * HTTP/1.1<CRLF>HOST: 239.255.255.250:1900<CRLF>CACHE-CONTROL: max-age=1800<CRLF>LOCATION: http://192.168.0.7:5001/description/fetch<CRLF>NT: uuid:6437d48e-3a0d-37f5-b4f0-6e11fbe6359e::<CRLF>NTS: ssdp:alive<CRLF>Server: Windows Vista-x86-6.0 UPnP/1.0, PMS<CRLF>USN: uuid:6437d48e-3a0d-37f5-b4f0-6e11fbe6359e::<CRLF><CRLF>
[Thread-16] DEBUG 17:22:44.688 Setting multicast network interface: name:eth2 (Marvell Yukon 88E8056 PCI-E Gigabit Ethernet Controller) index: 8 addresses:
/192.168.0.7;

[Thread-16] DEBUG 17:22:44.718 Setting multicast network interface: name:eth2 (Marvell Yukon 88E8056 PCI-E Gigabit Ethernet Controller) index: 8 addresses:
/192.168.0.7;

[Thread-15] DEBUG 17:22:44.748 Sending this SSDP packet: NOTIFY * HTTP/1.1<CRLF>HOST: 239.255.255.250:1900<CRLF>CACHE-CONTROL: max-age=1800<CRLF>LOCATION: http://192.168.0.7:5001/description/fetch<CRLF>NT: urn:schemas-upnp-org:device:MediaServer:1<CRLF>NTS: ssdp:alive<CRLF>Server: Windows Vista-x86-6.0 UPnP/1.0, PMS<CRLF>USN: uuid:6437d48e-3a0d-37f5-b4f0-6e11fbe6359e::urn:schemas-upnp-org:device:MediaServer:1<CRLF><CRLF>
[Thread-16] DEBUG 17:22:44.748 Setting multicast network interface: name:eth2 (Marvell Yukon 88E8056 PCI-E Gigabit Ethernet Controller) index: 8 addresses:
/192.168.0.7;

[Thread-16] DEBUG 17:22:44.778 Setting multicast network interface: name:eth2 (Marvell Yukon 88E8056 PCI-E Gigabit Ethernet Controller) index: 8 addresses:
/192.168.0.7;

[Thread-15] DEBUG 17:22:44.808 Sending this SSDP packet: NOTIFY * HTTP/1.1<CRLF>HOST: 239.255.255.250:1900<CRLF>CACHE-CONTROL: max-age=1800<CRLF>LOCATION: http://192.168.0.7:5001/description/fetch<CRLF>NT: urn:schemas-upnp-org:service:ContentDirectory:1<CRLF>NTS: ssdp:alive<CRLF>Server: Windows Vista-x86-6.0 UPnP/1.0, PMS<CRLF>USN: uuid:6437d48e-3a0d-37f5-b4f0-6e11fbe6359e::urn:schemas-upnp-org:service:ContentDirectory:1<CRLF><CRLF>
[Thread-16] DEBUG 17:22:44.808 Setting multicast network interface: name:eth2 (Marvell Yukon 88E8056 PCI-E Gigabit Ethernet Controller) index: 8 addresses:
/192.168.0.7;

[Thread-16] DEBUG 17:22:44.838 Setting multicast network interface: name:eth2 (Marvell Yukon 88E8056 PCI-E Gigabit Ethernet Controller) index: 8 addresses:
/192.168.0.7;

[Thread-15] DEBUG 17:22:44.868 Sending this SSDP packet: NOTIFY * HTTP/1.1<CRLF>HOST: 239.255.255.250:1900<CRLF>CACHE-CONTROL: max-age=1800<CRLF>LOCATION: http://192.168.0.7:5001/description/fetch<CRLF>NT: urn:schemas-upnp-org:service:ConnectionManager:1<CRLF>NTS: ssdp:alive<CRLF>Server: Windows Vista-x86-6.0 UPnP/1.0, PMS<CRLF>USN: uuid:6437d48e-3a0d-37f5-b4f0-6e11fbe6359e::urn:schemas-upnp-org:service:ConnectionManager:1<CRLF><CRLF>
[Thread-16] DEBUG 17:22:44.868 Setting multicast network interface: name:eth2 (Marvell Yukon 88E8056 PCI-E Gigabit Ethernet Controller) index: 8 addresses:
/192.168.0.7;

[Thread-16] DEBUG 17:22:44.898 Setting multicast network interface: name:eth2 (Marvell Yukon 88E8056 PCI-E Gigabit Ethernet Controller) index: 8 addresses:
/192.168.0.7;

[Thread-14] INFO 17:23:12.077 Sending BYEBYE...
[Thread-14] DEBUG 17:23:12.077 Setting multicast network interface: name:eth2 (Marvell Yukon 88E8056 PCI-E Gigabit Ethernet Controller) index: 8 addresses:
/192.168.0.7;

[Thread-14] DEBUG 17:23:12.107 Sending message from multicast socket on network interface: name:eth2 (Marvell Yukon 88E8056 PCI-E Gigabit Ethernet Controller) index: 8 addresses:
/192.168.0.7;

[Thread-14] DEBUG 17:23:12.107 Multicast socket is on interface: /192.168.0.7
[Thread-14] DEBUG 17:23:12.107 Socket Timeout: 0
[Thread-14] DEBUG 17:23:12.107 Socket TTL: 32
[Thread-14] DEBUG 17:23:12.107 Sending this SSDP packet: NOTIFY * HTTP/1.1<CRLF>HOST: 239.255.255.250:1900<CRLF>NT: upnp:rootdevice<CRLF>NTS: ssdp:byebye<CRLF>USN: uuid:6437d48e-3a0d-37f5-b4f0-6e11fbe6359e::upnp:rootdevice<CRLF><CRLF>
[Thread-16] DEBUG 17:23:12.112 Setting multicast network interface: name:eth2 (Marvell Yukon 88E8056 PCI-E Gigabit Ethernet Controller) index: 8 addresses:
/192.168.0.7;

[Thread-16] DEBUG 17:23:12.137 Setting multicast network interface: name:eth2 (Marvell Yukon 88E8056 PCI-E Gigabit Ethernet Controller) index: 8 addresses:
/192.168.0.7;

[Thread-14] DEBUG 17:23:12.172 Sending this SSDP packet: NOTIFY * HTTP/1.1<CRLF>HOST: 239.255.255.250:1900<CRLF>NT: uuid:6437d48e-3a0d-37f5-b4f0-6e11fbe6359e::<CRLF>NTS: ssdp:byebye<CRLF>USN: uuid:6437d48e-3a0d-37f5-b4f0-6e11fbe6359e::<CRLF><CRLF>
[Thread-16] DEBUG 17:23:12.172 Setting multicast network interface: name:eth2 (Marvell Yukon 88E8056 PCI-E Gigabit Ethernet Controller) index: 8 addresses:
/192.168.0.7;

[Thread-16] DEBUG 17:23:12.202 Setting multicast network interface: name:eth2 (Marvell Yukon 88E8056 PCI-E Gigabit Ethernet Controller) index: 8 addresses:
/192.168.0.7;

[Thread-14] DEBUG 17:23:12.232 Sending this SSDP packet: NOTIFY * HTTP/1.1<CRLF>HOST: 239.255.255.250:1900<CRLF>NT: urn:schemas-upnp-org:device:MediaServer:1<CRLF>NTS: ssdp:byebye<CRLF>USN: uuid:6437d48e-3a0d-37f5-b4f0-6e11fbe6359e::urn:schemas-upnp-org:device:MediaServer:1<CRLF><CRLF>
[Thread-16] DEBUG 17:23:12.232 Setting multicast network interface: name:eth2 (Marvell Yukon 88E8056 PCI-E Gigabit Ethernet Controller) index: 8 addresses:
/192.168.0.7;

[Thread-16] DEBUG 17:23:12.262 Setting multicast network interface: name:eth2 (Marvell Yukon 88E8056 PCI-E Gigabit Ethernet Controller) index: 8 addresses:
/192.168.0.7;

[Thread-14] DEBUG 17:23:12.292 Sending this SSDP packet: NOTIFY * HTTP/1.1<CRLF>HOST: 239.255.255.250:1900<CRLF>NT: urn:schemas-upnp-org:service:ContentDirectory:1<CRLF>NTS: ssdp:byebye<CRLF>USN: uuid:6437d48e-3a0d-37f5-b4f0-6e11fbe6359e::urn:schemas-upnp-org:service:ContentDirectory:1<CRLF><CRLF>
[Thread-16] DEBUG 17:23:12.292 Setting multicast network interface: name:eth2 (Marvell Yukon 88E8056 PCI-E Gigabit Ethernet Controller) index: 8 addresses:
/192.168.0.7;

[Thread-16] DEBUG 17:23:12.322 Setting multicast network interface: name:eth2 (Marvell Yukon 88E8056 PCI-E Gigabit Ethernet Controller) index: 8 addresses:
/192.168.0.7;

[Thread-14] DEBUG 17:23:12.352 Sending this SSDP packet: NOTIFY * HTTP/1.1<CRLF>HOST: 239.255.255.250:1900<CRLF>CACHE-CONTROL: max-age=1800<CRLF>LOCATION: http://192.168.0.7:5001/description/fetch<CRLF>NT: urn:schemas-upnp-org:service:ConnectionManager:1<CRLF>NTS: ssdp:alive<CRLF>Server: Windows Vista-x86-6.0 UPnP/1.0, PMS<CRLF>USN: uuid:6437d48e-3a0d-37f5-b4f0-6e11fbe6359e::urn:schemas-upnp-org:service:ConnectionManager:1<CRLF><CRLF>
[Thread-16] DEBUG 17:23:12.352 Setting multicast network interface: name:eth2 (Marvell Yukon 88E8056 PCI-E Gigabit Ethernet Controller) index: 8 addresses:
/192.168.0.7;

[Thread-16] DEBUG 17:23:12.382 Setting multicast network interface: name:eth2 (Marvell Yukon 88E8056 PCI-E Gigabit Ethernet Controller) index: 8 addresses:
/192.168.0.7;

[Thread-14] INFO 17:23:12.412 Forcing shutdown of all active processes
[Thread-14] INFO 17:23:12.412 Stopping server on host 192.168.0.7 and port 5001...
PS4
 
Posts: 21
Joined: Mon Jan 19, 2009 4:11 pm

Re: Some MKV's don't stream with 1.03

Postby shagrath » Mon Jan 19, 2009 11:39 pm

that's weird, ps3 disconnects from the first stream send and reconnect seconds later...
I would suggest to shutdown it and retry :)

your mkv must be strange though... the force framerate is an almost useless option I considered to remove :)
and I've yet to find a video not working with this mt build, so...
shagrath
Project Lead
 
Posts: 2668
Joined: Wed Jan 14, 2009 1:39 pm

Re: Some MKV's don't stream with 1.03

Postby PS4 » Mon Jan 19, 2009 11:52 pm

shagrath wrote:that's weird, ps3 disconnects from the first stream send and reconnect seconds later...
I would suggest to shutdown it and retry :)

your mkv must be strange though... the force framerate is an almost useless option I considered to remove :)
and I've yet to find a video not working with this mt build, so...


Well, I've got a few video's that are like that, just stuff I picked off the net. So please leave the option in there for future releases.

I'll do more tests later and post two logs, one with single core that works, and one with multi-core that hangs. Thanks.
PS4
 
Posts: 21
Joined: Mon Jan 19, 2009 4:11 pm

Re: Some MKV's don't stream with 1.03

Postby PS4 » Wed Jan 21, 2009 1:09 am

Sorry for the delay, life always gets in the way of more important things. :)

Attached are two logs for the same movie. Single-core works perfectly, multi-core just hangs at the start, with timer staying at 00:00:00, but the log shows pms thought everything was fine and kept buffering.

I also tried more mkv's. I would say about 40% don't work with multi-core checked.

ooops, this board doesn't accept log or txt. I tried renaming to jpg, let's see if that works
PS4
 
Posts: 21
Joined: Mon Jan 19, 2009 4:11 pm

Re: Some MKV's don't stream with 1.03

Postby PS4 » Wed Jan 21, 2009 1:16 am

ok, I don't see the attachments.

let's post the logs.

below is log for multi-core that hangs

[Thread-36] DEBUG 18:27:58.396 Setting DLNA id 0$0$3 to M2TS
[Thread-36] DEBUG 18:27:58.396 Setting DLNA id 0$0$4 to MKV
[Thread-36] DEBUG 18:27:58.396 Setting DLNA id 0$0$5 to Test1.mkv
[Thread-36] DEBUG 18:27:58.396 Setting DLNA id 0$0$6 to #--TRANSCODED--#
[Thread-36] DEBUG 18:27:58.396 Setting DLNA id 0$0$6$0 to Test1.mkv
[Thread-36] DEBUG 18:27:58.396 Setting DLNA id 0$0$6$0$0 to Test1.mkv
[pool-3-thread-1] INFO 18:27:58.401 Starting C:\Program Files\PS3 Media Server\win32\ffmpeg.exe -ss 120 -i E:\TVersity-E\Test1.mkv -an -an -s 320x180 -vframes 1 -f image2 pipe:
[pool-3-thread-1] INFO 18:27:58.464 Attaching thread: win32/ffmpeg.exe
[Thread-38] DEBUG 18:27:58.670 FFmpeg version SVN-r16043-Sherpya, Copyright (c) 2000-2008 Fabrice Bellard, et al.
[Thread-38] DEBUG 18:27:58.670 libavutil 49.12. 0 / 49.12. 0
[Thread-38] DEBUG 18:27:58.670 libavcodec 52. 6. 1 / 52. 6. 1
[Thread-38] DEBUG 18:27:58.670 libavformat 52.23. 1 / 52.23. 1
[Thread-38] DEBUG 18:27:58.670 libavdevice 52. 1. 0 / 52. 1. 0
[Thread-38] DEBUG 18:27:58.670 libavfilter 0. 1. 0 / 0. 1. 0
[Thread-38] DEBUG 18:27:58.670 libswscale 0. 6. 1 / 0. 6. 1
[Thread-38] DEBUG 18:27:58.670 libpostproc 51. 2. 0 / 51. 2. 0
[Thread-38] DEBUG 18:27:58.670 built on Dec 10 2008 18:25:26, gcc: 4.2.5 20080919 (prerelease) [Sherpya]
[Thread-38] DEBUG 18:27:58.670 Input #0, matroska, from 'E:\TVersity-E\Test1.mkv':
[Thread-38] DEBUG 18:27:58.670 Duration: 01:40:58.14, start: 0.000000, bitrate: N/A
[Thread-38] DEBUG 18:27:58.670 Stream #0.0(eng): Video: h264, yuv420p, 1280x544, 23.98 tb(r)
[Thread-38] DEBUG 18:27:58.670 Stream #0.1(eng): Audio: dca, 48000 Hz, 5.1, s16
[Thread-38] DEBUG 18:27:58.670 Stream #0.2(eng): Subtitle: 0x0000
[Thread-38] DEBUG 18:27:58.670 Output #0, image2, to 'pipe:':
[Thread-38] DEBUG 18:27:58.670 Stream #0.0(eng): Video: mjpeg, yuvj420p, 320x180 [PAR 45:34 DAR 40:17], q=2-31, 200 kb/s, 23.98 tb(c)
[Thread-38] DEBUG 18:27:58.670 Stream mapping:
[Thread-38] DEBUG 18:27:58.670 Stream #0.0 -> #0.0
[Thread-38] DEBUG 18:27:58.670 Press [q] to stop encoding
[Thread-38] DEBUG 18:27:58.671 video:14kB audio:0kB global headers:0kB muxing overhead -100.156807%
[pool-3-thread-1] DEBUG 18:27:58.674 EOF
[pool-3-thread-1] DEBUG 18:27:58.675 Ready to Stop: true
[pool-3-thread-1] DEBUG 18:27:58.708 Media info: mimeType: video/mp4 / container: matroska / bitrate: 0 / size: 4695348084 / codecV: h264 / duration: 01:40:58.140 / width: 1280 / height: 544 / frameRate: 23.98 / codecA: dca / sampleFrequency: 48000 / nrAudioChannels: 0
[Thread-36] DEBUG 18:27:58.708 End of analysis
[Thread-36] DEBUG 18:27:58.709 Wrote on socket: Server: Windows Vista-x86-6.0 UPnP/1.0, PMS
[Thread-36] DEBUG 18:27:58.709 Wrote on socket: Content-Length: 3801
[Thread-36] DEBUG 18:27:58.709 Wrote on socket:
[Thread-36] DEBUG 18:27:58.710 Close Connection
[Thread-42] DEBUG 18:27:59.252 Opened handler on socket Socket[addr=/192.168.0.98,port=63771,localport=5001]
[Thread-42] DEBUG 18:27:59.252 Received on socket: POST /upnp/control/content_directory HTTP/1.1
[Thread-42] DEBUG 18:27:59.252 Received on socket: X-AV-Client-Info: av=5.0; cn="Sony Computer Entertainment Inc."; mn="PLAYSTATION 3"; mv="1.0";
[Thread-42] DEBUG 18:27:59.266 Received on socket: Host: 192.168.0.7:5001
[Thread-42] DEBUG 18:27:59.266 Received on socket: User-Agent: UPnP/1.0 DLNADOC/1.00
[Thread-42] DEBUG 18:27:59.266 Received on socket: Content-Length: 276
[Thread-42] DEBUG 18:27:59.266 Received on socket: Content-Type: text/xml; charset="utf-8"
[Thread-42] DEBUG 18:27:59.266 Received on socket: SOAPACTION: "urn:schemas-upnp-org:service:ContentDirectory:1#GetSystemUpdateID"
[Thread-43] DEBUG 18:27:59.326 Opened handler on socket Socket[addr=/192.168.0.98,port=63770,localport=5001]
[Thread-43] DEBUG 18:27:59.326 Received on socket: GET /get/0$0$5/thumbnail0000Test1.mkv HTTP/1.0
[Thread-43] DEBUG 18:27:59.326 Received on socket: Host: 192.168.0.7:5001
[Thread-43] DEBUG 18:27:59.326 Received on socket: User-Agent: PLAYSTATION 3
[Thread-43] DEBUG 18:27:59.342 Received on socket: Connection: close
[Thread-43] DEBUG 18:27:59.342 Received on socket: Accept-Encoding: identity
[Thread-43] DEBUG 18:27:59.342 Received on socket: Cache-Control: no-cache
[Thread-43] INFO 18:27:59.342 HTTP: get/0$0$5/thumbnail0000Test1.mkv / 0-0
[Thread-43] DEBUG 18:27:59.342 Wrote on socket: HTTP/1.0 200 OK
[Thread-43] DEBUG 18:27:59.342 Searching for objectId: 0$0$5 with children option: false
[Thread-43] DEBUG 18:27:59.342 Wrote on socket: Content-Type: image/png
[Thread-43] DEBUG 18:27:59.342 Wrote on socket: Accept-Ranges: bytes
[Thread-43] DEBUG 18:27:59.343 Wrote on socket: Expires: Sat, 16 May 2009 17:14:39 GMT
[Thread-43] DEBUG 18:27:59.343 Wrote on socket: Connection: keep-alive
[Thread-43] DEBUG 18:27:59.343 Wrote on socket: Server: Windows Vista-x86-6.0 UPnP/1.0, PMS
[Thread-43] DEBUG 18:27:59.343 Available Content-Length: 12841
[Thread-43] DEBUG 18:27:59.343 Wrote on socket: Content-Length: 12841
[Thread-43] DEBUG 18:27:59.343 Wrote on socket:
[Thread-43] DEBUG 18:27:59.343 Sending stream: 12841 bytes of get/0$0$5/thumbnail0000Test1.mkv
[Thread-43] DEBUG 18:27:59.343 Close Connection
[Thread-44] DEBUG 18:27:59.360 Opened handler on socket Socket[addr=/192.168.0.98,port=63769,localport=5001]
[Thread-44] DEBUG 18:27:59.360 Received on socket: GET /get/0$0$5/thumbnail0000Test1.mkv HTTP/1.1
[Thread-44] DEBUG 18:27:59.360 Received on socket: Host: 192.168.0.7:5001
[Thread-44] DEBUG 18:27:59.360 Received on socket: User-Agent: PLAYSTATION 3
[Thread-44] DEBUG 18:27:59.377 Received on socket: Connection: Keep-Alive
[Thread-44] DEBUG 18:27:59.377 Received on socket: Accept-Encoding: identity
[Thread-44] INFO 18:27:59.377 HTTP: get/0$0$5/thumbnail0000Test1.mkv / 0-0
[Thread-44] DEBUG 18:27:59.377 Wrote on socket: HTTP/1.1 200 OK
[Thread-44] DEBUG 18:27:59.377 Searching for objectId: 0$0$5 with children option: false
[Thread-44] DEBUG 18:27:59.377 Wrote on socket: Content-Type: image/png
[Thread-44] DEBUG 18:27:59.377 Wrote on socket: Accept-Ranges: bytes
[Thread-44] DEBUG 18:27:59.378 Wrote on socket: Expires: Sat, 16 May 2009 17:14:39 GMT
[Thread-44] DEBUG 18:27:59.378 Wrote on socket: Connection: keep-alive
[Thread-44] DEBUG 18:27:59.378 Wrote on socket: Server: Windows Vista-x86-6.0 UPnP/1.0, PMS
[Thread-44] DEBUG 18:27:59.378 Available Content-Length: 12841
[Thread-44] DEBUG 18:27:59.378 Wrote on socket: Content-Length: 12841
[Thread-44] DEBUG 18:27:59.378 Wrote on socket:
[Thread-44] DEBUG 18:27:59.379 Sending stream: 12841 bytes of get/0$0$5/thumbnail0000Test1.mkv
[Thread-44] DEBUG 18:27:59.379 Close Connection
[Thread-41] INFO 18:27:59.379 Stopping process: win32/ffmpeg.exe
[Thread-41] INFO 18:27:59.379 Destroying buffer
[Thread-41] INFO 18:27:59.437 Destroying buffer
[Thread-42] INFO 18:27:59.482 HTTP: upnp/control/content_directory / 0-0
[Thread-42] DEBUG 18:27:59.482 Wrote on socket: HTTP/1.1 200 OK
[Thread-42] DEBUG 18:27:59.482 Wrote on socket: CONTENT-TYPE: text/xml; charset="utf-8"
[Thread-42] DEBUG 18:27:59.482 Wrote on socket: Server: Windows Vista-x86-6.0 UPnP/1.0, PMS
[Thread-42] DEBUG 18:27:59.482 Wrote on socket: Content-Length: 332
[Thread-42] DEBUG 18:27:59.482 Wrote on socket:
[Thread-42] DEBUG 18:27:59.482 Close Connection
[Thread-45] DEBUG 18:27:59.486 Opened handler on socket Socket[addr=/192.168.0.98,port=63768,localport=5001]
[Thread-45] DEBUG 18:27:59.486 Received on socket: POST /upnp/control/content_directory HTTP/1.1
[Thread-45] DEBUG 18:27:59.486 Received on socket: X-AV-Client-Info: av=5.0; cn="Sony Computer Entertainment Inc."; mn="PLAYSTATION 3"; mv="1.0";
[Thread-45] DEBUG 18:27:59.503 Received on socket: Host: 192.168.0.7:5001
[Thread-45] DEBUG 18:27:59.503 Received on socket: User-Agent: UPnP/1.0 DLNADOC/1.00
[Thread-45] DEBUG 18:27:59.503 Received on socket: Content-Length: 903
[Thread-45] DEBUG 18:27:59.503 Received on socket: Content-Type: text/xml; charset="utf-8"
[Thread-45] DEBUG 18:27:59.503 Received on socket: SOAPACTION: "urn:schemas-upnp-org:service:ContentDirectory:1#Browse"
[Thread-45] INFO 18:27:59.679 HTTP: upnp/control/content_directory / 0-0
[Thread-45] DEBUG 18:27:59.679 Wrote on socket: HTTP/1.1 200 OK
[Thread-45] DEBUG 18:27:59.679 Wrote on socket: CONTENT-TYPE: text/xml; charset="utf-8"
[Thread-45] DEBUG 18:27:59.679 Searching for objectId: 0$0 with children option: false
[Thread-45] DEBUG 18:27:59.679 Search extension for list1.txt
[Thread-45] DEBUG 18:27:59.680 Wrote on socket: Server: Windows Vista-x86-6.0 UPnP/1.0, PMS
[Thread-45] DEBUG 18:27:59.680 Wrote on socket: Content-Length: 1022
[Thread-45] DEBUG 18:27:59.680 Wrote on socket:
[Thread-45] DEBUG 18:27:59.680 Close Connection
[Thread-46] DEBUG 18:28:06.627 Opened handler on socket Socket[addr=/192.168.0.98,port=63767,localport=5001]
[Thread-46] DEBUG 18:28:06.627 Received on socket: GET /get/0$0$5/Test1.mkv HTTP/1.1
[Thread-46] DEBUG 18:28:06.628 Received on socket: Host: 192.168.0.7:5001
[Thread-46] DEBUG 18:28:06.628 Received on socket: User-Agent: PLAYSTATION 3
[Thread-46] DEBUG 18:28:06.643 Received on socket: Connection: Keep-Alive
[Thread-46] DEBUG 18:28:06.643 Received on socket: Accept-Encoding: identity
[Thread-46] INFO 18:28:06.643 HTTP: get/0$0$5/Test1.mkv / 0-0
[Thread-46] DEBUG 18:28:06.643 Wrote on socket: HTTP/1.1 200 OK
[Thread-46] DEBUG 18:28:06.643 Searching for objectId: 0$0$5 with children option: false
[Thread-46] DEBUG 18:28:06.643 Asked stream chunk [0-0] timeseek: 0.0 of Test1.mkv and player MEncoder
[Thread-46] TRACE 18:28:06.643 Starting transcode of Test1.mkv
[Thread-46] INFO 18:28:06.649 Creating pipe \\.\pipe\mencoder1232494086644
[Thread-47] INFO 18:28:06.784 Waiting for pipe connection \\.\pipe\mencoder1232494086644
[Timer-1] DEBUG 18:28:06.791 Buffered Space: 0 bytes
[win32/mencoder_mt.exe] INFO 18:28:06.873 Starting C:\Program Files\PS3 Media Server\win32\mencoder_mt.exe -ss 0 -quiet E:\TVersity-E\Test1.mkv -quiet -quiet -oac lavc -of mpeg -mpegopts format=mpeg2:muxrate=500000:vbuf_size=1194:abuf_size=64 -ovc lavc -channels 6 -lavdopts debug=0:threads=2 -lavcopts autoaspect=1:vcodec=mpeg2video:acodec=ac3:abitrate=384:threads=2:keyint=1:vqscale=1:vqmin=2 -ass -nofontconfig -subcp cp1252 -alang eng,fre,jpn,ger -ass-color ffffff00 -ass-border-color 00000000 -ass-font-scale 1.0 -ass-force-style FontName=Arial,Outline=1,Shadow=1,MarginV=10 -slang eng,fre,jpn,ger -quiet -quiet -fps 24000/1001 -ofps 24000/1001 -quiet -quiet -lavdopts fast -af lavcresample=48000 -srate 48000 -o \\.\pipe\mencoder1232494086644
[win32/mencoder_mt.exe] INFO 18:28:07.045 Reading pipe: \\.\pipe\mencoder1232494086644
[win32/mencoder_mt.exe] INFO 18:28:07.045 Attaching thread: win32/mencoder_mt.exe
[Thread-51] DEBUG 18:28:07.287 MEncoder MT-SVN-r28126-Build-from-Sherpya-4.2.4 (C) 2000-2008 MPlayer Team
[Thread-51] DEBUG 18:28:07.287 CPU: Intel(R) Core(TM)2 Duo CPU E8400 @ 3.00GHz (Family: 6, Model: 23, Stepping: 6)
[Thread-51] DEBUG 18:28:07.288 CPUflags: Type: 6 MMX: 1 MMX2: 1 3DNow: 0 3DNow2: 0 SSE: 1 SSE2: 1
[Thread-51] DEBUG 18:28:07.288 Compiled for x86 CPU with extensions: MMX MMX2 SSE SSE2
[Thread-51] DEBUG 18:28:07.302 success: format: 0 data: 0x0 - 0x17dd5374
[Thread-51] DEBUG 18:28:07.339 [mkv] Track ID 1: video (V_MPEG4/ISO/AVC), -vid 0
[Thread-51] DEBUG 18:28:07.339 [mkv] Track ID 2: audio (A_DTS), -aid 0, -alang eng
[Thread-51] DEBUG 18:28:07.339 [mkv] Track ID 3: subtitles (S_TEXT/UTF8), -sid 0, -slang eng
[Thread-51] DEBUG 18:28:07.339 [mkv] Will play video track 1.
[Thread-51] DEBUG 18:28:07.339 Matroska file format detected.
[Thread-51] DEBUG 18:28:07.339 VIDEO: [avc1] 1280x544 24bpp 23.976 fps 0.0 kbps ( 0.0 kbyte/s)
[Thread-51] DEBUG 18:28:07.339 [V] filefmt:31 fourcc:0x31637661 size:1280x544 fps:23.976 ftime:=0.0417
[Thread-51] DEBUG 18:28:07.339 Input fps will be interpreted as 23.976 instead.
[Thread-51] DEBUG 18:28:07.339 ==========================================================================
[Thread-51] DEBUG 18:28:07.341 Opening audio decoder: [libdca] DTS decoding with libdca
[Thread-51] DEBUG 18:28:07.358 AUDIO: 48000 Hz, 6 ch, s16le, 1536.0 kbit/33.33% (ratio: 192000->576000)
[Thread-51] DEBUG 18:28:07.358 Selected audio codec: [dts] afm: libdca (DTS-libdca)
[Thread-47] INFO 18:28:07.358 Result of \\.\pipe\mencoder1232494086644 : true
[Thread-51] DEBUG 18:28:07.358 ==========================================================================
[Thread-51] DEBUG 18:28:07.359 PACKET SIZE: 2048 bytes, deltascr: 884
[Thread-51] DEBUG 18:28:07.367 [ass] auto-open
[Thread-50] DEBUG 18:28:07.367 Stream with high frequencies VQ coding
[Thread-50] DEBUG 18:28:07.367 Warning: -ass implies -keep-pts, which may cause "badly interleaved" files.
[Thread-51] DEBUG 18:28:07.368 [ass] Init
[Thread-50] DEBUG 18:28:07.368 [ass] Fontconfig disabled, only default font will be used.
[Thread-51] DEBUG 18:28:07.368 ==========================================================================
[Thread-51] DEBUG 18:28:07.369 Opening video decoder: [ffmpeg] FFmpeg's libavcodec codec family
[Thread-51] DEBUG 18:28:07.370 Selected video codec: [ffh264] vfm: ffmpeg (FFmpeg H.264)
[Thread-51] DEBUG 18:28:07.370 ==========================================================================
[Thread-50] DEBUG 18:28:07.370 Limiting audio preload to 0.4s.
[Thread-50] DEBUG 18:28:07.370 Increasing audio density to 4.
[Thread-51] DEBUG 18:28:07.473 Writing header...
[Thread-51] DEBUG 18:28:07.488 VDec: vo config request - 1280 x 544 (preferred colorspace: Planar YV12)
[Thread-51] DEBUG 18:28:07.488 VDec: using Planar YV12 as output csp (no 0)
[Thread-51] DEBUG 18:28:07.488 Movie-Aspect is 2.35:1 - prescaling to correct movie aspect.
[Thread-51] DEBUG 18:28:07.489 videocodec: libavcodec (1280x544 fourcc=3267706d [mpg2])
[Thread-51] DEBUG 18:28:07.489 [VE_LAVC] Using constant qscale = 1.000000 (VBR).
[Timer-1] DEBUG 18:28:07.789 Buffered Space: 645120 bytes
[Thread-37] INFO 18:28:08.404 Stopping process: win32/ffmpeg.exe
[Thread-37] INFO 18:28:08.405 Destroying buffer
[Timer-1] DEBUG 18:28:08.791 Buffered Space: 6111232 bytes
[Timer-1] DEBUG 18:28:09.789 Buffered Space: 16465920 bytes
[Timer-1] DEBUG 18:28:10.791 Buffered Space: 24750080 bytes
[Timer-1] DEBUG 18:28:11.793 Buffered Space: 33646592 bytes
[Timer-1] DEBUG 18:28:12.793 Buffered Space: 41406464 bytes
[Thread-46] DEBUG 18:28:12.924 Wrote on socket: Content-Type: video/mpeg
[Thread-46] DEBUG 18:28:12.925 Wrote on socket: Connection: keep-alive
[Thread-46] DEBUG 18:28:12.925 Wrote on socket: Server: Windows Vista-x86-6.0 UPnP/1.0, PMS
[Thread-46] DEBUG 18:28:12.925 Wrote on socket:
[Thread-52] DEBUG 18:28:13.043 Opened handler on socket Socket[addr=/192.168.0.98,port=63766,localport=5001]
[Thread-52] DEBUG 18:28:13.043 Received on socket: GET /get/0$0$5/Test1.mkv HTTP/1.1
[Thread-52] DEBUG 18:28:13.043 Received on socket: Host: 192.168.0.7:5001
[Thread-52] DEBUG 18:28:13.043 Received on socket: User-Agent: PLAYSTATION 3
[Thread-52] DEBUG 18:28:13.068 Received on socket: Connection: Keep-Alive
[Thread-52] DEBUG 18:28:13.068 Received on socket: Accept-Encoding: identity
[Thread-52] INFO 18:28:13.069 HTTP: get/0$0$5/Test1.mkv / 0-0
[Thread-52] DEBUG 18:28:13.069 Wrote on socket: HTTP/1.1 200 OK
[Thread-52] DEBUG 18:28:13.069 Searching for objectId: 0$0$5 with children option: false
[Thread-52] DEBUG 18:28:13.069 Asked stream chunk [0-0] timeseek: 0.0 of Test1.mkv and player MEncoder
[Thread-52] DEBUG 18:28:13.069 Wrote on socket: Content-Type: video/mpeg
[Thread-52] DEBUG 18:28:13.069 Wrote on socket: Connection: keep-alive
[Thread-52] DEBUG 18:28:13.069 Wrote on socket: Server: Windows Vista-x86-6.0 UPnP/1.0, PMS
[Thread-52] DEBUG 18:28:13.069 Wrote on socket:
[Thread-52] DEBUG 18:28:13.163 Sending stream with premature end : 1179648 bytes of get/0$0$5/Test1.mkv. Reason: An existing connection was forcibly closed by the remote host
[Thread-52] DEBUG 18:28:13.163 Ready to Stop: true
[Thread-52] DEBUG 18:28:13.163 Sending stream: 1179648 bytes of get/0$0$5/Test1.mkv
[Thread-52] DEBUG 18:28:13.163 Close Connection
[Thread-46] DEBUG 18:28:13.217 Ready to Stop: false
[Thread-50] DEBUG 18:28:13.549 [ass] PlayResX undefined, setting 678.
[Timer-1] DEBUG 18:28:13.796 Buffered Space: 43737088 bytes
[Timer-1] DEBUG 18:28:14.796 Buffered Space: 49285120 bytes
[Thread-47] DEBUG 18:28:14.938 freeMemory: 41195576
[Thread-47] DEBUG 18:28:14.938 totalMemory: 95154176
[Thread-47] DEBUG 18:28:14.938 maxMemory: 799145984
[Thread-47] DEBUG 18:28:14.938 Extending buffer to 419430400
[Thread-47] DEBUG 18:28:15.360 Done extending
[Thread-46] DEBUG 18:28:15.360 Sending stream with premature end : 1245184 bytes of get/0$0$5/Test1.mkv. Reason: An existing connection was forcibly closed by the remote host
[Thread-46] DEBUG 18:28:15.360 Ready to Stop: true
[Thread-46] DEBUG 18:28:15.360 Sending stream: 1245184 bytes of get/0$0$5/Test1.mkv
[Thread-55] DEBUG 18:28:15.361 Opened handler on socket Socket[addr=/192.168.0.98,port=63765,localport=5001]
[Thread-55] DEBUG 18:28:15.361 Received on socket: GET /get/0$0$5/Test1.mkv HTTP/1.1
[Thread-55] DEBUG 18:28:15.361 Received on socket: Host: 192.168.0.7:5001
[Thread-55] DEBUG 18:28:15.361 Received on socket: User-Agent: PLAYSTATION 3
[Thread-46] DEBUG 18:28:15.362 Close Connection
[Thread-55] DEBUG 18:28:15.379 Received on socket: Connection: Keep-Alive
[Thread-55] DEBUG 18:28:15.380 Received on socket: Accept-Encoding: identity
[Thread-55] DEBUG 18:28:15.380 Received on socket: TimeSeekRange.dlna.org : npt=0.000-
[Thread-55] INFO 18:28:15.380 HTTP: get/0$0$5/Test1.mkv / 0-0
[Thread-55] DEBUG 18:28:15.380 Wrote on socket: HTTP/1.1 200 OK
[Thread-55] DEBUG 18:28:15.380 Searching for objectId: 0$0$5 with children option: false
[Thread-55] DEBUG 18:28:15.380 Asked stream chunk [0-0] timeseek: 0.0 of Test1.mkv and player MEncoder
[Thread-55] DEBUG 18:28:15.380 Ready to Stop: false
[Thread-55] DEBUG 18:28:15.380 Wrote on socket: Content-Type: video/mpeg
[Thread-55] DEBUG 18:28:15.381 Wrote on socket: Connection: keep-alive
[Thread-55] DEBUG 18:28:15.381 Wrote on socket: Server: Windows Vista-x86-6.0 UPnP/1.0, PMS
[Thread-55] DEBUG 18:28:15.381 Wrote on socket:
[Timer-1] DEBUG 18:28:15.806 Buffered Space: 47859712 bytes
[Timer-1] DEBUG 18:28:16.808 Buffered Space: 41963520 bytes
[Timer-1] DEBUG 18:28:17.812 Buffered Space: 36050944 bytes
[Timer-1] DEBUG 18:28:18.814 Buffered Space: 31498240 bytes
[Timer-1] DEBUG 18:28:19.815 Buffered Space: 27492352 bytes
[Timer-1] DEBUG 18:28:20.816 Buffered Space: 23117824 bytes
[Timer-1] DEBUG 18:28:21.817 Buffered Space: 21895168 bytes
[Timer-1] DEBUG 18:28:22.817 Buffered Space: 20434944 bytes
[Timer-1] DEBUG 18:28:23.823 Buffered Space: 19146752 bytes
[Timer-1] DEBUG 18:28:24.824 Buffered Space: 17070080 bytes
[Timer-1] DEBUG 18:28:25.829 Buffered Space: 12374016 bytes
[Timer-1] DEBUG 18:28:26.830 Buffered Space: 7006208 bytes
[Timer-1] DEBUG 18:28:27.837 Buffered Space: 2084864 bytes
[Thread-55] DEBUG 18:28:28.039 Suspend Read: readCount=144703488 / writeCount=145682432
[Thread-55] DEBUG 18:28:28.539 Resume Read: readCount=144703488 / writeCount=148758528
[Timer-1] DEBUG 18:28:28.837 Buffered Space: 2510848 bytes
[Thread-55] DEBUG 18:28:29.132 Suspend Read: readCount=151519232 / writeCount=152461312
[Thread-55] DEBUG 18:28:29.632 Resume Read: readCount=151519232 / writeCount=153858048
[Thread-55] DEBUG 18:28:29.790 Suspend Read: readCount=153354240 / writeCount=154308608
[Timer-1] DEBUG 18:28:29.837 Buffered Space: 1015808 bytes
[Thread-55] DEBUG 18:28:30.290 Resume Read: readCount=153354240 / writeCount=156710912
[Thread-55] DEBUG 18:28:30.774 Suspend Read: readCount=158924800 / writeCount=159907840
[Timer-1] DEBUG 18:28:30.841 Buffered Space: 1507328 bytes
[Thread-55] DEBUG 18:28:31.274 Resume Read: readCount=158924800 / writeCount=163684352
[Thread-55] DEBUG 18:28:31.821 Suspend Read: readCount=165216256 / writeCount=166201344
[Timer-1] DEBUG 18:28:31.842 Buffered Space: 1038336 bytes
[Thread-55] DEBUG 18:28:32.321 Resume Read: readCount=165216256 / writeCount=168341504
[Thread-55] DEBUG 18:28:32.658 Suspend Read: readCount=169082880 / writeCount=170082304
[Timer-1] DEBUG 18:28:32.842 Buffered Space: 2230272 bytes
[Thread-55] DEBUG 18:28:33.158 Resume Read: readCount=169082880 / writeCount=173445120
[Thread-55] DEBUG 18:28:33.669 Suspend Read: readCount=174981120 / writeCount=175978496
[Timer-1] DEBUG 18:28:33.841 Buffered Space: 2215936 bytes
[Thread-55] DEBUG 18:28:34.169 Resume Read: readCount=174981120 / writeCount=179761152
[Timer-1] DEBUG 18:28:34.844 Buffered Space: 2418688 bytes
[Thread-55] DEBUG 18:28:35.140 Suspend Read: readCount=186122240 / writeCount=187109376
[Thread-55] DEBUG 18:28:35.640 Resume Read: readCount=186122240 / writeCount=190744576
[Timer-1] DEBUG 18:28:35.844 Buffered Space: 3571712 bytes
[Thread-55] DEBUG 18:28:36.402 Suspend Read: readCount=194838528 / writeCount=195835904
[Timer-1] DEBUG 18:28:36.844 Buffered Space: 4460544 bytes
[Thread-55] DEBUG 18:28:36.902 Resume Read: readCount=194838528 / writeCount=199731200
[Thread-55] DEBUG 18:28:37.831 Suspend Read: readCount=205455360 / writeCount=206438400
[Timer-1] DEBUG 18:28:37.845 Buffered Space: 1148928 bytes
[Thread-55] DEBUG 18:28:38.331 Resume Read: readCount=205455360 / writeCount=211976192
[Timer-1] DEBUG 18:28:38.848 Buffered Space: 7194624 bytes
[Timer-1] DEBUG 18:28:39.851 Buffered Space: 1638400 bytes
[Thread-55] DEBUG 18:28:39.951 Suspend Read: readCount=223936512 / writeCount=224899072
[Thread-55] DEBUG 18:28:40.451 Resume Read: readCount=223936512 / writeCount=229476352
[Timer-1] DEBUG 18:28:40.851 Buffered Space: 5476352 bytes
[Timer-1] DEBUG 18:28:41.852 Buffered Space: 5052416 bytes
[Timer-1] DEBUG 18:28:42.852 Buffered Space: 3682304 bytes
[Thread-55] DEBUG 18:28:43.393 Suspend Read: readCount=257490944 / writeCount=258447360
[Timer-1] DEBUG 18:28:43.853 Buffered Space: 3346432 bytes
[Thread-55] DEBUG 18:28:43.893 Resume Read: readCount=257490944 / writeCount=260993024
[Thread-55] DEBUG 18:28:44.238 Suspend Read: readCount=261488640 / writeCount=262461440
[Thread-55] DEBUG 18:28:44.739 Resume Read: readCount=261488640 / writeCount=264896512
[Timer-1] DEBUG 18:28:44.853 Buffered Space: 2510848 bytes
[Thread-55] DEBUG 18:28:45.053 Suspend Read: readCount=265093120 / writeCount=266041344
[Thread-55] DEBUG 18:28:45.553 Resume Read: readCount=265093120 / writeCount=268464128
[Timer-1] DEBUG 18:28:45.856 Buffered Space: 1460224 bytes
[Thread-55] DEBUG 18:28:45.947 Suspend Read: readCount=269615104 / writeCount=270589952
[Thread-55] DEBUG 18:28:46.447 Resume Read: readCount=269615104 / writeCount=273920000
[Timer-1] DEBUG 18:28:46.859 Buffered Space: 2273280 bytes
[Thread-55] DEBUG 18:28:47.096 Suspend Read: readCount=277086208 / writeCount=278026240
[Thread-55] DEBUG 18:28:47.596 Resume Read: readCount=277086208 / writeCount=280721408
[Timer-1] DEBUG 18:28:47.858 Buffered Space: 1855488 bytes
[Thread-55] DEBUG 18:28:47.999 Suspend Read: readCount=281739264 / writeCount=282714112
[Thread-55] DEBUG 18:28:48.499 Resume Read: readCount=281739264 / writeCount=285716480
[Timer-1] DEBUG 18:28:48.858 Buffered Space: 1732608 bytes
[Thread-55] DEBUG 18:28:49.003 Suspend Read: readCount=287506432 / writeCount=288497664
[Thread-55] DEBUG 18:28:49.505 Resume Read: readCount=287506432 / writeCount=290850816
[Timer-1] DEBUG 18:28:49.862 Buffered Space: 1509376 bytes
[Thread-55] DEBUG 18:28:50.016 Suspend Read: readCount=293404672 / writeCount=294354944
[Thread-55] DEBUG 18:28:50.516 Resume Read: readCount=293404672 / writeCount=298731520
[Timer-1] DEBUG 18:28:50.862 Buffered Space: 4325376 bytes
[Timer-1] DEBUG 18:28:51.864 Buffered Space: 1556480 bytes
[Thread-55] DEBUG 18:28:52.020 Suspend Read: readCount=310509568 / writeCount=311457792
[Thread-55] DEBUG 18:28:52.520 Resume Read: readCount=310509568 / writeCount=316119040
[Timer-1] DEBUG 18:28:52.863 Buffered Space: 4317184 bytes
[Timer-1] DEBUG 18:28:53.870 Buffered Space: 1677312 bytes
[Thread-55] DEBUG 18:28:54.041 Suspend Read: readCount=327876608 / writeCount=328861696
[Thread-55] DEBUG 18:28:54.541 Resume Read: readCount=327876608 / writeCount=333277184
[Timer-1] DEBUG 18:28:54.869 Buffered Space: 3831808 bytes
[Thread-55] DEBUG 18:28:55.397 Suspend Read: readCount=337641472 / writeCount=338636800
[Timer-1] DEBUG 18:28:55.872 Buffered Space: 3807232 bytes
[Thread-55] DEBUG 18:28:55.897 Resume Read: readCount=337641472 / writeCount=341571584
[Timer-1] DEBUG 18:28:56.873 Buffered Space: 1191936 bytes
[Thread-55] DEBUG 18:28:56.893 Suspend Read: readCount=349044736 / writeCount=350042112
[Thread-55] DEBUG 18:28:57.393 Resume Read: readCount=349044736 / writeCount=354529280
[Timer-1] DEBUG 18:28:57.877 Buffered Space: 2574336 bytes
[Thread-55] DEBUG 18:28:58.191 Suspend Read: readCount=358154240 / writeCount=359131136
[Thread-55] DEBUG 18:28:58.691 Resume Read: readCount=358154240 / writeCount=363204608
[Timer-1] DEBUG 18:28:58.877 Buffered Space: 4483072 bytes
[Thread-55] DEBUG 18:28:59.703 Suspend Read: readCount=369688576 / writeCount=370665472
[Timer-1] DEBUG 18:28:59.878 Buffered Space: 1964032 bytes
[Thread-55] DEBUG 18:29:00.203 Resume Read: readCount=369688576 / writeCount=373135360
[Thread-55] DEBUG 18:29:00.627 Suspend Read: readCount=374538240 / writeCount=375517184
[Timer-1] DEBUG 18:29:00.879 Buffered Space: 2461696 bytes
[Thread-55] DEBUG 18:29:01.127 Resume Read: readCount=374538240 / writeCount=378236928
[Thread-55] DEBUG 18:29:01.589 Suspend Read: readCount=379846656 / writeCount=380803072
[Timer-1] DEBUG 18:29:01.879 Buffered Space: 2973696 bytes
[Thread-55] DEBUG 18:29:02.090 Resume Read: readCount=379846656 / writeCount=384210944
PS4
 
Posts: 21
Joined: Mon Jan 19, 2009 4:11 pm

Re: Some MKV's don't stream with 1.03

Postby PS4 » Wed Jan 21, 2009 1:18 am

and here's log for single core that works.


[Thread-36] DEBUG 18:23:55.377 Setting DLNA id 0$0$3 to M2TS
[Thread-36] DEBUG 18:23:55.377 Setting DLNA id 0$0$4 to MKV
[Thread-36] DEBUG 18:23:55.377 Setting DLNA id 0$0$5 to Test1.mkv
[Thread-36] DEBUG 18:23:55.377 Setting DLNA id 0$0$6 to #--TRANSCODED--#
[Thread-36] DEBUG 18:23:55.377 Setting DLNA id 0$0$6$0 to Test1.mkv
[Thread-36] DEBUG 18:23:55.378 Setting DLNA id 0$0$6$0$0 to Test1.mkv
[pool-3-thread-1] INFO 18:23:55.384 Starting C:\Program Files\PS3 Media Server\win32\ffmpeg.exe -ss 120 -i E:\TVersity-E\Test1.mkv -an -an -s 320x180 -vframes 1 -f image2 pipe:
[pool-3-thread-1] INFO 18:23:55.531 Attaching thread: win32/ffmpeg.exe
[Thread-38] DEBUG 18:23:56.437 FFmpeg version SVN-r16043-Sherpya, Copyright (c) 2000-2008 Fabrice Bellard, et al.
[Thread-38] DEBUG 18:23:56.437 libavutil 49.12. 0 / 49.12. 0
[Thread-38] DEBUG 18:23:56.437 libavcodec 52. 6. 1 / 52. 6. 1
[Thread-38] DEBUG 18:23:56.437 libavformat 52.23. 1 / 52.23. 1
[Thread-38] DEBUG 18:23:56.437 libavdevice 52. 1. 0 / 52. 1. 0
[Thread-38] DEBUG 18:23:56.437 libavfilter 0. 1. 0 / 0. 1. 0
[Thread-38] DEBUG 18:23:56.437 libswscale 0. 6. 1 / 0. 6. 1
[Thread-38] DEBUG 18:23:56.437 libpostproc 51. 2. 0 / 51. 2. 0
[Thread-38] DEBUG 18:23:56.437 built on Dec 10 2008 18:25:26, gcc: 4.2.5 20080919 (prerelease) [Sherpya]
[Thread-38] DEBUG 18:23:56.437 Input #0, matroska, from 'E:\TVersity-E\Test1.mkv':
[Thread-38] DEBUG 18:23:56.437 Duration: 01:40:58.14, start: 0.000000, bitrate: N/A
[Thread-38] DEBUG 18:23:56.437 Stream #0.0(eng): Video: h264, yuv420p, 1280x544, 23.98 tb(r)
[Thread-38] DEBUG 18:23:56.437 Stream #0.1(eng): Audio: dca, 48000 Hz, 5.1, s16
[Thread-38] DEBUG 18:23:56.437 Stream #0.2(eng): Subtitle: 0x0000
[Thread-38] DEBUG 18:23:56.438 Output #0, image2, to 'pipe:':
[Thread-38] DEBUG 18:23:56.438 Stream #0.0(eng): Video: mjpeg, yuvj420p, 320x180 [PAR 45:34 DAR 40:17], q=2-31, 200 kb/s, 23.98 tb(c)
[Thread-38] DEBUG 18:23:56.438 Stream mapping:
[Thread-38] DEBUG 18:23:56.438 Stream #0.0 -> #0.0
[Thread-38] DEBUG 18:23:56.438 Press [q] to stop encoding
[Thread-38] DEBUG 18:23:56.438 video:14kB audio:0kB global headers:0kB muxing overhead -100.156807%
[pool-3-thread-1] DEBUG 18:23:56.441 EOF
[pool-3-thread-1] DEBUG 18:23:56.441 Ready to Stop: true
[pool-3-thread-1] DEBUG 18:23:56.539 Media info: mimeType: video/mp4 / container: matroska / bitrate: 0 / size: 4695348084 / codecV: h264 / duration: 01:40:58.140 / width: 1280 / height: 544 / frameRate: 23.98 / codecA: dca / sampleFrequency: 48000 / nrAudioChannels: 0
[Thread-36] DEBUG 18:23:56.539 End of analysis
[Thread-36] DEBUG 18:23:56.541 Wrote on socket: Server: Windows Vista-x86-6.0 UPnP/1.0, PMS
[Thread-36] DEBUG 18:23:56.541 Wrote on socket: Content-Length: 3801
[Thread-36] DEBUG 18:23:56.541 Wrote on socket:
[Thread-36] DEBUG 18:23:56.541 Close Connection
[Thread-42] DEBUG 18:23:57.108 Opened handler on socket Socket[addr=/192.168.0.98,port=63812,localport=5001]
[Thread-42] DEBUG 18:23:57.108 Received on socket: POST /upnp/control/content_directory HTTP/1.1
[Thread-42] DEBUG 18:23:57.108 Received on socket: X-AV-Client-Info: av=5.0; cn="Sony Computer Entertainment Inc."; mn="PLAYSTATION 3"; mv="1.0";
[Thread-42] DEBUG 18:23:57.122 Received on socket: Host: 192.168.0.7:5001
[Thread-42] DEBUG 18:23:57.123 Received on socket: User-Agent: UPnP/1.0 DLNADOC/1.00
[Thread-42] DEBUG 18:23:57.123 Received on socket: Content-Length: 276
[Thread-42] DEBUG 18:23:57.123 Received on socket: Content-Type: text/xml; charset="utf-8"
[Thread-42] DEBUG 18:23:57.123 Received on socket: SOAPACTION: "urn:schemas-upnp-org:service:ContentDirectory:1#GetSystemUpdateID"
[Thread-41] INFO 18:23:57.142 Stopping process: win32/ffmpeg.exe
[Thread-41] INFO 18:23:57.142 Destroying buffer
[Thread-41] INFO 18:23:57.197 Destroying buffer
[Thread-43] DEBUG 18:23:57.242 Opened handler on socket Socket[addr=/192.168.0.98,port=63811,localport=5001]
[Thread-43] DEBUG 18:23:57.242 Received on socket: GET /get/0$0$5/thumbnail0000Test1.mkv HTTP/1.0
[Thread-43] DEBUG 18:23:57.242 Received on socket: Host: 192.168.0.7:5001
[Thread-43] DEBUG 18:23:57.242 Received on socket: User-Agent: PLAYSTATION 3
[Thread-43] DEBUG 18:23:57.251 Received on socket: Connection: close
[Thread-43] DEBUG 18:23:57.251 Received on socket: Accept-Encoding: identity
[Thread-43] DEBUG 18:23:57.251 Received on socket: Cache-Control: no-cache
[Thread-43] INFO 18:23:57.251 HTTP: get/0$0$5/thumbnail0000Test1.mkv / 0-0
[Thread-43] DEBUG 18:23:57.251 Wrote on socket: HTTP/1.0 200 OK
[Thread-43] DEBUG 18:23:57.251 Searching for objectId: 0$0$5 with children option: false
[Thread-43] DEBUG 18:23:57.251 Wrote on socket: Content-Type: image/png
[Thread-43] DEBUG 18:23:57.251 Wrote on socket: Accept-Ranges: bytes
[Thread-43] DEBUG 18:23:57.251 Wrote on socket: Expires: Sat, 16 May 2009 17:10:37 GMT
[Thread-43] DEBUG 18:23:57.251 Wrote on socket: Connection: keep-alive
[Thread-43] DEBUG 18:23:57.252 Wrote on socket: Server: Windows Vista-x86-6.0 UPnP/1.0, PMS
[Thread-43] DEBUG 18:23:57.252 Available Content-Length: 12841
[Thread-43] DEBUG 18:23:57.252 Wrote on socket: Content-Length: 12841
[Thread-43] DEBUG 18:23:57.252 Wrote on socket:
[Thread-43] DEBUG 18:23:57.252 Sending stream: 12841 bytes of get/0$0$5/thumbnail0000Test1.mkv
[Thread-43] DEBUG 18:23:57.252 Close Connection
[Thread-44] DEBUG 18:23:57.267 Opened handler on socket Socket[addr=/192.168.0.98,port=63810,localport=5001]
[Thread-44] DEBUG 18:23:57.267 Received on socket: GET /get/0$0$5/thumbnail0000Test1.mkv HTTP/1.1
[Thread-44] DEBUG 18:23:57.267 Received on socket: Host: 192.168.0.7:5001
[Thread-44] DEBUG 18:23:57.267 Received on socket: User-Agent: PLAYSTATION 3
[Thread-44] DEBUG 18:23:57.276 Received on socket: Connection: Keep-Alive
[Thread-44] DEBUG 18:23:57.276 Received on socket: Accept-Encoding: identity
[Thread-44] INFO 18:23:57.276 HTTP: get/0$0$5/thumbnail0000Test1.mkv / 0-0
[Thread-44] DEBUG 18:23:57.276 Wrote on socket: HTTP/1.1 200 OK
[Thread-44] DEBUG 18:23:57.276 Searching for objectId: 0$0$5 with children option: false
[Thread-44] DEBUG 18:23:57.276 Wrote on socket: Content-Type: image/png
[Thread-44] DEBUG 18:23:57.276 Wrote on socket: Accept-Ranges: bytes
[Thread-44] DEBUG 18:23:57.276 Wrote on socket: Expires: Sat, 16 May 2009 17:10:37 GMT
[Thread-44] DEBUG 18:23:57.276 Wrote on socket: Connection: keep-alive
[Thread-44] DEBUG 18:23:57.276 Wrote on socket: Server: Windows Vista-x86-6.0 UPnP/1.0, PMS
[Thread-44] DEBUG 18:23:57.276 Available Content-Length: 12841
[Thread-44] DEBUG 18:23:57.276 Wrote on socket: Content-Length: 12841
[Thread-44] DEBUG 18:23:57.276 Wrote on socket:
[Thread-44] DEBUG 18:23:57.277 Sending stream: 12841 bytes of get/0$0$5/thumbnail0000Test1.mkv
[Thread-44] DEBUG 18:23:57.278 Close Connection
[Thread-42] INFO 18:23:57.302 HTTP: upnp/control/content_directory / 0-0
[Thread-42] DEBUG 18:23:57.302 Wrote on socket: HTTP/1.1 200 OK
[Thread-42] DEBUG 18:23:57.302 Wrote on socket: CONTENT-TYPE: text/xml; charset="utf-8"
[Thread-42] DEBUG 18:23:57.302 Wrote on socket: Server: Windows Vista-x86-6.0 UPnP/1.0, PMS
[Thread-42] DEBUG 18:23:57.302 Wrote on socket: Content-Length: 332
[Thread-42] DEBUG 18:23:57.302 Wrote on socket:
[Thread-42] DEBUG 18:23:57.302 Close Connection
[Thread-45] DEBUG 18:23:57.306 Opened handler on socket Socket[addr=/192.168.0.98,port=63809,localport=5001]
[Thread-45] DEBUG 18:23:57.306 Received on socket: POST /upnp/control/content_directory HTTP/1.1
[Thread-45] DEBUG 18:23:57.306 Received on socket: X-AV-Client-Info: av=5.0; cn="Sony Computer Entertainment Inc."; mn="PLAYSTATION 3"; mv="1.0";
[Thread-45] DEBUG 18:23:57.314 Received on socket: Host: 192.168.0.7:5001
[Thread-45] DEBUG 18:23:57.314 Received on socket: User-Agent: UPnP/1.0 DLNADOC/1.00
[Thread-45] DEBUG 18:23:57.314 Received on socket: Content-Length: 903
[Thread-45] DEBUG 18:23:57.314 Received on socket: Content-Type: text/xml; charset="utf-8"
[Thread-45] DEBUG 18:23:57.314 Received on socket: SOAPACTION: "urn:schemas-upnp-org:service:ContentDirectory:1#Browse"
[Thread-45] INFO 18:23:57.502 HTTP: upnp/control/content_directory / 0-0
[Thread-45] DEBUG 18:23:57.502 Wrote on socket: HTTP/1.1 200 OK
[Thread-45] DEBUG 18:23:57.502 Wrote on socket: CONTENT-TYPE: text/xml; charset="utf-8"
[Thread-45] DEBUG 18:23:57.502 Searching for objectId: 0$0 with children option: false
[Thread-45] DEBUG 18:23:57.502 Search extension for list1.txt
[Thread-45] DEBUG 18:23:57.503 Wrote on socket: Server: Windows Vista-x86-6.0 UPnP/1.0, PMS
[Thread-45] DEBUG 18:23:57.503 Wrote on socket: Content-Length: 1022
[Thread-45] DEBUG 18:23:57.503 Wrote on socket:
[Thread-45] DEBUG 18:23:57.503 Close Connection
[Thread-46] DEBUG 18:24:01.141 Opened handler on socket Socket[addr=/192.168.0.98,port=63808,localport=5001]
[Thread-46] DEBUG 18:24:01.141 Received on socket: GET /get/0$0$5/Test1.mkv HTTP/1.1
[Thread-46] DEBUG 18:24:01.141 Received on socket: Host: 192.168.0.7:5001
[Thread-46] DEBUG 18:24:01.142 Received on socket: User-Agent: PLAYSTATION 3
[Thread-46] DEBUG 18:24:01.155 Received on socket: Connection: Keep-Alive
[Thread-46] DEBUG 18:24:01.155 Received on socket: Accept-Encoding: identity
[Thread-46] INFO 18:24:01.155 HTTP: get/0$0$5/Test1.mkv / 0-0
[Thread-46] DEBUG 18:24:01.155 Wrote on socket: HTTP/1.1 200 OK
[Thread-46] DEBUG 18:24:01.155 Searching for objectId: 0$0$5 with children option: false
[Thread-46] DEBUG 18:24:01.155 Asked stream chunk [0-0] timeseek: 0.0 of Test1.mkv and player MEncoder
[Thread-46] TRACE 18:24:01.155 Starting transcode of Test1.mkv
[Thread-46] INFO 18:24:01.159 Creating pipe \\.\pipe\mencoder1232493841156
[Timer-1] DEBUG 18:24:01.362 Buffered Space: 0 bytes
[Thread-47] INFO 18:24:01.362 Waiting for pipe connection \\.\pipe\mencoder1232493841156
[win32/mencoder.exe] INFO 18:24:01.478 Starting C:\Program Files\PS3 Media Server\win32\mencoder.exe -ss 0 -quiet E:\TVersity-E\Test1.mkv -quiet -quiet -oac lavc -of mpeg -mpegopts format=mpeg2:muxrate=500000:vbuf_size=1194:abuf_size=64 -ovc lavc -channels 6 -lavdopts debug=0:threads=2 -lavcopts autoaspect=1:vcodec=mpeg2video:acodec=ac3:abitrate=384:threads=2:keyint=1:vqscale=1:vqmin=2 -ass -nofontconfig -subcp cp1252 -alang eng,fre,jpn,ger -ass-color ffffff00 -ass-border-color 00000000 -ass-font-scale 1.0 -ass-force-style FontName=Arial,Outline=1,Shadow=1,MarginV=10 -slang eng,fre,jpn,ger -quiet -quiet -fps 24000/1001 -ofps 24000/1001 -quiet -quiet -af lavcresample=48000 -srate 48000 -o \\.\pipe\mencoder1232493841156
[win32/mencoder.exe] INFO 18:24:01.480 Reading pipe: \\.\pipe\mencoder1232493841156
[win32/mencoder.exe] INFO 18:24:01.480 Attaching thread: win32/mencoder.exe
[Thread-51] DEBUG 18:24:01.492 MEncoder Sherpya-SVN-r28126-4.2.5 (C) 2000-2008 MPlayer Team
[Thread-51] DEBUG 18:24:01.492 CPU: Intel(R) Core(TM)2 Duo CPU E8400 @ 3.00GHz (Family: 6, Model: 23, Stepping: 6)
[Thread-51] DEBUG 18:24:01.493 CPUflags: Type: 6 MMX: 1 MMX2: 1 3DNow: 0 3DNow2: 0 SSE: 1 SSE2: 1
[Thread-51] DEBUG 18:24:01.493 Compiled with runtime CPU detection.
[Thread-51] DEBUG 18:24:01.507 success: format: 0 data: 0x0 - 0x17dd5374
[Thread-51] DEBUG 18:24:01.510 [mkv] Track ID 1: video (V_MPEG4/ISO/AVC), -vid 0
[Thread-51] DEBUG 18:24:01.510 [mkv] Track ID 2: audio (A_DTS), -aid 0, -alang eng
[Thread-51] DEBUG 18:24:01.510 [mkv] Track ID 3: subtitles (S_TEXT/UTF8), -sid 0, -slang eng
[Thread-51] DEBUG 18:24:01.510 [mkv] Will play video track 1.
[Thread-51] DEBUG 18:24:01.510 Matroska file format detected.
[Thread-51] DEBUG 18:24:01.510 VIDEO: [avc1] 1280x544 24bpp 23.976 fps 0.0 kbps ( 0.0 kbyte/s)
[Thread-51] DEBUG 18:24:01.510 [V] filefmt:31 fourcc:0x31637661 size:1280x544 fps:23.976 ftime:=0.0417
[Thread-51] DEBUG 18:24:01.510 Input fps will be interpreted as 23.976 instead.
[Thread-51] DEBUG 18:24:01.510 ==========================================================================
[Thread-51] DEBUG 18:24:01.510 Opening audio decoder: [libdca] DTS decoding with libdca
[Thread-51] DEBUG 18:24:01.511 AUDIO: 48000 Hz, 6 ch, s16le, 1536.0 kbit/33.33% (ratio: 192000->576000)
[Thread-51] DEBUG 18:24:01.511 Selected audio codec: [dts] afm: libdca (DTS-libdca)
[Thread-51] DEBUG 18:24:01.511 ==========================================================================
[Thread-47] INFO 18:24:01.511 Result of \\.\pipe\mencoder1232493841156 : true
[Thread-50] DEBUG 18:24:01.512 Stream with high frequencies VQ coding
[Thread-50] DEBUG 18:24:01.512 Warning: -ass implies -keep-pts, which may cause "badly interleaved" files.
[Thread-51] DEBUG 18:24:01.512 PACKET SIZE: 2048 bytes, deltascr: 884
[Thread-51] DEBUG 18:24:01.512 [ass] auto-open
[Thread-51] DEBUG 18:24:01.512 [ass] Init
[Thread-50] DEBUG 18:24:01.512 [ass] Fontconfig disabled, only default font will be used.
[Thread-51] DEBUG 18:24:01.512 ==========================================================================
[Thread-51] DEBUG 18:24:01.513 Opening video decoder: [ffmpeg] FFmpeg's libavcodec codec family
[Thread-51] DEBUG 18:24:01.514 Selected video codec: [ffh264] vfm: ffmpeg (FFmpeg H.264)
[Thread-51] DEBUG 18:24:01.514 ==========================================================================
[Thread-50] DEBUG 18:24:01.515 Limiting audio preload to 0.4s.
[Thread-50] DEBUG 18:24:01.515 Increasing audio density to 4.
[Thread-51] DEBUG 18:24:01.543 VDec: vo config request - 1280 x 544 (preferred colorspace: Planar YV12)
[Thread-51] DEBUG 18:24:01.543 VDec: using Planar YV12 as output csp (no 0)
[Thread-51] DEBUG 18:24:01.543 Movie-Aspect is 2.35:1 - prescaling to correct movie aspect.
[Thread-51] DEBUG 18:24:01.543 videocodec: libavcodec (1280x544 fourcc=3267706d [mpg2])
[Thread-51] DEBUG 18:24:01.544 [VE_LAVC] Using constant qscale = 1.000000 (VBR).
[Thread-51] DEBUG 18:24:01.548 Writing header...
[Timer-1] DEBUG 18:24:02.362 Buffered Space: 1992704 bytes
[Timer-1] DEBUG 18:24:03.362 Buffered Space: 5978112 bytes
[Timer-1] DEBUG 18:24:04.362 Buffered Space: 12564480 bytes
[Timer-1] DEBUG 18:24:05.362 Buffered Space: 18894848 bytes
[Thread-37] INFO 18:24:05.394 Stopping process: win32/ffmpeg.exe
[Thread-37] INFO 18:24:05.394 Destroying buffer
[Timer-1] DEBUG 18:24:06.362 Buffered Space: 24035328 bytes
[Timer-1] DEBUG 18:24:07.362 Buffered Space: 29413376 bytes
[Thread-46] DEBUG 18:24:07.528 Wrote on socket: Content-Type: video/mpeg
[Thread-46] DEBUG 18:24:07.528 Wrote on socket: Connection: keep-alive
[Thread-46] DEBUG 18:24:07.528 Wrote on socket: Server: Windows Vista-x86-6.0 UPnP/1.0, PMS
[Thread-46] DEBUG 18:24:07.528 Wrote on socket:
[Thread-52] DEBUG 18:24:07.636 Opened handler on socket Socket[addr=/192.168.0.98,port=63807,localport=5001]
[Thread-52] DEBUG 18:24:07.636 Received on socket: GET /get/0$0$5/Test1.mkv HTTP/1.1
[Thread-52] DEBUG 18:24:07.636 Received on socket: Host: 192.168.0.7:5001
[Thread-52] DEBUG 18:24:07.636 Received on socket: User-Agent: PLAYSTATION 3
[Thread-52] DEBUG 18:24:07.644 Received on socket: Connection: Keep-Alive
[Thread-52] DEBUG 18:24:07.644 Received on socket: Accept-Encoding: identity
[Thread-52] INFO 18:24:07.644 HTTP: get/0$0$5/Test1.mkv / 0-0
[Thread-52] DEBUG 18:24:07.644 Wrote on socket: HTTP/1.1 200 OK
[Thread-52] DEBUG 18:24:07.644 Searching for objectId: 0$0$5 with children option: false
[Thread-52] DEBUG 18:24:07.644 Asked stream chunk [0-0] timeseek: 0.0 of Test1.mkv and player MEncoder
[Thread-52] DEBUG 18:24:07.644 Wrote on socket: Content-Type: video/mpeg
[Thread-52] DEBUG 18:24:07.644 Wrote on socket: Connection: keep-alive
[Thread-52] DEBUG 18:24:07.644 Wrote on socket: Server: Windows Vista-x86-6.0 UPnP/1.0, PMS
[Thread-52] DEBUG 18:24:07.644 Wrote on socket:
[Thread-52] DEBUG 18:24:07.737 Sending stream with premature end : 1114112 bytes of get/0$0$5/Test1.mkv. Reason: An existing connection was forcibly closed by the remote host
[Thread-52] DEBUG 18:24:07.737 Ready to Stop: true
[Thread-52] DEBUG 18:24:07.737 Sending stream: 1114112 bytes of get/0$0$5/Test1.mkv
[Thread-52] DEBUG 18:24:07.738 Close Connection
[Thread-46] DEBUG 18:24:07.818 Ready to Stop: false
[Timer-1] DEBUG 18:24:08.362 Buffered Space: 36685824 bytes
[Timer-1] DEBUG 18:24:09.362 Buffered Space: 42119168 bytes
[Thread-46] DEBUG 18:24:09.855 Sending stream with premature end : 1245184 bytes of get/0$0$5/Test1.mkv. Reason: An existing connection was forcibly closed by the remote host
[Thread-46] DEBUG 18:24:09.855 Ready to Stop: true
[Thread-46] DEBUG 18:24:09.855 Sending stream: 1245184 bytes of get/0$0$5/Test1.mkv
[Thread-46] DEBUG 18:24:09.855 Close Connection
[Thread-57] DEBUG 18:24:09.856 Opened handler on socket Socket[addr=/192.168.0.98,port=63806,localport=5001]
[Thread-57] DEBUG 18:24:09.858 Received on socket: GET /get/0$0$5/Test1.mkv HTTP/1.1
[Thread-57] DEBUG 18:24:09.858 Received on socket: Host: 192.168.0.7:5001
[Thread-57] DEBUG 18:24:09.858 Received on socket: User-Agent: PLAYSTATION 3
[Thread-57] DEBUG 18:24:09.871 Received on socket: Connection: Keep-Alive
[Thread-57] DEBUG 18:24:09.871 Received on socket: Accept-Encoding: identity
[Thread-57] DEBUG 18:24:09.871 Received on socket: TimeSeekRange.dlna.org : npt=0.000-
[Thread-57] INFO 18:24:09.871 HTTP: get/0$0$5/Test1.mkv / 0-0
[Thread-57] DEBUG 18:24:09.872 Wrote on socket: HTTP/1.1 200 OK
[Thread-57] DEBUG 18:24:09.872 Searching for objectId: 0$0$5 with children option: false
[Thread-57] DEBUG 18:24:09.872 Asked stream chunk [0-0] timeseek: 0.0 of Test1.mkv and player MEncoder
[Thread-57] DEBUG 18:24:09.872 Ready to Stop: false
[Thread-57] DEBUG 18:24:09.872 Wrote on socket: Content-Type: video/mpeg
[Thread-57] DEBUG 18:24:09.872 Wrote on socket: Connection: keep-alive
[Thread-57] DEBUG 18:24:09.872 Wrote on socket: Server: Windows Vista-x86-6.0 UPnP/1.0, PMS
[Thread-57] DEBUG 18:24:09.873 Wrote on socket:
[Thread-50] DEBUG 18:24:10.086 [h264 @ 02D71930]Cannot parallelize deblocking type 1, decoding such frames in sequential order
[Thread-50] DEBUG 18:24:10.086 [ass] PlayResX undefined, setting 678.
[Timer-1] DEBUG 18:24:10.362 Buffered Space: 39356416 bytes
[Timer-1] DEBUG 18:24:11.362 Buffered Space: 39858176 bytes
[Thread-47] DEBUG 18:24:12.029 freeMemory: 38465824
[Thread-47] DEBUG 18:24:12.029 totalMemory: 95137792
[Thread-47] DEBUG 18:24:12.029 maxMemory: 799145984
[Thread-47] DEBUG 18:24:12.029 Extending buffer to 419430400
[Timer-1] DEBUG 18:24:12.363 Buffered Space: 40626176 bytes
[Thread-47] DEBUG 18:24:12.455 Done extending
[Timer-1] DEBUG 18:24:13.362 Buffered Space: 44111872 bytes
[Timer-1] DEBUG 18:24:14.362 Buffered Space: 45797376 bytes
[Timer-1] DEBUG 18:24:15.362 Buffered Space: 46436352 bytes
[Timer-1] DEBUG 18:24:16.362 Buffered Space: 47302656 bytes
[Timer-1] DEBUG 18:24:17.362 Buffered Space: 49682432 bytes
[Timer-1] DEBUG 18:24:18.362 Buffered Space: 52348928 bytes
[Timer-1] DEBUG 18:24:19.362 Buffered Space: 55443456 bytes
[Timer-1] DEBUG 18:24:20.362 Buffered Space: 58419200 bytes
[Timer-1] DEBUG 18:24:21.362 Buffered Space: 61227008 bytes
[Timer-1] DEBUG 18:24:22.362 Buffered Space: 67031040 bytes
[Timer-1] DEBUG 18:24:23.362 Buffered Space: 71557120 bytes
[Timer-1] DEBUG 18:24:24.362 Buffered Space: 76226560 bytes
PS4
 
Posts: 21
Joined: Mon Jan 19, 2009 4:11 pm

Next

Return to General Help and Support

Who is online

Users browsing this forum: Bing [Bot], Google [Bot], Yahoo [Bot] and 13 guests