Description
Related Objects
- Mentioned Here
- P4746 Production Operating-Mechanism-and-Molecular-Dynamics-of-Pheromone-Binding-Protein-ASP1-as-Influenced-by-pH-pone.0110565.s001.ogv 160p.ogv transcode
P4747 Labs Operating-Mechanism-and-Molecular-Dynamics-of-Pheromone-Binding-Protein-ASP1-as-Influenced-by-pH-pone.0110565.s001.ogv 160p.ogv transcode
P4748 Last lines of straced labs Operating-Mechanism-and-Molecular-Dynamics-of-Pheromone-Binding-Protein-ASP1-as-Influenced-by-pH-pone.0110565.s001.ogv 160p.ogv transcode
Event Timeline
Production SELECT * FROM commonswiki_p.transcode WHERE transcode_image_name = "Operating-Mechanism-and-Molecular-Dynamics-of-Pheromone-Binding-Protein-ASP1-as-Influenced-by-pH-pone.0110565.s001.ogv";:
Exitcode: 124 is a timeout error.
I went ahead and reproduced this on labs:
ffmpeg2theora hangs until I gave it a SIGINT. Also noting that there is about 100% CPU utilization by this process.
Naturally I reran the process with strace to see if the process is actually doing any IO during the hanging, and no:
Also reproduced locally. I'm not sure how to set a debug loglevel in order to debug it.
hehehhe "2147483647 duplicate frames added to maintain sync" *cough* yeah there's a bug in here
The source file has a packet that ffmpeg reports a wildly incorrect decode timestamp for; this completely throws off ffmpeg2theora.
ffprobe -show_packets Operating-Mechanism-and-Molecular-Dynamics-of-Pheromone-Binding-Protein-ASP1-as-Influenced-by-pH-pone.0110565.s001.ogv | grep dts .... dts_time=87.733333 [ogg @ 0x7fdad1000000] Broken file, keyframe not correctly marked. dts=2633 dts_time=87.766667 dts=288230376151711804 dts_time=9607679205057060.000000 dts=288230376151711805 dts_time=9607679205057060.000000 dts=2636 dts_time=87.866667
Looking at the actual ogg packets, something's definitely wrong looking:
oggz-dump Operating-Mechanism-and-Molecular-Dynamics-of-Pheromone-Binding-Protein-ASP1-as-Influenced-by-pH-pone.0110565.s001.ogv | grep 'packetno 26' ... 00:01:27.733: serialno 0387272803, granulepos 2604|29, packetno 2637: 17.977 kB 00:01:27.766: serialno 0387272803, calc. gpos 2634|0, packetno 2638: 37.686 kB 00:01:27.800: serialno 0387272803, granulepos 2634|1 ERR: file gp -1|62, packetno 2639: 16.588 kB 00:01:27.833: serialno 0387272803, calc. gpos 2634|2, packetno 2640: 19.027 kB 00:01:27.866: serialno 0387272803, calc. gpos 2634|3, packetno 2641: 15.764 kB
Looks like there's a bogus granulepos on one of the packets, which ffmpeg/libav fouls up with and interprets as a legit but totally out of whack timestamp. ffmpeg2theora then explodes trying to adjust a/v sync for the bogus data.
I can probably remux the file and fix it as a on-off, but might be wise to submit some fix patches.
I recompressed the .ogv file from the original source .mpg and uploaded a new copy, which appears to be transcoding correctly.
ffmpeg2theora's behavior is sensible enough assuming ffmpeg/libav doesn't foul up, should see whether it's feasible to get libav to handle this case better upstream.
Upstream report https://trac.ffmpeg.org/ticket/6080#ticket
Patch submitted via ffmpeg-devel list, isn't in archives yet (presumably I'm held for moderation as a new joiner).
@brion hi, should we back port your fix into wmf? Or should wmf update all the way to 3.3 with your fix?
No longer using ffmpeg2theora or creating .ogv output; WebM transcodes are unaffected by the bug. Closing out.