From 8042743e1a80591a2a961759a7398492943660d9 Mon Sep 17 00:00:00 2001 From: Kamil Trzcinski Date: Thu, 23 Feb 2023 18:30:20 +0100 Subject: [PATCH] links: allow to log processing statistics --- cmd/camera-streamer/opts.c | 1 + device/buffer_list.h | 7 +++- device/buffer_queue.c | 6 ++-- device/links.c | 72 ++++++++++++++++++++++++++++++++------ util/opts/log.h | 1 + 5 files changed, 74 insertions(+), 13 deletions(-) diff --git a/cmd/camera-streamer/opts.c b/cmd/camera-streamer/opts.c index d03a964..1049a91 100644 --- a/cmd/camera-streamer/opts.c +++ b/cmd/camera-streamer/opts.c @@ -124,6 +124,7 @@ option_t all_options[] = { DEFINE_OPTION_DEFAULT(log, debug, bool, "1", "Enable debug logging."), DEFINE_OPTION_DEFAULT(log, verbose, bool, "1", "Enable verbose logging."), + DEFINE_OPTION_DEFAULT(log, stats, uint, "1", "Print statistics every duration."), DEFINE_OPTION_PTR(log, filter, list, "Enable debug logging from the given files. Ex.: `-log-filter=buffer.cc`"), {} diff --git a/device/buffer_list.h b/device/buffer_list.h index 4133f1a..ea836b3 100644 --- a/device/buffer_list.h +++ b/device/buffer_list.h @@ -22,6 +22,10 @@ typedef struct buffer_format_s { buffer_type_t type; } buffer_format_t; +typedef struct buffer_stats_s { + int frames, dropped; +} buffer_stats_t; + typedef struct buffer_list_s { char *name; char *path; @@ -40,8 +44,9 @@ typedef struct buffer_list_s { }; uint64_t last_enqueued_us, last_dequeued_us; + int last_capture_time_us, last_in_queue_time_us; bool streaming; - int frames; + buffer_stats_t stats, stats_last; } buffer_list_t; buffer_list_t *buffer_list_open(const char *name, int index, struct device_s *dev, const char *path, buffer_format_t fmt, bool do_capture, bool do_mmap); diff --git a/device/buffer_queue.c b/device/buffer_queue.c index de9fd51..e767aaf 100644 --- a/device/buffer_queue.c +++ b/device/buffer_queue.c @@ -172,6 +172,8 @@ buffer_t *buffer_list_dequeue(buffer_list_t *buf_list) } buf_list->last_dequeued_us = get_monotonic_time_us(NULL, NULL); + buf_list->last_capture_time_us = buf_list->last_dequeued_us - buf->captured_time_us; + buf_list->last_in_queue_time_us = buf_list->last_dequeued_us - buf->enqueue_time_us; if (buf->mmap_reflinks > 0) { LOG_PERROR(buf, "Buffer appears to be enqueued? (links=%d)", buf->mmap_reflinks); @@ -184,7 +186,7 @@ buffer_t *buffer_list_dequeue(buffer_list_t *buf_list) buf->index, buf->length, buf->used, - buf_list->frames, + buf_list->stats.frames, buf->dma_source ? buf->dma_source->name : NULL); if (buf->dma_source) { @@ -197,7 +199,7 @@ buffer_t *buffer_list_dequeue(buffer_list_t *buf_list) buffer_update_h264_key_frame(buf); } - buf_list->frames++; + buf_list->stats.frames++; return buf; error: diff --git a/device/links.c b/device/links.c index d82ff80..fb3f33a 100644 --- a/device/links.c +++ b/device/links.c @@ -155,14 +155,21 @@ int links_enqueue_from_capture_list(buffer_list_t *buf_list, link_t *link) } } + bool dropped = false; + for (int j = 0; link->output_lists[j]; j++) { if (link->output_lists[j]->dev->paused) { continue; } - if (!links_sink_can_enqueue(link->output_lists[j])) { - continue; + if (links_sink_can_enqueue(link->output_lists[j])) { + buffer_list_enqueue(link->output_lists[j], buf); + } else { + dropped = true; } - buffer_list_enqueue(link->output_lists[j], buf); + } + + if (dropped) { + buf_list->stats.dropped++; } for (int j = 0; j < link->n_callbacks; j++) { @@ -227,7 +234,8 @@ static int links_step(link_t *all_links, int timeout_now_ms, int *timeout_next_m buffer_list_t *buf_list = pool.buf_lists[i]; link_t *link = pool.links[i]; - LOG_DEBUG(buf_list, "pool event=%s%s%s%s%s%08x streaming=%d enqueued=%d/%d paused=%d", + LOG_DEBUG(buf_list, "pool event=%08x revent=%s%s%s%s%s%08x streaming=%d enqueued=%d/%d paused=%d", + pool.fds[i].events, !pool.fds[i].revents ? "NONE/" : "", pool.fds[i].revents & POLLIN ? "IN/" : "", pool.fds[i].revents & POLLOUT ? "OUT/" : "", @@ -325,6 +333,50 @@ error: return -1; } +static void links_refresh_stats(link_t *all_links, uint64_t *last_refresh_us) +{ + uint64_t now_us = get_monotonic_time_us(NULL, NULL); + + if (now_us - *last_refresh_us < 1000*1000) + return; + + *last_refresh_us = now_us; + + if (log_options.stats) { + printf("Statistics:"); + + for (int i = 0; all_links[i].capture_list; i++) { + buffer_list_t *capture_list = all_links[i].capture_list; + buffer_stats_t *now = &capture_list->stats; + buffer_stats_t *prev = &capture_list->stats_last; + + printf(" [%8s %2d FPS/%2d D/%3dms/%3dms/%c/O%d:C%d]", + capture_list->dev->name, + (now->frames - prev->frames) / log_options.stats, + (now->dropped - prev->dropped) / log_options.stats, + capture_list->last_capture_time_us > 0 ? capture_list->last_capture_time_us / 1000 : -1, + capture_list->last_in_queue_time_us > 0 ? capture_list->last_in_queue_time_us / 1000 : -1, + capture_list->streaming ? (capture_list->dev->paused ? 'P' : 'S') : 'X', + capture_list->dev->output_list ? buffer_list_count_enqueued(capture_list->dev->output_list) : 0, + buffer_list_count_enqueued(capture_list) + ); + } + + printf("\n"); + fflush(stdout); + } + + for (int i = 0; all_links[i].capture_list; i++) { + buffer_list_t *capture_list = all_links[i].capture_list; + capture_list->stats_last = capture_list->stats; + + if (now_us - capture_list->last_dequeued_us > 1000) { + capture_list->last_capture_time_us = 0; + capture_list->last_in_queue_time_us = 0; + } + } +} + int links_loop(link_t *all_links, bool *running) { *running = true; @@ -334,19 +386,19 @@ int links_loop(link_t *all_links, bool *running) } int timeout_ms = LINKS_LOOP_INTERVAL; + uint64_t last_refresh_us = get_monotonic_time_us(NULL, NULL); + int ret = 0; - while(*running) { + while(*running && ret == 0) { int timeout_now_ms = timeout_ms; timeout_ms = LINKS_LOOP_INTERVAL; - if (links_step(all_links, timeout_now_ms, &timeout_ms) < 0) { - links_stream(all_links, false); - return -1; - } + ret = links_step(all_links, timeout_now_ms, &timeout_ms); + links_refresh_stats(all_links, &last_refresh_us); } links_stream(all_links, false); - return 0; + return ret; } static void links_dump_buf_list(char *output, buffer_list_t *buf_list) diff --git a/util/opts/log.h b/util/opts/log.h index 370db43..acc8988 100644 --- a/util/opts/log.h +++ b/util/opts/log.h @@ -26,6 +26,7 @@ typedef struct log_options_s { bool debug; bool verbose; + unsigned stats; char filter[256]; } log_options_t;