[FFmpeg-cvslog] fftools/sync_queue: add debug logging
Anton Khirnov
git at videolan.org
Sun May 28 11:52:50 EEST 2023
ffmpeg | branch: master | Anton Khirnov <anton at khirnov.net> | Tue May 23 15:45:37 2023 +0200| [e9a868e9eef5215b468244596e2103a3add7759f] | committer: Anton Khirnov
fftools/sync_queue: add debug logging
> http://git.videolan.org/gitweb.cgi/ffmpeg.git/?a=commit;h=e9a868e9eef5215b468244596e2103a3add7759f
---
fftools/ffmpeg_mux_init.c | 4 ++--
fftools/sync_queue.c | 40 +++++++++++++++++++++++++++++++++++++---
fftools/sync_queue.h | 2 +-
3 files changed, 40 insertions(+), 6 deletions(-)
diff --git a/fftools/ffmpeg_mux_init.c b/fftools/ffmpeg_mux_init.c
index dc33d225df..7878789bb4 100644
--- a/fftools/ffmpeg_mux_init.c
+++ b/fftools/ffmpeg_mux_init.c
@@ -1625,7 +1625,7 @@ static int setup_sync_queues(Muxer *mux, AVFormatContext *oc, int64_t buf_size_u
* - at least one audio encoder requires constant frame sizes
*/
if ((of->shortest && nb_av_enc > 1) || limit_frames_av_enc || nb_audio_fs) {
- of->sq_encode = sq_alloc(SYNC_QUEUE_FRAMES, buf_size_us);
+ of->sq_encode = sq_alloc(SYNC_QUEUE_FRAMES, buf_size_us, mux);
if (!of->sq_encode)
return AVERROR(ENOMEM);
@@ -1650,7 +1650,7 @@ static int setup_sync_queues(Muxer *mux, AVFormatContext *oc, int64_t buf_size_u
/* if there are any additional interleaved streams, then ALL the streams
* are also synchronized before sending them to the muxer */
if (nb_interleaved > nb_av_enc) {
- mux->sq_mux = sq_alloc(SYNC_QUEUE_PACKETS, buf_size_us);
+ mux->sq_mux = sq_alloc(SYNC_QUEUE_PACKETS, buf_size_us, mux);
if (!mux->sq_mux)
return AVERROR(ENOMEM);
diff --git a/fftools/sync_queue.c b/fftools/sync_queue.c
index a7aac04047..c0f33e9235 100644
--- a/fftools/sync_queue.c
+++ b/fftools/sync_queue.c
@@ -27,6 +27,7 @@
#include "libavutil/mathematics.h"
#include "libavutil/mem.h"
#include "libavutil/samplefmt.h"
+#include "libavutil/timestamp.h"
#include "objpool.h"
#include "sync_queue.h"
@@ -87,6 +88,8 @@ typedef struct SyncQueueStream {
struct SyncQueue {
enum SyncQueueType type;
+ void *logctx;
+
/* no more frames will be sent for any stream */
int finished;
/* sync head: the stream with the _smallest_ head timestamp
@@ -169,6 +172,11 @@ static void finish_stream(SyncQueue *sq, unsigned int stream_idx)
{
SyncQueueStream *st = &sq->streams[stream_idx];
+ if (!st->finished)
+ av_log(sq->logctx, AV_LOG_DEBUG,
+ "sq: finish %u; head ts %s\n", stream_idx,
+ av_ts2timestr(st->head_ts, &st->tb));
+
st->finished = 1;
if (st->limiting && st->head_ts != AV_NOPTS_VALUE) {
@@ -186,8 +194,14 @@ static void finish_stream(SyncQueue *sq, unsigned int stream_idx)
for (unsigned int i = 0; i < sq->nb_streams; i++) {
SyncQueueStream *st1 = &sq->streams[i];
if (st != st1 && st1->head_ts != AV_NOPTS_VALUE &&
- av_compare_ts(st->head_ts, st->tb, st1->head_ts, st1->tb) <= 0)
+ av_compare_ts(st->head_ts, st->tb, st1->head_ts, st1->tb) <= 0) {
+ if (!st1->finished)
+ av_log(sq->logctx, AV_LOG_DEBUG,
+ "sq: finish secondary %u; head ts %s\n", i,
+ av_ts2timestr(st1->head_ts, &st1->tb));
+
st1->finished = 1;
+ }
}
}
@@ -197,6 +211,8 @@ static void finish_stream(SyncQueue *sq, unsigned int stream_idx)
return;
}
sq->finished = 1;
+
+ av_log(sq->logctx, AV_LOG_DEBUG, "sq: finish queue\n");
}
static void queue_head_update(SyncQueue *sq)
@@ -306,6 +322,9 @@ static int overflow_heartbeat(SyncQueue *sq, int stream_idx)
if (st1->head_ts != AV_NOPTS_VALUE)
ts = FFMAX(st1->head_ts + 1, ts);
+ av_log(sq->logctx, AV_LOG_DEBUG, "sq: %u overflow heardbeat %s -> %s\n",
+ i, av_ts2timestr(st1->head_ts, &st1->tb), av_ts2timestr(ts, &st1->tb));
+
stream_update_ts(sq, i, ts);
}
@@ -323,6 +342,7 @@ int sq_send(SyncQueue *sq, unsigned int stream_idx, SyncQueueFrame frame)
st = &sq->streams[stream_idx];
if (frame_null(sq, frame)) {
+ av_log(sq->logctx, AV_LOG_DEBUG, "sq: %u EOF\n", stream_idx);
finish_stream(sq, stream_idx);
return 0;
}
@@ -347,6 +367,9 @@ int sq_send(SyncQueue *sq, unsigned int stream_idx, SyncQueueFrame frame)
ts = frame_end(sq, dst, 0);
+ av_log(sq->logctx, AV_LOG_DEBUG, "sq: send %u ts %s\n", stream_idx,
+ av_ts2timestr(ts, &st->tb));
+
ret = av_fifo_write(st->fifo, &dst, 1);
if (ret < 0) {
frame_move(sq, frame, dst);
@@ -364,8 +387,12 @@ int sq_send(SyncQueue *sq, unsigned int stream_idx, SyncQueueFrame frame)
else
st->frames_sent++;
- if (st->frames_sent >= st->frames_max)
+ if (st->frames_sent >= st->frames_max) {
+ av_log(sq->logctx, AV_LOG_DEBUG, "sq: %u frames_max %"PRIu64" reached\n",
+ stream_idx, st->frames_max);
+
finish_stream(sq, stream_idx);
+ }
return 0;
}
@@ -531,6 +558,12 @@ static int receive_for_stream(SyncQueue *sq, unsigned int stream_idx,
st->samples_queued -= frame_samples(sq, frame);
}
+ av_log(sq->logctx, AV_LOG_DEBUG,
+ "sq: receive %u ts %s queue head %d ts %s\n", stream_idx,
+ av_ts2timestr(frame_end(sq, frame, 0), &st->tb),
+ sq->head_stream,
+ st_head ? av_ts2timestr(st_head->head_ts, &st_head->tb) : "N/A");
+
return 0;
}
}
@@ -630,7 +663,7 @@ void sq_frame_samples(SyncQueue *sq, unsigned int stream_idx,
sq->align_mask = av_cpu_max_align() - 1;
}
-SyncQueue *sq_alloc(enum SyncQueueType type, int64_t buf_size_us)
+SyncQueue *sq_alloc(enum SyncQueueType type, int64_t buf_size_us, void *logctx)
{
SyncQueue *sq = av_mallocz(sizeof(*sq));
@@ -639,6 +672,7 @@ SyncQueue *sq_alloc(enum SyncQueueType type, int64_t buf_size_us)
sq->type = type;
sq->buf_size_us = buf_size_us;
+ sq->logctx = logctx;
sq->head_stream = -1;
sq->head_finished_stream = -1;
diff --git a/fftools/sync_queue.h b/fftools/sync_queue.h
index bc7cd42390..dc5acfd499 100644
--- a/fftools/sync_queue.h
+++ b/fftools/sync_queue.h
@@ -50,7 +50,7 @@ typedef struct SyncQueue SyncQueue;
*
* @param buf_size_us maximum duration that will be buffered in microseconds
*/
-SyncQueue *sq_alloc(enum SyncQueueType type, int64_t buf_size_us);
+SyncQueue *sq_alloc(enum SyncQueueType type, int64_t buf_size_us, void *logctx);
void sq_free(SyncQueue **sq);
/**
More information about the ffmpeg-cvslog
mailing list