Bug #1677

Playback reached EOF

Added by Ema Nymton over 7 years ago. Updated over 7 years ago.

Status:FixedStart date:04/06/2013
Priority:NormalDue date:
Assignee:Andreas Smas% Done:

100%

Category:Video playback
Target version:4.4
Found in version:4.3.144.g57f67 Platform:PS3

Description

Hi,
I'm experiencing a "Playback reached EOF" bug with a file I split with FFSJ after a few minutes of playback. The bug didn't happen before when the movie was packed in RAR files.

See the trace below:

00:18:05.314: Video [DEBUG]:Selecting subtitle track file:///dev_usb001/VIDEO/Films/Salt.Director's.Cut.2010.720p.BluRay.DTS.x264-xXx.srt
00:18:05.315: Subtitles [DEBUG]:Trying to load file:///dev_usb001/VIDEO/Films/Salt.Director's.Cut.2010.720p.BluRay.DTS.x264-xXx.srt
00:18:05.501: Video [DEBUG]:seek direct to 124.25 (124254000 - 0)
00:18:05.541: VDEC [DEBUG]:Waiting for end sequence
00:18:05.542: VDEC [DEBUG]:Waiting for end sequence -> done
00:18:05.571: Video [DEBUG]:seek direct to 139.25 (139254000 - 0)
00:18:05.621: VDEC [DEBUG]:Waiting for end sequence
00:18:05.622: VDEC [DEBUG]:Waiting for end sequence -> done
00:18:06.112: Video [DEBUG]:seek direct to 155.01 (155015000 - 0)
00:18:06.200: Video [DEBUG]:seek direct to 185.01 (185015000 - 0)
00:18:06.295: Video [DEBUG]:seek direct to 200.01 (200015000 - 0)
00:18:06.338: VDEC [DEBUG]:Waiting for end sequence
00:18:06.341: VDEC [DEBUG]:Waiting for end sequence -> done
00:18:06.785: Video [DEBUG]:seek direct to 215.70 (215700000 - 0)
00:18:06.834: VDEC [DEBUG]:Waiting for end sequence
00:18:06.837: VDEC [DEBUG]:Waiting for end sequence -> done
00:18:07.071: Video [DEBUG]:seek direct to 230.70 (230700000 - 0)
00:18:07.173: VDEC [DEBUG]:Waiting for end sequence
00:18:07.174: VDEC [DEBUG]:Waiting for end sequence -> done
00:18:07.307: Video [DEBUG]:seek direct to 245.70 (245700000 - 0)
00:18:07.353: VDEC [DEBUG]:Waiting for end sequence
00:18:07.354: VDEC [DEBUG]:Waiting for end sequence -> done
00:18:07.628: Video [DEBUG]:seek direct to 260.87 (260871000 - 0)
00:18:07.720: VDEC [DEBUG]:Waiting for end sequence
00:18:07.723: VDEC [DEBUG]:Waiting for end sequence -> done
00:18:08.545: Video [DEBUG]:Playback reached EOF: Invalid data found when processing input
00:18:08.570: Video [DEBUG]:seek direct to 276.43 (276428000 - 0)
00:18:08.667: VDEC [DEBUG]:Waiting for end sequence
00:18:08.670: VDEC [DEBUG]:Waiting for end sequence -> done
00:18:08.892: Video [DEBUG]:seek direct to 291.43 (291428000 - 0)
00:18:08.914: VDEC [DEBUG]:Waiting for end sequence
00:18:08.915: VDEC [DEBUG]:Waiting for end sequence -> done
00:18:09.582: Video [DEBUG]:seek direct to 276.43 (276428000 - 0)
00:18:09.689: VDEC [DEBUG]:Waiting for end sequence
00:18:09.690: VDEC [DEBUG]:Waiting for end sequence -> done
00:18:09.800: Video [DEBUG]:seek direct to 261.43 (261428000 - 0)
00:18:09.898: VDEC [DEBUG]:Waiting for end sequence
00:18:09.899: VDEC [DEBUG]:Waiting for end sequence -> done
00:18:10.711: Video [DEBUG]:Playback reached EOF: Invalid data found when processing input
00:18:13.232: Video [DEBUG]:Stopped playback of file:///dev_usb001/VIDEO/Films/Salt.Director's.Cut.2010.720p.BluRay.DTS.x264-xXx.mkv
00:18:13.232: THREADS [DEBUG]:Waiting for thread 0x10200e1
00:18:13.251: THREADS [DEBUG]:Thread 0x10200e1 (audio decoder) exiting
00:18:13.251: THREADS [DEBUG]:Thread 0x10200e1 joined

Associated revisions

Revision 2f9cdb99
Added by Andreas Smas over 7 years ago

Fix recently introduced memory leak

Fixes #1677

Change included in version 4.3.171

History

#1 Updated by Andreas Smas over 7 years ago

  • Status changed from New to Need feedback

I need more info to be able to fix this.

Does it happen to all files?

If not, a magnet link or whatever to the file and the exact size of each segment that FFSJ splits it info.

#2 Updated by Ema Nymton over 7 years ago

Andreas Öman wrote:

I need more info to be able to fix this.

Does it happen to all files?

If not, a magnet link or whatever to the file and the exact size of each segment that FFSJ splits it info.

It only happens to this file so far. I've tried with other files split with FFSJ without and didn't encounter any issue. But again, this bug didn't happen when the original movie was in RAR files.
The bug only happens on this movie on a certain sequence between 4:10 and 4:23. If you fast forward to say 4:50, Showtime won't crash for the rest of the movie run.

Here's a Magnet link of the movie: magnet:?xt=urn:btih:be2a3d0ca04de4bec8649f09bbdea8c08609d60b&dn=Salt.Directors.Cut.2010.720p.BluRay.DTS.x264-xXx&tr=udp%3A%2F%2Ftracker.openbittorrent.com%3A80&tr=udp%3A%2F%2Ftracker.publicbt.com%3A80&tr=udp%3A%2F%2Ftracker.istole.it%3A6969&tr=udp%3A%2F%2Ftracker.ccc.de%3A80

The movie is split in two files:
Salt.Director's.Cut.2010.720p.BluRay.DTS.x264-xXx.mkv.001 size 4 187 593 114 bytes
Salt.Director's.Cut.2010.720p.BluRay.DTS.x264-xXx.mkv.002 size 2 834 802 915 bytes

#3 Updated by Andreas Smas over 7 years ago

  • Status changed from Need feedback to Accepted
  • Target version set to 4.4

Thanks, will check as soon as it's downloaded.

#4 Updated by Ema Nymton over 7 years ago

It's happening to other movies now, and only to movies that have been split with FFSJ.
Here the trace for another one:

00:28:44.044: PANIC [EMERG]:OOM: malloc(126336)
00:28:44.051: BACKTRACE [EMERG]:0x20f660: .pixmap_box_blur+0x100
00:28:44.052: BACKTRACE [EMERG]:0x2439f4: .text_render0+0x148c
00:28:44.052: BACKTRACE [EMERG]:0x243c2c: .text_render+0xa4
00:28:44.052: BACKTRACE [EMERG]:0x269594: .do_render+0x3fc
00:28:44.052: BACKTRACE [EMERG]:0x2698b8: .font_render_thread+0x100
00:28:44.053: BACKTRACE [EMERG]:0x1a5608: .thread_trampoline+0x90
00:28:44.053: PANIC [EMERG]:Thread list (self=0x10200be)
00:28:44.053: PANIC [EMERG]:0x1030058: audio decoder
00:28:44.053: PANIC [EMERG]:0x103004f: video player
00:28:44.054: PANIC [EMERG]:0x103004e: video decoder
00:28:44.054: PANIC [EMERG]:0x103004d: PC:mp
00:28:44.054: PANIC [EMERG]:0x10200dc: fa scanner
00:28:44.054: PANIC [EMERG]:0x10200c9: fa scanner
00:28:44.054: PANIC [EMERG]:0x10200c4: GLW texture loader
00:28:44.055: PANIC [EMERG]:0x10200c3: GLW texture loader
00:28:44.055: PANIC [EMERG]:0x10200c2: GLW texture loader
00:28:44.055: PANIC [EMERG]:0x10200c1: GLW texture loader
00:28:44.055: PANIC [EMERG]:0x10200c0: GLW texture loader
00:28:44.056: PANIC [EMERG]:0x10200bf: GLW texture loader
00:28:44.056: PANIC [EMERG]:0x10200be: GLW font renderer
00:28:44.056: PANIC [EMERG]:0x10200bb: ssdp
00:28:44.056: PANIC [EMERG]:0x10200ba: httpsrv
00:28:44.057: PANIC [EMERG]:0x10200b8: PC:navigator
00:28:44.057: PANIC [EMERG]:0x10200b7: audioplayer
00:28:44.057: PANIC [EMERG]:0x10200b6: PC:mp
00:28:44.057: PANIC [EMERG]:0x10200b5: PC:js
00:28:44.058: PANIC [EMERG]:0x10200b4: indexer
00:28:44.058: PANIC [EMERG]:0x10200b3: service probe
00:28:44.058: PANIC [EMERG]:0x10200b2: deco
00:28:44.058: PANIC [EMERG]:0x10200b1: metadata
00:28:44.058: PANIC [EMERG]:0x10200b0: blobcache
00:28:44.059: PANIC [EMERG]:0x10200af: callout
00:28:44.059: PANIC [EMERG]:0x10200ae: PC:global
00:28:44.059: PANIC [EMERG]:0x10200ac: main

#5 Updated by Ema Nymton over 7 years ago

Note that this time it's worse as the PS3 reboots (previously, only the playback crashed)

#6 Updated by Ema Nymton over 7 years ago

Another trace showing that the EOF error and the reset are slightly separated:

00:32:08.593: Video [DEBUG]:Playback reached EOF: Error -12
00:33:04.331: Video [DEBUG]:Stopped playback of file:///dev_usb001/VIDEO/Films/Midnight.in.Paris.720p.BluRay.x264-MHD.mkv
00:33:04.331: THREADS [DEBUG]:Waiting for thread 0x11000a8
00:33:04.332: VDEC [DEBUG]:Waiting for end sequence
00:33:04.334: VDEC [DEBUG]:Waiting for end sequence -> done
00:33:04.350: THREADS [DEBUG]:Thread 0x11000a8 (audio decoder) exiting
00:33:04.351: THREADS [DEBUG]:Thread 0x11000a8 joined
00:33:04.351: vp [DEBUG]:Waiting for event
00:33:04.698: VDEC [DEBUG]:Freeing picture list
00:33:04.699: THREADS [DEBUG]:Waiting for thread 0x11000a2
00:33:04.699: VDEC [DEBUG]:Free picture 0x424c50f0
00:33:04.700: VDEC [DEBUG]:Free RSX mem 513a4c0 +1320960
00:33:04.700: VDEC [DEBUG]:Free picture 0x45451028
00:33:04.701: VDEC [DEBUG]:Free RSX mem 4eb54c0 +1320960
00:33:04.701: THREADS [DEBUG]:Thread 0x11000a3 (video player) exiting
00:33:04.701: VDEC [DEBUG]:Free picture 0x43b00d08
00:33:04.702: VDEC [DEBUG]:Free RSX mem 4c304c0 +1320960
00:33:04.702: VDEC [DEBUG]:Free picture 0x40d15e88
00:33:04.702: VDEC [DEBUG]:Free RSX mem 527ccc0 +1320960
00:33:04.702: VDEC [DEBUG]:Free picture 0x40416df8
00:33:04.703: VDEC [DEBUG]:Free RSX mem 4a54910 +1320960
00:33:04.704: VDEC [DEBUG]:Cell decoder closed
00:33:04.707: THREADS [DEBUG]:Thread 0x11000a2 (video decoder) exiting
00:33:04.707: THREADS [DEBUG]:Thread 0x11000a2 joined
00:33:04.732: THREADS [DEBUG]:Thread 0x11000a1 (PC:mp) exiting
00:33:04.733: THREADS [DEBUG]:Waiting for thread 0x11000a1
00:33:04.733: THREADS [DEBUG]:Thread 0x11000a1 joined
00:33:07.926: THREADS [DEBUG]:Thread 0x11000a0 (fa scanner) exiting
00:33:09.725: navigator [INFO]:Opening file:///dev_usb001/VIDEO/Films
00:33:09.890: THREADS [DEBUG]:Created thread fa scanner (0x11000aa)
00:33:09.979: FA [DEBUG]:file:///dev_usb001/VIDEO/Films: Found 108 items in cache
00:33:10.160: GLW [ERROR]:Unable to load skin://graphics/boxart-overlay.png -- Unable to decode image of size (483 x 659)
00:33:10.341: PANIC [EMERG]:OOM: malloc(478464)
00:33:10.351: BACKTRACE [EMERG]:0x20f660: .pixmap_box_blur+0x100
00:33:10.352: BACKTRACE [EMERG]:0x2439f4: .text_render0+0x148c
00:33:10.352: BACKTRACE [EMERG]:0x243c2c: .text_render+0xa4
00:33:10.352: BACKTRACE [EMERG]:0x269594: .do_render+0x3fc
00:33:10.353: BACKTRACE [EMERG]:0x2698b8: .font_render_thread+0x100
00:33:10.353: BACKTRACE [EMERG]:0x1a5608: .thread_trampoline+0x90
00:33:10.353: PANIC [EMERG]:Thread list (self=0x1100099)
00:33:10.354: PANIC [EMERG]:0x11000aa: fa scanner
00:33:10.354: PANIC [EMERG]:0x110009f: GLW texture loader
00:33:10.354: PANIC [EMERG]:0x110009e: GLW texture loader
00:33:10.355: PANIC [EMERG]:0x110009d: GLW texture loader
00:33:10.355: PANIC [EMERG]:0x110009c: GLW texture loader
00:33:10.355: PANIC [EMERG]:0x110009b: GLW texture loader
00:33:10.356: PANIC [EMERG]:0x110009a: GLW texture loader
00:33:10.356: PANIC [EMERG]:0x1100099: GLW font renderer
00:33:10.356: PANIC [EMERG]:0x1100096: ssdp
00:33:10.357: PANIC [EMERG]:0x1100095: httpsrv
00:33:10.357: PANIC [EMERG]:0x1100093: PC:navigator
00:33:10.358: PANIC [EMERG]:0x1100092: audioplayer
00:33:10.358: PANIC [EMERG]:0x1100091: PC:mp
00:33:10.358: PANIC [EMERG]:0x1100090: PC:js
00:33:10.359: PANIC [EMERG]:0x110008f: indexer
00:33:10.359: PANIC [EMERG]:0x110008e: service probe
00:33:10.359: PANIC [EMERG]:0x110008d: deco
00:33:10.359: PANIC [EMERG]:0x110008b: metadata
00:33:10.360: PANIC [EMERG]:0x110008a: blobcache
00:33:10.360: PANIC [EMERG]:0x1100089: callout
00:33:10.361: PANIC [EMERG]:0x1100088: PC:global
00:33:10.361: PANIC [EMERG]:0x1100086: main
00:33:10.396: GLW [DEBUG]:Load of dataroot://resources/svg/Movie.svg was aborted

#7 Updated by Ema Nymton over 7 years ago

It now happens to normal non split movies with the latest version.
Here's a trace:

00:32:23.985: Video [DEBUG]:Playback reached EOF: Error -12
00:32:24.354: PANIC [EMERG]:OOM: malloc(32256)
00:32:24.362: BACKTRACE [EMERG]:0x20f660: .pixmap_box_blur+0x100
00:32:24.362: BACKTRACE [EMERG]:0x2439f4: .text_render0+0x148c
00:32:24.362: BACKTRACE [EMERG]:0x243c2c: .text_render+0xa4
00:32:24.362: BACKTRACE [EMERG]:0x269594: .do_render+0x3fc
00:32:24.363: BACKTRACE [EMERG]:0x2698b8: .font_render_thread+0x100
00:32:24.363: BACKTRACE [EMERG]:0x1a5608: .thread_trampoline+0x90
00:32:24.363: PANIC [EMERG]:Thread list (self=0x1020095)
00:32:24.363: PANIC [EMERG]:0x10200ce: audio decoder
00:32:24.363: PANIC [EMERG]:0x10200c9: video player
00:32:24.364: PANIC [EMERG]:0x10200c8: video decoder
00:32:24.364: PANIC [EMERG]:0x10200c7: PC:mp
00:32:24.364: PANIC [EMERG]:0x10200a3: fa scanner
00:32:24.364: PANIC [EMERG]:0x102009b: GLW texture loader
00:32:24.365: PANIC [EMERG]:0x102009a: GLW texture loader
00:32:24.365: PANIC [EMERG]:0x1020099: GLW texture loader
00:32:24.365: PANIC [EMERG]:0x1020098: GLW texture loader
00:32:24.365: PANIC [EMERG]:0x1020097: GLW texture loader
00:32:24.366: PANIC [EMERG]:0x1020096: GLW texture loader
00:32:24.366: PANIC [EMERG]:0x1020095: GLW font renderer
00:32:24.366: PANIC [EMERG]:0x1020092: ssdp
00:32:24.366: PANIC [EMERG]:0x1020091: httpsrv
00:32:24.366: PANIC [EMERG]:0x102008f: PC:navigator
00:32:24.367: PANIC [EMERG]:0x102008e: audioplayer
00:32:24.367: PANIC [EMERG]:0x102008c: PC:mp
00:32:24.367: PANIC [EMERG]:0x102008b: PC:js
00:32:24.367: PANIC [EMERG]:0x102008a: indexer
00:32:24.368: PANIC [EMERG]:0x1020089: service probe
00:32:24.368: PANIC [EMERG]:0x1020088: deco
00:32:24.368: PANIC [EMERG]:0x1020087: metadata
00:32:24.368: PANIC [EMERG]:0x1020086: blobcache
00:32:24.368: PANIC [EMERG]:0x1020070: callout
00:32:24.369: PANIC [EMERG]:0x102006f: PC:global
00:32:24.369: PANIC [EMERG]:0x102006d: main
00:32:24.469: PANIC [EMERG]:Thread audio decoder (0x10200ce) crashed (r=0x80010005)
00:32:24.469: PANIC [EMERG]:Thread list (self=0x102006e)
00:32:24.470: PANIC [EMERG]:0x10200ce: audio decoder
00:32:24.470: PANIC [EMERG]:0x10200c9: video player
00:32:24.470: PANIC [EMERG]:0x10200c8: video decoder
00:32:24.470: PANIC [EMERG]:0x10200c7: PC:mp
00:32:24.471: PANIC [EMERG]:0x10200a3: fa scanner
00:32:24.471: PANIC [EMERG]:0x102009b: GLW texture loader
00:32:24.471: PANIC [EMERG]:0x102009a: GLW texture loader
00:32:24.471: PANIC [EMERG]:0x1020099: GLW texture loader
00:32:24.472: PANIC [EMERG]:0x1020098: GLW texture loader
00:32:24.472: PANIC [EMERG]:0x1020097: GLW texture loader
00:32:24.472: PANIC [EMERG]:0x1020096: GLW texture loader
00:32:24.472: PANIC [EMERG]:0x1020095: GLW font renderer
00:32:24.472: PANIC [EMERG]:0x1020092: ssdp
00:32:24.473: PANIC [EMERG]:0x1020091: httpsrv
00:32:24.473: PANIC [EMERG]:0x102008f: PC:navigator
00:32:24.473: PANIC [EMERG]:0x102008e: audioplayer
00:32:24.473: PANIC [EMERG]:0x102008c: PC:mp
00:32:24.474: PANIC [EMERG]:0x102008b: PC:js
00:32:24.474: PANIC [EMERG]:0x102008a: indexer
00:32:24.474: PANIC [EMERG]:0x1020089: service probe
00:32:24.474: PANIC [EMERG]:0x1020088: deco
00:32:24.474: PANIC [EMERG]:0x1020087: metadata
00:32:24.475: PANIC [EMERG]:0x1020086: blobcache
00:32:24.475: PANIC [EMERG]:0x1020070: callout
00:32:24.475: PANIC [EMERG]:0x102006f: PC:global
00:32:24.475: PANIC [EMERG]:0x102006d: main

#8 Updated by Andreas Smas over 7 years ago

It seems there is some kind of recent memory leak.

I've been able to reproduce it just now. Gonna look more into it tomorrow.

#9 Updated by Andreas Smas over 7 years ago

  • Status changed from Accepted to Fixed
  • % Done changed from 0 to 100

#10 Updated by Ema Nymton over 7 years ago

Thanks. It works great now.

Also available in: Atom PDF