Problems with DTS-HD and Subtitles

[Concorde Rules]

Hi Guys,

Having issues with embedded and external subtitles.

Essentially with m2ts files:

Video: AVCHD H264

Case 1: DTS-HD + Embedded Subtitles = 'go-to' doesn't work correctly, it's a factor of 10 out. (I.e. ask for 3600 seconds, get 360 seconds).
Case 2: DTS-HD + No Embedded Subtitles = 'go-to' doesn't work correctly, it's a factor of 10 out. (I.e. ask for 3600 seconds, get 360 seconds).
Case 3: AC3 + Embedded Subtitles = 'go-to' doesn't work correctly, it's a factor of 10 out. (I.e. ask for 3600 seconds, get 360 seconds).
Case 4: AC3 + No Embedded Subtitles = 'go-to' works correctly.
Case 5: AC3 + External .sub (.itx) Subtitles = 'go-to' doesn't work correctly, it's a factor of 10 out. (I.e. ask for 3600 seconds, get 360 seconds).

It's been encoded using ripbot264 and being shared by:
The latest OS X beta (1.31 beta 1) and the last stable linux (1.30.1).

Both have the same issue, both connected by gigabit.

Linux server is UnRAID slackware install on a 3Ghz AMD Athlon X2 with 4Gb ram.
OS X is running on OS X Lion 10.7.1 on a 2.66Ghz Mac Pro 2009 with 12Gb ram.

I need subtitles because it has forced subtitles in this film, and i'd rather not have to re-encode my entire blu-ray collection given it takes 7 hours a pop...

Will get the debug logs.

Edit: Here they are

Important bit:

Code: Select all

[New I/O server boss #1 ([id: 0x23087d61, /192.168.1.5:5001])] TRACE 18:41:30.188 Creating new pipeline
[New I/O server worker #1-5] TRACE 18:41:30.189 Opened request handler on socket /192.168.1.30:57570 // Playstation 3
[New I/O server worker #1-5] TRACE 18:41:30.189 Request: HTTP/1.1 : GET : get/0$0$1/Avatar_1080_AC3_no_subs.m2ts
[New I/O server worker #1-5] TRACE 18:41:30.189 Received on socket: Accept-Encoding: identity
[New I/O server worker #1-5] TRACE 18:41:30.189 Received on socket: Connection: Keep-Alive
[New I/O server worker #1-5] TRACE 18:41:30.190 Received on socket: Host: 192.168.1.5:5001
[New I/O server worker #1-5] TRACE 18:41:30.190 Received on socket: Range: bytes=6430556160-18658646015
[New I/O server worker #1-5] TRACE 18:41:30.190 Received on socket: transferMode.dlna.org: Streaming
[New I/O server worker #1-5] TRACE 18:41:30.190 Received on socket: User-Agent: PLAYSTATION 3
[New I/O server worker #1-5] TRACE 18:41:30.190 Recognized media renderer Playstation 3
[New I/O server worker #1-5] TRACE 18:41:30.190 HTTP: get/0$0$1/Avatar_1080_AC3_no_subs.m2ts / 6430556160-18658646015
[New I/O server worker #1-5] TRACE 18:41:30.190 Searching for objectId: 0$0$1 with children option: false
[New I/O server worker #1-5] TRACE 18:41:30.190 Asked stream chunk [6430556160-18658646015] timeseek: 0.0 of Avatar_1080_AC3_no_subs.m2ts and player null
[New I/O server worker #1-5] TRACE 18:41:30.191 Sent to socket: Accept-Ranges: bytes
[New I/O server worker #1-5] TRACE 18:41:30.191 Sent to socket: Connection: keep-alive
[New I/O server worker #1-5] TRACE 18:41:30.191 Sent to socket: Content-Length: 12228089856
[New I/O server worker #1-5] TRACE 18:41:30.192 Sent to socket: Content-Range: bytes 6430556160-18658646015/18658646016
[New I/O server worker #1-5] TRACE 18:41:30.192 Sent to socket: Content-Type: video/mpeg
[New I/O server worker #1-5] TRACE 18:41:30.192 Sent to socket: Server: Mac_OS_X-x86_64-10.7.1, UPnP/1.0, PMS/1.31.0
[New I/O server worker #1-5] TRACE 18:41:30.192 Sent to socket: TransferMode.DLNA.ORG: Streaming
[Thread-20] TRACE 18:41:36.015 Receiving a M-SEARCH from [192.168.1.114:57551]
[Thread-20] TRACE 18:41:36.015 Sending this reply [192.168.1.114:57551]: HTTP/1.1 200 OK<CRLF>CACHE-CONTROL: max-age=1200<CRLF>DATE: Wed, 17 Aug 2011 17:41:36 GMT<CRLF>LOCATION: http://192.168.1.5:5001/description/fetch<CRLF>SERVER: Mac_OS_X-x86_64-10.7.1, UPnP/1.0, PMS/1.31.0<CRLF>ST: upnp:rootdevice<CRLF>EXT: <CRLF>USN: uuid:0d7ad94c-92de-3cf0-9b4c-00cb790a1803::upnp:rootdevice<CRLF>Content-Length: 0<CRLF><CRLF>
[New I/O server boss #1 ([id: 0x23087d61, /192.168.1.5:5001])] TRACE 18:41:36.431 Creating new pipeline
[New I/O server worker #1-6] TRACE 18:41:36.432 Opened request handler on socket /192.168.1.30:57569 // Playstation 3
[New I/O server worker #1-6] TRACE 18:41:36.432 Request: HTTP/1.1 : GET : get/0$0$1/thumbnail0000Avatar_1080_AC3_no_subs.m2ts
[New I/O server worker #1-6] TRACE 18:41:36.432 Received on socket: Accept-Encoding: identity
[New I/O server worker #1-6] TRACE 18:41:36.432 Received on socket: Connection: Keep-Alive
[New I/O server worker #1-6] TRACE 18:41:36.432 Received on socket: Host: 192.168.1.5:5001
[New I/O server worker #1-6] TRACE 18:41:36.432 Received on socket: transferMode.dlna.org: Interactive
[New I/O server worker #1-6] TRACE 18:41:36.432 Received on socket: User-Agent: PLAYSTATION 3
[New I/O server worker #1-6] TRACE 18:41:36.432 Recognized media renderer Playstation 3
[New I/O server worker #1-6] TRACE 18:41:36.433 HTTP: get/0$0$1/thumbnail0000Avatar_1080_AC3_no_subs.m2ts / 0-0
[New I/O server worker #1-6] TRACE 18:41:36.433 Searching for objectId: 0$0$1 with children option: false
[New I/O server worker #1-6] TRACE 18:41:36.433 Available Content-Length: 660
[New I/O server worker #1-6] TRACE 18:41:36.434 Sent to socket: Accept-Ranges: bytes
[New I/O server worker #1-6] TRACE 18:41:36.434 Sent to socket: Connection: keep-alive
[New I/O server worker #1-6] TRACE 18:41:36.434 Sent to socket: Content-Length: 660
[New I/O server worker #1-6] TRACE 18:41:36.434 Sent to socket: Content-Type: image/jpeg
[New I/O server worker #1-6] TRACE 18:41:36.434 Sent to socket: Expires: Sun, 11 Dec 2011 11:28:16 GMT
[New I/O server worker #1-6] TRACE 18:41:36.434 Sent to socket: Server: Mac_OS_X-x86_64-10.7.1, UPnP/1.0, PMS/1.31.0
[New I/O server worker #1-6] TRACE 18:41:36.434 Sent to socket: TransferMode.DLNA.ORG: Interactive
[Thread-37] TRACE 18:41:40.213 StartStopListener: event:    stop
[Thread-37] TRACE 18:41:40.214 StartStopListener: renderer: 192.168.1.30
[Thread-37] TRACE 18:41:40.214 StartStopListener: file:     /Volumes/Macintosh HD 2/Temporary Files/Avatar_1080_AC3_no_subs.m2ts
[Thread-37] TRACE 18:41:40.214 StartStopListener:
[New I/O server boss #1 ([id: 0x23087d61, /192.168.1.5:5001])] TRACE 18:41:41.982 Creating new pipeline
[New I/O server worker #1-7] TRACE 18:41:41.982 Opened request handler on socket /192.168.1.30:57568 // Playstation 3
[New I/O server worker #1-7] TRACE 18:41:41.983 Request: HTTP/1.0 : HEAD : get/0$0$3/Avatar_1080_AC3_subs.m2ts
[New I/O server worker #1-7] TRACE 18:41:41.983 Received on socket: Accept-Encoding: identity
[New I/O server worker #1-7] TRACE 18:41:41.983 Received on socket: Cache-Control: no-cache
[New I/O server worker #1-7] TRACE 18:41:41.983 Received on socket: Connection: close
[New I/O server worker #1-7] TRACE 18:41:41.983 Received on socket: Host: 192.168.1.5:5001
[New I/O server worker #1-7] TRACE 18:41:41.983 Received on socket: User-Agent: PLAYSTATION 3
[New I/O server worker #1-7] TRACE 18:41:41.983 Recognized media renderer Playstation 3
[New I/O server worker #1-7] TRACE 18:41:41.983 HTTP: get/0$0$3/Avatar_1080_AC3_subs.m2ts / 0-0
[New I/O server worker #1-7] TRACE 18:41:41.983 Searching for objectId: 0$0$3 with children option: false
[New I/O server worker #1-7] TRACE 18:41:41.983 Asked stream chunk [0-0] timeseek: 0.0 of Avatar_1080_AC3_subs.m2ts and player MEncoder
[New I/O server worker #1-7] INFO  18:41:41.983 Starting transcode/remux of Avatar_1080_AC3_subs.m2ts
[New I/O server worker #1-7] TRACE 18:41:41.984 Looking for an audio track with lang: eng
[New I/O server worker #1-7] TRACE 18:41:41.989 Matched audio track: Audio: AC3 / lang: en / ID: 4352
[mkfifo] DEBUG 18:41:42.033 Starting mkfifo -m 777 /var/folders/q_/_j884m4173767mn4d63bjgzh0000gn/T/ps3mediaserver/1313602902032tsmuxerout.ts
[mkfifo] DEBUG 18:41:42.046 Unix process ID (mkfifo): 7050
[mkfifo] DEBUG 18:41:42.084 Starting mkfifo -m 777 /var/folders/q_/_j884m4173767mn4d63bjgzh0000gn/T/ps3mediaserver/1313602902031ffmpegvideo
[mkfifo] DEBUG 18:41:42.084 Starting mkfifo -m 777 /var/folders/q_/_j884m4173767mn4d63bjgzh0000gn/T/ps3mediaserver/1313602902031videoout
[mkfifo] DEBUG 18:41:42.105 Unix process ID (mkfifo): 7052
[mkfifo] DEBUG 18:41:42.105 Unix process ID (mkfifo): 7051
[Thread-38] TRACE 18:41:42.235 Opening file /var/folders/q_/_j884m4173767mn4d63bjgzh0000gn/T/ps3mediaserver/1313602902031ffmpegvideo for reading...
[osx/mencoder] DEBUG 18:41:42.286 Starting /Applications/PS3 Media Server.app/Contents/Resources/Java/osx/mencoder -ss 0 /Volumes/Macintosh HD 2/Temporary Files/Avatar_1080_AC3_subs.m2ts -quiet -quiet -really-quiet -msglevel statusline=2 -ovc copy -nosound -mc 0 -noskip -of rawvideo -o /var/folders/q_/_j884m4173767mn4d63bjgzh0000gn/T/ps3mediaserver/1313602902031ffmpegvideo
[osx/mencoder] DEBUG 18:41:42.301 Should allocate 22562515 bytes realistically, forcing allocation of 50500000 bytes instead.
[osx/mencoder] DEBUG 18:41:42.303 Attaching thread: osx/mencoder
[osx/mencoder] DEBUG 18:41:42.303 Unix process ID (/Applications/PS3 Media Server.app/Contents/Resources/Java/osx/mencoder): 7053
[mkfifo] DEBUG 18:41:42.338 Starting mkfifo -m 777 /var/folders/q_/_j884m4173767mn4d63bjgzh0000gn/T/ps3mediaserver/1313602902031ffmpegaudio01
[New I/O server boss #1 ([id: 0x23087d61, /192.168.1.5:5001])] TRACE 18:41:42.350 Creating new pipeline
[mkfifo] DEBUG 18:41:42.351 Starting mkfifo -m 777 /var/folders/q_/_j884m4173767mn4d63bjgzh0000gn/T/ps3mediaserver/1313602902031audioout
[mkfifo] DEBUG 18:41:42.364 Unix process ID (mkfifo): 7055
[mkfifo] DEBUG 18:41:42.364 Unix process ID (mkfifo): 7056
[New I/O server worker #1-8] TRACE 18:41:42.365 Opened request handler on socket /192.168.1.114:56271 // WMP
[New I/O server worker #1-8] TRACE 18:41:42.365 Request: HTTP/1.1 : GET : description/fetch
[New I/O server worker #1-8] TRACE 18:41:42.366 Received on socket: Accept: text/xml, application/xml
[New I/O server worker #1-8] TRACE 18:41:42.366 Received on socket: Cache-Control: no-cache
[New I/O server worker #1-8] TRACE 18:41:42.366 Received on socket: Connection: Keep-Alive
[New I/O server worker #1-8] TRACE 18:41:42.366 Received on socket: Host: 192.168.1.5
[New I/O server worker #1-8] TRACE 18:41:42.366 Received on socket: Pragma: no-cache
[New I/O server worker #1-8] TRACE 18:41:42.366 Received on socket: User-Agent: Mozilla/4.0 (compatible; UPnP/1.0; Windows NT/5.1)
[New I/O server worker #1-8] TRACE 18:41:42.367 Recognized media renderer WMP
[New I/O server worker #1-8] TRACE 18:41:42.367 HTTP: description/fetch / 0-0
[New I/O server worker #1-8] TRACE 18:41:42.368 Sent to socket: Accept-Ranges: bytes
[New I/O server worker #1-8] TRACE 18:41:42.369 Sent to socket: Cache-Control: no-cache
[New I/O server worker #1-8] TRACE 18:41:42.369 Sent to socket: Connection: keep-alive
[New I/O server worker #1-8] TRACE 18:41:42.369 Sent to socket: Content-Length: 2004
[New I/O server worker #1-8] TRACE 18:41:42.369 Sent to socket: Content-Type: text/xml; charset="utf-8"
[New I/O server worker #1-8] TRACE 18:41:42.369 Sent to socket: Expires: 0
[New I/O server worker #1-8] TRACE 18:41:42.369 Sent to socket: Server: Mac_OS_X-x86_64-10.7.1, UPnP/1.0, PMS/1.31.0
[Thread-38] TRACE 18:41:42.377 Opening file /var/folders/q_/_j884m4173767mn4d63bjgzh0000gn/T/ps3mediaserver/1313602902031videoout for writing...
[Thread-39] TRACE 18:41:42.503 Opening file /var/folders/q_/_j884m4173767mn4d63bjgzh0000gn/T/ps3mediaserver/1313602902031ffmpegaudio01 for reading...
[osx/mencoder] DEBUG 18:41:42.553 Starting /Applications/PS3 Media Server.app/Contents/Resources/Java/osx/mencoder -ss 0 /Volumes/Macintosh HD 2/Temporary Files/Avatar_1080_AC3_subs.m2ts -quiet -quiet -really-quiet -msglevel statusline=2 -channels 6 -ovc copy -of rawaudio -mc 0 -noskip -oac copy -fafmttag 0x2000 -lavcopts acodec=ac3:abitrate=640 -af lavcresample=48000 -srate 48000 -quiet -quiet -o /var/folders/q_/_j884m4173767mn4d63bjgzh0000gn/T/ps3mediaserver/1313602902031ffmpegaudio01
[osx/mencoder] DEBUG 18:41:42.566 Should allocate 21696532 bytes realistically, forcing allocation of 50500000 bytes instead.
[osx/mencoder] DEBUG 18:41:42.567 Attaching thread: osx/mencoder
[osx/mencoder] DEBUG 18:41:42.568 Unix process ID (/Applications/PS3 Media Server.app/Contents/Resources/Java/osx/mencoder): 7057
[Thread-39] TRACE 18:41:42.602 Opening file /var/folders/q_/_j884m4173767mn4d63bjgzh0000gn/T/ps3mediaserver/1313602902031audioout for writing...
[New I/O server worker #1-7] TRACE 18:41:42.655 Sleeping for 5000 milliseconds
[osx/tsMuxeR] DEBUG 18:41:42.655 Starting /Applications/PS3 Media Server.app/Contents/Resources/Java/osx/tsMuxeR /var/folders/q_/_j884m4173767mn4d63bjgzh0000gn/T/ps3mediaserver/pms-tsmuxer.meta /var/folders/q_/_j884m4173767mn4d63bjgzh0000gn/T/ps3mediaserver/1313602902032tsmuxerout.ts
[osx/tsMuxeR] DEBUG 18:41:42.667 Reading pipe: /var/folders/q_/_j884m4173767mn4d63bjgzh0000gn/T/ps3mediaserver/1313602902032tsmuxerout.ts
[osx/tsMuxeR] TRACE 18:41:42.668 Opening file /var/folders/q_/_j884m4173767mn4d63bjgzh0000gn/T/ps3mediaserver/1313602902032tsmuxerout.ts for reading...
[osx/tsMuxeR] DEBUG 18:41:42.685 Should allocate 21169615 bytes realistically, forcing allocation of 50500000 bytes instead.
[osx/tsMuxeR] DEBUG 18:41:42.686 Not enough memory to allocate 104857600 bytes, using 50500000 bytes instead.
[osx/tsMuxeR] DEBUG 18:41:42.712 Attaching thread: osx/tsMuxeR
[Timer-2] TRACE 18:41:42.712 buffered: 0 bytes / inputs: 0
[osx/tsMuxeR] DEBUG 18:41:42.713 Unix process ID (/Applications/PS3 Media Server.app/Contents/Resources/Java/osx/tsMuxeR): 7058
[Thread-59] TRACE 18:41:42.713 SmartLabs tsMuxeR.  Version 1.10.6  http://www.smlabs.net
[Thread-59] TRACE 18:41:42.713 Decoding H264 stream (track 1): Profile: High@4.0  Resolution: 1920:1080p  Frame rate: 23.976
[Thread-59] TRACE 18:41:42.713 Change H264 level from 4 to 4.1
[Thread-59] TRACE 18:41:42.714 H.264 stream does not contain fps field. Muxing fps=23.976
[Thread-59] TRACE 18:41:42.714 100.0% complete
[Thread-59] TRACE 18:41:42.714 H264 bitstream changed: insert nal unit delimiters
[Thread-59] TRACE 18:41:42.714 Decoding AC3 stream (track 2): Bitrate: 640Kbps Sample Rate: 48KHz Channels: 6
[Thread-59] TRACE 18:41:42.975 100.0% complete
[Thread-59] TRACE 18:41:43.238 M100.0% complete
[Thread-59] TRACE 18:41:43.488 M100.0% complete
[Thread-59] TRACE 18:41:43.786 M100.0% complete
[Thread-59] TRACE 18:41:44.045 M100.0% complete
[Thread-59] TRACE 18:41:44.299 M100.0% complete
[Thread-59] TRACE 18:41:44.549 M100.0% complete
[Timer-2] TRACE 18:41:44.713 buffered: 30,507,008 bytes / inputs: 0
[Timer-2] TRACE 18:41:46.713 buffered: 30,507,008 bytes / inputs: 0
[New I/O server worker #1-7] TRACE 18:41:47.656 Finished sleeping for 5000 milliseconds
[Thread-60] TRACE 18:41:47.657 StartStopListener: event:    start
[Thread-60] TRACE 18:41:47.657 StartStopListener: renderer: 192.168.1.30
[Thread-60] TRACE 18:41:47.657 StartStopListener: file:     /Volumes/Macintosh HD 2/Temporary Files/Avatar_1080_AC3_subs.m2ts
[Thread-60] TRACE 18:41:47.657 StartStopListener:
[New I/O server worker #1-7] TRACE 18:41:47.659 Ready to Stop: true
[New I/O server worker #1-7] TRACE 18:41:47.660 Sent to socket: Accept-Ranges: bytes
[New I/O server worker #1-7] TRACE 18:41:47.660 Sent to socket: Connection: keep-alive
[New I/O server worker #1-7] TRACE 18:41:47.660 Sent to socket: Content-Type: video/mpeg
[New I/O server worker #1-7] TRACE 18:41:47.660 Sent to socket: Server: Mac_OS_X-x86_64-10.7.1, UPnP/1.0, PMS/1.31.0
[New I/O server boss #1 ([id: 0x23087d61, /192.168.1.5:5001])] TRACE 18:41:47.661 Creating new pipeline
[New I/O server worker #1-9] TRACE 18:41:47.662 Opened request handler on socket /192.168.1.30:57567 // Playstation 3
[New I/O server worker #1-9] TRACE 18:41:47.662 Request: HTTP/1.0 : GET : get/0$0$3/Avatar_1080_AC3_subs.m2ts
[New I/O server worker #1-9] TRACE 18:41:47.662 Received on socket: Accept-Encoding: identity
[New I/O server worker #1-9] TRACE 18:41:47.663 Received on socket: Cache-Control: no-cache
[New I/O server worker #1-9] TRACE 18:41:47.663 Received on socket: Connection: close
[New I/O server worker #1-9] TRACE 18:41:47.663 Received on socket: Host: 192.168.1.5:5001
[New I/O server worker #1-9] TRACE 18:41:47.663 Received on socket: User-Agent: PLAYSTATION 3
[New I/O server worker #1-9] TRACE 18:41:47.663 Recognized media renderer Playstation 3
[New I/O server worker #1-9] TRACE 18:41:47.663 HTTP: get/0$0$3/Avatar_1080_AC3_subs.m2ts / 0-0
[New I/O server worker #1-9] TRACE 18:41:47.663 Searching for objectId: 0$0$3 with children option: false
[New I/O server worker #1-9] TRACE 18:41:47.664 Asked stream chunk [0-0] timeseek: 0.0 of Avatar_1080_AC3_subs.m2ts and player MEncoder
[New I/O server worker #1-9] TRACE 18:41:47.664 Ready to Stop: false
[New I/O server worker #1-9] TRACE 18:41:47.667 Sent to socket: Accept-Ranges: bytes
[New I/O server worker #1-9] TRACE 18:41:47.667 Sent to socket: Connection: keep-alive
[New I/O server worker #1-9] TRACE 18:41:47.667 Sent to socket: Content-Type: video/mpeg
[New I/O server worker #1-9] TRACE 18:41:47.667 Sent to socket: Server: Mac_OS_X-x86_64-10.7.1, UPnP/1.0, PMS/1.31.0
[New I/O server worker #1-9] TRACE 18:41:47.667 Ready to Stop: true
[New I/O server boss #1 ([id: 0x23087d61, /192.168.1.5:5001])] TRACE 18:41:47.669 Creating new pipeline
[New I/O server worker #1-10] TRACE 18:41:47.670 Opened request handler on socket /192.168.1.30:57566 // Playstation 3
[New I/O server worker #1-10] TRACE 18:41:47.670 Request: HTTP/1.1 : GET : get/0$0$3/Avatar_1080_AC3_subs.m2ts
[New I/O server worker #1-10] TRACE 18:41:47.670 Received on socket: Accept-Encoding: identity
[New I/O server worker #1-10] TRACE 18:41:47.670 Received on socket: Connection: Keep-Alive
[New I/O server worker #1-10] TRACE 18:41:47.670 Received on socket: Host: 192.168.1.5:5001
[New I/O server worker #1-10] TRACE 18:41:47.670 Received on socket: TimeSeekRange.dlna.org: npt=0.000-
[New I/O server worker #1-10] TRACE 18:41:47.671 Received on socket: transferMode.dlna.org: Streaming
[New I/O server worker #1-10] TRACE 18:41:47.671 Received on socket: User-Agent: PLAYSTATION 3
[New I/O server worker #1-10] TRACE 18:41:47.671 Recognized media renderer Playstation 3
[New I/O server worker #1-10] TRACE 18:41:47.671 HTTP: get/0$0$3/Avatar_1080_AC3_subs.m2ts / 0-0
[New I/O server worker #1-10] TRACE 18:41:47.671 Searching for objectId: 0$0$3 with children option: false
[New I/O server worker #1-10] TRACE 18:41:47.671 Asked stream chunk [0-0] timeseek: 0.0 of Avatar_1080_AC3_subs.m2ts and player MEncoder
[New I/O server worker #1-10] TRACE 18:41:47.672 Ready to Stop: false
[New I/O server worker #1-10] TRACE 18:41:47.673 Sent to socket: Accept-Ranges: bytes
[New I/O server worker #1-10] TRACE 18:41:47.673 Sent to socket: Connection: keep-alive
[New I/O server worker #1-10] TRACE 18:41:47.673 Sent to socket: Content-Type: video/mpeg
[New I/O server worker #1-10] TRACE 18:41:47.673 Sent to socket: Server: Mac_OS_X-x86_64-10.7.1, UPnP/1.0, PMS/1.31.0
[New I/O server worker #1-10] TRACE 18:41:47.674 Sent to socket: TransferMode.DLNA.ORG: Streaming
[Thread-59] TRACE 18:41:47.746 M100.0% complete
[Timer-2] TRACE 18:41:48.715 buffered: 30,507,007 bytes / inputs: 1
[New I/O server worker #1-10] TRACE 18:41:49.561 Ready to Stop: true
[New I/O server boss #1 ([id: 0x23087d61, /192.168.1.5:5001])] TRACE 18:41:49.562 Creating new pipeline
[New I/O server worker #1-11] TRACE 18:41:49.563 Opened request handler on socket /192.168.1.30:57565 // Playstation 3
[New I/O server worker #1-11] TRACE 18:41:49.563 Request: HTTP/1.1 : GET : get/0$0$3/Avatar_1080_AC3_subs.m2ts
[New I/O server worker #1-11] TRACE 18:41:49.563 Received on socket: Accept-Encoding: identity
[New I/O server worker #1-11] TRACE 18:41:49.563 Received on socket: Connection: Keep-Alive
[New I/O server worker #1-11] TRACE 18:41:49.563 Received on socket: Host: 192.168.1.5:5001
[New I/O server worker #1-11] TRACE 18:41:49.563 Received on socket: TimeSeekRange.dlna.org: npt=0.000-
[New I/O server worker #1-11] TRACE 18:41:49.563 Received on socket: transferMode.dlna.org: Streaming
[New I/O server worker #1-11] TRACE 18:41:49.564 Received on socket: User-Agent: PLAYSTATION 3
[New I/O server worker #1-11] TRACE 18:41:49.564 Recognized media renderer Playstation 3
[New I/O server worker #1-11] TRACE 18:41:49.564 HTTP: get/0$0$3/Avatar_1080_AC3_subs.m2ts / 0-0
[New I/O server worker #1-11] TRACE 18:41:49.564 Searching for objectId: 0$0$3 with children option: false
[New I/O server worker #1-11] TRACE 18:41:49.564 Asked stream chunk [0-0] timeseek: 0.0 of Avatar_1080_AC3_subs.m2ts and player MEncoder
[New I/O server worker #1-11] TRACE 18:41:49.564 Ready to Stop: false
[New I/O server worker #1-11] TRACE 18:41:49.566 Sent to socket: Accept-Ranges: bytes
[New I/O server worker #1-11] TRACE 18:41:49.566 Sent to socket: Connection: keep-alive
[New I/O server worker #1-11] TRACE 18:41:49.566 Sent to socket: Content-Type: video/mpeg
[New I/O server worker #1-11] TRACE 18:41:49.566 Sent to socket: Server: Mac_OS_X-x86_64-10.7.1, UPnP/1.0, PMS/1.31.0
[New I/O server worker #1-11] TRACE 18:41:49.566 Sent to socket: TransferMode.DLNA.ORG: Streaming
[Thread-59] TRACE 18:41:49.842 M100.0% complete
[Thread-59] TRACE 18:41:50.095 M100.0% complete
[Thread-59] TRACE 18:41:50.662 M100.0% complete
[Timer-2] TRACE 18:41:50.715 buffered: 30,507,007 bytes / inputs: 1
[Thread-59] TRACE 18:41:51.728 M100.0% complete
[Timer-2] TRACE 18:41:52.716 buffered: 29,442,047 bytes / inputs: 1
[Thread-59] TRACE 18:41:52.793 M100.0% complete
[Thread-59] TRACE 18:41:53.356 M100.0% complete
[Thread-59] TRACE 18:41:54.423 M100.0% complete
[Timer-2] TRACE 18:41:54.718 buffered: 30,507,007 bytes / inputs: 1
[Thread-59] TRACE 18:41:55.507 M100.0% complete
[Thread-59] TRACE 18:41:56.633 M100.0% complete
[Timer-2] TRACE 18:41:56.720 buffered: 30,507,007 bytes / inputs: 1
[Thread-59] TRACE 18:41:58.199 M100.0% complete
[New I/O server boss #1 ([id: 0x23087d61, /192.168.1.5:5001])] TRACE 18:41:58.335 Creating new pipeline
[New I/O server worker #1-11] TRACE 18:41:58.335 Ready to Stop: true
[New I/O server worker #1-12] TRACE 18:41:58.336 Opened request handler on socket /192.168.1.30:57564 // Playstation 3
[New I/O server worker #1-12] TRACE 18:41:58.336 Request: HTTP/1.1 : GET : get/0$0$3/Avatar_1080_AC3_subs.m2ts
[New I/O server worker #1-12] TRACE 18:41:58.336 Received on socket: Accept-Encoding: identity
[New I/O server worker #1-12] TRACE 18:41:58.336 Received on socket: Connection: Keep-Alive
[New I/O server worker #1-12] TRACE 18:41:58.336 Received on socket: Host: 192.168.1.5:5001
[New I/O server worker #1-12] TRACE 18:41:58.336 Received on socket: TimeSeekRange.dlna.org: npt=3600.000-
[New I/O server worker #1-12] TRACE 18:41:58.337 Received on socket: transferMode.dlna.org: Streaming
[New I/O server worker #1-12] TRACE 18:41:58.337 Received on socket: User-Agent: PLAYSTATION 3
[New I/O server worker #1-12] TRACE 18:41:58.337 Recognized media renderer Playstation 3
[New I/O server worker #1-12] TRACE 18:41:58.337 HTTP: get/0$0$3/Avatar_1080_AC3_subs.m2ts / 0-0
[New I/O server worker #1-12] TRACE 18:41:58.337 Searching for objectId: 0$0$3 with children option: false
[New I/O server worker #1-12] TRACE 18:41:58.337 Asked stream chunk [0-0] timeseek: 3600.0 of Avatar_1080_AC3_subs.m2ts and player MEncoder
[New I/O server worker #1-12] DEBUG 18:41:58.337 Requesting time seek: 3600.0 seconds
[New I/O server worker #1-12] TRACE 18:41:58.338 Looking for an audio track with lang: eng
[Thread-75] DEBUG 18:41:58.338 Stopping Unix process 7058: osx/tsMuxeR
[Thread-75] TRACE 18:41:58.338 Killing the Unix process: 7058
[Thread-75] DEBUG 18:41:58.339 Stopping Unix process 7050: mkfifo
[New I/O server worker #1-12] TRACE 18:41:58.339 Matched audio track: Audio: AC3 / lang: en / ID: 4352
[Thread-75] TRACE 18:41:58.339 Killing the Unix process: 7050
[Thread-75] DEBUG 18:41:58.341 Stopping Unix process 7053: osx/mencoder
[Thread-75] TRACE 18:41:58.341 Killing the Unix process: 7053
[Thread-75] TRACE 18:41:58.341 Destroying buffer
[Thread-75] DEBUG 18:41:58.342 Stopping Unix process 7057: osx/mencoder
[Thread-75] TRACE 18:41:58.342 Killing the Unix process: 7057
[Thread-75] TRACE 18:41:58.342 Destroying buffer
[Thread-75] TRACE 18:41:58.342 Destroying buffer
[mkfifo] DEBUG 18:41:58.348 Starting mkfifo -m 777 /var/folders/q_/_j884m4173767mn4d63bjgzh0000gn/T/ps3mediaserver/1313602918348tsmuxerout.ts
[mkfifo] DEBUG 18:41:58.379 Unix process ID (mkfifo): 7059
[mkfifo] DEBUG 18:41:58.399 Starting mkfifo -m 777 /var/folders/q_/_j884m4173767mn4d63bjgzh0000gn/T/ps3mediaserver/1313602918347ffmpegvideo
[mkfifo] DEBUG 18:41:58.399 Starting mkfifo -m 777 /var/folders/q_/_j884m4173767mn4d63bjgzh0000gn/T/ps3mediaserver/1313602918347videoout
[mkfifo] DEBUG 18:41:58.430 Unix process ID (mkfifo): 7060
[mkfifo] DEBUG 18:41:58.431 Unix process ID (mkfifo): 7061
[Thread-80] TRACE 18:41:58.551 Opening file /var/folders/q_/_j884m4173767mn4d63bjgzh0000gn/T/ps3mediaserver/1313602918347ffmpegvideo for reading...
[osx/mencoder] DEBUG 18:41:58.601 Starting /Applications/PS3 Media Server.app/Contents/Resources/Java/osx/mencoder -ss 3600.0 /Volumes/Macintosh HD 2/Temporary Files/Avatar_1080_AC3_subs.m2ts -quiet -quiet -really-quiet -msglevel statusline=2 -ovc copy -nosound -mc 0 -noskip -of rawvideo -o /var/folders/q_/_j884m4173767mn4d63bjgzh0000gn/T/ps3mediaserver/1313602918347ffmpegvideo
[osx/mencoder] DEBUG 18:41:58.615 Should allocate 13339720 bytes realistically, forcing allocation of 50500000 bytes instead.
[osx/mencoder] DEBUG 18:41:58.616 Attaching thread: osx/mencoder
[osx/mencoder] DEBUG 18:41:58.617 Unix process ID (/Applications/PS3 Media Server.app/Contents/Resources/Java/osx/mencoder): 7062
[Thread-80] TRACE 18:41:58.635 Opening file /var/folders/q_/_j884m4173767mn4d63bjgzh0000gn/T/ps3mediaserver/1313602918347videoout for writing...
[mkfifo] DEBUG 18:41:58.652 Starting mkfifo -m 777 /var/folders/q_/_j884m4173767mn4d63bjgzh0000gn/T/ps3mediaserver/1313602918347ffmpegaudio01
[mkfifo] DEBUG 18:41:58.653 Starting mkfifo -m 777 /var/folders/q_/_j884m4173767mn4d63bjgzh0000gn/T/ps3mediaserver/1313602918347audioout
[mkfifo] DEBUG 18:41:58.685 Unix process ID (mkfifo): 7064
[mkfifo] DEBUG 18:41:58.688 Unix process ID (mkfifo): 7063
[Thread-81] TRACE 18:41:58.804 Opening file /var/folders/q_/_j884m4173767mn4d63bjgzh0000gn/T/ps3mediaserver/1313602918347ffmpegaudio01 for reading...
[osx/mencoder] DEBUG 18:41:58.855 Starting /Applications/PS3 Media Server.app/Contents/Resources/Java/osx/mencoder -ss 3600.0 /Volumes/Macintosh HD 2/Temporary Files/Avatar_1080_AC3_subs.m2ts -quiet -quiet -really-quiet -msglevel statusline=2 -channels 6 -ovc copy -of rawaudio -mc 0 -noskip -oac copy -fafmttag 0x2000 -lavcopts acodec=ac3:abitrate=640 -af lavcresample=48000 -srate 48000 -quiet -quiet -o /var/folders/q_/_j884m4173767mn4d63bjgzh0000gn/T/ps3mediaserver/1313602918347ffmpegaudio01
[osx/mencoder] DEBUG 18:41:58.873 Should allocate 12580392 bytes realistically, forcing allocation of 50500000 bytes instead.
[osx/mencoder] DEBUG 18:41:58.874 Attaching thread: osx/mencoder
[osx/mencoder] DEBUG 18:41:58.875 Unix process ID (/Applications/PS3 Media Server.app/Contents/Resources/Java/osx/mencoder): 7065
[Thread-81] TRACE 18:41:58.892 Opening file /var/folders/q_/_j884m4173767mn4d63bjgzh0000gn/T/ps3mediaserver/1313602918347audioout for writing...
[osx/tsMuxeR] DEBUG 18:41:58.956 Starting /Applications/PS3 Media Server.app/Contents/Resources/Java/osx/tsMuxeR /var/folders/q_/_j884m4173767mn4d63bjgzh0000gn/T/ps3mediaserver/pms-tsmuxer.meta /var/folders/q_/_j884m4173767mn4d63bjgzh0000gn/T/ps3mediaserver/1313602918348tsmuxerout.ts
[osx/tsMuxeR] DEBUG 18:41:58.973 Reading pipe: /var/folders/q_/_j884m4173767mn4d63bjgzh0000gn/T/ps3mediaserver/1313602918348tsmuxerout.ts
[osx/tsMuxeR] TRACE 18:41:58.974 Opening file /var/folders/q_/_j884m4173767mn4d63bjgzh0000gn/T/ps3mediaserver/1313602918348tsmuxerout.ts for reading...
[osx/tsMuxeR] DEBUG 18:41:58.983 Should allocate 12078528 bytes realistically, forcing allocation of 50500000 bytes instead.
[osx/tsMuxeR] DEBUG 18:41:58.983 Not enough memory to allocate 104857600 bytes, using 50500000 bytes instead.
[osx/tsMuxeR] DEBUG 18:41:59.137 Attaching thread: osx/tsMuxeR
[Timer-5] TRACE 18:41:59.137 buffered: 0 bytes / inputs: 0
[osx/tsMuxeR] DEBUG 18:41:59.137 Unix process ID (/Applications/PS3 Media Server.app/Contents/Resources/Java/osx/tsMuxeR): 7066
[Thread-101] TRACE 18:41:59.137 SmartLabs tsMuxeR.  Version 1.10.6  http://www.smlabs.net
[Thread-101] TRACE 18:41:59.137 Decoding H264 stream (track 1): Profile: High@4.0  Resolution: 1920:1080p  Frame rate: 23.976
[Thread-101] TRACE 18:41:59.138 Change H264 level from 4 to 4.1
[Thread-101] TRACE 18:41:59.138 H.264 stream does not contain fps field. Muxing fps=23.976
[Thread-101] TRACE 18:41:59.138 100.0% complete
[Thread-101] TRACE 18:41:59.138 H264 bitstream changed: insert nal unit delimiters
[Thread-101] TRACE 18:41:59.138 Decoding AC3 stream (track 2): Bitrate: 640Kbps Sample Rate: 48KHz Channels: 6
[Thread-101] TRACE 18:41:59.277 100.0% complete
[osx/tsMuxeR] TRACE 18:41:59.342 EOF
[Thread-101] TRACE 18:41:59.530 M100.0% complete
[Thread-101] TRACE 18:41:59.780 M100.0% complete
[New I/O server worker #1-12] TRACE 18:41:59.958 Suspend Read: readCount=0 / writeCount=12779520
[Thread-101] TRACE 18:42:00.030 M100.0% complete
[Thread-101] TRACE 18:42:00.283 M100.0% complete
[Thread-101] TRACE 18:42:00.540 M100.0% complete
[Thread-20] TRACE 18:42:00.548 Receiving a M-SEARCH from [192.168.1.114:60685]
[Thread-101] TRACE 18:42:00.801 M100.0% complete
[New I/O server worker #1-12] TRACE 18:42:00.961 Resume Read: readCount=0 / writeCount=28508160
[New I/O server worker #1-12] TRACE 18:42:00.962 Sent to socket: Accept-Ranges: bytes
[New I/O server worker #1-12] TRACE 18:42:00.962 Sent to socket: Connection: keep-alive
[New I/O server worker #1-12] TRACE 18:42:00.962 Sent to socket: Content-Type: video/mpeg
[New I/O server worker #1-12] TRACE 18:42:00.962 Sent to socket: Server: Mac_OS_X-x86_64-10.7.1, UPnP/1.0, PMS/1.31.0
[New I/O server worker #1-12] TRACE 18:42:00.962 Sent to socket: TimeSeekRange.dlna.org: npt=01:00:00.00-02:41:41.00/02:41:41.00
[New I/O server worker #1-12] TRACE 18:42:00.962 Sent to socket: TransferMode.DLNA.ORG: Streaming
[New I/O server worker #1-12] TRACE 18:42:00.962 Sent to socket: X-Seek-Range: npt=01:00:00.00-02:41:41.00/02:41:41.00
[Thread-101] TRACE 18:42:01.060 M100.0% complete
[Timer-5] TRACE 18:42:01.138 buffered: 28,246,015 bytes / inputs: 1
[Thread-101] TRACE 18:42:01.321 M100.0% complete
[Thread-101] TRACE 18:42:01.577 M100.0% complete
[Thread-101] TRACE 18:42:02.200 M100.0% complete
[Timer-5] TRACE 18:42:03.139 buffered: 30,507,007 bytes / inputs: 1
[Thread-20] TRACE 18:42:03.549 Receiving a M-SEARCH from [192.168.1.114:60685]
[Thread-101] TRACE 18:42:04.772 M100.0% complete
[Timer-5] TRACE 18:42:05.140 buffered: 30,220,287 bytes / inputs: 1
[Thread-101] TRACE 18:42:05.838 M100.0% complete
[New I/O server worker #1-12] TRACE 18:42:06.192 Ready to Stop: true
[New I/O server boss #1 ([id: 0x23087d61, /192.168.1.5:5001])] TRACE 18:42:06.395 Creating new pipeline
[New I/O server worker #1-13] TRACE 18:42:06.395 Opened request handler on socket /192.168.1.30:57563 // Playstation 3
[New I/O server worker #1-13] TRACE 18:42:06.395 Request: HTTP/1.1 : GET : get/0$0$3/thumbnail0000Avatar_1080_AC3_subs.m2ts
[New I/O server worker #1-13] TRACE 18:42:06.395 Received on socket: Accept-Encoding: identity
[New I/O server worker #1-13] TRACE 18:42:06.395 Received on socket: Connection: Keep-Alive
[New I/O server worker #1-13] TRACE 18:42:06.396 Received on socket: Host: 192.168.1.5:5001
[New I/O server worker #1-13] TRACE 18:42:06.396 Received on socket: transferMode.dlna.org: Interactive
[New I/O server worker #1-13] TRACE 18:42:06.396 Received on socket: User-Agent: PLAYSTATION 3
[New I/O server worker #1-13] TRACE 18:42:06.396 Recognized media renderer Playstation 3
[New I/O server worker #1-13] TRACE 18:42:06.396 HTTP: get/0$0$3/thumbnail0000Avatar_1080_AC3_subs.m2ts / 0-0
[New I/O server worker #1-13] TRACE 18:42:06.396 Searching for objectId: 0$0$3 with children option: false
[New I/O server worker #1-13] TRACE 18:42:06.397 Available Content-Length: 660
[New I/O server worker #1-13] TRACE 18:42:06.397 Sent to socket: Accept-Ranges: bytes
[New I/O server worker #1-13] TRACE 18:42:06.397 Sent to socket: Connection: keep-alive
[New I/O server worker #1-13] TRACE 18:42:06.397 Sent to socket: Content-Length: 660
[New I/O server worker #1-13] TRACE 18:42:06.398 Sent to socket: Content-Type: image/jpeg
[New I/O server worker #1-13] TRACE 18:42:06.398 Sent to socket: Expires: Sun, 11 Dec 2011 11:28:46 GMT
[New I/O server worker #1-13] TRACE 18:42:06.398 Sent to socket: Server: Mac_OS_X-x86_64-10.7.1, UPnP/1.0, PMS/1.31.0
[New I/O server worker #1-13] TRACE 18:42:06.398 Sent to socket: TransferMode.DLNA.ORG: Interactive
[Thread-20] TRACE 18:42:06.548 Receiving a M-SEARCH from [192.168.1.114:60685]
[Timer-5] TRACE 18:42:07.141 buffered: 41,295,872 bytes / inputs: 0
[Thread-78] WARN  18:42:08.343 Sending kill -14 to the Unix process: 7053
[Thread-79] WARN  18:42:08.343 Sending kill -14 to the Unix process: 7057
[osx/mencoder] TRACE 18:42:08.374 EOF
[osx/mencoder] TRACE 18:42:08.374 EOF
[Thread-78] DEBUG 18:42:08.379 Successfully sent kill -14 to the Unix process: 7053
[Thread-79] DEBUG 18:42:08.380 Successfully sent kill -14 to the Unix process: 7057
[Thread-104] TRACE 18:42:08.693 Destroying buffer
[Thread-103] DEBUG 18:42:08.693 Stopping Unix process 7066: osx/tsMuxeR
[Thread-103] TRACE 18:42:08.695 Killing the Unix process: 7066
[Thread-103] DEBUG 18:42:08.695 Stopping Unix process 7059: mkfifo
[Thread-103] TRACE 18:42:08.696 Killing the Unix process: 7059
[Thread-103] DEBUG 18:42:08.696 Stopping Unix process 7062: osx/mencoder
[Thread-103] TRACE 18:42:08.696 Killing the Unix process: 7062
[Thread-103] TRACE 18:42:08.697 Destroying buffer
[Thread-103] DEBUG 18:42:08.697 Stopping Unix process 7065: osx/mencoder
[Thread-103] TRACE 18:42:08.697 Killing the Unix process: 7065
[Thread-103] TRACE 18:42:08.697 Destroying buffer
[Thread-20] TRACE 18:42:09.592 Receiving a M-SEARCH from [192.168.1.114:60685]
[osx/tsMuxeR] TRACE 18:42:09.697 EOF
[Thread-114] TRACE 18:42:10.195 StartStopListener: event:    stop
[Thread-114] TRACE 18:42:10.196 StartStopListener: renderer: 192.168.1.30
[Thread-114] TRACE 18:42:10.196 StartStopListener: file:     /Volumes/Macintosh HD 2/Temporary Files/Avatar_1080_AC3_subs.m2ts
[Thread-114] TRACE 18:42:10.196 StartStopListener:
[Thread-20] TRACE 18:42:12.594 Receiving a M-SEARCH from [192.168.1.114:60685]
[Thread-20] TRACE 18:42:14.511 Receiving a M-SEARCH from [192.168.1.114:51415]
[Thread-20] TRACE 18:42:14.511 Sending this reply [192.168.1.114:51415]: HTTP/1.1 200 OK<CRLF>CACHE-CONTROL: max-age=1200<CRLF>DATE: Wed, 17 Aug 2011 17:42:14 GMT<CRLF>LOCATION: http://192.168.1.5:5001/description/fetch<CRLF>SERVER: Mac_OS_X-x86_64-10.7.1, UPnP/1.0, PMS/1.31.0<CRLF>ST: upnp:rootdevice<CRLF>EXT: <CRLF>USN: uuid:0d7ad94c-92de-3cf0-9b4c-00cb790a1803::upnp:rootdevice<CRLF>Content-Length: 0<CRLF><CRLF>
[Thread-20] TRACE 18:42:15.591 Receiving a M-SEARCH from [192.168.1.114:60685]
[Thread-113] WARN  18:42:18.698 Sending kill -14 to the Unix process: 7065
[Thread-112] WARN  18:42:18.698 Sending kill -14 to the Unix process: 7062
[osx/mencoder] TRACE 18:42:18.722 EOF
[osx/mencoder] TRACE 18:42:18.722 EOF
[Thread-112] DEBUG 18:42:18.724 Successfully sent kill -14 to the Unix process: 7062
[Thread-113] DEBUG 18:42:18.725 Successfully sent kill -14 to the Unix process: 7065
[New I/O server boss #1 ([id: 0x23087d61, /192.168.1.5:5001])] TRACE 18:42:20.519 Creating new pipeline
[New I/O server worker #1-14] TRACE 18:42:20.520 Opened request handler on socket /192.168.1.114:56296 // WMP
[New I/O server worker #1-14] TRACE 18:42:20.520 Request: HTTP/1.1 : GET : description/fetch
[New I/O server worker #1-14] TRACE 18:42:20.520 Received on socket: Accept: text/xml, application/xml
[New I/O server worker #1-14] TRACE 18:42:20.520 Received on socket: Cache-Control: no-cache
[New I/O server worker #1-14] TRACE 18:42:20.520 Received on socket: Connection: Keep-Alive
[New I/O server worker #1-14] TRACE 18:42:20.520 Received on socket: Host: 192.168.1.5
[New I/O server worker #1-14] TRACE 18:42:20.521 Received on socket: Pragma: no-cache
[New I/O server worker #1-14] TRACE 18:42:20.521 Received on socket: User-Agent: Mozilla/4.0 (compatible; UPnP/1.0; Windows NT/5.1)
[New I/O server worker #1-14] TRACE 18:42:20.521 Recognized media renderer WMP
[New I/O server worker #1-14] TRACE 18:42:20.521 HTTP: description/fetch / 0-0
[New I/O server worker #1-14] TRACE 18:42:20.522 Sent to socket: Accept-Ranges: bytes
[New I/O server worker #1-14] TRACE 18:42:20.522 Sent to socket: Cache-Control: no-cache
[New I/O server worker #1-14] TRACE 18:42:20.522 Sent to socket: Connection: keep-alive
[New I/O server worker #1-14] TRACE 18:42:20.522 Sent to socket: Content-Length: 2004
[New I/O server worker #1-14] TRACE 18:42:20.522 Sent to socket: Content-Type: text/xml; charset="utf-8"
[New I/O server worker #1-14] TRACE 18:42:20.522 Sent to socket: Expires: 0
[New I/O server worker #1-14] TRACE 18:42:20.522 Sent to socket: Server: Mac_OS_X-x86_64-10.7.1, UPnP/1.0, PMS/1.31.0

From what I can see, PS3MS is understanding that I want 3600 seconds in to the film, but only ever gives 360 seconds in (or a tenth of the seconds actually asked for!)

Ideas?

[Concorde Rules]

Anybody? :/

I might test the windows version too, because if it doesn't work then it's something seriously wrong with PS3MS if three separate devices playing three different files don;t work!!!

[mario595]

I have it on Windows. I never checked to see if it is a factor of 10 but that seems right.

The problem is not specific to subtitles. If you take a h264 video and AC3 audio in an m2ts container and force transcoding the same problem occurs. If you have the same streams in an MKV container and force transcoding the problem does not occur.

For subtitles, the worst part of the problem is that the time stamp in the XMB is never corrected even if you exit and go back into the movie. If you choose to overcompensate (by a factor of 10) to get to a certain point in the movie then you run into another situation: Subtitles will go by this new timestamp and not play the subtitles at the proper points.

I don't know if this is a bug in PM3MS or something to do with the nature of m2ts containers. Anybody have a thought?

[mario595]

I ran a quick back-to-back test. I tried to goto 1775 seconds in an mkv vs. the same video/audio in an m2ts

Code: Select all

mkv:
[New I/O server worker #1-9] DEBUG 19:51:21.350 Setting margin to 2Mb
[Thread-17] DEBUG 19:51:26.318 Sending ALIVE...
[New I/O server worker #1-10] DEBUG 19:51:29.674 HTTP: description/fetch / 0-0
[New I/O server worker #1-11] DEBUG 19:51:44.259 HTTP: get/0$3$7$3$4/X-Men.SRT.mkv / 0-0
[New I/O server worker #1-11] DEBUG 19:51:44.259 Requesting time seek: 1775.0 seconds
[Thread-56] DEBUG 19:51:44.259 Stopping process: win32/mencoder-alternate_mt.exe
[New I/O server worker #1-11] DEBUG 19:51:44.263 Creating pipe \\.\pipe\mencoder1315525904263
[Thread-57] DEBUG 19:51:44.388 Waiting for pipe connection \\.\pipe\mencoder1315525904263
[win32/mencoder-alternate_mt.exe] DEBUG 19:51:44.450 Starting C:\Program Files (x86)\PS3 Media Server\win32\mencoder-alternate_mt.exe -ss 1775.0 -quiet M:\Work in Progress\X-Men.SRT.mkv -quiet -quiet -oac copy -of mpeg -quiet -quiet -mpegopts format=mpeg2:muxrate=500000:vbuf_size=1194:abuf_size=64 -ovc lavc -channels 6 -lavdopts debug=0:threads=8 -lavcopts autoaspect=1:vcodec=mpeg2video:acodec=ac3:abitrate=640:threads=8:keyint=5:vqscale=1:vqmin=2 -subfont C:\Windows\Fonts\Arial.ttf -subfont-text-scale 3 -subfont-outline 1 -subfont-blur 1 -subpos 98 -quiet -quiet -sid 0 -quiet -quiet -ofps 24000/1001 -quiet -quiet -lavdopts fast -mc 0 -noskip -af lavcresample=48000 -srate 48000 -o \\.\pipe\mencoder1315525904263
[win32/mencoder-alternate_mt.exe] DEBUG 19:51:44.450 Reading pipe: \\.\pipe\mencoder1315525904263
[win32/mencoder-alternate_mt.exe] DEBUG 19:51:44.450 Attaching thread: win32/mencoder-alternate_mt.exe
[Thread-57] DEBUG 19:51:44.494 Result of \\.\pipe\mencoder1315525904263 : true
[Thread-55] DEBUG 19:51:46.757 Destroying buffer


m2ts:
[New I/O server worker #1-1] DEBUG 19:53:44.261 Setting margin to 2Mb
[New I/O server worker #1-2] DEBUG 19:53:54.588 HTTP: get/0$3$7$2$4/X-Men.SRT.m2ts / 0-0
[New I/O server worker #1-2] DEBUG 19:53:54.588 Requesting time seek: 627.0 seconds
[Thread-85] DEBUG 19:53:54.588 Stopping process: win32/mencoder_mt.exe
[New I/O server worker #1-2] DEBUG 19:53:54.588 Creating pipe \\.\pipe\mencoder1315526034588
[Thread-86] DEBUG 19:53:54.713 Waiting for pipe connection \\.\pipe\mencoder1315526034588
[win32/mencoder_mt.exe] DEBUG 19:53:54.775 Starting C:\Program Files (x86)\PS3 Media Server\win32\mencoder_mt.exe -ss 627.0 -quiet M:\Work in Progress\X-Men.SRT.m2ts -quiet -quiet -oac copy -of mpeg -quiet -quiet -mpegopts format=mpeg2:muxrate=500000:vbuf_size=1194:abuf_size=64 -ovc lavc -channels 6 -lavdopts debug=0:threads=8 -lavcopts autoaspect=1:vcodec=mpeg2video:acodec=ac3:abitrate=640:threads=8:keyint=5:vqscale=1:vqmin=2 -subcp cp1252 -subfont C:\Windows\Fonts\Arial.ttf -subfont-text-scale 3 -subfont-outline 1 -subfont-blur 1 -subpos 98 -quiet -quiet -sid 100 -quiet -quiet -ofps 24000/1001 -sub M:\Work in Progress\X-Men.SRT.srt -lavdopts fast -mc 0 -noskip -af lavcresample=48000 -srate 48000 -o \\.\pipe\mencoder1315526034588
[win32/mencoder_mt.exe] DEBUG 19:53:54.775 Reading pipe: \\.\pipe\mencoder1315526034588
[win32/mencoder_mt.exe] DEBUG 19:53:54.775 Attaching thread: win32/mencoder_mt.exe
[Thread-86] DEBUG 19:53:54.791 Result of \\.\pipe\mencoder1315526034588 : true
[Thread-82] DEBUG 19:53:57.084 Destroying buffer

The first thing that stands out to me is that for mkv we are calling:
mencoder-alternate_mt.exe -ss 1775.0 -quiet

and for m2ts we are calling:
mencoder_mt.exe -ss 627.0 -quiet

what is the differnce between mencoder and mencoder-alternate?

[mario595]

FYI, I did a quick test where I backed up my Mencoder exes and made mencoder_mt.exe a copy of alternate just to see what would happen and the result was that the file still had the seek problem even though it was using the alternate mencoder. It must have something to do with the original container...

[mario595]

Anybody have any thougts?