hamnet70/impl/src/jsonlogger.c
Simon Ruderich 5fb5a2908d jsonlogger: increase pipe buffer to reduce likelihood of corrupted messages
Our JSON messages can get rather large which can cause a buffer overrun
when the reading program is not scheduled at the same time. When the
kernel returns EAGAIN we abort writing the current JSON message.
However, the unfinished (and thus invalid) JSON message is still in the
pipe and will be processed by the reading program.

Increase the pipe buffer from the default 65536 to reduce the likelihood
of this happening. It's difficult to completely prevent the issue as we
don't want to slow down the main program due to slow logging.
2024-05-28 08:51:56 +02:00

192 lines
4.2 KiB
C

// For F_SETPIPE_SZ
#define _GNU_SOURCE
#include <fcntl.h>
#include <unistd.h>
#include <errno.h>
#include <sys/types.h>
#include <sys/stat.h>
#include <stdlib.h>
#include <stdio.h>
#include <string.h>
#include "jsonlogger.h"
#define LOG_OR_RETURN(...) \
if(dprintf(m_fifo_fd, __VA_ARGS__) < 0) { \
return false; \
}
static int m_fifo_fd = -1;
static char m_fifo_path[1024];
static bool start_message(void)
{
if(m_fifo_fd < 0) {
// FIFO was not opened yet. Try to open it now.
m_fifo_fd = open(m_fifo_path, O_WRONLY | O_NONBLOCK);
if(m_fifo_fd < 0) {
if(errno != ENXIO) {
perror("open");
}
return false;
}
// Increase pipe buffer to prevent/reduce EAGAIN during a JSON
// message to prevent corrupted JSON messages. 1048576 is the
// current maximum as permitted by the Linux kernel.
if (fcntl(m_fifo_fd, F_SETPIPE_SZ, 1048576) < 0) {
perror("fcntl");
}
}
ssize_t ret = write(m_fifo_fd, "{", 1);
if(ret < 0) {
// FIFO is not writable or other error
switch(errno) {
case EAGAIN: // FIFO not ready for writing -> drop message
break;
case EPIPE: // FIFO was closed on the other side
close(m_fifo_fd);
m_fifo_fd = -1;
break;
default: // other errors are logged to stderr
perror("write");
break;
}
return false;
}
return true;
}
static bool end_message(void)
{
ssize_t ret = write(m_fifo_fd, "}\n", 2);
if(ret < 0) {
// FIFO is not writable or other error
if(errno != EAGAIN) {
perror("write");
}
return false;
}
return true;
}
static bool dump_var_array_cf(const var_array_cf_t *varray)
{
LOG_OR_RETURN("[");
if(varray->used > 0) {
LOG_OR_RETURN("[%g, %g]", crealf(varray->symbols[0]), cimagf(varray->symbols[0]));
for(size_t i = 1; i < varray->used; i++) {
LOG_OR_RETURN(", [%g, %g]", crealf(varray->symbols[i]), cimagf(varray->symbols[i]));
}
}
LOG_OR_RETURN("]");
return true;
}
bool jsonlogger_init(const char *fifoname)
{
// try to create the named FIFO
int ret = mkfifo(fifoname, 0666);
if(ret < 0) {
if(errno != EEXIST) {
perror("mkfifo");
return false;
}
}
strncpy(m_fifo_path, fifoname, sizeof(m_fifo_path));
m_fifo_path[sizeof(m_fifo_path)-1] = '\0';
m_fifo_fd = -1; // open on demand
return true;
}
void jsonlogger_shutdown(void)
{
close(m_fifo_fd);
}
bool jsonlogger_log_simple_integer(const char *msg_type, int64_t value)
{
if(!start_message()) {
return false;
}
LOG_OR_RETURN("\"%s\": %ld", msg_type, value);
return end_message();
}
bool jsonlogger_log_simple_double(const char *msg_type, double value)
{
if(!start_message()) {
return false;
}
LOG_OR_RETURN("\"%s\": %g", msg_type, value);
return end_message();
}
bool jsonlogger_log_rx_stats(const rx_stats_t *rx_stats)
{
if(!start_message()) {
return false;
}
LOG_OR_RETURN("\"preambles_found\": %zd, ", rx_stats->preambles_found);
LOG_OR_RETURN("\"successful_decodes\": %zd, ", rx_stats->successful_decodes);
LOG_OR_RETURN("\"failed_decodes\": %zd, ", rx_stats->failed_decodes);
LOG_OR_RETURN("\"header_errors\": %zd", rx_stats->header_errors);
return end_message();
}
bool jsonlogger_log_rx_packet_info(const rx_packet_dbg_t *rx_packet_dbg)
{
if(!start_message()) {
return false;
}
LOG_OR_RETURN("\"preamble_symbols\": ");
dump_var_array_cf(&rx_packet_dbg->preamble_symbols);
LOG_OR_RETURN(", \"header_symbols\": ");
dump_var_array_cf(&rx_packet_dbg->header_symbols);
LOG_OR_RETURN(", \"data_symbols\": ");
dump_var_array_cf(&rx_packet_dbg->data_symbols);
LOG_OR_RETURN(", ");
LOG_OR_RETURN("\"preamble_correlation_peak\": %g, ", rx_packet_dbg->preamble_correlation_peak);
LOG_OR_RETURN("\"header_rssi_dB\": %g, ", rx_packet_dbg->header_rssi);
LOG_OR_RETURN("\"data_rssi_dB\": %g, ", rx_packet_dbg->data_rssi);
LOG_OR_RETURN("\"noise_floor_level_dB\": %g, ", rx_packet_dbg->noise_floor_level);
LOG_OR_RETURN("\"carrier_tracked_freq_Hz\": %g, ", rx_packet_dbg->carrier_tracked_freq);
LOG_OR_RETURN("\"initial_freq_offset_Hz\": %g, ", rx_packet_dbg->initial_freq_offset);
LOG_OR_RETURN("\"final_freq_offset_Hz\": %g, ", rx_packet_dbg->final_freq_offset);
LOG_OR_RETURN("\"header_evm\": %g, ", rx_packet_dbg->header_evm);
LOG_OR_RETURN("\"data_evm\": %g", rx_packet_dbg->data_evm);
return end_message();
}