Make Librador logger configurable (#210)

* Refactor librador logging

* Make librador logger configurable
This commit is contained in:
Andrew Dona-Couch -- GitHub drop ICE 2022-01-31 15:48:10 -05:00 committed by GitHub
parent eec9dfdee1
commit 9169bc10b9
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
6 changed files with 107 additions and 43 deletions

View File

@ -1,6 +1,7 @@
#include "librador.h" #include "librador.h"
#include "librador_internal.h" #include "librador_internal.h"
#include "usbcallhandler.h" #include "usbcallhandler.h"
#include "logging_internal.h"
#include <vector> #include <vector>
#include <math.h> #include <math.h>
@ -94,7 +95,7 @@ std::vector<uint8_t> * librador_get_digital_data(int channel, double timeWindow_
int delay_subsamples = round(delay_seconds * subsamples_per_second); int delay_subsamples = round(delay_seconds * subsamples_per_second);
int numToGet = round(timeWindow_seconds * subsamples_per_second)/interval_subsamples; int numToGet = round(timeWindow_seconds * subsamples_per_second)/interval_subsamples;
printf("interval_subsamples = %d\ndelay_subsamples = %d\nnumToGet=%d\n", interval_subsamples, delay_subsamples, numToGet); LIBRADOR_LOG(LOG_DEBUG, "interval_subsamples = %d\ndelay_subsamples = %d\nnumToGet=%d\n", interval_subsamples, delay_subsamples, numToGet);
return internal_librador_object->usb_driver->getMany_singleBit(channel, numToGet, interval_subsamples, delay_subsamples); return internal_librador_object->usb_driver->getMany_singleBit(channel, numToGet, interval_subsamples, delay_subsamples);
} }
@ -295,3 +296,32 @@ int librador_synchronise_end(){
return internal_librador_object->usb_driver->set_synchronous_pause_state(false); return internal_librador_object->usb_driver->set_synchronous_pause_state(false);
} }
*/ */
static void std_logger(void * userdata, const int level, const char * format, va_list ap);
static librador_logger_p _librador_global_logger = std_logger;
static void * _librador_global_userdata = NULL;
void librador_global_logger(const int level, const char * format, ...){
va_list args;
va_start(args, format);
if (_librador_global_logger)
_librador_global_logger(_librador_global_userdata, level, format, args);
va_end(args);
}
void librador_logger_set(void * userdata, librador_logger_p logger){
_librador_global_logger = logger ? logger : std_logger;
_librador_global_userdata = userdata;
}
librador_logger_p librador_logger_get(void){
return _librador_global_logger;
}
void * librador_logger_get_userdata(void){
return _librador_global_userdata;
}
static void std_logger(void * userdata, const int level, const char * format, va_list ap){
vfprintf((level > LOG_ERROR) ? stdout : stderr , format, ap);
}

View File

@ -2,7 +2,9 @@
#define LIBRADOR_H #define LIBRADOR_H
#include "librador_global.h" #include "librador_global.h"
#include "logging.h"
#include <vector> #include <vector>
#include <stdarg.h>
#include <stdint.h> #include <stdint.h>
int LIBRADORSHARED_EXPORT librador_init(); int LIBRADORSHARED_EXPORT librador_init();
@ -52,5 +54,11 @@ int LIBRADORSHARED_EXPORT librador_synchronise_begin();
int LIBRADORSHARED_EXPORT librador_synchronise_end(); int LIBRADORSHARED_EXPORT librador_synchronise_end();
*/ */
typedef void (*librador_logger_p)(void * userdata, const int level, const char * format, va_list);
void LIBRADORSHARED_EXPORT librador_logger_set(void * userdata, librador_logger_p logger);
librador_logger_p LIBRADORSHARED_EXPORT librador_logger_get(void);
void * LIBRADORSHARED_EXPORT librador_logger_get_userdata(void);
#endif // LIBRADOR_H #endif // LIBRADOR_H

View File

@ -0,0 +1,11 @@
#ifndef LOGGING_H
#define LOGGING_H
enum {
LOG_NONE = 0,
LOG_ERROR,
LOG_WARNING,
LOG_DEBUG,
};
#endif // LOGGING_H

View File

@ -0,0 +1,13 @@
#ifndef LOGGING_INTERNAL_H
#define LOGGING_INTERNAL_H
#include "logging.h"
#define LIBRADOR_LOG(level, ...) \
do { \
librador_global_logger(level, __VA_ARGS__); \
} while (0)
void librador_global_logger(const int level, const char * format, ...);
#endif // LOGGING_INTERNAL_H

View File

@ -1,4 +1,5 @@
#include "o1buffer.h" #include "o1buffer.h"
#include "logging_internal.h"
#include <stdio.h> #include <stdio.h>
#include <stdlib.h> #include <stdlib.h>
#include <stdint.h> #include <stdint.h>
@ -34,7 +35,7 @@ void o1buffer::add(int value, int address){
address = address % NUM_SAMPLES_PER_CHANNEL; address = address % NUM_SAMPLES_PER_CHANNEL;
} }
if(address<0){ if(address<0){
fprintf(stderr, "ERROR: o1buffer::add was given a negative address\n"); LIBRADOR_LOG(LOG_ERROR, "ERROR: o1buffer::add was given a negative address\n");
} }
//Assign the value //Assign the value
buffer[address] = value; buffer[address] = value;
@ -88,7 +89,7 @@ int o1buffer::get(int address){
address = address % NUM_SAMPLES_PER_CHANNEL; address = address % NUM_SAMPLES_PER_CHANNEL;
} }
if(address<0){ if(address<0){
fprintf(stderr, "ERROR: o1buffer::get was given a negative address\n"); LIBRADOR_LOG(LOG_ERROR, "ERROR: o1buffer::get was given a negative address\n");
} }
//Return the value //Return the value
return buffer[address]; return buffer[address];

View File

@ -2,6 +2,7 @@
#include <stdio.h> #include <stdio.h>
#include "o1buffer.h" #include "o1buffer.h"
#include "logging_internal.h"
#include <mutex> #include <mutex>
#include <chrono> #include <chrono>
#include <thread> #include <thread>
@ -88,20 +89,20 @@ static void LIBUSB_CALL isoCallback(struct libusb_transfer * transfer){
if(usb_iso_needs_rearming()){ if(usb_iso_needs_rearming()){
int error = libusb_submit_transfer(transfer); int error = libusb_submit_transfer(transfer);
if(error){ if(error){
printf("Error re-arming the endpoint!\n"); LIBRADOR_LOG(LOG_DEBUG, "Error re-arming the endpoint!\n");
begin_usb_thread_shutdown(); begin_usb_thread_shutdown();
decrement_remaining_transfers(); decrement_remaining_transfers();
printf("Transfer not being rearmed! %d armed transfers remaining\n", usb_shutdown_remaining_transfers); LIBRADOR_LOG(LOG_WARNING, "Transfer not being rearmed! %d armed transfers remaining\n", usb_shutdown_remaining_transfers);
} }
} else { } else {
decrement_remaining_transfers(); decrement_remaining_transfers();
printf("Transfer not being rearmed! %d armed transfers remaining\n", usb_shutdown_remaining_transfers); LIBRADOR_LOG(LOG_WARNING, "Transfer not being rearmed! %d armed transfers remaining\n", usb_shutdown_remaining_transfers);
} }
return; return;
} }
void usb_polling_function(libusb_context *ctx){ void usb_polling_function(libusb_context *ctx){
printf("usb_polling_function thread spawned\n"); LIBRADOR_LOG(LOG_DEBUG, "usb_polling_function thread spawned\n");
struct timeval tv; struct timeval tv;
tv.tv_sec = 1; tv.tv_sec = 1;
tv.tv_usec = 0;//ISO_PACKETS_PER_CTX*4000; tv.tv_usec = 0;//ISO_PACKETS_PER_CTX*4000;
@ -120,7 +121,7 @@ usbCallHandler::usbCallHandler(unsigned short VID_in, unsigned short PID_in)
for(int k=0; k<NUM_ISO_ENDPOINTS; k++){ for(int k=0; k<NUM_ISO_ENDPOINTS; k++){
pipeID[k] = 0x81+k; pipeID[k] = 0x81+k;
printf("pipeID %d = %d\n", k, pipeID[k]); LIBRADOR_LOG(LOG_DEBUG, "pipeID %d = %d\n", k, pipeID[k]);
} }
internal_o1_buffer_375_CH1 = new o1buffer(); internal_o1_buffer_375_CH1 = new o1buffer();
@ -135,12 +136,12 @@ usbCallHandler::usbCallHandler(unsigned short VID_in, unsigned short PID_in)
usbCallHandler::~usbCallHandler(){ usbCallHandler::~usbCallHandler(){
//Kill off usb_polling_thread. Maybe join then get it to detect its own timeout condition. //Kill off usb_polling_thread. Maybe join then get it to detect its own timeout condition.
printf("Calling destructor for librador USB call handler\n"); LIBRADOR_LOG(LOG_DEBUG, "Calling destructor for librador USB call handler\n");
begin_usb_thread_shutdown(); begin_usb_thread_shutdown();
printf("Shutting down USB polling thread...\n"); LIBRADOR_LOG(LOG_DEBUG, "Shutting down USB polling thread...\n");
usb_polling_thread->join(); usb_polling_thread->join();
printf("USB polling thread stopped.\n"); LIBRADOR_LOG(LOG_DEBUG, "USB polling thread stopped.\n");
delete usb_polling_thread; delete usb_polling_thread;
for (int i=0; i<NUM_FUTURE_CTX; i++){ for (int i=0; i<NUM_FUTURE_CTX; i++){
@ -148,58 +149,58 @@ usbCallHandler::~usbCallHandler(){
libusb_free_transfer(isoCtx[k][i]); libusb_free_transfer(isoCtx[k][i]);
} }
} }
printf("Transfers freed.\n"); LIBRADOR_LOG(LOG_DEBUG, "Transfers freed.\n");
if(handle != NULL){ if(handle != NULL){
libusb_release_interface(handle, 0); libusb_release_interface(handle, 0);
printf("Interface released\n"); LIBRADOR_LOG(LOG_DEBUG, "Interface released\n");
libusb_close(handle); libusb_close(handle);
printf("Device Closed\n"); LIBRADOR_LOG(LOG_DEBUG, "Device Closed\n");
} }
if(ctx != NULL){ if(ctx != NULL){
libusb_exit(ctx); libusb_exit(ctx);
printf("Libusb exited\n"); LIBRADOR_LOG(LOG_DEBUG, "Libusb exited\n");
} }
printf("librador USB call handler deleted\n"); LIBRADOR_LOG(LOG_DEBUG, "librador USB call handler deleted\n");
} }
int usbCallHandler::setup_usb_control(){ int usbCallHandler::setup_usb_control(){
printf("usbCallHandler::setup_usb_control()\n"); LIBRADOR_LOG(LOG_DEBUG, "usbCallHandler::setup_usb_control()\n");
if(ctx != NULL){ if(ctx != NULL){
printf("There is already a libusb context!\n"); LIBRADOR_LOG(LOG_ERROR, "There is already a libusb context!\n");
return 1; return 1;
} else printf("libusb context is null\n"); } else LIBRADOR_LOG(LOG_WARNING, "libusb context is null\n");
//Initialise the Library //Initialise the Library
int error; int error;
error = libusb_init(&ctx); error = libusb_init(&ctx);
if(error){ if(error){
printf("libusb_init FAILED\n"); LIBRADOR_LOG(LOG_ERROR, "libusb_init FAILED\n");
return -1; return -1;
} else printf("Libusb context initialised\n"); } else LIBRADOR_LOG(LOG_DEBUG, "Libusb context initialised\n");
libusb_set_debug(ctx, 3); libusb_set_debug(ctx, 3);
//Get a handle on the Labrador device //Get a handle on the Labrador device
handle = libusb_open_device_with_vid_pid(ctx, VID, PID); handle = libusb_open_device_with_vid_pid(ctx, VID, PID);
if(handle==NULL){ if(handle==NULL){
printf("DEVICE NOT FOUND\n"); LIBRADOR_LOG(LOG_ERROR, "DEVICE NOT FOUND\n");
libusb_exit(ctx); libusb_exit(ctx);
ctx = NULL; ctx = NULL;
return -2; return -2;
} }
printf("Device found!!\n"); LIBRADOR_LOG(LOG_DEBUG, "Device found!!\n");
//Claim the interface //Claim the interface
error = libusb_claim_interface(handle, 0); error = libusb_claim_interface(handle, 0);
if(error){ if(error){
printf("libusb_claim_interface FAILED\n"); LIBRADOR_LOG(LOG_ERROR, "libusb_claim_interface FAILED\n");
libusb_close(handle); libusb_close(handle);
handle = NULL; handle = NULL;
return -3; return -3;
} else printf("Interface claimed!\n"); } else LIBRADOR_LOG(LOG_DEBUG, "Interface claimed!\n");
/* /*
error = libusb_set_interface_alt_setting(handle, 0, 0); error = libusb_set_interface_alt_setting(handle, 0, 0);
if(error){ if(error){
@ -219,7 +220,7 @@ int usbCallHandler::setup_usb_control(){
int usbCallHandler::setup_usb_iso(){ int usbCallHandler::setup_usb_iso(){
int error; int error;
printf("usbCallHandler::setup_usb_iso()\n"); LIBRADOR_LOG(LOG_DEBUG, "usbCallHandler::setup_usb_iso()\n");
for(int n=0;n<NUM_FUTURE_CTX;n++){ for(int n=0;n<NUM_FUTURE_CTX;n++){
for (unsigned char k=0;k<NUM_ISO_ENDPOINTS;k++){ for (unsigned char k=0;k<NUM_ISO_ENDPOINTS;k++){
@ -228,7 +229,7 @@ int usbCallHandler::setup_usb_iso(){
libusb_set_iso_packet_lengths(isoCtx[k][n], ISO_PACKET_SIZE); libusb_set_iso_packet_lengths(isoCtx[k][n], ISO_PACKET_SIZE);
error = libusb_submit_transfer(isoCtx[k][n]); error = libusb_submit_transfer(isoCtx[k][n]);
if(error){ if(error){
printf("libusb_submit_transfer #%d:%d FAILED with error %d %s\n", n, k, error, libusb_error_name(error)); LIBRADOR_LOG(LOG_ERROR, "libusb_submit_transfer #%d:%d FAILED with error %d %s\n", n, k, error, libusb_error_name(error));
return error; return error;
} }
} }
@ -242,7 +243,7 @@ int usbCallHandler::send_control_transfer(uint8_t RequestType, uint8_t Request,
unsigned char *controlBuffer; unsigned char *controlBuffer;
if(!connected){ if(!connected){
printf("Control packet requested before device has connected!\n"); LIBRADOR_LOG(LOG_ERROR, "Control packet requested before device has connected!\n");
return -1; return -1;
} }
@ -253,7 +254,7 @@ int usbCallHandler::send_control_transfer(uint8_t RequestType, uint8_t Request,
int error = libusb_control_transfer(handle, RequestType, Request, Value, Index, controlBuffer, Length, 4000); int error = libusb_control_transfer(handle, RequestType, Request, Value, Index, controlBuffer, Length, 4000);
if(error<0){ if(error<0){
printf("send_control_transfer FAILED with error %s", libusb_error_name(error)); LIBRADOR_LOG(LOG_ERROR, "send_control_transfer FAILED with error %s", libusb_error_name(error));
return error - 100; return error - 100;
} }
/* /*
@ -270,7 +271,7 @@ int usbCallHandler::send_control_transfer(uint8_t RequestType, uint8_t Request,
int usbCallHandler::avrDebug(void){ int usbCallHandler::avrDebug(void){
send_control_transfer_with_error_checks(0xc0, 0xa0, 0, 0, sizeof(unified_debug), NULL); send_control_transfer_with_error_checks(0xc0, 0xa0, 0, 0, sizeof(unified_debug), NULL);
printf("unified debug is of size %lu\n", sizeof(unified_debug)); LIBRADOR_LOG(LOG_DEBUG, "unified debug is of size %lu\n", sizeof(unified_debug));
unified_debug *udsPtr = (unified_debug *) inBuffer; unified_debug *udsPtr = (unified_debug *) inBuffer;
uint16_t trfcnt0 = (udsPtr->trfcntH0 << 8) + udsPtr->trfcntL0; uint16_t trfcnt0 = (udsPtr->trfcntH0 << 8) + udsPtr->trfcntL0;
@ -281,18 +282,18 @@ int usbCallHandler::avrDebug(void){
uint16_t dma_ch0_cnt = (udsPtr->dma_ch0_cntH << 8) + udsPtr->dma_ch0_cntL; uint16_t dma_ch0_cnt = (udsPtr->dma_ch0_cntH << 8) + udsPtr->dma_ch0_cntL;
uint16_t dma_ch1_cnt = (udsPtr->dma_ch1_cntH << 8) + udsPtr->dma_ch1_cntL; uint16_t dma_ch1_cnt = (udsPtr->dma_ch1_cntH << 8) + udsPtr->dma_ch1_cntL;
printf("%s", udsPtr->header); LIBRADOR_LOG(LOG_DEBUG, "%s", udsPtr->header);
printf("trfcnt0 = %d\n", trfcnt0); LIBRADOR_LOG(LOG_DEBUG, "trfcnt0 = %d\n", trfcnt0);
printf("trfcnt1 = %d\n", trfcnt1); LIBRADOR_LOG(LOG_DEBUG, "trfcnt1 = %d\n", trfcnt1);
printf("medianTrfcnt = %d\n", medianTrfcnt); LIBRADOR_LOG(LOG_DEBUG, "medianTrfcnt = %d\n", medianTrfcnt);
printf("outOfRange = %d\n", outOfRange); LIBRADOR_LOG(LOG_DEBUG, "outOfRange = %d\n", outOfRange);
printf("counter = %d\n", counter); LIBRADOR_LOG(LOG_DEBUG, "counter = %d\n", counter);
printf("calValNeg = %d\n", udsPtr->calValNeg); LIBRADOR_LOG(LOG_DEBUG, "calValNeg = %d\n", udsPtr->calValNeg);
printf("calValPos = %d\n", udsPtr->calValPos); LIBRADOR_LOG(LOG_DEBUG, "calValPos = %d\n", udsPtr->calValPos);
printf("CALA = %d\n", udsPtr->CALA); LIBRADOR_LOG(LOG_DEBUG, "CALA = %d\n", udsPtr->CALA);
printf("CALB = %d\n", udsPtr->CALB); LIBRADOR_LOG(LOG_DEBUG, "CALB = %d\n", udsPtr->CALB);
printf("dma_ch0_cnt = %d\n", dma_ch0_cnt); LIBRADOR_LOG(LOG_DEBUG, "dma_ch0_cnt = %d\n", dma_ch0_cnt);
printf("dma_ch1_cnt = %d\n", dma_ch1_cnt); LIBRADOR_LOG(LOG_DEBUG, "dma_ch1_cnt = %d\n", dma_ch1_cnt);
return 0; return 0;
} }
@ -404,7 +405,7 @@ int usbCallHandler::set_gain(double newGain){
else if (newGain == 32) gainMask = 0x05; else if (newGain == 32) gainMask = 0x05;
else if (newGain == 64) gainMask = 0x06; else if (newGain == 64) gainMask = 0x06;
else{ else{
printf("Invalid gain value. Valid values are 0.1, 1, 2, 4, 8, 16, 32, 64\n"); LIBRADOR_LOG(LOG_ERROR, "Invalid gain value. Valid values are 0.1, 1, 2, 4, 8, 16, 32, 64\n");
return -1; return -1;
} }