From cd788cb73646ea38db3b6392058f2183c7ac0b72 Mon Sep 17 00:00:00 2001 From: Bernhard Luedtke Date: Tue, 26 Nov 2024 15:41:59 +0100 Subject: [PATCH] documentation improved for additions and removed commented out code --- src/transmission/bidib_transmission_receive.c | 42 ++++++------------- src/transmission/bidib_transmission_send.c | 38 ++++++++++------- 2 files changed, 34 insertions(+), 46 deletions(-) diff --git a/src/transmission/bidib_transmission_receive.c b/src/transmission/bidib_transmission_receive.c index 3826dc7..b28163d 100644 --- a/src/transmission/bidib_transmission_receive.c +++ b/src/transmission/bidib_transmission_receive.c @@ -717,19 +717,22 @@ static void bidib_split_packet(const uint8_t *const buffer, size_t buffer_size) } } clock_gettime(CLOCK_MONOTONIC_RAW, &end); - uint64_t msg_read_in_delta_us = (end.tv_sec - start.tv_sec) * 1000000 + (end.tv_nsec - start.tv_nsec) / 1000; + uint64_t msg_read_in_us = (end.tv_sec - start.tv_sec) * 1000000 + (end.tv_nsec - start.tv_nsec) / 1000; clock_gettime(CLOCK_MONOTONIC_RAW, &start); unsigned int action_id = bidib_node_state_update(addr_stack, type); clock_gettime(CLOCK_MONOTONIC_RAW, &end); - uint64_t node_update_delta_us = (end.tv_sec - start.tv_sec) * 1000000 + (end.tv_nsec - start.tv_nsec) / 1000; + uint64_t node_update_us = (end.tv_sec - start.tv_sec) * 1000000 + (end.tv_nsec - start.tv_nsec) / 1000; clock_gettime(CLOCK_MONOTONIC_RAW, &start); bidib_handle_received_message(message, type, addr_stack, msg_seqnum, action_id); clock_gettime(CLOCK_MONOTONIC_RAW, &end); - uint64_t handle_receive_delta_us = (end.tv_sec - start.tv_sec) * 1000000 + (end.tv_nsec - start.tv_nsec) / 1000; - if (msg_read_in_delta_us + node_update_delta_us + handle_receive_delta_us > 100000) { - syslog_libbidib(LOG_WARNING, "bidib_split_packet msg-read-in: %llu us\n", msg_read_in_delta_us); - syslog_libbidib(LOG_WARNING, "bidib_split_packet node-update: %llu us\n", node_update_delta_us); - syslog_libbidib(LOG_WARNING, "bidib_split_packet handle-receive: %llu us\n", handle_receive_delta_us); + uint64_t handle_receive_us = (end.tv_sec - start.tv_sec) * 1000000 + (end.tv_nsec - start.tv_nsec) / 1000; + const uint64_t slow_processing_threshold_us = 100000; // 0.1 s + if (msg_read_in_us + node_update_us + handle_receive_us > slow_processing_threshold_us) { + // In case the processing steps above take above the specified threshold, + // i.e., longer than expected, log the time taken for each of the three steps. + 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); } } } @@ -742,24 +745,18 @@ static void bidib_receive_packet(void) { size_t buffer_index = 0; bool escape_hot = false; uint8_t crc = 0x00; - struct timespec start, end; - bool start_set = false; + // Read the packet bytes while (bidib_running && !bidib_discard_rx) { data = read_byte(&read_byte_success); while (!read_byte_success) { - //usleep(5000); // 0.005s - usleep(500); // 0.0005s + usleep(5000); // 0.005s data = read_byte(&read_byte_success); if (!bidib_running || bidib_discard_rx) { return; } } read_byte_success = 0; - if (!start_set) { - start_set = true; - clock_gettime(CLOCK_MONOTONIC_RAW, &start); - } if (data == BIDIB_PKT_MAGIC) { if (buffer_index != 0) { @@ -779,13 +776,6 @@ static void bidib_receive_packet(void) { buffer_index++; } } - if (start_set) { - clock_gettime(CLOCK_MONOTONIC_RAW, &end); - uint64_t delta_us = (end.tv_sec - start.tv_sec) * 1000000 + (end.tv_nsec - start.tv_nsec) / 1000; - if (delta_us > 100000) { - syslog_libbidib(LOG_WARNING, "receive_packet reading packet bytes took %llu us from reading of first byte\n", delta_us); - } - } if (!bidib_running || bidib_discard_rx) { return; @@ -794,7 +784,6 @@ static void bidib_receive_packet(void) { syslog_libbidib(LOG_DEBUG, "%s", "Received packet"); if (crc == 0x00) { - //syslog_libbidib(LOG_DEBUG, "%s", "CRC correct, split packet in messages"); // Split packet in messages and add them to queue, exclude crc sum buffer_index--; bidib_split_packet(buffer, buffer_index); @@ -832,15 +821,8 @@ static void bidib_receive_first_pkt_magic(void) { void *bidib_auto_receive(void *par __attribute__((unused))) { while (bidib_running) { bidib_receive_first_pkt_magic(); - struct timespec start, end; while (bidib_running && !bidib_discard_rx) { - clock_gettime(CLOCK_MONOTONIC_RAW, &start); bidib_receive_packet(); - clock_gettime(CLOCK_MONOTONIC_RAW, &end); - uint64_t delta_us = (end.tv_sec - start.tv_sec) * 1000000 + (end.tv_nsec - start.tv_nsec) / 1000; - if (delta_us > 1000000) { // > 1s - syslog_libbidib(LOG_WARNING, "bidib_receive_packet took very long - %llu us\n", delta_us); - } } } return NULL; diff --git a/src/transmission/bidib_transmission_send.c b/src/transmission/bidib_transmission_send.c index 06fa488..2e76481 100644 --- a/src/transmission/bidib_transmission_send.c +++ b/src/transmission/bidib_transmission_send.c @@ -52,11 +52,6 @@ static volatile uint8_t buffer[PACKET_BUFFER_SIZE]; static volatile uint8_t buffer_aux[PACKET_BUFFER_AUX_SIZE]; static volatile size_t buffer_index = 0; -typedef struct { - uint8_t *message; - size_t len; -} t_bidib_send_buff_arr; - void bidib_set_write_dest(void (*write)(uint8_t)) { write_byte = write; syslog_libbidib(LOG_INFO, "%s", "Write function was set"); @@ -107,16 +102,32 @@ static void bidib_flush_impl_old(void) { // start-delimiter for next one buffer_index = 0; } - //syslog_libbidib(LOG_DEBUG, "%s", "Cache flushed"); + syslog_libbidib(LOG_DEBUG, "%s", "Cache flushed"); } -// Must be called with bidib_send_buffer_mutex locked. -static void bidib_flush_impl(void) { //bidib_flush_batch_impl0 +/** + * @brief Will flush the send cache, if possible in once go (as one batch); + * if batching not possible, then send byte-per-byte. + * Must be called with bidib_send_buffer_mutex locked. + * + * How does it work? It copies the actual buffer (called `buffer`) + * byte-per-byte to an auxiliary buffer (called `buffer_aux`), + * and whilst doing so it computes the crc and adds/inserts the crc and escape + * related bytes/chars where needed. + * Due the need to insert bytes (e.g., related to the crc or escapes), we can't + * modify the `buffer` in-place. The solution with an auxiliary buffer + * has been compared against solutions with dynamic memory allocation, + * where the auxiliary buffer solution has shown to be faster, more timing-predictable, + * and easier to maintain/less risk of a memory leak. + * + */ +static void bidib_flush_impl(void) { if (buffer_index > 0) { uint8_t crc = 0; int32_t aux_index = 0; buffer_aux[aux_index++] = BIDIB_PKT_MAGIC; // send_delimiter equiv for (size_t i = 0; i < buffer_index; ++i) { + // At most 2 more chars can be added in one loop iteration if (aux_index + 3 >= PACKET_BUFFER_AUX_SIZE) { // Too big for flush_batch. Fallback to traditional one-by-one send. bidib_flush_impl_old(); @@ -131,6 +142,7 @@ static void bidib_flush_impl(void) { //bidib_flush_batch_impl0 } } + // At most 3 more chars can be added in the code below if (aux_index + 4 >= PACKET_BUFFER_AUX_SIZE) { // Too big for flush batch, can't fit crc+delim in aux buffer. // Fallback to traditional one-by-one send. @@ -147,24 +159,18 @@ static void bidib_flush_impl(void) { //bidib_flush_batch_impl0 } buffer_aux[aux_index++] = BIDIB_PKT_MAGIC; // send_delimiter equiv + // Batch-write aux buffer. write_bytes((uint8_t*)buffer_aux, aux_index); buffer_index = 0; } + syslog_libbidib(LOG_DEBUG, "%s", "Cache flushed"); } void bidib_flush(void) { - //struct timespec start, end; pthread_mutex_lock(&bidib_send_buffer_mutex); - //bool smth_to_send = buffer_index > 0; - //clock_gettime(CLOCK_MONOTONIC_RAW, &start); bidib_flush_impl(); - //clock_gettime(CLOCK_MONOTONIC_RAW, &end); pthread_mutex_unlock(&bidib_send_buffer_mutex); - //uint64_t delta_us = (end.tv_sec - start.tv_sec) * 1000000 + (end.tv_nsec - start.tv_nsec) / 1000; - //if (smth_to_send) { - // syslog_libbidib(LOG_WARNING, "Flush took %llu\n", delta_us); - //} } void *bidib_auto_flush(void *interval) {