From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: from ffbox0-bg.mplayerhq.hu (ffbox0-bg.ffmpeg.org [79.124.17.100]) by master.gitmailbox.com (Postfix) with ESMTP id 6F3E74864A for ; Tue, 12 Dec 2023 12:10:17 +0000 (UTC) Received: from [127.0.1.1] (localhost [127.0.0.1]) by ffbox0-bg.mplayerhq.hu (Postfix) with ESMTP id 2BE7068D13F; Tue, 12 Dec 2023 14:10:15 +0200 (EET) Received: from mail1.khirnov.net (quelana.khirnov.net [94.230.150.81]) by ffbox0-bg.mplayerhq.hu (Postfix) with ESMTPS id 2DF2068D008 for ; Tue, 12 Dec 2023 14:10:08 +0200 (EET) Received: from localhost (mail1.khirnov.net [IPv6:::1]) by mail1.khirnov.net (Postfix) with ESMTP id 8772E1BA2 for ; Tue, 12 Dec 2023 13:10:07 +0100 (CET) Received: from mail1.khirnov.net ([IPv6:::1]) by localhost (mail1.khirnov.net [IPv6:::1]) (amavis, port 10024) with ESMTP id Co9lraV-S3jf for ; Tue, 12 Dec 2023 13:10:06 +0100 (CET) Received: from libav.khirnov.net (libav.khirnov.net [IPv6:2a00:c500:561:201::7]) (using TLSv1.3 with cipher TLS_AES_256_GCM_SHA384 (256/256 bits) key-exchange X25519 server-signature RSA-PSS (2048 bits) server-digest SHA256 client-signature RSA-PSS (2048 bits) client-digest SHA256) (Client CN "libav.khirnov.net", Issuer "smtp.khirnov.net SMTP CA" (verified OK)) by mail1.khirnov.net (Postfix) with ESMTPS id C156612B6 for ; Tue, 12 Dec 2023 13:10:06 +0100 (CET) Received: from libav.khirnov.net (libav.khirnov.net [IPv6:::1]) by libav.khirnov.net (Postfix) with ESMTP id AD8233A05D0 for ; Tue, 12 Dec 2023 13:09:59 +0100 (CET) From: Anton Khirnov To: ffmpeg-devel@ffmpeg.org Date: Tue, 12 Dec 2023 13:09:58 +0100 Message-ID: <20231212120958.21313-3-anton@khirnov.net> X-Mailer: git-send-email 2.42.0 In-Reply-To: <20231212120958.21313-1-anton@khirnov.net> References: <20231212120958.21313-1-anton@khirnov.net> MIME-Version: 1.0 Subject: [FFmpeg-devel] [PATCH 3/3] fftools/ffmpeg_mux: print latency information in -debug_ts muxing output X-BeenThere: ffmpeg-devel@ffmpeg.org X-Mailman-Version: 2.1.29 Precedence: list List-Id: FFmpeg development discussions and patches List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Reply-To: FFmpeg development discussions and patches Content-Type: text/plain; charset="us-ascii" Content-Transfer-Encoding: 7bit Errors-To: ffmpeg-devel-bounces@ffmpeg.org Sender: "ffmpeg-devel" Archived-At: List-Archive: List-Post: --- fftools/ffmpeg_mux.c | 87 +++++++++++++++++++++++++++++++++++++++----- 1 file changed, 77 insertions(+), 10 deletions(-) diff --git a/fftools/ffmpeg_mux.c b/fftools/ffmpeg_mux.c index 62925be8d0..ca1996622d 100644 --- a/fftools/ffmpeg_mux.c +++ b/fftools/ffmpeg_mux.c @@ -25,10 +25,12 @@ #include "ffmpeg_utils.h" #include "sync_queue.h" +#include "libavutil/avstring.h" #include "libavutil/fifo.h" #include "libavutil/intreadwrite.h" #include "libavutil/log.h" #include "libavutil/mem.h" +#include "libavutil/time.h" #include "libavutil/timestamp.h" #include "libavcodec/packet.h" @@ -59,6 +61,79 @@ static int64_t filesize(AVIOContext *pb) return ret; } +static void mux_log_debug_ts(OutputStream *ost, const AVPacket *pkt) +{ + static const char *desc[] = { + [LATENCY_PROBE_DEMUX] = "demux", + [LATENCY_PROBE_DEC_PRE] = "decode", + [LATENCY_PROBE_DEC_POST] = "decode", + [LATENCY_PROBE_FILTER_PRE] = "filter", + [LATENCY_PROBE_FILTER_POST] = "filter", + [LATENCY_PROBE_ENC_PRE] = "encode", + [LATENCY_PROBE_ENC_POST] = "encode", + [LATENCY_PROBE_NB] = "mux", + }; + + char latency[512] = { 0 }; + + if (pkt->opaque_ref) { + const FrameData *fd = (FrameData*)pkt->opaque_ref->data; + int64_t now = av_gettime_relative(); + int64_t total = INT64_MIN; + + int next; + + for (unsigned i = 0; i < FF_ARRAY_ELEMS(fd->wallclock); i = next) { + int64_t val = fd->wallclock[i]; + + next = i + 1; + + if (val == INT64_MIN) + continue; + + if (total == INT64_MIN) { + total = now - val; + snprintf(latency, sizeof(latency), "total:%gms", total / 1e3); + } + + // find the next valid entry + for (; next <= FF_ARRAY_ELEMS(fd->wallclock); next++) { + int64_t val_next = (next == FF_ARRAY_ELEMS(fd->wallclock)) ? + now : fd->wallclock[next]; + int64_t diff; + + if (val_next == INT64_MIN) + continue; + diff = val_next - val; + + // print those stages that take at least 5% of total + if (100. * diff > 5. * total) { + av_strlcat(latency, ", ", sizeof(latency)); + + if (!strcmp(desc[i], desc[next])) + av_strlcat(latency, desc[i], sizeof(latency)); + else + av_strlcatf(latency, sizeof(latency), "%s-%s:", + desc[i], desc[next]); + + av_strlcatf(latency, sizeof(latency), " %gms/%d%%", + diff / 1e3, (int)(100. * diff / total)); + } + + break; + } + + } + } + + av_log(ost, AV_LOG_INFO, "muxer <- pts:%s pts_time:%s dts:%s dts_time:%s " + "duration:%s duration_time:%s size:%d latency(%s)\n", + av_ts2str(pkt->pts), av_ts2timestr(pkt->pts, &ost->st->time_base), + av_ts2str(pkt->dts), av_ts2timestr(pkt->dts, &ost->st->time_base), + av_ts2str(pkt->duration), av_ts2timestr(pkt->duration, &ost->st->time_base), + pkt->size, *latency ? latency : "N/A"); +} + static int write_packet(Muxer *mux, OutputStream *ost, AVPacket *pkt) { MuxStream *ms = ms_from_ost(ost); @@ -140,16 +215,8 @@ static int write_packet(Muxer *mux, OutputStream *ost, AVPacket *pkt) pkt->stream_index = ost->index; - if (debug_ts) { - av_log(ost, AV_LOG_INFO, "muxer <- type:%s " - "pkt_pts:%s pkt_pts_time:%s pkt_dts:%s pkt_dts_time:%s duration:%s duration_time:%s size:%d\n", - av_get_media_type_string(ost->type), - av_ts2str(pkt->pts), av_ts2timestr(pkt->pts, &ost->st->time_base), - av_ts2str(pkt->dts), av_ts2timestr(pkt->dts, &ost->st->time_base), - av_ts2str(pkt->duration), av_ts2timestr(pkt->duration, &ost->st->time_base), - pkt->size - ); - } + if (debug_ts) + mux_log_debug_ts(ost, pkt); if (ms->stats.io) enc_stats_write(ost, &ms->stats, NULL, pkt, frame_num); -- 2.42.0 _______________________________________________ ffmpeg-devel mailing list ffmpeg-devel@ffmpeg.org https://ffmpeg.org/mailman/listinfo/ffmpeg-devel To unsubscribe, visit link above, or email ffmpeg-devel-request@ffmpeg.org with subject "unsubscribe".