jeka/utun2
1
0 Fork 0
Code Issues Pull Requests Projects Releases Wiki Activity

Allow video playout diagnostics outside the timer thread

Browse Source
This commit is contained in:
evgeny committed 2026-10-19 21:09:22 +02:00
1 parent 402c0c0611
commit 93f6fa1d52
2 files changed
+61 -15
Download Patch File Download Diff File Expand all files Collapse all files

No files matched your search

src/call/call_video_playout.c
+46 -15
View File
@@ -26,10 +26,30 @@ void call_video_playout_init(struct call_video_playout *p, uint64_t call_id) {
(unsigned long long)call_id, VIDEO_MAX_SPEED_PPM, VIDEO_AHEAD_US);
}
/* Сводка агрегирует штатные ожидания и пропуски; per-frame spam не нужен. */
static void report(struct call_video_playout *p, int64_t now) {
if (!p->report_us) p->report_us = now;
if (now - p->report_us < 1000000) return;
void call_video_playout_log_event(const struct call_video_playout_event *event) {
const struct call_video_playout *p = &event->state;
const struct call_video_playout_frame *f = &event->frame;
int64_t now = event->now_us;
if (event->kind == CALL_VIDEO_LOG_CLOCK) {
DEBUG_DEBUG(DEBUG_CATEGORY_CALL, "video playout clock call=%llu valid=%d pts=%lld",
(unsigned long long)p->call_id, p->audio_valid, (long long)f->pts_us); return;
}
if (event->kind == CALL_VIDEO_LOG_ORDER) {
DEBUG_WARN(DEBUG_CATEGORY_CALL, "video playout invalid/order call=%llu pts=%lld last=%lld received=%lld now=%lld interval_us=%u",
(unsigned long long)p->call_id, (long long)f->pts_us, (long long)p->last_pts,
(long long)f->received_us, (long long)now, f->interval_us); return;
}
if (event->kind == CALL_VIDEO_LOG_GAP) {
DEBUG_WARN(DEBUG_CATEGORY_CALL,
"video source gap call=%llu pts_delta_us=%lld interval_us=%u av_us=%lld display_step_us=%lld; no extra gap wait",
(unsigned long long)p->call_id, (long long)(f->pts_us - p->last_pts), f->interval_us,
(long long)p->pending_av, (long long)((int64_t)f->interval_us * 1000000 / p->speed_ppm)); return;
}
if (event->kind == CALL_VIDEO_LOG_ACK) {
DEBUG_WARN(DEBUG_CATEGORY_CALL, "video presentation ACK rejected call=%llu pts=%lld expected=%lld awaiting=%d now=%lld selected=%lld",
(unsigned long long)p->call_id, (long long)f->pts_us, (long long)p->pending.pts_us, p->awaiting,
(long long)now, (long long)p->selected_us); return;
}
DEBUG_DEBUG(DEBUG_CATEGORY_CALL,
"video playout call=%llu interval_us=%lld shown=%u speed_ppm=%u drop_order=%u "
"cadence_us=%lld..%lld gap_pts_us=%lld gap_rx_us=%lld gap_dispatch_us=%lld "
@@ -41,6 +61,21 @@ static void report(struct call_video_playout *p, int64_t now) {
(long long)(p->shown ? p->av_min : 0), (long long)(p->shown ? p->av_max : 0),
(long long)p->dispatch_max, (long long)p->data_shift, p->audio_wait, p->clock_wait,
p->source_gaps, (long long)p->source_gap_max, p->queued, p->reserve, p->awaiting, (long long)p->lead_us);
}
static void log_event(struct call_video_playout *p, enum call_video_playout_event_kind kind,
const struct call_video_playout_frame *frame, int64_t now) {
struct call_video_playout_event event = {.kind = kind, .state = *p, .now_us = now};
if (frame) event.frame = *frame;
if (p->log_event) p->log_event(p->log_arg, &event);
else call_video_playout_log_event(&event);
}
/* Сводка агрегирует штатные ожидания; timer лишь копирует событие в ограниченную очередь. */
static void report(struct call_video_playout *p, int64_t now) {
if (!p->report_us) p->report_us = now;
if (now - p->report_us < 1000000) return;
log_event(p, CALL_VIDEO_LOG_REPORT, NULL, now);
p->report_us = now; p->shown = p->order = p->audio_wait = p->clock_wait = 0;
p->interval_min = p->av_min = INT64_MAX; p->av_max = INT64_MIN;
p->interval_max = p->dispatch_max = p->data_shift = 0;
@@ -56,18 +91,16 @@ enum call_video_playout_action call_video_playout_poll(struct call_video_playout
p->queued = queued; p->reserve = reserve;
report(p, now); p->deadline_us = now + 5000;
if (p->audio_valid != !!audio_valid) {
DEBUG_DEBUG(DEBUG_CATEGORY_CALL, "video playout clock call=%llu valid=%d pts=%lld",
(unsigned long long)p->call_id, !!audio_valid, (long long)audio);
p->audio_valid = !!audio_valid;
struct call_video_playout_frame changed = {.pts_us = audio};
log_event(p, CALL_VIDEO_LOG_CLOCK, &changed, now);
}
if (!audio_valid) { p->head_pts = -1; p->clock_wait++; return CALL_VIDEO_PLAYOUT_WAIT; }
// Пустой FIFO не означает разрыв часов; срок сохраняется до появления следующей головы.
if (!f || p->awaiting) return CALL_VIDEO_PLAYOUT_WAIT;
if (f->pts_us <= p->last_pts || f->received_us < 0 || f->received_us > now
|| f->interval_us < 16666 || f->interval_us > 1000000) {
DEBUG_WARN(DEBUG_CATEGORY_CALL, "video playout invalid/order call=%llu pts=%lld last=%lld received=%lld now=%lld interval_us=%u",
(unsigned long long)p->call_id, (long long)f->pts_us, (long long)p->last_pts,
(long long)f->received_us, (long long)now, f->interval_us);
log_event(p, CALL_VIDEO_LOG_ORDER, f, now);
p->order++; return CALL_VIDEO_PLAYOUT_DROP_ORDER;
}
// Небольшой рабочий запас сохраняем; ускорение снимает избыток всего конвейера, а не только decoded FIFO.
@@ -99,9 +132,8 @@ enum call_video_playout_action call_video_playout_poll(struct call_video_playout
}
if (deadline > now) return CALL_VIDEO_PLAYOUT_WAIT;
if (delta > (int64_t)f->interval_us * 3) {
if (!p->source_gaps) DEBUG_WARN(DEBUG_CATEGORY_CALL,
"video source gap call=%llu pts_delta_us=%lld interval_us=%u av_us=%lld display_step_us=%lld; no extra gap wait",
(unsigned long long)p->call_id, (long long)delta, f->interval_us, (long long)av, (long long)step);
p->pending_av = av;
if (!p->source_gaps) log_event(p, CALL_VIDEO_LOG_GAP, f, now);
p->source_gaps++;
if (delta > p->source_gap_max) p->source_gap_max = delta;
}
@@ -112,9 +144,8 @@ enum call_video_playout_action call_video_playout_poll(struct call_video_playout
void call_video_playout_presented(struct call_video_playout *p, int64_t pts, int64_t now) {
if (!p->awaiting || p->pending.pts_us != pts || now < p->selected_us) {
DEBUG_WARN(DEBUG_CATEGORY_CALL, "video presentation ACK rejected call=%llu pts=%lld expected=%lld awaiting=%d now=%lld selected=%lld",
(unsigned long long)p->call_id, (long long)pts, (long long)p->pending.pts_us, p->awaiting,
(long long)now, (long long)p->selected_us); return;
struct call_video_playout_frame rejected = {.pts_us = pts};
log_event(p, CALL_VIDEO_LOG_ACK, &rejected, now); return;
}
const struct call_video_playout_frame *f = &p->pending;
int64_t av = p->pending_av, lead = now - p->selected_us;
src/call/call_video_playout.h
+15
View File
@@ -20,6 +20,7 @@ struct call_video_playout_frame {
enum call_video_playout_action {
CALL_VIDEO_PLAYOUT_WAIT, CALL_VIDEO_PLAYOUT_SHOW, CALL_VIDEO_PLAYOUT_DROP_ORDER
};
struct call_video_playout_event;
struct call_video_playout {
uint64_t call_id;
int anchored, audio_valid;
@@ -34,7 +35,21 @@ struct call_video_playout {
int awaiting;
int64_t selected_us, pending_av, head_pts, head_due_us, lead_us, rate_us;
unsigned queued, reserve; // reserve — будущие кадры сверх головы, включая необходимый pipeline backend.
// NULL пишет DEBUG напрямую; timer устанавливает неблокирующий callback с копированием события.
void (*log_event)(void *, const struct call_video_playout_event *);
void *log_arg;
};
enum call_video_playout_event_kind {
CALL_VIDEO_LOG_REPORT, CALL_VIDEO_LOG_CLOCK, CALL_VIDEO_LOG_ORDER, CALL_VIDEO_LOG_GAP, CALL_VIDEO_LOG_ACK
};
struct call_video_playout_event {
enum call_video_playout_event_kind kind;
struct call_video_playout state; // Снимок принадлежит событию, указатели logger не разыменовываются reporter.
struct call_video_playout_frame frame;
int64_t now_us;
};
/* Reporter вне timer: форматирует и выводит сохранённое событие через DEBUG категории call. */
void call_video_playout_log_event(const struct call_video_playout_event *event);
int64_t call_video_playout_now_us(void);
void call_video_playout_init(struct call_video_playout *p, uint64_t call_id);