Use the new logging system everywhere

This commit is contained in:
Thomas Kolb 2024-05-30 10:44:42 +02:00
parent d6eaef91cd
commit 65daa182ef
10 changed files with 70 additions and 67 deletions

View file

@ -1,11 +1,10 @@
#include <stdio.h>
#include <string.h>
#include <malloc.h>
#include <math.h>
#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;
}

View file

@ -3,6 +3,8 @@
#include <stdbool.h>
#include <malloc.h>
#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;
}

View file

@ -8,6 +8,8 @@
#include <stdio.h>
#include <string.h>
#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");

View file

@ -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 <stdio.h>
#include <liquid/liquid.h>
@ -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);

View file

@ -1,8 +1,6 @@
#include <libhackrf/hackrf.h>
#include <liquid/liquid.h>
#include <semaphore.h>
#include <stdio.h> //printf
#include <stdlib.h> //free
#include <complex.h>
#include <math.h>
#include <string.h>
@ -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;
}

View file

@ -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
)

View file

@ -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

View file

@ -1,7 +1,6 @@
#include <stdio.h>
#include <stdlib.h>
#include <string.h>
#include <math.h>
#include <ctype.h>
#include <time.h>
@ -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.");
}

View file

@ -4,7 +4,6 @@
#include <liquid/liquid.h>
#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;

View file

@ -3,6 +3,8 @@
#include <stdlib.h>
#include <unistd.h>
#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.");
}