From 45c86b7e4511adf448286bcc0ac253581778f002 Mon Sep 17 00:00:00 2001 From: Bernhard Luedtke Date: Fri, 29 Nov 2024 12:05:38 +0100 Subject: [PATCH] log for long flush --- src/transmission/bidib_transmission_receive.c | 6 +++--- src/transmission/bidib_transmission_send.c | 13 +++++++++++++ 2 files changed, 16 insertions(+), 3 deletions(-) diff --git a/src/transmission/bidib_transmission_receive.c b/src/transmission/bidib_transmission_receive.c index 001f641..94814b5 100644 --- a/src/transmission/bidib_transmission_receive.c +++ b/src/transmission/bidib_transmission_receive.c @@ -741,9 +741,9 @@ static void bidib_split_packet(const uint8_t *const buffer, size_t buffer_size) syslog_libbidib(LOG_WARNING, "bidib_split_packet took longer than threshold %llu us for message of type %s", slow_processing_threshold_us, bidib_message_string_mapping[type]); - syslog_libbidib(LOG_WARNING, "bidib_split_packet msg-read-in: %llu us\n", msg_read_in_us); - syslog_libbidib(LOG_WARNING, "bidib_split_packet node-update: %llu us\n", node_update_us); - syslog_libbidib(LOG_WARNING, "bidib_split_packet handle-receive: %llu us\n", handle_receive_us); + syslog_libbidib(LOG_WARNING, "bidib_split_packet msg-read-in: %llu us", msg_read_in_us); + syslog_libbidib(LOG_WARNING, "bidib_split_packet node-update: %llu us", node_update_us); + syslog_libbidib(LOG_WARNING, "bidib_split_packet handle-receive: %llu us", handle_receive_us); } } } diff --git a/src/transmission/bidib_transmission_send.c b/src/transmission/bidib_transmission_send.c index eb86430..8002ea3 100644 --- a/src/transmission/bidib_transmission_send.c +++ b/src/transmission/bidib_transmission_send.c @@ -122,6 +122,9 @@ static void bidib_flush_impl_old(void) { * */ static void bidib_flush_impl(void) { + struct timespec start, end1, end2; + + clock_gettime(CLOCK_MONOTONIC_RAW, &start); if (buffer_index > 0) { uint8_t crc = 0; int32_t aux_index = 0; @@ -164,7 +167,17 @@ static void bidib_flush_impl(void) { buffer_index = 0; } + clock_gettime(CLOCK_MONOTONIC_RAW, &end1); syslog_libbidib(LOG_DEBUG, "%s", "Cache flushed"); + clock_gettime(CLOCK_MONOTONIC_RAW, &end2); + uint64_t flush_us = (end1.tv_sec - start.tv_sec) * 1000000 + (end1.tv_nsec - start.tv_nsec) / 1000; + uint64_t log_us = (end2.tv_sec - end1.tv_sec) * 1000000 + (end2.tv_nsec - end1.tv_nsec) / 1000; + // longer than 0.01s + if (flush_us + log_us > 10000) { + syslog_libbidib(LOG_WARNING, "bidib_flush_impl took longer than 10000 us"); + syslog_libbidib(LOG_WARNING, " Flushing took %llu us", flush_us); + syslog_libbidib(LOG_WARNING, "Logging debug took %llu us", log_us); + } } void bidib_flush(void) {