View Bug Details

IDProjectCategoryView StatusLast Update
0002588DCP-o-maticBugspublic2023-10-14 22:30
Reporteroverlookmotel Assigned Tocarl  
PriorityurgentSeverityminorReproducibilityalways
Status resolvedResolutionfixed 
PlatformMacOSOS XOS Version10.14
Product Version2.16.59 
Target Version2.16.63 
Summary0002588: Export as ProRes produces video file 1 frame shorter than DCP
Description

When you use DCP-o-matic to export a DCP to ProRes video file, the resulting ProRes is 1 frame shorter than it should be. The last frame is missed off.

Have seen this consistently with DOM 2.16.x when exporting a variety of Interop and SMPTE DCPs, of varying lengths, 24fps or 25fps, and with/without multiple reels.

Repro case here (DOM 2.16.59):
https://drive.google.com/file/d/1mVqB17H7yfprHsti28e2a6qVhdM2ELEk

The above example uses a very short ProResHQ file (1s01f length @ 25fps = 26 frames) which has burned in timecode.

Contents of the example:

  • sources/timecode_25fps_1s1f.mov: Original source ProResHQ.
  • DOM project create DCP: DOM project to create DCP from the source (including the resulting DCP).
  • DOM project export: DOM project to export ProRes from that DCP.
  • exports/timecode_25fps_1s1f DOM export.mov: ProResHQ exported from DOM.
  • ffprobe output.json: ffprobe output for the exported ProRes.
  • ffprobe command.txt: ffprobe command used to produce the above.

When exports/timecode_25fps_1s1f DOM export.mov is viewed in Premiere or Resolve, it appears to be 25 frames long, and the last frame of the DCP is missing.

However, what's really odd is that ffprobe's reading of the file's properties contains inconsistencies:

  • nb_frames: 26 (correct)
  • r_frame_rate: 25/1 (correct)
  • avg_frame_rate: 26/1 (wrong)
  • duration: 1.000000 (wrong)

The "frames" output from ffprobe which lists every individual frame in the file lists only 25 frames.

This is a wild guess, but maybe DOM is giving FFMPEG the correct number of frames to expect at the outset, and then sends it each frame, but the final call to close the file happens before FFMPEG has finished flushing the last frame.

Tagsgit-bug
Branch2588-missing-frame
Estimated weeks required
Estimated work requiredUndecided

Activities

carl

2023-08-20 00:09

administrator   ~0005874

last frame in file with -show_frames 86400
code writes "15" @ 86400
then "16" @ 90000

carl

2023-08-20 23:43

administrator   ~0005875

Seems to be a similar thing if twice as much is written to the output (only the last frame is missing).

carl

2023-08-21 23:14

administrator   ~0005878

The output of ffprobe -v quiet -print_format json -show_format -show_streams -show_frames -select_streams v:0 build/test/ffmpeg_encoder_missing_frame_at_end.mov seems quite interesting.

carl

2023-08-24 00:44

administrator   ~0005890

When the trak tags are written, with track duration, they are wrong because the durations are obtained from trk->end_pts, which (in the video case, at least) is calculated by adding the AVPacket.duration onto the last PTS seen. Nobody is setting the AVPacket duration; hacking it into DoM seems to fix it. Not sure why packets coming back from avcodec_receive_packet() have no duration.

carl

2023-08-24 00:46

administrator   ~0005891

Need to finish off the test and then maybe just get DoM to set these durations.

carl

2023-08-24 01:08

administrator   ~0005892

Seems like when reading the video stream we have 26 chunks read from the STCO atom. We then read 25 video frames from that. Maybe there should be 27 chunks.

It's written in DoM as 26, during the mov_write_trailer. The "good" file also seems to have 26 chunks. But bad ends up with nb_index_entries=25, good with 26.

Good and bad end up[ with START_WITH 26 but then bad has

[1]nb_index_entries -> 25

good

[1]nb_index_entries -> 26

i.e. the loop marked index=%d, current=%p being run one less time.
but the termination condition looks the same

edit_list_duration is 90000 when I think it should be higher?

bad 90000/3600 = 25
good 26 / 1 = 26

edit_list_duration seems to be read by get_edit_list_entry(); ELST atom

** WRITING 1000
<WB>: 4
<WB>: 12
<WB>: 4
<WB>: 11
<WB>: 31
WRITE THE * STCO 26
get chunkCount as 26
**
WRITING 1040
<WB>: 4
<WB>: 12
<WB>: 4
<WB>: 11

is it writing it twice here, first time wrong?

Writing trak tags for 2 streams, first length 1000, second length 1040.
one has duration 90000, scaled by 1000/90000
one has duration 49920, scaled by 1000/48000

trk->end_pts is used, set to 90000.

pkt->duration is 0?

carl

2023-08-24 14:51

administrator   ~0005893

Running tests.

overlookmotel

2023-08-24 18:24

developer   ~0005894

Holy moley. This is more complicated than I expected!

carl

2023-08-24 18:42

administrator   ~0005895

Yeah it's a classic FFmpeg rabbit hole... I think I must be missing something but it's hard to work out what.

carl

2023-08-26 09:24

administrator   ~0005900

d33678b8e64de795becd3fa336dbbb099c691f58

overlookmotel

2023-10-14 12:39

developer   ~0006006

Confirmed fixed in 2.16.65.

carl

2023-10-14 22:30

administrator   ~0006014

Thanks for checking!

Bug History

Date Modified Username Field Change
2023-07-07 12:20 overlookmotel New Bug
2023-07-08 15:42 carl Priority normal => urgent
2023-07-08 15:42 carl Status new => acknowledged
2023-07-08 15:42 carl Estimated work required => Undecided
2023-08-13 12:18 carl Target Version => 2.16.62
2023-08-13 14:39 carl Assigned To => carl
2023-08-13 14:39 carl Status acknowledged => confirmed
2023-08-13 22:42 carl Tag Attached: git-bug
2023-08-20 00:09 carl Note Added: 0005874
2023-08-20 21:18 carl Target Version 2.16.62 => 2.16.63
2023-08-20 23:43 carl Note Added: 0005875
2023-08-21 23:14 carl Note Added: 0005878
2023-08-24 00:44 carl Note Added: 0005890
2023-08-24 00:46 carl Note Added: 0005891
2023-08-24 01:08 carl Note Added: 0005892
2023-08-24 14:48 carl Branch => 2588-missing-frame
2023-08-24 14:51 carl Note Added: 0005893
2023-08-24 18:24 overlookmotel Note Added: 0005894
2023-08-24 18:42 carl Note Added: 0005895
2023-08-26 09:24 carl Status confirmed => resolved
2023-08-26 09:24 carl Resolution open => fixed
2023-08-26 09:24 carl Note Added: 0005900
2023-10-14 12:39 overlookmotel Note Added: 0006006
2023-10-14 22:30 carl Note Added: 0006014