From f18a3ef9924634e2da7fa5730b848336bdcd8938 Mon Sep 17 00:00:00 2001 From: Devaev Maxim Date: Sun, 30 Sep 2018 16:54:29 +0300 Subject: [PATCH] --add-x-timings --- src/device.h | 3 +++ src/encoder.c | 4 +++ src/http.c | 69 ++++++++++++++++++++++++++++++++++++++++++++++----- src/http.h | 3 +++ src/main.c | 16 +++++++----- src/stream.c | 16 ++++++------ 6 files changed, 90 insertions(+), 21 deletions(-) diff --git a/src/device.h b/src/device.h index 963ed39..e3619b3 100644 --- a/src/device.h +++ b/src/device.h @@ -44,6 +44,9 @@ struct picture_t { unsigned char *data; unsigned long size; unsigned long allocated; + long double grab_time; + long double encode_begin_time; + long double encode_end_time; }; struct device_runtime_t { diff --git a/src/encoder.c b/src/encoder.c index 0dcf8fc..e5ea97f 100644 --- a/src/encoder.c +++ b/src/encoder.c @@ -131,6 +131,8 @@ void encoder_prepare_for_device(struct encoder_t *encoder, struct device_t *dev) int encoder_compress_buffer(struct encoder_t *encoder, struct device_t *dev, const unsigned index) { assert(encoder->type != ENCODER_TYPE_UNKNOWN); + dev->run->pictures[index].encode_begin_time = now_monotonic_ms(); + if (encoder->type == ENCODER_TYPE_CPU) { jpeg_encoder_compress_buffer(dev, index, encoder->quality); } @@ -142,6 +144,8 @@ int encoder_compress_buffer(struct encoder_t *encoder, struct device_t *dev, con } # endif + dev->run->pictures[index].encode_end_time = now_monotonic_ms(); + return 0; # pragma GCC diagnostic ignored "-Wunused-label" diff --git a/src/http.c b/src/http.c index 4b6e98f..0184341 100644 --- a/src/http.c +++ b/src/http.c @@ -85,7 +85,7 @@ struct http_server_t *http_server_init(struct stream_t *stream) { assert(!evhttp_set_cb(run->http, "/", _http_callback_root, NULL)); assert(!evhttp_set_cb(run->http, "/ping", _http_callback_ping, (void *)server)); - assert(!evhttp_set_cb(run->http, "/snapshot", _http_callback_snapshot, (void *)exposed)); + assert(!evhttp_set_cb(run->http, "/snapshot", _http_callback_snapshot, (void *)server)); assert(!evhttp_set_cb(run->http, "/stream", _http_callback_stream, (void *)server)); refresh_interval.tv_sec = 0; @@ -184,22 +184,44 @@ static void _http_callback_ping(struct evhttp_request *request, void *v_server) evbuffer_free(buf); } -static void _http_callback_snapshot(struct evhttp_request *request, void *v_exposed) { - struct exposed_t *exposed = (struct exposed_t *)v_exposed; +static void _http_callback_snapshot(struct evhttp_request *request, void *v_server) { + struct http_server_t *server = (struct http_server_t *)v_server; struct evbuffer *buf; char x_timestamp_buf[64]; PROCESS_HEAD_REQUEST; assert((buf = evbuffer_new())); - assert(!evbuffer_add(buf, (const void *)exposed->picture.data, exposed->picture.size)); + assert(!evbuffer_add(buf, (const void *)server->run->exposed->picture.data, server->run->exposed->picture.size)); ADD_HEADER("Access-Control-Allow-Origin:", "*"); ADD_HEADER("Cache-Control", "no-store, no-cache, must-revalidate, pre-check=0, post-check=0, max-age=0"); ADD_HEADER("Pragma", "no-cache"); ADD_HEADER("Expires", "Mon, 3 Jan 2000 12:34:56 GMT"); + sprintf(x_timestamp_buf, "%.06Lf", now_real_ms()); ADD_HEADER("X-Timestamp", x_timestamp_buf); + + if (server->add_x_timings) { + sprintf(x_timestamp_buf, "%.06Lf", server->run->exposed->picture.grab_time); + ADD_HEADER("X-UStreamer-Grab-Time", x_timestamp_buf); + + sprintf(x_timestamp_buf, "%.06Lf", server->run->exposed->picture.encode_begin_time); + ADD_HEADER("X-UStreamer-Encode-Begin-Time", x_timestamp_buf); + + sprintf(x_timestamp_buf, "%.06Lf", server->run->exposed->picture.encode_end_time); + ADD_HEADER("X-UStreamer-Encode-End-Time", x_timestamp_buf); + + sprintf(x_timestamp_buf, "%.06Lf", server->run->exposed->expose_begin_time); + ADD_HEADER("X-UStreamer-Expose-Begin-Time", x_timestamp_buf); + + sprintf(x_timestamp_buf, "%.06Lf", server->run->exposed->expose_end_time); + ADD_HEADER("X-UStreamer-Expose-End-Time", x_timestamp_buf); + + sprintf(x_timestamp_buf, "%.06Lf", now_monotonic_ms()); + ADD_HEADER("X-UStreamer-Send-Time", x_timestamp_buf); + } + ADD_HEADER("Content-Type", "image/jpeg"); evhttp_send_reply(request, HTTP_OK, "OK", buf); @@ -287,10 +309,28 @@ static void _http_callback_stream_write(struct bufferevent *buf_event, void *v_c "Content-Type: image/jpeg" RN "Content-Length: %lu" RN "X-Timestamp: %.06Lf" RN - RN, + "%s", client->server->run->exposed->picture.size * sizeof(*client->server->run->exposed->picture.data), - now_real_ms() + now_real_ms(), (client->server->add_x_timings ? "" : RN) )); + if (client->server->add_x_timings) { + assert(evbuffer_add_printf(buf, + "X-UStreamer-Grab-Time: %.06Lf" RN + "X-UStreamer-Encode-Begin-Time: %.06Lf" RN + "X-UStreamer-Encode-End-Time: %.06Lf" RN + "X-UStreamer-Expose-Begin-Time: %.06Lf" RN + "X-UStreamer-Expose-End-Time: %.06Lf" RN + "X-UStreamer-Send-Time: %.06Lf" RN + RN, + client->server->run->exposed->picture.grab_time, + client->server->run->exposed->picture.encode_begin_time, + client->server->run->exposed->picture.encode_end_time, + client->server->run->exposed->expose_begin_time, + client->server->run->exposed->expose_end_time, + now_monotonic_ms() + )); + } + assert(!evbuffer_add(buf, (void *)client->server->run->exposed->picture.data, client->server->run->exposed->picture.size * sizeof(*client->server->run->exposed->picture.data) @@ -393,6 +433,7 @@ static void _http_exposed_refresh(UNUSED int fd, UNUSED short what, void *v_serv static bool _expose_new_picture(struct http_server_t *server) { assert(server->run->stream->picture.size > 0); server->run->exposed->fps = server->run->stream->fps; + server->run->exposed->expose_begin_time = now_monotonic_ms(); # define MEM_STREAM_TO_EXPOSED \ server->run->exposed->picture.data, server->run->stream->picture.data, \ @@ -407,6 +448,7 @@ static bool _expose_new_picture(struct http_server_t *server) { ) { LOG_PERF("HTTP: dropped same frame number %u", server->run->exposed->dropped); server->run->exposed->dropped += 1; + server->run->exposed->expose_end_time = now_monotonic_ms(); return false; // Not updated } } @@ -421,14 +463,22 @@ static bool _expose_new_picture(struct http_server_t *server) { # undef MEM_STREAM_TO_EXPOSED server->run->exposed->picture.size = server->run->stream->picture.size; + + server->run->exposed->picture.grab_time = server->run->stream->picture.grab_time; + server->run->exposed->picture.encode_begin_time = server->run->stream->picture.encode_begin_time; + server->run->exposed->picture.encode_end_time = server->run->stream->picture.encode_end_time; + server->run->exposed->width = server->run->stream->width; server->run->exposed->height = server->run->stream->height; server->run->exposed->online = true; server->run->exposed->dropped = 0; + server->run->exposed->expose_end_time = now_monotonic_ms(); return true; // Updated } static bool _expose_blank_picture(struct http_server_t *server) { + server->run->exposed->expose_begin_time = now_monotonic_ms(); + if (server->run->exposed->online || server->run->exposed->picture.size == 0) { if (server->run->exposed->picture.allocated < BLANK_JPG_SIZE) { A_REALLOC(server->run->exposed->picture.data, BLANK_JPG_SIZE); @@ -441,6 +491,11 @@ static bool _expose_blank_picture(struct http_server_t *server) { ); server->run->exposed->picture.size = BLANK_JPG_SIZE; + + server->run->exposed->picture.grab_time = 0; + server->run->exposed->picture.encode_begin_time = 0; + server->run->exposed->picture.encode_end_time = 0; + server->run->exposed->width = BLANK_JPG_WIDTH; server->run->exposed->height = BLANK_JPG_HEIGHT; server->run->exposed->fps = 0; @@ -451,10 +506,12 @@ static bool _expose_blank_picture(struct http_server_t *server) { if (server->run->exposed->dropped < server->run->drop_same_frames_blank) { LOG_PERF("HTTP: dropped same frame (BLANK) number %u", server->run->exposed->dropped); server->run->exposed->dropped += 1; + server->run->exposed->expose_end_time = now_monotonic_ms(); return false; // Not updated } updated: server->run->exposed->dropped = 0; + server->run->exposed->expose_end_time = now_monotonic_ms(); return true; // Updated } diff --git a/src/http.h b/src/http.h index 75faf4c..a4c3514 100644 --- a/src/http.h +++ b/src/http.h @@ -45,6 +45,8 @@ struct exposed_t { unsigned fps; bool online; unsigned dropped; + long double expose_begin_time; + long double expose_end_time; }; struct http_server_runtime_t { @@ -62,6 +64,7 @@ struct http_server_t { char *host; unsigned port; unsigned drop_same_frames; + bool add_x_timings; unsigned fake_width; unsigned fake_height; unsigned timeout; diff --git a/src/main.c b/src/main.c index 94720bd..9bd42b0 100644 --- a/src/main.c +++ b/src/main.c @@ -63,9 +63,10 @@ static const struct option _long_opts[] = { {"host", required_argument, NULL, 's'}, {"port", required_argument, NULL, 'p'}, {"drop-same-frames", required_argument, NULL, 'r'}, - {"fake-width", required_argument, NULL, 2000}, - {"fake-height", required_argument, NULL, 2001}, - {"server-timeout", required_argument, NULL, 2002}, + {"add-x-timings", no_argument, NULL, 2000}, + {"fake-width", required_argument, NULL, 2001}, + {"fake-height", required_argument, NULL, 2002}, + {"server-timeout", required_argument, NULL, 2003}, {"perf", no_argument, NULL, 5000}, {"verbose", no_argument, NULL, 5001}, @@ -116,6 +117,8 @@ static void _help(struct device_t *dev, struct encoder_t *encoder, struct http_s printf(" It can significantly reduce the outgoing traffic, but will increase\n"); printf(" the CPU loading. Don't use this option with analog signal sources\n"); printf(" or webcams, it's useless. Default: disabled.\n\n"); + printf(" --add-x-timings -- Add X-UStreamer-*-Time headers to the /stream and /snapshot handles.\n"); + printf(" Default: disabled.\n\n"); printf(" --fake-width -- Override image width for /ping. Default: disabled\n\n"); printf(" --fake-height -- Override image height for /ping. Default: disabled.\n\n"); printf(" --server-timeout -- Timeout for client connections. Default: %d\n\n", server->timeout); @@ -179,9 +182,10 @@ static int _parse_options(int argc, char *argv[], struct device_t *dev, struct e case 's': server->host = optarg; break; case 'p': OPT_UNSIGNED(server->port, "--port", 1, 65535); case 'r': OPT_UNSIGNED(server->drop_same_frames, "--drop-same-frames", 0, 30); - case 2000: OPT_UNSIGNED(server->fake_width, "--fake-width", 0, 1920); - case 2001: OPT_UNSIGNED(server->fake_height, "--fake-height", 0, 1200); - case 2002: OPT_UNSIGNED(server->timeout, "--server-timeout", 1, 60); + case 2000: server->add_x_timings = true; break; + case 2001: OPT_UNSIGNED(server->fake_width, "--fake-width", 0, 1920); + case 2002: OPT_UNSIGNED(server->fake_height, "--fake-height", 0, 1200); + case 2003: OPT_UNSIGNED(server->timeout, "--server-timeout", 1, 60); case 5000: log_level = LOG_LEVEL_PERF; break; case 5001: log_level = LOG_LEVEL_VERBOSE; break; diff --git a/src/stream.c b/src/stream.c index 1848a3d..935064f 100644 --- a/src/stream.c +++ b/src/stream.c @@ -162,10 +162,12 @@ void stream_loop(struct stream_t *stream) { LOG_DEBUG("Frame is ready"); struct v4l2_buffer buf_info; + long double now = now_monotonic_ms(); if (_stream_grab_buffer(stream->dev, &buf_info) < 0) { break; } + stream->dev->run->pictures[buf_info.index].grab_time = now; if (stream->dev->every_frame) { if (frames_count < stream->dev->every_frame - 1) { @@ -187,8 +189,6 @@ void stream_loop(struct stream_t *stream) { } { - long double now = now_monotonic_ms(); - if (now < grab_after) { fluency_passed += 1; LOG_VERBOSE("Passed %u frames for fluency: now=%.03Lf; grab_after=%.03Lf", fluency_passed, now, grab_after); @@ -291,6 +291,9 @@ static void _stream_expose_picture(struct stream_t *stream, unsigned buf_index) stream->picture.data, stream->dev->run->pictures[buf_index].data, stream->picture.size * sizeof(*stream->picture.data) ); + stream->picture.grab_time = stream->dev->run->pictures[buf_index].grab_time; + stream->picture.encode_begin_time = stream->dev->run->pictures[buf_index].encode_begin_time; + stream->picture.encode_end_time = stream->dev->run->pictures[buf_index].encode_end_time; stream->width = stream->dev->run->width; stream->height = stream->dev->run->height; @@ -404,11 +407,6 @@ static void *_stream_worker_thread(void *v_ctx) { A_PTHREAD_M_UNLOCK(ctx->has_job_mutex); if (!*ctx->workers_stop) { - long double start_time; - long double last_comp_time; - - start_time = now_monotonic_ms(); - LOG_DEBUG("Worker %u compressing JPEG from buffer %d ...", ctx->number, ctx->buf_index); if (encoder_compress_buffer(ctx->encoder, ctx->dev, ctx->buf_index) < 0) { @@ -416,10 +414,10 @@ static void *_stream_worker_thread(void *v_ctx) { } if (_stream_release_buffer(ctx->dev, &ctx->buf_info) == 0) { - *ctx->job_start_time = start_time; + *ctx->job_start_time = ctx->dev->run->pictures[ctx->buf_index].encode_begin_time; *ctx->has_job = false; - last_comp_time = now_monotonic_ms() - start_time; + long double last_comp_time = ctx->dev->run->pictures[ctx->buf_index].encode_end_time - *ctx->job_start_time; A_PTHREAD_M_LOCK(ctx->last_comp_time_mutex); *ctx->last_comp_time = last_comp_time;