Playback stops after a minute, mencoder error

[henriksson]

Hello!

I am a new user to PMS, but I have already streamed some ordinary xvid-videos to my PS3 and it is working perfectly!

But last night I thought I would try to play a mkv-movie. At first, everything was working all right, but after a minute or so playback stops and the PMS-log says:

Code: Select all

[Thread-97] TRACE 12:04:15.598 Starting transcode/remux of refined-qos-blu720p.mkv
[mencoder] TRACE 12:05:15.585 Process mencoder has a return code of 139! Maybe an error occured...

I don't know what to do.. I've tried to run PMS as root, and I have also tried to play another mkv.

If anyone know something that could help me, I would be very pleased

Edit: I found this in the debug log, I copied from when my media files was read to where I get an error message.

Code: Select all

[Thread-71] DEBUG 12:04:05.018 Wrote on socket: HTTP/1.1 200 OK
[Thread-71] DEBUG 12:04:05.018 Wrote on socket: CONTENT-TYPE: text/xml; charset="utf-8"
[Thread-71] DEBUG 12:04:05.019 Searching for objectId: 0$0$5$0$8 with children option: true
[Thread-71] DEBUG 12:04:05.032 Search extension for /home/oskar/Skrivbord/Punisher.War.Zone.2008.720p.BD5.x264-BDFLiX
[Thread-71] INFO  12:04:05.033 Adding Punisher.War.Zone.2008.720p.BD5.x264-BDFLiX / class: net.pms.dlna.RealFile
[Thread-71] DEBUG 12:04:05.033 Search extension for /home/oskar/Skrivbord/Quantum.of.Solace.720p.BluRay.x264-REFiNED
[Thread-71] INFO  12:04:05.033 Adding Quantum.of.Solace.720p.BluRay.x264-REFiNED / class: net.pms.dlna.RealFile
[Thread-71] DEBUG 12:04:05.034 Search extension for /home/oskar/Skrivbord/Total.KO.23032009.SWEDiSH.DSR.XviD-MaM
[Thread-71] INFO  12:04:05.034 Adding Total.KO.23032009.SWEDiSH.DSR.XviD-MaM / class: net.pms.dlna.RealFile
[Thread-71] DEBUG 12:04:05.035 Setting DLNA id 0$0$5$0$8$0 to Punisher.War.Zone.2008.720p.BD5.x264-BDFLiX
[Thread-71] DEBUG 12:04:05.035 Setting DLNA id 0$0$5$0$8$1 to Quantum.of.Solace.720p.BluRay.x264-REFiNED
[Thread-71] DEBUG 12:04:05.035 Setting DLNA id 0$0$5$0$8$2 to Total.KO.23032009.SWEDiSH.DSR.XviD-MaM
[Thread-71] DEBUG 12:04:05.037 End of analysis
[Thread-71] DEBUG 12:04:05.038 Wrote on socket: Server: Linux-i386-2.6.27-11-generic, UPnP/1.0, PMS/1.10.5
[Thread-71] DEBUG 12:04:05.038 Wrote on socket: Content-Length: 1491
[Thread-71] DEBUG 12:04:05.038 Wrote on socket:
[Thread-71] DEBUG 12:04:05.038 Close Connection
[Thread-72] DEBUG 12:04:05.079 Opened handler on socket Socket[addr=/192.168.1.4,port=64626,localport=5001]
[Thread-72] DEBUG 12:04:05.080 Received on socket: POST /upnp/control/content_directory HTTP/1.1
[Thread-72] DEBUG 12:04:05.080 Received on socket: X-AV-Client-Info: av=5.0; cn="Sony Computer Entertainment Inc."; mn="PLAYSTATION 3"; mv="1.0";
[Thread-72] DEBUG 12:04:05.152 Received on socket: Host: 192.168.1.100:5001
[Thread-72] DEBUG 12:04:05.152 Received on socket: User-Agent: UPnP/1.0 DLNADOC/1.50
[Thread-72] DEBUG 12:04:05.152 Received on socket: Content-Length: 276
[Thread-72] DEBUG 12:04:05.153 Received on socket: Content-Type: text/xml; charset="utf-8"
[Thread-72] DEBUG 12:04:05.153 Received on socket: SOAPACTION: "urn:schemas-upnp-org:service:ContentDirectory:1#GetSystemUpdateID"
[Thread-72] INFO  12:04:05.153 HTTP: upnp/control/content_directory / 0-0
[Thread-72] DEBUG 12:04:05.154 Wrote on socket: HTTP/1.1 200 OK
[Thread-72] DEBUG 12:04:05.154 Wrote on socket: CONTENT-TYPE: text/xml; charset="utf-8"
[Thread-72] DEBUG 12:04:05.155 Wrote on socket: Server: Linux-i386-2.6.27-11-generic, UPnP/1.0, PMS/1.10.5
[Thread-72] DEBUG 12:04:05.155 Wrote on socket: Content-Length: 335
[Thread-72] DEBUG 12:04:05.156 Wrote on socket:
[Thread-72] DEBUG 12:04:05.156 Close Connection
[Thread-73] DEBUG 12:04:05.165 Opened handler on socket Socket[addr=/192.168.1.4,port=64625,localport=5001]
[Thread-73] DEBUG 12:04:05.165 Received on socket: POST /upnp/control/content_directory HTTP/1.1
[Thread-73] DEBUG 12:04:05.166 Received on socket: X-AV-Client-Info: av=5.0; cn="Sony Computer Entertainment Inc."; mn="PLAYSTATION 3"; mv="1.0";
[Thread-73] DEBUG 12:04:05.199 Received on socket: Host: 192.168.1.100:5001
[Thread-73] DEBUG 12:04:05.199 Received on socket: User-Agent: UPnP/1.0 DLNADOC/1.50
[Thread-73] DEBUG 12:04:05.199 Received on socket: Content-Length: 909
[Thread-73] DEBUG 12:04:05.199 Received on socket: Content-Type: text/xml; charset="utf-8"
[Thread-73] DEBUG 12:04:05.199 Received on socket: SOAPACTION: "urn:schemas-upnp-org:service:ContentDirectory:1#Browse"
[Thread-73] INFO  12:04:05.199 HTTP: upnp/control/content_directory / 0-0
[Thread-73] DEBUG 12:04:05.200 Wrote on socket: HTTP/1.1 200 OK
[Thread-73] DEBUG 12:04:05.200 Wrote on socket: CONTENT-TYPE: text/xml; charset="utf-8"
[Thread-73] DEBUG 12:04:05.200 Searching for objectId: 0$0$5$0$8 with children option: false
[Thread-73] DEBUG 12:04:05.202 Wrote on socket: Server: Linux-i386-2.6.27-11-generic, UPnP/1.0, PMS/1.10.5
[Thread-73] DEBUG 12:04:05.202 Wrote on socket: Content-Length: 860
[Thread-73] DEBUG 12:04:05.202 Wrote on socket:
[Thread-73] DEBUG 12:04:05.203 Close Connection
[Thread-74] DEBUG 12:04:06.227 Opened handler on socket Socket[addr=/192.168.1.4,port=64624,localport=5001]
[Thread-74] DEBUG 12:04:06.228 Received on socket: POST /upnp/control/content_directory HTTP/1.1
[Thread-74] DEBUG 12:04:06.229 Received on socket: X-AV-Client-Info: av=5.0; cn="Sony Computer Entertainment Inc."; mn="PLAYSTATION 3"; mv="1.0";
[Thread-74] DEBUG 12:04:06.263 Received on socket: Host: 192.168.1.100:5001
[Thread-74] DEBUG 12:04:06.263 Received on socket: User-Agent: UPnP/1.0 DLNADOC/1.50
[Thread-74] DEBUG 12:04:06.263 Received on socket: Content-Length: 276
[Thread-74] DEBUG 12:04:06.264 Received on socket: Content-Type: text/xml; charset="utf-8"
[Thread-74] DEBUG 12:04:06.264 Received on socket: SOAPACTION: "urn:schemas-upnp-org:service:ContentDirectory:1#GetSystemUpdateID"
[Thread-74] INFO  12:04:06.264 HTTP: upnp/control/content_directory / 0-0
[Thread-74] DEBUG 12:04:06.265 Wrote on socket: HTTP/1.1 200 OK
[Thread-74] DEBUG 12:04:06.275 Wrote on socket: CONTENT-TYPE: text/xml; charset="utf-8"
[Thread-74] DEBUG 12:04:06.276 Unexpected IO Error: class java.io.IOException: Broken pipe
[Thread-74] DEBUG 12:04:06.277 Close Connection

Regards
Henriksson

[henriksson]

Anyone?

[shagrath]

post the whole log, this section isn't relevant

[henriksson]

Ok, here it is!

Debug log

It was a lot more characters then the limited 20000 so I hosted the whole file on my server.

[llblasi]

I had the same problem. My solution was changing the buffer size from 500 to 400 and the problem was solved.

[henriksson]

It didn't work

Thanks anyway though

[5ketcher]

I do experience the same problem:

Code: Select all

[Timer-219] DEBUG 21:43:54.985 Buffered Space: 16617472 bytes / inputs: 1
[Timer-219] DEBUG 21:43:56.985 Buffered Space: 17178624 bytes / inputs: 1
[Timer-219] DEBUG 21:43:58.986 Buffered Space: 17463296 bytes / inputs: 1
[Timer-219] DEBUG 21:44:00.986 Buffered Space: 17346560 bytes / inputs: 1
[Timer-219] DEBUG 21:44:02.985 Buffered Space: 23070720 bytes / inputs: 1
[Timer-219] DEBUG 21:44:04.986 Buffered Space: 28919808 bytes / inputs: 1
[Timer-219] DEBUG 21:44:06.985 Buffered Space: 23617536 bytes / inputs: 1
[Timer-219] DEBUG 21:44:08.986 Buffered Space: 15976448 bytes / inputs: 1
[Timer-219] DEBUG 21:44:10.986 Buffered Space: 10608640 bytes / inputs: 1
[Timer-219] DEBUG 21:44:12.985 Buffered Space: 11558912 bytes / inputs: 1
[Timer-219] DEBUG 21:44:14.986 Buffered Space: 18286592 bytes / inputs: 1
[Timer-219] DEBUG 21:44:16.987 Buffered Space: 29581312 bytes / inputs: 1
[Timer-219] DEBUG 21:44:18.986 Buffered Space: 44494848 bytes / inputs: 1
[Timer-219] DEBUG 21:44:20.987 Buffered Space: 52531200 bytes / inputs: 1
[Timer-219] DEBUG 21:44:22.987 Buffered Space: 50599936 bytes / inputs: 1
[Timer-219] DEBUG 21:44:24.986 Buffered Space: 47208448 bytes / inputs: 1
[Timer-219] DEBUG 21:44:26.987 Buffered Space: 42889216 bytes / inputs: 1
[Timer-219] DEBUG 21:44:28.986 Buffered Space: 37261312 bytes / inputs: 1
[Timer-219] DEBUG 21:44:30.987 Buffered Space: 32380928 bytes / inputs: 1
[Timer-219] DEBUG 21:44:32.988 Buffered Space: 24414208 bytes / inputs: 1
[Timer-219] DEBUG 21:44:34.987 Buffered Space: 19816448 bytes / inputs: 1
[Timer-219] DEBUG 21:44:36.988 Buffered Space: 19470336 bytes / inputs: 1
[Timer-219] DEBUG 21:44:38.987 Buffered Space: 19378176 bytes / inputs: 1
[Timer-219] DEBUG 21:44:40.990 Buffered Space: 27693056 bytes / inputs: 1
[Timer-219] DEBUG 21:44:42.991 Buffered Space: 30969856 bytes / inputs: 1
[mencoder] DEBUG 21:44:44.546 EOF
[mencoder] TRACE 21:44:44.546 Process mencoder has a return code of 139! Maybe an error occured... check the log file
[mencoder] INFO  21:44:44.548 Stopping process: mkfifo
[mencoder] DEBUG 21:44:44.548 Killing the Unix process: 22025
[Thread-4925] DEBUG 21:44:44.590 kill: No such process
[Timer-219] DEBUG 21:44:44.991 Buffered Space: 29394944 bytes / inputs: 1
[Timer-219] DEBUG 21:44:46.990 Buffered Space: 23169024 bytes / inputs: 1
[Timer-219] DEBUG 21:44:48.991 Buffered Space: 13731840 bytes / inputs: 1
[Thread-18] TRACE 21:44:49.886 Sending ALIVE...
[Thread-18] DEBUG 21:44:49.886 Setting multicast network interface: name:eth0 (eth0) index: 2 addresses:
/192.168.22.10;

[Thread-18] DEBUG 21:44:49.887 Sending message from multicast socket on network interface: name:eth0 (eth0) index: 2 addresses:
/192.168.22.10;

[Thread-18] DEBUG 21:44:49.887 Multicast socket is on interface: /192.168.22.10
[Thread-18] DEBUG 21:44:49.887 Socket Timeout: 0
[Thread-18] DEBUG 21:44:49.887 Socket TTL: 32
[Thread-19] DEBUG 21:44:49.887 Receiving a NOTIFY from [192.168.22.10:32942]
[Thread-19] DEBUG 21:44:50.462 Receiving a NOTIFY from [192.168.22.10:32942]
[Thread-19] DEBUG 21:44:50.506 Receiving a NOTIFY from [192.168.22.10:32942]
[Thread-19] DEBUG 21:44:50.847 Receiving a NOTIFY from [192.168.22.10:32942]
[Timer-219] DEBUG 21:44:50.990 Buffered Space: 5343232 bytes / inputs: 1
[Thread-19] DEBUG 21:44:51.328 Receiving a NOTIFY from [192.168.22.10:32942]
[Thread-19] DEBUG 21:44:52.189 Receiving a NOTIFY from [192.168.22.10:32942]
[Thread-19] DEBUG 21:44:52.223 Receiving a NOTIFY from [192.168.22.10:32942]
[Thread-4924] DEBUG 21:44:52.755 Ready to Stop: true
[Thread-4924] DEBUG 21:44:52.755 Sending stream: 291962880 bytes of get/0$1$113$0/hd1080-tdk.mkv
[Thread-4924] DEBUG 21:44:52.756 Close Connection
[Timer-219] DEBUG 21:44:52.990 Buffered Space: 291932160 bytes / inputs: 0
[Thread-19] DEBUG 21:44:53.008 Receiving a NOTIFY from [192.168.22.10:32942]
[Thread-4929] DEBUG 21:44:53.324 Opened handler on socket Socket[addr=/192.168.22.240,port=54913,localport=5001]
[Thread-4929] DEBUG 21:44:53.324 Received on socket: GET /description/fetch HTTP/1.1
[Thread-4929] DEBUG 21:44:53.324 Received on socket: Host: 192.168.22.10:5001
[Thread-4929] DEBUG 21:44:53.324 Received on socket: Date: Sun, 12 Apr 2009 19:45:04 GMT
[Thread-4929] DEBUG 21:44:53.324 Received on socket: User-Agent: UPnP/1.0
[Thread-4929] DEBUG 21:44:53.325 Received on socket: X-AV-Client-Info: av=5.0; cn="Sony Computer Entertainment Inc."; mn="PLAYSTATION 3"; mv="1.0";
[Thread-4929] INFO  21:44:53.331 HTTP: description/fetch / 0-0
[Thread-4929] DEBUG 21:44:53.331 Wrote on socket: HTTP/1.1 200 OK
[Thread-4929] DEBUG 21:44:53.331 Wrote on socket: Content-Type: text/xml
[Thread-4929] DEBUG 21:44:53.332 Wrote on socket: Cache-Control: no-cache
[Thread-4929] DEBUG 21:44:53.332 Wrote on socket: Expires: 0
[Thread-4929] DEBUG 21:44:53.332 Wrote on socket: Accept-Ranges: bytes
[Thread-4929] DEBUG 21:44:53.332 Wrote on socket: Connection: keep-alive
[Thread-4929] DEBUG 21:44:53.332 Wrote on socket: Server: Linux-amd64-2.6.27-11-generic, UPnP/1.0, PMS/1.10.5
[Thread-4929] DEBUG 21:44:53.332 Available Content-Length: 1786
[Thread-4929] DEBUG 21:44:53.332 Wrote on socket: Content-Length: 1786
[Thread-4929] DEBUG 21:44:53.332 Wrote on socket:
[Thread-4929] DEBUG 21:44:53.332 Sending stream: 1786 bytes of description/fetch
[Thread-4929] DEBUG 21:44:53.333 Close Connection
[Thread-19] DEBUG 21:44:53.846 Receiving a NOTIFY from [192.168.22.10:32942]
[Thread-19] DEBUG 21:44:54.177 Receiving a NOTIFY from [192.168.22.10:32942]
[Timer-219] DEBUG 21:44:54.990 Buffered Space: 291932160 bytes / inputs: 0
[Thread-4927] INFO  21:44:55.255 Stopping process: mencoder
[Thread-4927] DEBUG 21:44:55.256 Killing the Unix process: 22028
[Thread-4928] INFO  21:44:55.256 Destroying buffer
[Thread-4930] DEBUG 21:44:55.601 kill: No such process
[Thread-4927] INFO  21:44:55.602 Stopping process: mkfifo
[Thread-4927] DEBUG 21:44:55.602 Killing the Unix process: 22025
[Thread-4932] DEBUG 21:44:55.641 kill: No such process
[Thread-4927] INFO  21:44:55.642 Destroying buffer
[Thread-4927] INFO  21:44:55.914 Destroying buffer
[Thread-4934] DEBUG 21:44:57.040 Opened handler on socket Socket[addr=/192.168.22.240,port=54912,localport=5001]
[Thread-4934] DEBUG 21:44:57.040 Received on socket: GET /get/0$1$113$0/thumbnail0000hd1080-tdk.mkv HTTP/1.1
[Thread-4934] DEBUG 21:44:57.040 Received on socket: Host: 192.168.22.10:5001
[Thread-4934] DEBUG 21:44:57.040 Received on socket: User-Agent: PLAYSTATION 3
[Thread-4934] DEBUG 21:44:57.047 Received on socket: Connection: Keep-Alive
[Thread-4934] DEBUG 21:44:57.047 Received on socket: Accept-Encoding: identity
[Thread-4934] DEBUG 21:44:57.047 Received on socket: transferMode.dlna.org: Interactive
[Thread-4934] INFO  21:44:57.047 HTTP: get/0$1$113$0/thumbnail0000hd1080-tdk.mkv / 0-0
[Thread-4934] DEBUG 21:44:57.047 Wrote on socket: HTTP/1.1 200 OK
[Thread-4934] DEBUG 21:44:57.047 Searching for objectId: 0$1$113$0 with children option: false
[Thread-4934] DEBUG 21:44:57.047 Wrote on socket: Content-Type: image/png
[Thread-4934] DEBUG 21:44:57.047 Wrote on socket: Accept-Ranges: bytes
[Thread-4934] DEBUG 21:44:57.047 Wrote on socket: Expires: Thu, 06 Aug 2009 13:31:37 GMT
[Thread-4934] DEBUG 21:44:57.047 Wrote on socket: Connection: keep-alive
[Thread-4934] DEBUG 21:44:57.047 Wrote on socket: Server: Linux-amd64-2.6.27-11-generic, UPnP/1.0, PMS/1.10.5
[Thread-4934] DEBUG 21:44:57.047 Available Content-Length: 2135
[Thread-4934] DEBUG 21:44:57.047 Wrote on socket: Content-Length: 2135
[Thread-4934] DEBUG 21:44:57.048 Wrote on socket:
[Thread-4934] DEBUG 21:44:57.048 Sending stream: 2135 bytes of get/0$1$113$0/thumbnail0000hd1080-tdk.mkv
[Thread-4934] DEBUG 21:44:57.048 Close Connection


[Xeo84]

same problem here

[alka-seltzer]

same problem here.

[myster_fr]

Hi,

I got the same problem and a simple Googling brung me the answer.
See here : http://code.google.com/p/ps3mediaserver ... tail?id=11

For the lazy ones who do not want to read : try unchecking the ASS subtitle support in mencoder video options