Timecodestamper error in detecting upstream timecode

ivan94fi · April 2, 2024, 9:15am

Hi, I am trying to develop a pipeline that needs to read timecodes from incoming h264 SEI messages and that is able to write timecodes in the output stream.

See my other, a the time of writing, unanswered post for more context: Multiple SRT stream synchronization with timecode

I managed to add SEI timecode metadata to a video with AWS Elemental and this is the result: aspen_25_aws.mp4 - Google Drive

To read timecodes from this file with Gstreamer and see if they would be written with an x264 encoding, I used this pipeline:

GST_DEBUG=timecodestamper:6 gst-launch-1.0 filesrc location=aspen_25_aws.mp4 ! decodebin ! timecodestamper source=last-known ! timeoverlay time-mode=time-code ! videoconvert ! x264enc ! matroskamux ! filesink location=gst_timecodestamper.mkv

There are two problems:

The timecodes reported by timecodestamper and consequently by timeoverlay are wrong
The timecoes are not present in the ouput file

Problem 1

The first problem is that the parsed timecodes are wrong (they start from 01:02:06 instead of 01:02:12), are duplicated in adjacent frames and wrap at 12 frames instead of 24, as can be seen in the generated file and in the (truncated) output of the command:

Setting pipeline to PAUSED ...
Pipeline is PREROLLING ...
Got context from element 'vaapipostproc0': gst.gl.GLDisplay=context, gst.gl.GLDisplay=(GstGLDisplay)"\(GstGLDisplayX11\)\ gldisplayx11-0";
Got context from element 'vaapipostproc0': gst.vaapi.Display=context, gst.vaapi.Display=(GstVaapiDisplay)"\(GstVaapiDisplayDRM\)\ vaapidisplaydrm1", gst.vaapi.Display.GObject=(GstObject)"\(GstVaapiDisplayDRM\)\ vaapidisplaydrm1";
Redistribute latency...
0:00:00.145431217 3591108 0x7fcc38014180 DEBUG        timecodestamper gsttimecodestamper.c:847:gst_timecodestamper_sink_event:<timecodestamper0> received event stream-start event: 0x7fcc3c004dc0, time 99:99:99.999999999, seq-num 63, GstEventStreamStart, stream-id=(string)69015cb715e129d53dc6b10e0d1f1c839f9bb1782b336f94d415e77236806465/001, flags=(GstStreamFlags)GST_STREAM_FLAG_NONE, group-id=(uint)2;
0:00:00.145457176 3591108 0x7fcc38014180 DEBUG        timecodestamper gsttimecodestamper.c:847:gst_timecodestamper_sink_event:<timecodestamper0> received event caps event: 0x7fcbec004d90, time 99:99:99.999999999, seq-num 248, GstEventCaps, caps=(GstCaps)"video/x-raw\,\ format\=\(string\)NV12\,\ width\=\(int\)1920\,\ height\=\(int\)1080\,\ framerate\=\(fraction\)25/1\,\ interlace-mode\=\(string\)progressive\,\ pixel-aspect-ratio\=\(fraction\)1/1\,\ multiview-mode\=\(string\)mono\,\ multiview-flags\=\(GstVideoMultiviewFlagsSet\)0:ffffffff:/right-view-first/left-flipped/left-flopped/right-flipped/right-flopped/half-aspect/mixed-mono\,\ views\=\(int\)2\,\ chroma-site\=\(string\)mpeg2\,\ colorimetry\=\(string\)bt709";
Redistribute latency...
Redistribute latency...
0:00:00.170825402 3591108 0x7fcc38014180 DEBUG        timecodestamper gsttimecodestamper.c:847:gst_timecodestamper_sink_event:<timecodestamper0> received event caps event: 0x7fcbec005400, time 99:99:99.999999999, seq-num 265, GstEventCaps, caps=(GstCaps)"video/x-raw\,\ format\=\(string\)NV12\,\ width\=\(int\)1920\,\ height\=\(int\)1080\,\ framerate\=\(fraction\)25/1\,\ interlace-mode\=\(string\)progressive\,\ pixel-aspect-ratio\=\(fraction\)1/1\,\ multiview-mode\=\(string\)mono\,\ multiview-flags\=\(GstVideoMultiviewFlagsSet\)0:ffffffff:/right-view-first/left-flipped/left-flopped/right-flipped/right-flopped/half-aspect/mixed-mono\,\ views\=\(int\)2\,\ chroma-site\=\(string\)mpeg2\,\ colorimetry\=\(string\)bt709";
0:00:00.171848357 3591108 0x7fcc38014180 DEBUG        timecodestamper gsttimecodestamper.c:847:gst_timecodestamper_sink_event:<timecodestamper0> received event segment event: 0x7fcc381e4670, time 99:99:99.999999999, seq-num 225, GstEventSegment, segment=(GstSegment)"segment, flags=(GstSegmentFlags)GST_SEGMENT_FLAG_NONE, rate=(double)1, applied-rate=(double)1, format=(GstFormat)time, base=(guint64)0, offset=(guint64)0, start=(guint64)80000000, stop=(guint64)5080000000, time=(guint64)0, position=(guint64)80000000, duration=(guint64)18446744073709551615;";
0:00:00.171866647 3591108 0x7fcc38014180 DEBUG        timecodestamper gsttimecodestamper.c:847:gst_timecodestamper_sink_event:<timecodestamper0> received event tag event: 0x7fcbf0005b20, time 99:99:99.999999999, seq-num 241, GstTagList-stream, taglist=(taglist)"taglist\,\ video-codec\=\(string\)\"H.264\\\ /\\\ AVC\"\,\ maximum-bitrate\=\(uint\)11121904\,\ bitrate\=\(uint\)8355902\;";
0:00:00.171895407 3591108 0x7fcc38014180 DEBUG        timecodestamper gsttimecodestamper.c:847:gst_timecodestamper_sink_event:<timecodestamper0> received event tag event: 0x7fcc381e4590, time 99:99:99.999999999, seq-num 227, GstTagList-global, taglist=(taglist)"taglist\,\ datetime\=\(datetime\)2024-03-25T15:44:37Z\,\ container-format\=\(string\)\"ISO\\\ MP4/M4A\"\;";
0:00:00.171904597 3591108 0x7fcc38014180 DEBUG        timecodestamper gsttimecodestamper.c:847:gst_timecodestamper_sink_event:<timecodestamper0> received event tag event: 0x7fcc2c00bc80, time 99:99:99.999999999, seq-num 243, GstTagList-stream, taglist=(taglist)"taglist\,\ video-codec\=\(string\)\"H.264\\\ \\\(High\\\ Profile\\\)\"\,\ maximum-bitrate\=\(uint\)11121904\,\ bitrate\=\(uint\)8355902\;";
0:00:00.172469225 3591108 0x7fcc38014180 DEBUG        timecodestamper gsttimecodestamper.c:1084:gst_timecodestamper_update_latency:<timecodestamper0:sink> Queried latency: live 0, min latency 0:00:00.000000000
0:00:00.172685444 3591108 0x7fcc38014180 DEBUG        timecodestamper gsttimecodestamper.c:1152:gst_timecodestamper_transform_ip:<timecodestamper0> Handling video frame with running time 0:00:00.000000000
0:00:00.172692034 3591108 0x7fcc38014180 DEBUG        timecodestamper gsttimecodestamper.c:1204:gst_timecodestamper_transform_ip:<timecodestamper0> Initialized internal timecode to 00:00:00:00
0:00:00.172696324 3591108 0x7fcc38014180 DEBUG        timecodestamper gsttimecodestamper.c:1228:gst_timecodestamper_transform_ip:<timecodestamper0> Updated upstream timecode to 00:01:02:06
0:00:00.172710533 3591108 0x7fcc38014180 DEBUG        timecodestamper gsttimecodestamper.c:1272:gst_timecodestamper_transform_ip:<timecodestamper0> Created RTC timecode 10:56:34:05 for 2024-04-02 10:56 +0200 (210441 us)
0:00:00.172713993 3591108 0x7fcc38014180 DEBUG        timecodestamper gsttimecodestamper.c:1282:gst_timecodestamper_transform_ip:<timecodestamper0> Initialized RTC timecode to 10:56:34:05
0:00:00.195627411 3591108 0x7fcc38014180 DEBUG        timecodestamper gsttimecodestamper.c:1084:gst_timecodestamper_update_latency:<timecodestamper0:sink> Queried latency: live 0, min latency 0:00:00.000000000
0:00:00.195665951 3591108 0x7fcc38014180 DEBUG        timecodestamper gsttimecodestamper.c:1152:gst_timecodestamper_transform_ip:<timecodestamper0> Handling video frame with running time 0:00:00.040000000
0:00:00.195671431 3591108 0x7fcc38014180 DEBUG        timecodestamper gsttimecodestamper.c:1212:gst_timecodestamper_transform_ip:<timecodestamper0> Incremented internal timecode to 00:00:00:01
0:00:00.195675321 3591108 0x7fcc38014180 DEBUG        timecodestamper gsttimecodestamper.c:1228:gst_timecodestamper_transform_ip:<timecodestamper0> Updated upstream timecode to 00:01:02:06
0:00:00.195686761 3591108 0x7fcc38014180 DEBUG        timecodestamper gsttimecodestamper.c:1272:gst_timecodestamper_transform_ip:<timecodestamper0> Created RTC timecode 10:56:34:06 for 2024-04-02 10:56 +0200 (233422 us)
0:00:00.195691521 3591108 0x7fcc38014180 DEBUG        timecodestamper gsttimecodestamper.c:1315:gst_timecodestamper_transform_ip:<timecodestamper0> Incremented RTC timecode to 10:56:34:06 (+0:00:00.000000000 drift)
0:00:00.204009114 3591108 0x7fcc38014180 DEBUG        timecodestamper gsttimecodestamper.c:1152:gst_timecodestamper_transform_ip:<timecodestamper0> Handling video frame with running time 0:00:00.080000000
0:00:00.204027504 3591108 0x7fcc38014180 DEBUG        timecodestamper gsttimecodestamper.c:1212:gst_timecodestamper_transform_ip:<timecodestamper0> Incremented internal timecode to 00:00:00:02
0:00:00.204031314 3591108 0x7fcc38014180 DEBUG        timecodestamper gsttimecodestamper.c:1228:gst_timecodestamper_transform_ip:<timecodestamper0> Updated upstream timecode to 00:01:02:07
0:00:00.204043554 3591108 0x7fcc38014180 DEBUG        timecodestamper gsttimecodestamper.c:1272:gst_timecodestamper_transform_ip:<timecodestamper0> Created RTC timecode 10:56:34:06 for 2024-04-02 10:56 +0200 (241755 us)
0:00:00.204048704 3591108 0x7fcc38014180 DEBUG        timecodestamper gsttimecodestamper.c:1315:gst_timecodestamper_transform_ip:<timecodestamper0> Incremented RTC timecode to 10:56:34:07 (-0:00:00.040000000 drift)
0:00:00.212613464 3591108 0x7fcc38014180 DEBUG        timecodestamper gsttimecodestamper.c:1152:gst_timecodestamper_transform_ip:<timecodestamper0> Handling video frame with running time 0:00:00.120000000
0:00:00.212635324 3591108 0x7fcc38014180 DEBUG        timecodestamper gsttimecodestamper.c:1212:gst_timecodestamper_transform_ip:<timecodestamper0> Incremented internal timecode to 00:00:00:03
0:00:00.212639454 3591108 0x7fcc38014180 DEBUG        timecodestamper gsttimecodestamper.c:1228:gst_timecodestamper_transform_ip:<timecodestamper0> Updated upstream timecode to 00:01:02:07
0:00:00.212651504 3591108 0x7fcc38014180 DEBUG        timecodestamper gsttimecodestamper.c:1272:gst_timecodestamper_transform_ip:<timecodestamper0> Created RTC timecode 10:56:34:06 for 2024-04-02 10:56 +0200 (250360 us)
0:00:00.212666034 3591108 0x7fcc38014180 DEBUG        timecodestamper gsttimecodestamper.c:1315:gst_timecodestamper_transform_ip:<timecodestamper0> Incremented RTC timecode to 10:56:34:08 (-0:00:00.080000000 drift)
0:00:00.218078810 3591108 0x7fcc38014180 DEBUG        timecodestamper gsttimecodestamper.c:1152:gst_timecodestamper_transform_ip:<timecodestamper0> Handling video frame with running time 0:00:00.160000000
0:00:00.218102190 3591108 0x7fcc38014180 DEBUG        timecodestamper gsttimecodestamper.c:1212:gst_timecodestamper_transform_ip:<timecodestamper0> Incremented internal timecode to 00:00:00:04
0:00:00.218106190 3591108 0x7fcc38014180 DEBUG        timecodestamper gsttimecodestamper.c:1228:gst_timecodestamper_transform_ip:<timecodestamper0> Updated upstream timecode to 00:01:02:08
0:00:00.218119730 3591108 0x7fcc38014180 DEBUG        timecodestamper gsttimecodestamper.c:1272:gst_timecodestamper_transform_ip:<timecodestamper0> Created RTC timecode 10:56:34:06 for 2024-04-02 10:56 +0200 (255823 us)
0:00:00.218124060 3591108 0x7fcc38014180 DEBUG        timecodestamper gsttimecodestamper.c:1315:gst_timecodestamper_transform_ip:<timecodestamper0> Incremented RTC timecode to 10:56:34:09 (-0:00:00.120000000 drift)
0:00:00.222132872 3591108 0x7fcc38014180 DEBUG        timecodestamper gsttimecodestamper.c:1152:gst_timecodestamper_transform_ip:<timecodestamper0> Handling video frame with running time 0:00:00.200000000
0:00:00.222150291 3591108 0x7fcc38014180 DEBUG        timecodestamper gsttimecodestamper.c:1212:gst_timecodestamper_transform_ip:<timecodestamper0> Incremented internal timecode to 00:00:00:05
0:00:00.222154181 3591108 0x7fcc38014180 DEBUG        timecodestamper gsttimecodestamper.c:1228:gst_timecodestamper_transform_ip:<timecodestamper0> Updated upstream timecode to 00:01:02:08
0:00:00.222165371 3591108 0x7fcc38014180 DEBUG        timecodestamper gsttimecodestamper.c:1272:gst_timecodestamper_transform_ip:<timecodestamper0> Created RTC timecode 10:56:34:06 for 2024-04-02 10:56 +0200 (259881 us)
0:00:00.222170421 3591108 0x7fcc38014180 DEBUG        timecodestamper gsttimecodestamper.c:1315:gst_timecodestamper_transform_ip:<timecodestamper0> Incremented RTC timecode to 10:56:34:10 (-0:00:00.160000000 drift)
0:00:00.225642356 3591108 0x7fcc38014180 DEBUG        timecodestamper gsttimecodestamper.c:1152:gst_timecodestamper_transform_ip:<timecodestamper0> Handling video frame with running time 0:00:00.240000000
0:00:00.225665126 3591108 0x7fcc38014180 DEBUG        timecodestamper gsttimecodestamper.c:1212:gst_timecodestamper_transform_ip:<timecodestamper0> Incremented internal timecode to 00:00:00:06
0:00:00.225669436 3591108 0x7fcc38014180 DEBUG        timecodestamper gsttimecodestamper.c:1228:gst_timecodestamper_transform_ip:<timecodestamper0> Updated upstream timecode to 00:01:02:09
0:00:00.225682526 3591108 0x7fcc38014180 DEBUG        timecodestamper gsttimecodestamper.c:1272:gst_timecodestamper_transform_ip:<timecodestamper0> Created RTC timecode 10:56:34:07 for 2024-04-02 10:56 +0200 (263388 us)
0:00:00.225687416 3591108 0x7fcc38014180 DEBUG        timecodestamper gsttimecodestamper.c:1315:gst_timecodestamper_transform_ip:<timecodestamper0> Incremented RTC timecode to 10:56:34:11 (-0:00:00.160000000 drift)
0:00:00.232291676 3591108 0x7fcc38014180 DEBUG        timecodestamper gsttimecodestamper.c:1152:gst_timecodestamper_transform_ip:<timecodestamper0> Handling video frame with running time 0:00:00.280000000
0:00:00.232311066 3591108 0x7fcc38014180 DEBUG        timecodestamper gsttimecodestamper.c:1212:gst_timecodestamper_transform_ip:<timecodestamper0> Incremented internal timecode to 00:00:00:07
0:00:00.232315056 3591108 0x7fcc38014180 DEBUG        timecodestamper gsttimecodestamper.c:1228:gst_timecodestamper_transform_ip:<timecodestamper0> Updated upstream timecode to 00:01:02:09
0:00:00.232326316 3591108 0x7fcc38014180 DEBUG        timecodestamper gsttimecodestamper.c:1272:gst_timecodestamper_transform_ip:<timecodestamper0> Created RTC timecode 10:56:34:07 for 2024-04-02 10:56 +0200 (270039 us)
0:00:00.232338536 3591108 0x7fcc38014180 DEBUG        timecodestamper gsttimecodestamper.c:1315:gst_timecodestamper_transform_ip:<timecodestamper0> Incremented RTC timecode to 10:56:34:12 (-0:00:00.200000000 drift)
0:00:00.238551008 3591108 0x7fcc38014180 DEBUG        timecodestamper gsttimecodestamper.c:1152:gst_timecodestamper_transform_ip:<timecodestamper0> Handling video frame with running time 0:00:00.320000000
0:00:00.238567928 3591108 0x7fcc38014180 DEBUG        timecodestamper gsttimecodestamper.c:1212:gst_timecodestamper_transform_ip:<timecodestamper0> Incremented internal timecode to 00:00:00:08
0:00:00.238571618 3591108 0x7fcc38014180 DEBUG        timecodestamper gsttimecodestamper.c:1228:gst_timecodestamper_transform_ip:<timecodestamper0> Updated upstream timecode to 00:01:02:10
0:00:00.238583548 3591108 0x7fcc38014180 DEBUG        timecodestamper gsttimecodestamper.c:1272:gst_timecodestamper_transform_ip:<timecodestamper0> Created RTC timecode 10:56:34:07 for 2024-04-02 10:56 +0200 (276298 us)
0:00:00.238587708 3591108 0x7fcc38014180 DEBUG        timecodestamper gsttimecodestamper.c:1315:gst_timecodestamper_transform_ip:<timecodestamper0> Incremented RTC timecode to 10:56:34:13 (-0:00:00.240000000 drift)
0:00:00.248982171 3591108 0x7fcc38014180 DEBUG        timecodestamper gsttimecodestamper.c:847:gst_timecodestamper_sink_event:<timecodestamper0> received event tag event: 0x7fcc2c066170, time 99:99:99.999999999, seq-num 270, GstTagList-stream, taglist=(taglist)"taglist\,\ video-codec\=\(string\)\"H.264\\\ \\\(High\\\ Profile\\\)\"\,\ maximum-bitrate\=\(uint\)11121904\,\ bitrate\=\(uint\)8355902\,\ minimum-bitrate\=\(uint\)20572000\;";
0:00:00.249028481 3591108 0x7fcc38014180 DEBUG        timecodestamper gsttimecodestamper.c:847:gst_timecodestamper_sink_event:<timecodestamper0> received event tag event: 0x7fcc2c0662c0, time 99:99:99.999999999, seq-num 272, GstTagList-stream, taglist=(taglist)"taglist\,\ video-codec\=\(string\)\"H.264\\\ \\\(High\\\ Profile\\\)\"\,\ maximum-bitrate\=\(uint\)11121904\,\ bitrate\=\(uint\)8355902\,\ minimum-bitrate\=\(uint\)8319400\;";
0:00:00.249039961 3591108 0x7fcc38014180 DEBUG        timecodestamper gsttimecodestamper.c:847:gst_timecodestamper_sink_event:<timecodestamper0> received event tag event: 0x7fcc2c066100, time 99:99:99.999999999, seq-num 274, GstTagList-stream, taglist=(taglist)"taglist\,\ video-codec\=\(string\)\"H.264\\\ \\\(High\\\ Profile\\\)\"\,\ maximum-bitrate\=\(uint\)11121904\,\ bitrate\=\(uint\)8355902\,\ minimum-bitrate\=\(uint\)4174200\;";
0:00:00.249231290 3591108 0x7fcc38014180 DEBUG        timecodestamper gsttimecodestamper.c:1152:gst_timecodestamper_transform_ip:<timecodestamper0> Handling video frame with running time 0:00:00.360000000
0:00:00.249238010 3591108 0x7fcc38014180 DEBUG        timecodestamper gsttimecodestamper.c:1212:gst_timecodestamper_transform_ip:<timecodestamper0> Incremented internal timecode to 00:00:00:09
0:00:00.249241520 3591108 0x7fcc38014180 DEBUG        timecodestamper gsttimecodestamper.c:1228:gst_timecodestamper_transform_ip:<timecodestamper0> Updated upstream timecode to 00:01:02:10
0:00:00.249254060 3591108 0x7fcc38014180 DEBUG        timecodestamper gsttimecodestamper.c:1272:gst_timecodestamper_transform_ip:<timecodestamper0> Created RTC timecode 10:56:34:07 for 2024-04-02 10:56 +0200 (286986 us)
0:00:00.249259220 3591108 0x7fcc38014180 DEBUG        timecodestamper gsttimecodestamper.c:1308:gst_timecodestamper_transform_ip:<timecodestamper0> Updated RTC timecode to 10:56:34:07 (-0:00:00.280000000 drift)
0:00:00.259347975 3591108 0x7fcc38014180 DEBUG        timecodestamper gsttimecodestamper.c:1152:gst_timecodestamper_transform_ip:<timecodestamper0> Handling video frame with running time 0:00:00.400000000
0:00:00.259370605 3591108 0x7fcc38014180 DEBUG        timecodestamper gsttimecodestamper.c:1212:gst_timecodestamper_transform_ip:<timecodestamper0> Incremented internal timecode to 00:00:00:10
0:00:00.259383005 3591108 0x7fcc38014180 DEBUG        timecodestamper gsttimecodestamper.c:1228:gst_timecodestamper_transform_ip:<timecodestamper0> Updated upstream timecode to 00:01:02:11
0:00:00.259396595 3591108 0x7fcc38014180 DEBUG        timecodestamper gsttimecodestamper.c:1272:gst_timecodestamper_transform_ip:<timecodestamper0> Created RTC timecode 10:56:34:07 for 2024-04-02 10:56 +0200 (297095 us)
0:00:00.259401475 3591108 0x7fcc38014180 DEBUG        timecodestamper gsttimecodestamper.c:1315:gst_timecodestamper_transform_ip:<timecodestamper0> Incremented RTC timecode to 10:56:34:08 (-0:00:00.040000000 drift)
0:00:00.269463399 3591108 0x7fcc38014180 DEBUG        timecodestamper gsttimecodestamper.c:1152:gst_timecodestamper_transform_ip:<timecodestamper0> Handling video frame with running time 0:00:00.440000000
0:00:00.269484629 3591108 0x7fcc38014180 DEBUG        timecodestamper gsttimecodestamper.c:1212:gst_timecodestamper_transform_ip:<timecodestamper0> Incremented internal timecode to 00:00:00:11
0:00:00.269488449 3591108 0x7fcc38014180 DEBUG        timecodestamper gsttimecodestamper.c:1228:gst_timecodestamper_transform_ip:<timecodestamper0> Updated upstream timecode to 00:01:02:11
0:00:00.269500709 3591108 0x7fcc38014180 DEBUG        timecodestamper gsttimecodestamper.c:1272:gst_timecodestamper_transform_ip:<timecodestamper0> Created RTC timecode 10:56:34:08 for 2024-04-02 10:56 +0200 (307210 us)
0:00:00.269505159 3591108 0x7fcc38014180 DEBUG        timecodestamper gsttimecodestamper.c:1315:gst_timecodestamper_transform_ip:<timecodestamper0> Incremented RTC timecode to 10:56:34:09 (-0:00:00.040000000 drift)
0:00:00.279658863 3591108 0x7fcc38014180 DEBUG        timecodestamper gsttimecodestamper.c:1152:gst_timecodestamper_transform_ip:<timecodestamper0> Handling video frame with running time 0:00:00.480000000
0:00:00.279680523 3591108 0x7fcc38014180 DEBUG        timecodestamper gsttimecodestamper.c:1212:gst_timecodestamper_transform_ip:<timecodestamper0> Incremented internal timecode to 00:00:00:12
0:00:00.279684493 3591108 0x7fcc38014180 DEBUG        timecodestamper gsttimecodestamper.c:1228:gst_timecodestamper_transform_ip:<timecodestamper0> Updated upstream timecode to 00:01:02:12
0:00:00.279697023 3591108 0x7fcc38014180 DEBUG        timecodestamper gsttimecodestamper.c:1272:gst_timecodestamper_transform_ip:<timecodestamper0> Created RTC timecode 10:56:34:08 for 2024-04-02 10:56 +0200 (317406 us)
0:00:00.279701773 3591108 0x7fcc38014180 DEBUG        timecodestamper gsttimecodestamper.c:1315:gst_timecodestamper_transform_ip:<timecodestamper0> Incremented RTC timecode to 10:56:34:10 (-0:00:00.080000000 drift)
0:00:00.289749638 3591108 0x7fcc38014180 DEBUG        timecodestamper gsttimecodestamper.c:847:gst_timecodestamper_sink_event:<timecodestamper0> received event tag event: 0x7fcc2c00dec0, time 99:99:99.999999999, seq-num 279, GstTagList-stream, taglist=(taglist)"taglist\,\ video-codec\=\(string\)\"H.264\\\ \\\(High\\\ Profile\\\)\"\,\ maximum-bitrate\=\(uint\)11121904\,\ bitrate\=\(uint\)8355902\,\ minimum-bitrate\=\(uint\)3571200\;";
0:00:00.289967257 3591108 0x7fcc38014180 DEBUG        timecodestamper gsttimecodestamper.c:1152:gst_timecodestamper_transform_ip:<timecodestamper0> Handling video frame with running time 0:00:00.520000000
0:00:00.289973407 3591108 0x7fcc38014180 DEBUG        timecodestamper gsttimecodestamper.c:1212:gst_timecodestamper_transform_ip:<timecodestamper0> Incremented internal timecode to 00:00:00:13
0:00:00.289976787 3591108 0x7fcc38014180 DEBUG        timecodestamper gsttimecodestamper.c:1228:gst_timecodestamper_transform_ip:<timecodestamper0> Updated upstream timecode to 00:01:03:00
0:00:00.289988707 3591108 0x7fcc38014180 DEBUG        timecodestamper gsttimecodestamper.c:1272:gst_timecodestamper_transform_ip:<timecodestamper0> Created RTC timecode 10:56:34:08 for 2024-04-02 10:56 +0200 (327721 us)
0:00:00.289993207 3591108 0x7fcc38014180 DEBUG        timecodestamper gsttimecodestamper.c:1315:gst_timecodestamper_transform_ip:<timecodestamper0> Incremented RTC timecode to 10:56:34:11 (-0:00:00.120000000 drift)
0:00:00.299376815 3591108 0x7fcc38014180 DEBUG        timecodestamper gsttimecodestamper.c:1152:gst_timecodestamper_transform_ip:<timecodestamper0> Handling video frame with running time 0:00:00.560000000
0:00:00.299395325 3591108 0x7fcc38014180 DEBUG        timecodestamper gsttimecodestamper.c:1212:gst_timecodestamper_transform_ip:<timecodestamper0> Incremented internal timecode to 00:00:00:14
0:00:00.299399415 3591108 0x7fcc38014180 DEBUG        timecodestamper gsttimecodestamper.c:1228:gst_timecodestamper_transform_ip:<timecodestamper0> Updated upstream timecode to 00:01:03:00
0:00:00.299413105 3591108 0x7fcc38014180 DEBUG        timecodestamper gsttimecodestamper.c:1272:gst_timecodestamper_transform_ip:<timecodestamper0> Created RTC timecode 10:56:34:08 for 2024-04-02 10:56 +0200 (337124 us)
0:00:00.299418075 3591108 0x7fcc38014180 DEBUG        timecodestamper gsttimecodestamper.c:1315:gst_timecodestamper_transform_ip:<timecodestamper0> Incremented RTC timecode to 10:56:34:12 (-0:00:00.160000000 drift)
0:00:00.310924213 3591108 0x7fcc38014180 DEBUG        timecodestamper gsttimecodestamper.c:847:gst_timecodestamper_sink_event:<timecodestamper0> received event tag event: 0x7fcbed55e120, time 99:99:99.999999999, seq-num 281, GstTagList-stream, taglist=(taglist)"taglist\,\ video-codec\=\(string\)\"H.264\\\ \\\(High\\\ Profile\\\)\"\,\ maximum-bitrate\=\(uint\)11121904\,\ bitrate\=\(uint\)8355902\,\ minimum-bitrate\=\(uint\)3454800\;";
0:00:00.311144352 3591108 0x7fcc38014180 DEBUG        timecodestamper gsttimecodestamper.c:1152:gst_timecodestamper_transform_ip:<timecodestamper0> Handling video frame with running time 0:00:00.600000000
0:00:00.311151092 3591108 0x7fcc38014180 DEBUG        timecodestamper gsttimecodestamper.c:1212:gst_timecodestamper_transform_ip:<timecodestamper0> Incremented internal timecode to 00:00:00:15
0:00:00.311154762 3591108 0x7fcc38014180 DEBUG        timecodestamper gsttimecodestamper.c:1228:gst_timecodestamper_transform_ip:<timecodestamper0> Updated upstream timecode to 00:01:03:01
0:00:00.311166582 3591108 0x7fcc38014180 DEBUG        timecodestamper gsttimecodestamper.c:1272:gst_timecodestamper_transform_ip:<timecodestamper0> Created RTC timecode 10:56:34:09 for 2024-04-02 10:56 +0200 (348899 us)
0:00:00.311171242 3591108 0x7fcc38014180 DEBUG        timecodestamper gsttimecodestamper.c:1315:gst_timecodestamper_transform_ip:<timecodestamper0> Incremented RTC timecode to 10:56:34:13 (-0:00:00.160000000 drift)
0:00:00.322555961 3591108 0x7fcc38014180 DEBUG        timecodestamper gsttimecodestamper.c:1152:gst_timecodestamper_transform_ip:<timecodestamper0> Handling video frame with running time 0:00:00.640000000
0:00:00.322577821 3591108 0x7fcc38014180 DEBUG        timecodestamper gsttimecodestamper.c:1212:gst_timecodestamper_transform_ip:<timecodestamper0> Incremented internal timecode to 00:00:00:16
0:00:00.322581801 3591108 0x7fcc38014180 DEBUG        timecodestamper gsttimecodestamper.c:1228:gst_timecodestamper_transform_ip:<timecodestamper0> Updated upstream timecode to 00:01:03:01
0:00:00.322596800 3591108 0x7fcc38014180 DEBUG        timecodestamper gsttimecodestamper.c:1272:gst_timecodestamper_transform_ip:<timecodestamper0> Created RTC timecode 10:56:34:09 for 2024-04-02 10:56 +0200 (360304 us)
0:00:00.322601360 3591108 0x7fcc38014180 DEBUG        timecodestamper gsttimecodestamper.c:1315:gst_timecodestamper_transform_ip:<timecodestamper0> Incremented RTC timecode to 10:56:34:14 (-0:00:00.200000000 drift)

[...]

So the sequence of timecodes in input and the ones printed on the frame by timeoverlay are:

  Frame Num.   Original Timecode     Timeoverlay Timecode
------------  --------------------  -----------------------
           0  00:01:02:12           00:01:02:06
           1  00:01:02:13           00:01:02:06
           2  00:01:02:14           00:01:02:07
           3  00:01:02:15           00:01:02:07
           4  00:01:02:16           00:01:02:08
           5  00:01:02:17           00:01:02:08
           6  00:01:02:18           00:01:02:09
           7  00:01:02:19           00:01:02:09
           8  00:01:02:20           00:01:02:10
           9  00:01:02:21           00:01:02:10
          10  00:01:02:22           00:01:02:11
          11  00:01:02:23           00:01:02:11
          12  00:01:02:24           00:01:02:12
          13  00:01:03:00           00:01:03:00
          14  00:01:03:01           00:01:03:00
          15  00:01:03:02           00:01:03:01
          16  00:01:03:03           00:01:03:01
          17  00:01:03:04           00:01:03:02
          18  00:01:03:05           00:01:03:02
          19  00:01:03:06           00:01:03:03
          20  00:01:03:07           00:01:03:03
          [...]

Problem 2

Moreover, the output file does not contain timing information, as timecodes are not written automatically by x264. Is there a way to write timecode in the output stream? Maybe an output codec that does this automatically?

slomo · April 3, 2024, 8:32am

This looks like a problem in the stream. The VUI parameters are wrong, causing the frame count in the timecode to be divided by 2 while they shouldn’t.

The code in question is in h264parse and around the lines this MR is touching: https://gitlab.freedesktop.org/gstreamer/gstreamer/-/merge_requests/5254

That MR also adds a long comment explaining the calculations that are done there so you can compare the with your software producing the stream and fix it there accordingly.

This should work if you put a h264parse update-timecode=true after the encoder.

ivan94fi · April 3, 2024, 3:02pm

Hi, thank you for your answer.

I analized the stream with a free software (YUVView) and this is the result for VUI Parameters:

Can you spot something wrong? I see that time_scale is double of the frame rate, but I don’t know if that can cause problems.

In the meantime I will investigate the merge request you linked from Gitlab to understand better.

I tried this and all I got was a lot of errors like this, and no timecode in output:

WARNING: from element /GstPipeline:pipeline0/GstH264Parse:h264parse0: Element doesn't implement handling of this stream. Please file a bug.
Additional debug info:
../gst/videoparsers/gsth264parse.c(2938): gst_h264_parse_create_pic_timing_sei (): /GstPipeline:pipeline0/GstH264Parse:h264parse0:
timecode update was requested but VUI doesn't support timecode

These errors also appear in this pipeline which does not depend from my possibly broken video:

gst-launch-1.0 videotestsrc ! timecodestamper ! x264enc ! h264parse update-timecode=true ! matroskamux ! filesink location=gst_update_timecode.mkv

seungha · April 3, 2024, 5:49pm

Checks nuit_field_based_flag in VUI. It should be 1 but I guess it’s 0 in your bitstream.

For inband timecode update, the stream must contain VUI and pic-struct. Try this
videotestsrc ! timecodestamper ! x264enc insert-vui=true option-string="pic-struct" ! h264parse update-timecode=true

ivan94fi · April 4, 2024, 12:43pm

Hi, you are correct, the field nuit_field_based_flag is set at 0 as you can see:

I can confirm that adding insert-vui=true option-string="pic-struct" in x264enc settings makes the inband timecode work.

Thank you