From 65daa182ef2aac03e85ffd95904238afc39dcf94 Mon Sep 17 00:00:00 2001 From: Thomas Kolb Date: Thu, 30 May 2024 10:44:42 +0200 Subject: [PATCH] Use the new logging system everywhere --- impl/src/layer1/correlator.c | 7 +++---- impl/src/layer1/tx.c | 10 +++++---- impl/src/layer2/tundev.c | 10 +++++---- impl/src/results.h | 7 ++++--- impl/src/sdr/sdr.c | 32 ++++++++++++++--------------- impl/test/CMakeLists.txt | 4 ++++ impl/test/layer1/test_freq_est.c | 9 -------- impl/test/layer1/test_loopback.c | 35 ++++++++++++++++---------------- impl/test/layer1/test_rx_file.c | 11 ++++++---- impl/test/test_jsonlogger.c | 12 +++++++---- 10 files changed, 70 insertions(+), 67 deletions(-) diff --git a/impl/src/layer1/correlator.c b/impl/src/layer1/correlator.c index 1340313..38ead45 100644 --- a/impl/src/layer1/correlator.c +++ b/impl/src/layer1/correlator.c @@ -1,11 +1,10 @@ #include #include #include -#include #include "freq_est.h" -#include "utils.h" +#include "logger.h" #include "correlator.h" @@ -32,13 +31,13 @@ bool correlator_init(correlator_ctx_t *ctx, const float complex *search_seq, siz // Allocate the buffers ctx->input_history = malloc(ctx->buffer_size * sizeof(ctx->input_history[0])); if(!ctx->input_history) { - fprintf(stderr, "correlator: malloc() failed!\n"); + LOG(LVL_ERR, "correlator: malloc() failed!"); goto fail; } ctx->search_sequence = malloc(ctx->buffer_size * sizeof(ctx->search_sequence[0])); if(!ctx->search_sequence) { - fprintf(stderr, "correlator: malloc() failed!\n"); + LOG(LVL_ERR, "correlator: malloc() failed!"); goto fail; } diff --git a/impl/src/layer1/tx.c b/impl/src/layer1/tx.c index c48df0f..c1054f0 100644 --- a/impl/src/layer1/tx.c +++ b/impl/src/layer1/tx.c @@ -3,6 +3,8 @@ #include #include +#include "logger.h" + #include "results.h" #include "tx.h" @@ -88,7 +90,7 @@ result_t layer1_tx_add_packet_to_burst(layer1_tx_t *tx, const uint8_t *data, siz result_t res = transmission_ramp_up(&tx->transmission, get_write_ptr(tx), &len); if(res != OK) { - fprintf(stderr, "Ramp-up requires %zd samples at offset %zd.\n", len, tx->samples_used); + LOG(LVL_ERR, "Ramp-up requires %zd samples at offset %zd.", len, tx->samples_used); return res; } @@ -126,7 +128,7 @@ result_t layer1_tx_add_packet_to_burst(layer1_tx_t *tx, const uint8_t *data, siz result_t res = transmission_filter_packet(&tx->transmission, msg_mod, nsyms, get_write_ptr(tx), &len); if(res != OK) { - fprintf(stderr, "Packet requires %zd samples at offset %zd.\n", len, tx->samples_used); + LOG(LVL_ERR, "Packet requires %zd samples at offset %zd.", len, tx->samples_used); return res; } @@ -153,7 +155,7 @@ result_t layer1_tx_finalize_burst(layer1_tx_t *tx) result_t res = transmission_ramp_down(&tx->transmission, get_write_ptr(tx), &len); if(res != OK) { - fprintf(stderr, "Ramp-down requires %zd samples at offset %zd.\n", len, tx->samples_used); + LOG(LVL_ERR, "Ramp-down requires %zd samples at offset %zd.", len, tx->samples_used); return res; } @@ -164,7 +166,7 @@ result_t layer1_tx_finalize_burst(layer1_tx_t *tx) // allocate a temporary buffer float complex *tmp = malloc(sizeof(float complex) * tx->samples_used); if(!tmp) { - fprintf(stderr, "Could not allocate buffer for TX frequency correction.\n"); + LOG(LVL_ERR, "Could not allocate buffer for TX frequency correction."); return ERR_NO_MEM; } diff --git a/impl/src/layer2/tundev.c b/impl/src/layer2/tundev.c index 600aa1f..9367b61 100644 --- a/impl/src/layer2/tundev.c +++ b/impl/src/layer2/tundev.c @@ -8,6 +8,8 @@ #include #include +#include "logger.h" + #include "tundev.h" int tundev_open(char *dev) @@ -33,12 +35,12 @@ int tundev_open(char *dev) strcpy(dev, ifr.ifr_name); - fprintf(stderr, "tundev: Successfully allocated tun device %s\n", dev); + LOG(LVL_INFO, "tundev: Successfully allocated tun device %s", dev); return tunfd; - fprintf(stderr, "tundev: Closing device.\n"); + LOG(LVL_DEBUG, "tundev: Closing device."); close(tunfd); return 0; @@ -71,11 +73,11 @@ result_t tundev_read_loop(int tunfd, tundev_read_callback_t callback) break; } - fprintf(stderr, "tundev: Read %d bytes from tun device.\n", ret); + LOG(LVL_DEBUG, "tundev: Read %d bytes from tun device.", ret); } while(callback(buf, ret)); if(ret == 0) { - fprintf(stderr, "tundev: no more data.\n"); + LOG(LVL_DEBUG, "tundev: no more data."); return OK; } else { perror("tundev: read"); diff --git a/impl/src/results.h b/impl/src/results.h index 34373ca..faa686f 100644 --- a/impl/src/results.h +++ b/impl/src/results.h @@ -1,6 +1,8 @@ #ifndef RESULTS_H #define RESULTS_H +#include "logger.h" + typedef enum { OK, ERR_INVALID_STATE, @@ -14,7 +16,6 @@ typedef enum { } result_t; #ifdef DEBUG_LIQUID -#include #include @@ -22,7 +23,7 @@ typedef enum { do { \ liquid_error_code lq_result; \ if((lq_result = (call)) != LIQUID_OK) { \ - fprintf(stderr, "Liquid call failed in %s:%d: %s\n", __FILE__, __LINE__, liquid_error_info(lq_result)); \ + LOG(LVL_ERR, "Liquid call failed in %s:%d: %s", __FILE__, __LINE__, liquid_error_info(lq_result)); \ return ERR_LIQUID; \ } \ } while(0); @@ -34,7 +35,7 @@ typedef enum { do { \ result_t err_check_result = call; \ if(err_check_result != OK) { \ - fprintf(stderr, "Error detected at %s:%d: %d\n", __FILE__, __LINE__, err_check_result); \ + LOG(LVL_ERR, "Error detected at %s:%d: %d", __FILE__, __LINE__, err_check_result); \ return err_check_result; \ } \ } while(0); diff --git a/impl/src/sdr/sdr.c b/impl/src/sdr/sdr.c index 011f6e4..983e1a2 100644 --- a/impl/src/sdr/sdr.c +++ b/impl/src/sdr/sdr.c @@ -1,8 +1,6 @@ #include #include #include -#include //printf -#include //free #include #include #include @@ -17,7 +15,7 @@ #define CHECK_HACKRF_RESULT(result, call) do { \ if(result != HACKRF_SUCCESS) { \ - fprintf(stderr, call "() failed: %s (%d)\n", hackrf_error_name(result), result); \ + LOG(LVL_ERR, call "() failed: %s (%d)", hackrf_error_name(result), result); \ return ERR_SDR; \ } \ } while(0); @@ -40,7 +38,7 @@ static int rx_callback(hackrf_transfer *transfer) int result = cbuffercf_push(sdr_ctx->rx_buf, sample); if(result != LIQUID_OK) { - fprintf(stderr, "cbuffercf_push failed on sample %zu of %zu: %d. Samples are lost.\n", i, nsamples, result); + LOG(LVL_ERR, "cbuffercf_push failed on sample %zu of %zu: %d. Samples are lost.", i, nsamples, result); break; } } @@ -70,12 +68,12 @@ static int tx_callback(hackrf_transfer *transfer) int result; int retcode = 0; - fprintf(stderr, "tx_callback()\n"); + LOG(LVL_DEBUG, "tx_callback()"); sdr_ctx_t *sdr_ctx = (sdr_ctx_t*)transfer->tx_ctx; if(transfer->valid_length % 2 != 0) { - fprintf(stderr, "WARNING! Buffer unaligned!\n"); + LOG(LVL_WARN, "Buffer unaligned!"); } if(sem_wait(&sdr_ctx->buf_sem) < 0) { @@ -89,7 +87,7 @@ static int tx_callback(hackrf_transfer *transfer) result = cbuffercf_read(sdr_ctx->tx_buf, samples_requested, &samples, &samples_read); if(result != LIQUID_OK) { - fprintf(stderr, "cbuffercf_read failed: %d. Samples are lost.\n", result); + LOG(LVL_ERR, "cbuffercf_read failed: %d. Samples are lost.", result); sem_post(&sdr_ctx->buf_sem); return HACKRF_ERROR_OTHER; } @@ -97,7 +95,7 @@ static int tx_callback(hackrf_transfer *transfer) if(sdr_ctx->tx_start_time == 0.0) { sdr_ctx->tx_start_time = get_hires_time(); sdr_ctx->tx_duration = 10e-3; // give a little headroom - fprintf(stderr, "TX time tracking reset: start = %.3f.\n", sdr_ctx->tx_start_time); + LOG(LVL_INFO, "TX time tracking reset: start = %.3f.", sdr_ctx->tx_start_time); } for(size_t i = 0; i < samples_read; i++) { @@ -110,7 +108,7 @@ static int tx_callback(hackrf_transfer *transfer) sdr_ctx->tx_duration += (double)samples_requested / SDR_TX_SAMPLING_RATE; } - fprintf(stderr, "copied %u samples to HackRF.\n", samples_read); + LOG(LVL_DEBUG, "copied %u samples to HackRF.", samples_read); if(samples_read < samples_requested) { // fill the rest with zeros @@ -119,7 +117,7 @@ static int tx_callback(hackrf_transfer *transfer) result = cbuffercf_release(sdr_ctx->tx_buf, samples_read); if(result != LIQUID_OK) { - fprintf(stderr, "cbuffercf_release failed: %d.\n", result); + LOG(LVL_ERR, "cbuffercf_release failed: %d.", result); sem_post(&sdr_ctx->buf_sem); return ERR_LIQUID; } @@ -226,7 +224,7 @@ result_t sdr_start_rx(sdr_ctx_t *ctx) CHECK_HACKRF_RESULT(result, "hackrf_set_sample_rate"); result = hackrf_set_freq(ctx->hackrf, SDR_RX_FREQ - SDR_RX_IF_SHIFT); - fprintf(stderr, "Set RX frequency to %f Hz.\n", SDR_RX_FREQ - SDR_RX_IF_SHIFT); + LOG(LVL_DEBUG, "Set RX frequency to %f Hz.", SDR_RX_FREQ - SDR_RX_IF_SHIFT); CHECK_HACKRF_RESULT(result, "hackrf_set_freq"); result = hackrf_set_lna_gain(ctx->hackrf, SDR_GAIN_RX_LNA); @@ -299,7 +297,7 @@ result_t sdr_transmit(sdr_ctx_t *ctx, const float complex *samples, size_t nsamp int result = cbuffercf_write(ctx->tx_buf, (float complex*)samples, nsamples); if(result != LIQUID_OK) { - fprintf(stderr, "cbuffercf_write failed: %d. Samples are lost.\n", result); + LOG(LVL_ERR, "cbuffercf_write failed: %d. Samples are lost.", result); sem_post(&ctx->buf_sem); return ERR_LIQUID; } @@ -338,7 +336,7 @@ result_t sdr_receive(sdr_ctx_t *ctx, float complex *samples, size_t *nsamples, l float complex *buf_samples; result = cbuffercf_read(ctx->rx_buf, *nsamples, &buf_samples, &samples_read); if(result != LIQUID_OK) { - fprintf(stderr, "cbuffercf_read failed: %d. Samples are lost.\n", result); + LOG(LVL_ERR, "cbuffercf_read failed: %d. Samples are lost.", result); sem_post(&ctx->buf_sem); return ERR_LIQUID; } @@ -347,7 +345,7 @@ result_t sdr_receive(sdr_ctx_t *ctx, float complex *samples, size_t *nsamples, l result = cbuffercf_release(ctx->rx_buf, samples_read); if(result != LIQUID_OK) { - fprintf(stderr, "cbuffercf_release failed: %d.\n", result); + LOG(LVL_ERR, "cbuffercf_release failed: %d.", result); sem_post(&ctx->buf_sem); return ERR_LIQUID; } @@ -436,12 +434,12 @@ result_t sdr_rf_to_baseband(sdr_ctx_t *ctx, float complex *bb_samples, size_t *nbb) { if((nrf % SDR_OVERSAMPLING) != 0) { - fprintf(stderr, "sdr_rf_to_baseband: the given number of RF samples (%zd) is not a multiple of SDR_OVERSAMPLING (%d).\n", nrf, SDR_OVERSAMPLING); + LOG(LVL_ERR, "sdr_rf_to_baseband: the given number of RF samples (%zd) is not a multiple of SDR_OVERSAMPLING (%d).", nrf, SDR_OVERSAMPLING); return ERR_SIZE; } if((*nbb * SDR_OVERSAMPLING) < nrf) { - fprintf(stderr, "sdr_rf_to_baseband: result would not fit in output: %zd * %d < %zd\n", *nbb, SDR_OVERSAMPLING, nrf); + LOG(LVL_ERR, "sdr_rf_to_baseband: result would not fit in output: %zd * %d < %zd", *nbb, SDR_OVERSAMPLING, nrf); return ERR_SIZE; } @@ -469,7 +467,7 @@ result_t sdr_baseband_to_rf(sdr_ctx_t *ctx, float complex *rf_samples, size_t *nrf) { if((nbb * SDR_OVERSAMPLING) > *nrf) { - fprintf(stderr, "sdr_baseband_to_rf: result would not fit in output: %zd * %d > %zd\n", nbb, SDR_OVERSAMPLING, *nrf); + LOG(LVL_ERR, "sdr_baseband_to_rf: result would not fit in output: %zd * %d > %zd", nbb, SDR_OVERSAMPLING, *nrf); return ERR_SIZE; } diff --git a/impl/test/CMakeLists.txt b/impl/test/CMakeLists.txt index d5c28a3..47e9de8 100644 --- a/impl/test/CMakeLists.txt +++ b/impl/test/CMakeLists.txt @@ -4,6 +4,8 @@ add_executable( ../src/layer1/correlator.h ../src/layer1/freq_est.c ../src/layer1/freq_est.h + ../src/logger.c + ../src/logger.h ../src/utils.c layer1/test_correlator.c ) @@ -118,6 +120,8 @@ add_executable( test_jsonlogger ../src/jsonlogger.c ../src/jsonlogger.h + ../src/logger.c + ../src/logger.h ../src/debug_structs.h test_jsonlogger.c ) diff --git a/impl/test/layer1/test_freq_est.c b/impl/test/layer1/test_freq_est.c index 5c82142..b53aa07 100644 --- a/impl/test/layer1/test_freq_est.c +++ b/impl/test/layer1/test_freq_est.c @@ -7,15 +7,6 @@ #include "utils.h" -#define RESULT_CHECK(stmt) { \ - result_t res = stmt; \ - if(res != OK) { \ - fprintf(stderr, "Error %d in %s:%d!\n", res, __FILE__, __LINE__); \ - exit(1); \ - } \ -} - - int main(void) { #define N 63 diff --git a/impl/test/layer1/test_loopback.c b/impl/test/layer1/test_loopback.c index c44b308..37c5cf1 100644 --- a/impl/test/layer1/test_loopback.c +++ b/impl/test/layer1/test_loopback.c @@ -1,7 +1,6 @@ #include #include #include -#include #include #include @@ -10,16 +9,14 @@ #include "layer1/tx.h" #include "layer1/rx.h" +#include "logger.h" + #include "utils.h" -#include "sdr/sdr.h" - -#include "config.h" - #define RESULT_CHECK(stmt) { \ result_t res = stmt; \ if(res != OK) { \ - fprintf(stderr, "Error %d in %s:%d!\n", res, __FILE__, __LINE__); \ + LOG(LVL_ERR, "Error %d in %s:%d!", res, __FILE__, __LINE__); \ exit(1); \ } \ } @@ -83,25 +80,25 @@ void cb_rx(rx_evt_t evt, const layer1_rx_t *rx, uint8_t *packet_data, size_t pac switch(evt) { case RX_EVT_CHECKSUM_ERROR: - fprintf(stderr, "Received a message of %zu bytes, but decoding failed.\n", packet_len); - fprintf(stderr, "=== FAILED PAYLOAD ===\n"); + LOG(LVL_ERR, "Received a message of %zu bytes, but decoding failed.", packet_len); + LOG(LVL_INFO, "=== FAILED PAYLOAD ==="); hexdump(packet_data, packet_len); - fprintf(stderr, "=======================\n"); + LOG(LVL_INFO, "======================="); break; case RX_EVT_PACKET_RECEIVED: - fprintf(stderr, "A message of %zu bytes was decoded successfully.\n", packet_len); - fprintf(stderr, "=== DECODED PAYLOAD (%4zu bytes) ===\n", packet_len); + LOG(LVL_INFO, "A message of %zu bytes was decoded successfully.", packet_len); + LOG(LVL_INFO, "=== DECODED PAYLOAD (%4zu bytes) ===", packet_len); hexdump(packet_data, packet_len < 64 ? packet_len : 64); - fprintf(stderr, "====================================\n"); + LOG(LVL_INFO, "===================================="); break; case RX_EVT_HEADER_ERROR: - fprintf(stderr, "Header decoding failed!\n"); + LOG(LVL_ERR, "Header decoding failed!"); break; case RX_EVT_PREAMBLE_FOUND: - fprintf(stderr, "Found preamble!\n"); + LOG(LVL_INFO, "Found preamble!"); break; case RX_EVT_PACKET_DEBUG_INFO_COMPLETE: @@ -118,6 +115,8 @@ int main(void) // ** Initialize ** + logger_init(); + srand(time(NULL)); RESULT_CHECK(layer1_tx_init(&tx)); @@ -131,14 +130,14 @@ int main(void) uint8_t packetbuf1[] = "Hello World! 1234567890"; size_t l = sizeof(packetbuf1); - fprintf(stderr, "Transmitting packet with %zd bytes.\n", l); + LOG(LVL_INFO, "Transmitting packet with %zd bytes.", l); RESULT_CHECK(layer1_tx_add_packet_to_burst(&tx, packetbuf1, l)); uint8_t packetbuf2[] = "This is just a test message. Just writing some stuff here to create a longer packet."; l = sizeof(packetbuf2); - fprintf(stderr, "Transmitting packet with %zd bytes.\n", l); + LOG(LVL_INFO, "Transmitting packet with %zd bytes.", l); RESULT_CHECK(layer1_tx_add_packet_to_burst(&tx, packetbuf2, l)); @@ -152,7 +151,7 @@ int main(void) // ** Simulate channel effects ** channel_cccf ch = channel_cccf_create(); channel_cccf_add_awgn(ch, -30, 10); - channel_cccf_add_carrier_offset(ch, 0.05f, 1.23f); + //channel_cccf_add_carrier_offset(ch, 0.05f, 1.23f); float complex whole_burst_ch[burst_len]; channel_cccf_execute_block(ch, (float complex*)whole_burst, burst_len, whole_burst_ch); @@ -169,5 +168,5 @@ int main(void) layer1_tx_shutdown(&tx); layer1_rx_shutdown(&rx); - fprintf(stderr, "Done.\n"); + LOG(LVL_INFO, "Done."); } diff --git a/impl/test/layer1/test_rx_file.c b/impl/test/layer1/test_rx_file.c index 1fcbee5..99ebe88 100644 --- a/impl/test/layer1/test_rx_file.c +++ b/impl/test/layer1/test_rx_file.c @@ -4,7 +4,6 @@ #include -#include "jsonlogger.h" #include "logger.h" #include "layer1/rx.h" @@ -13,7 +12,7 @@ #define RESULT_CHECK(stmt) { \ result_t res = stmt; \ if(res != OK) { \ - fprintf(stderr, "Error %d in %s:%d!\n", res, __FILE__, __LINE__); \ + LOG(LVL_ERR, "Error %d in %s:%d!", res, __FILE__, __LINE__); \ exit(1); \ } \ } @@ -24,6 +23,10 @@ #define JSONLOGGER 0 +#if JSONLOGGER + #include "jsonlogger.h" +#endif + static rx_stats_t m_rx_stats; @@ -32,7 +35,7 @@ static result_t sdr_rf_to_baseband(nco_crcf nco, firdecim_crcf decim, float complex *bb_samples, size_t *nbb) { if((*nbb * SDR_OVERSAMPLING) < nrf) { - fprintf(stderr, "sdr_rf_to_baseband: result would not fit in output: %zd * %d < %zd\n", *nbb, SDR_OVERSAMPLING, nrf); + LOG(LVL_ERR, "sdr_rf_to_baseband: result would not fit in output: %zd * %d < %zd", *nbb, SDR_OVERSAMPLING, nrf); return ERR_SIZE; } @@ -85,7 +88,7 @@ void cb_rx(rx_evt_t evt, const layer1_rx_t *rx, uint8_t *packet_data, size_t pac break; case RX_EVT_PREAMBLE_FOUND: - //fprintf(stderr, "Found preamble!\n"); + //LOG(LVL_INFO, "Found preamble!"); m_rx_stats.preambles_found++; break; diff --git a/impl/test/test_jsonlogger.c b/impl/test/test_jsonlogger.c index 36f1b28..311db1a 100644 --- a/impl/test/test_jsonlogger.c +++ b/impl/test/test_jsonlogger.c @@ -3,6 +3,8 @@ #include #include +#include "logger.h" + #include "../src/jsonlogger.h" #include "../src/debug_structs.h" @@ -16,16 +18,18 @@ static void signal_handler(int signal, siginfo_t *info, void *ctx) (void)info; (void)ctx; - fprintf(stderr, "\nGracefully shutting down on signal %d.\n", signal); + LOG(LVL_INFO, "Gracefully shutting down on signal %d.", signal); m_running = false; } -int main() +int main(void) { + logger_init(); + if(!jsonlogger_init("jsonlog_test.fifo")) { - fprintf(stderr, "Could not initialize JSON logger.\n"); + LOG(LVL_ERR, "Could not initialize JSON logger."); return EXIT_FAILURE; } @@ -69,5 +73,5 @@ int main() jsonlogger_shutdown(); - fprintf(stderr, "Done.\n"); + LOG(LVL_INFO, "Done."); }