[FFmpeg-devel] [PATCH 2/2] doc/examples/transcode: introduce timestamp logging

[Stefano Sabatini]

---
 doc/examples/transcode.c | 39 ++++++++++++++++++++++++++++++++++-----
 1 file changed, 34 insertions(+), 5 deletions(-)

diff --git a/doc/examples/transcode.c b/doc/examples/transcode.c
index 3bc85dce85..a7398db3d9 100644
--- a/doc/examples/transcode.c
+++ b/doc/examples/transcode.c
@@ -37,6 +37,7 @@
 #include <libavutil/channel_layout.h>
 #include <libavutil/opt.h>
 #include <libavutil/pixdesc.h>
+#include <libavutil/timestamp.h>
 
 static AVFormatContext *ifmt_ctx;
 static AVFormatContext *ofmt_ctx;
@@ -432,6 +433,28 @@ static int init_filters(void)
     return 0;
 }
 
+static void log_packet(AVPacket *pkt, const AVFormatContext *fmt_ctx, const char *tag)
+{
+    AVRational *time_base = &fmt_ctx->streams[pkt->stream_index]->time_base;
+
+    av_log(NULL, AV_LOG_INFO,
+           "%s [pkt] stream:%d pts_time:%s dts_time:%s\n",
+           tag, pkt->stream_index,
+           av_ts2timestr(pkt->pts, time_base),
+           av_ts2timestr(pkt->dts, time_base));
+}
+
+static void log_frame(AVFrame *frame, int stream_index, const char *tag)
+{
+    AVRational *time_base = &frame->time_base;
+
+    av_log(NULL, AV_LOG_INFO,
+           "%s [frame] stream:%d pts_time:%s dts_time:%s\n",
+           tag, stream_index,
+           av_ts2timestr(frame->pts, time_base),
+           av_ts2timestr(frame->pkt_dts, time_base));
+}
+
 static int encode_write_frame(unsigned int stream_index, int flush)
 {
     StreamContext *stream = &stream_ctx[stream_index];
@@ -440,7 +463,6 @@ static int encode_write_frame(unsigned int stream_index, int flush)
     AVPacket *enc_pkt = filter->enc_pkt;
     int ret;
 
-    av_log(NULL, AV_LOG_INFO, "Encoding frame\n");
     /* encode filtered frame */
     av_packet_unref(enc_pkt);
 
@@ -451,9 +473,10 @@ static int encode_write_frame(unsigned int stream_index, int flush)
         filt_frame->pkt_dts = av_rescale_q(filt_frame->pkt_dts, filt_frame->time_base,
                                            stream->enc_ctx->time_base);
         filt_frame->time_base = stream->enc_ctx->time_base;
+        log_frame(filt_frame, stream_index, "encoder <-");
     }
-    ret = avcodec_send_frame(stream->enc_ctx, filt_frame);
 
+    ret = avcodec_send_frame(stream->enc_ctx, filt_frame);
     if (ret < 0)
         return ret;
 
@@ -469,8 +492,8 @@ static int encode_write_frame(unsigned int stream_index, int flush)
                              stream->enc_ctx->time_base,
                              ofmt_ctx->streams[stream_index]->time_base);
 
-        av_log(NULL, AV_LOG_DEBUG, "Muxing frame\n");
         /* mux encoded frame */
+        log_packet(enc_pkt, ofmt_ctx, "muxer <-");
         ret = av_interleaved_write_frame(ofmt_ctx, enc_pkt);
     }
 
@@ -482,8 +505,11 @@ static int filter_encode_write_frame(AVFrame *frame, unsigned int stream_index)
     FilteringContext *filter = &filter_ctx[stream_index];
     int ret;
 
-    av_log(NULL, AV_LOG_INFO, "Pushing decoded frame to filters\n");
     /* push the decoded frame into the filtergraph */
+    if (frame) {
+        log_frame(frame, stream_index, "filters <-");
+    }
+
     ret = av_buffersrc_add_frame(filter->buffersrc_ctx, frame);
     if (ret < 0) {
         av_log(NULL, AV_LOG_ERROR, "Error while feeding the filtergraph\n");
@@ -492,7 +518,6 @@ static int filter_encode_write_frame(AVFrame *frame, unsigned int stream_index)
 
     /* pull filtered frames from the filtergraph */
     while (1) {
-        av_log(NULL, AV_LOG_INFO, "Pulling filtered frame from filters\n");
         ret = av_buffersink_get_frame(filter->buffersink_ctx, filter->filtered_frame);
         if (ret < 0) {
             /* if no more frames for output - returns AVERROR(EAGAIN)
@@ -505,6 +530,8 @@ static int filter_encode_write_frame(AVFrame *frame, unsigned int stream_index)
         }
 
         filter->filtered_frame->pict_type = AV_PICTURE_TYPE_NONE;
+
+        log_frame(filter->filtered_frame, stream_index, "filters ->");
         ret = encode_write_frame(stream_index, 0);
         av_frame_unref(filter->filtered_frame);
         if (ret < 0)
@@ -550,6 +577,7 @@ int main(int argc, char **argv)
             break;
         stream_index = packet->stream_index;
         av_log(NULL, AV_LOG_DEBUG, "Demuxer gave frame of stream_index %u\n", stream_index);
+        log_packet(packet, ifmt_ctx, "demuxer ->");
 
         if (filter_ctx[stream_index].filter_graph) {
             StreamContext *stream = &stream_ctx[stream_index];
@@ -584,6 +612,7 @@ int main(int argc, char **argv)
                                  ifmt_ctx->streams[stream_index]->time_base,
                                  ofmt_ctx->streams[stream_index]->time_base);
 
+            log_packet(packet, ofmt_ctx, "muxer <-");
             ret = av_interleaved_write_frame(ofmt_ctx, packet);
             if (ret < 0)
                 goto end;
-- 
2.25.1