From 56729041b33a9d71555725d4400d2a1539225a6e Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Jan=20Grome=C5=A1?= Date: Sun, 2 Mar 2025 09:37:55 +0100 Subject: [PATCH] [MOD] Add debug timestamps (#1440) --- src/BuildOpt.h | 82 ++++++++++++++++++++++++--------------------- src/Hal.cpp | 12 ++++++- src/Hal.h | 3 ++ src/Module.cpp | 8 ++--- src/utils/Utils.cpp | 23 ++++++++++--- src/utils/Utils.h | 4 +-- 6 files changed, 82 insertions(+), 50 deletions(-) diff --git a/src/BuildOpt.h b/src/BuildOpt.h index 47511aba..2f8b1001 100644 --- a/src/BuildOpt.h +++ b/src/BuildOpt.h @@ -473,23 +473,20 @@ #endif #if RADIOLIB_DEBUG - #if defined(RADIOLIB_BUILD_ARDUINO) - #define RADIOLIB_DEBUG_PRINT(...) rlb_printf(__VA_ARGS__) - #define RADIOLIB_DEBUG_PRINTLN(M, ...) rlb_printf(M "" RADIOLIB_LINE_FEED, ##__VA_ARGS__) - #define RADIOLIB_DEBUG_PRINT_LVL(LEVEL, M, ...) rlb_printf(LEVEL "" M, ##__VA_ARGS__) - #define RADIOLIB_DEBUG_PRINTLN_LVL(LEVEL, M, ...) rlb_printf(LEVEL "" M "" RADIOLIB_LINE_FEED, ##__VA_ARGS__) + #if !defined(RADIOLIB_DEBUG_PRINT) + #define RADIOLIB_DEBUG_PRINT(M, ...) rlb_printf(false, M, ##__VA_ARGS__) + #define RADIOLIB_DEBUG_PRINT_LVL(LEVEL, M, ...) rlb_printf(true, LEVEL "" M, ##__VA_ARGS__) + #endif - // some platforms do not support printf("%f"), so it has to be done this way + #if !defined(RADIOLIB_DEBUG_PRINTLN) + #define RADIOLIB_DEBUG_PRINTLN(M, ...) rlb_printf(false, M RADIOLIB_LINE_FEED, ##__VA_ARGS__) + #define RADIOLIB_DEBUG_PRINTLN_LVL(LEVEL, M, ...) rlb_printf(true, LEVEL "" M RADIOLIB_LINE_FEED, ##__VA_ARGS__) + #endif + + // some Arduino platforms do not support printf("%f"), so it has to be done this way + #if defined(RADIOLIB_BUILD_ARDUINO) #define RADIOLIB_DEBUG_PRINT_FLOAT(LEVEL, VAL, DECIMALS) RADIOLIB_DEBUG_PRINT(LEVEL); RADIOLIB_DEBUG_PORT.print(VAL, DECIMALS) #else - #if !defined(RADIOLIB_DEBUG_PRINT) - #define RADIOLIB_DEBUG_PRINT(...) fprintf(RADIOLIB_DEBUG_PORT, __VA_ARGS__) - #define RADIOLIB_DEBUG_PRINT_LVL(LEVEL, M, ...) fprintf(RADIOLIB_DEBUG_PORT, LEVEL "" M, ##__VA_ARGS__) - #endif - #if !defined(RADIOLIB_DEBUG_PRINTLN) - #define RADIOLIB_DEBUG_PRINTLN(M, ...) fprintf(RADIOLIB_DEBUG_PORT, M "" RADIOLIB_LINE_FEED, ##__VA_ARGS__) - #define RADIOLIB_DEBUG_PRINTLN_LVL(LEVEL, M, ...) fprintf(RADIOLIB_DEBUG_PORT, LEVEL "" M "" RADIOLIB_LINE_FEED, ##__VA_ARGS__) - #endif #define RADIOLIB_DEBUG_PRINT_FLOAT(LEVEL, VAL, DECIMALS) RADIOLIB_DEBUG_PRINT(LEVEL "%.3f", VAL) #endif @@ -497,52 +494,61 @@ #else #define RADIOLIB_DEBUG_PRINT(...) {} #define RADIOLIB_DEBUG_PRINTLN(...) {} - #define RADIOLIB_DEBUG_PRINT_FLOAT(VAL, DECIMALS) {} + #define RADIOLIB_DEBUG_PRINT_FLOAT(LEVEL, VAL, DECIMALS) {} #define RADIOLIB_DEBUG_HEXDUMP(...) {} #endif +#define RADIOLIB_DEBUG_TAG ": " +#define RADIOLIB_DEBUG_TAG_BASIC "RLB_DBG" RADIOLIB_DEBUG_TAG +#define RADIOLIB_DEBUG_TAG_PROTOCOL "RLB_PRO" RADIOLIB_DEBUG_TAG +#define RADIOLIB_DEBUG_TAG_SPI "RLB_SPI" RADIOLIB_DEBUG_TAG + #if RADIOLIB_DEBUG_BASIC - #define RADIOLIB_DEBUG_BASIC_PRINT(...) RADIOLIB_DEBUG_PRINT_LVL("RLB_DBG: ", __VA_ARGS__) - #define RADIOLIB_DEBUG_BASIC_PRINT_NOTAG(...) RADIOLIB_DEBUG_PRINT_LVL("", __VA_ARGS__) - #define RADIOLIB_DEBUG_BASIC_PRINTLN(...) RADIOLIB_DEBUG_PRINTLN_LVL("RLB_DBG: ", __VA_ARGS__) - #define RADIOLIB_DEBUG_BASIC_PRINT_FLOAT(...) RADIOLIB_DEBUG_PRINT_FLOAT("RLB_DBG: ", __VA_ARGS__); - #define RADIOLIB_DEBUG_BASIC_HEXDUMP(...) RADIOLIB_DEBUG_HEXDUMP("RLB_DBG: ", __VA_ARGS__); + #define RADIOLIB_DEBUG_BASIC_PRINT(...) RADIOLIB_DEBUG_PRINT_LVL(RADIOLIB_DEBUG_TAG_BASIC, __VA_ARGS__) + #define RADIOLIB_DEBUG_BASIC_PRINTLN(...) RADIOLIB_DEBUG_PRINTLN_LVL(RADIOLIB_DEBUG_TAG_BASIC, __VA_ARGS__) + #define RADIOLIB_DEBUG_BASIC_HEXDUMP(...) RADIOLIB_DEBUG_HEXDUMP(RADIOLIB_DEBUG_TAG_BASIC, __VA_ARGS__) + #define RADIOLIB_DEBUG_BASIC_PRINT_FLOAT(...) RADIOLIB_DEBUG_PRINT_FLOAT(RADIOLIB_DEBUG_TAG_BASIC, __VA_ARGS__) + #define RADIOLIB_DEBUG_BASIC_PRINT_NOTAG(...) RADIOLIB_DEBUG_PRINT(__VA_ARGS__) + #define RADIOLIB_DEBUG_BASIC_PRINTLN_NOTAG(...) RADIOLIB_DEBUG_PRINTLN(__VA_ARGS__) #else #define RADIOLIB_DEBUG_BASIC_PRINT(...) {} - #define RADIOLIB_DEBUG_BASIC_PRINT_NOTAG(...) {} #define RADIOLIB_DEBUG_BASIC_PRINTLN(...) {} - #define RADIOLIB_DEBUG_BASIC_PRINT_FLOAT(...) {} #define RADIOLIB_DEBUG_BASIC_HEXDUMP(...) {} + #define RADIOLIB_DEBUG_BASIC_PRINT_FLOAT(...) {} + #define RADIOLIB_DEBUG_BASIC_PRINT_NOTAG(...) {} + #define RADIOLIB_DEBUG_BASIC_PRINTLN_NOTAG(...) {} #endif #if RADIOLIB_DEBUG_PROTOCOL - #define RADIOLIB_DEBUG_PROTOCOL_PRINT(...) RADIOLIB_DEBUG_PRINT_LVL("RLB_PRO: ", __VA_ARGS__) - #define RADIOLIB_DEBUG_PROTOCOL_PRINT_NOTAG(...) RADIOLIB_DEBUG_PRINT_LVL("", __VA_ARGS__) - #define RADIOLIB_DEBUG_PROTOCOL_PRINTLN(...) RADIOLIB_DEBUG_PRINTLN_LVL("RLB_PRO: ", __VA_ARGS__) - #define RADIOLIB_DEBUG_PROTOCOL_PRINT_FLOAT(...) RADIOLIB_DEBUG_PRINT_FLOAT("RLB_PRO: ", __VA_ARGS__); - #define RADIOLIB_DEBUG_PROTOCOL_HEXDUMP(...) RADIOLIB_DEBUG_HEXDUMP("RLB_PRO: ", __VA_ARGS__); + #define RADIOLIB_DEBUG_PROTOCOL_PRINT(...) RADIOLIB_DEBUG_PRINT_LVL(RADIOLIB_DEBUG_TAG_PROTOCOL, __VA_ARGS__) + #define RADIOLIB_DEBUG_PROTOCOL_PRINTLN(...) RADIOLIB_DEBUG_PRINTLN_LVL(RADIOLIB_DEBUG_TAG_PROTOCOL, __VA_ARGS__) + #define RADIOLIB_DEBUG_PROTOCOL_HEXDUMP(...) RADIOLIB_DEBUG_HEXDUMP(RADIOLIB_DEBUG_TAG_PROTOCOL, __VA_ARGS__) + #define RADIOLIB_DEBUG_PROTOCOL_PRINT_FLOAT(...) RADIOLIB_DEBUG_PRINT_FLOAT(RADIOLIB_DEBUG_TAG_PROTOCOL, __VA_ARGS__) + #define RADIOLIB_DEBUG_PROTOCOL_PRINT_NOTAG(...) RADIOLIB_DEBUG_PRINT(__VA_ARGS__) + #define RADIOLIB_DEBUG_PROTOCOL_PRINTLN_NOTAG(...) RADIOLIB_DEBUG_PRINTLN(__VA_ARGS__) #else #define RADIOLIB_DEBUG_PROTOCOL_PRINT(...) {} - #define RADIOLIB_DEBUG_PROTOCOL_PRINT_NOTAG(...) {} #define RADIOLIB_DEBUG_PROTOCOL_PRINTLN(...) {} - #define RADIOLIB_DEBUG_PROTOCOL_PRINT_FLOAT(...) {} #define RADIOLIB_DEBUG_PROTOCOL_HEXDUMP(...) {} + #define RADIOLIB_DEBUG_PROTOCOL_PRINT_FLOAT(...) {} + #define RADIOLIB_DEBUG_PROTOCOL_PRINT_NOTAG(...) {} + #define RADIOLIB_DEBUG_PROTOCOL_PRINTLN_NOTAG(...) {} #endif #if RADIOLIB_DEBUG_SPI - #define RADIOLIB_DEBUG_SPI_PRINT(...) RADIOLIB_DEBUG_PRINT_LVL("RLB_SPI: ", __VA_ARGS__) - #define RADIOLIB_DEBUG_SPI_PRINT_NOTAG(...) RADIOLIB_DEBUG_PRINT_LVL("", __VA_ARGS__) - #define RADIOLIB_DEBUG_SPI_PRINTLN(...) RADIOLIB_DEBUG_PRINTLN_LVL("RLB_SPI: ", __VA_ARGS__) - #define RADIOLIB_DEBUG_SPI_PRINTLN_NOTAG(...) RADIOLIB_DEBUG_PRINTLN_LVL("", __VA_ARGS__) - #define RADIOLIB_DEBUG_SPI_PRINT_FLOAT(...) RADIOLIB_DEBUG_PRINT_FLOAT("RLB_SPI: ", __VA_ARGS__); - #define RADIOLIB_DEBUG_SPI_HEXDUMP(...) RADIOLIB_DEBUG_HEXDUMP("RLB_SPI: ", __VA_ARGS__); + #define RADIOLIB_DEBUG_SPI_PRINT(...) RADIOLIB_DEBUG_PRINT_LVL(RADIOLIB_DEBUG_TAG_SPI, __VA_ARGS__) + #define RADIOLIB_DEBUG_SPI_PRINTLN(...) RADIOLIB_DEBUG_PRINTLN_LVL(RADIOLIB_DEBUG_TAG_SPI, __VA_ARGS__) + #define RADIOLIB_DEBUG_SPI_HEXDUMP(...) RADIOLIB_DEBUG_HEXDUMP(RADIOLIB_DEBUG_TAG_SPI, __VA_ARGS__) + #define RADIOLIB_DEBUG_SPI_PRINT_FLOAT(...) RADIOLIB_DEBUG_PRINT_FLOAT(RADIOLIB_DEBUG_TAG_SPI, __VA_ARGS__) + #define RADIOLIB_DEBUG_SPI_PRINT_NOTAG(...) RADIOLIB_DEBUG_PRINT(__VA_ARGS__) + #define RADIOLIB_DEBUG_SPI_PRINTLN_NOTAG(...) RADIOLIB_DEBUG_PRINTLN(__VA_ARGS__) #else #define RADIOLIB_DEBUG_SPI_PRINT(...) {} - #define RADIOLIB_DEBUG_SPI_PRINT_NOTAG(...) {} #define RADIOLIB_DEBUG_SPI_PRINTLN(...) {} - #define RADIOLIB_DEBUG_SPI_PRINTLN_NOTAG(...) {} - #define RADIOLIB_DEBUG_SPI_PRINT_FLOAT(...) {} #define RADIOLIB_DEBUG_SPI_HEXDUMP(...) {} + #define RADIOLIB_DEBUG_SPI_PRINT_FLOAT(...) {} + #define RADIOLIB_DEBUG_SPI_PRINT_NOTAG(...) {} + #define RADIOLIB_DEBUG_SPI_PRINTLN_NOTAG(...) {} #endif // debug info strings diff --git a/src/Hal.cpp b/src/Hal.cpp index acc43bfe..90c86f4f 100644 --- a/src/Hal.cpp +++ b/src/Hal.cpp @@ -1,12 +1,18 @@ #include "Hal.h" +static RadioLibHal* rlb_timestamp_hal = nullptr; + RadioLibHal::RadioLibHal(const uint32_t input, const uint32_t output, const uint32_t low, const uint32_t high, const uint32_t rising, const uint32_t falling) : GpioModeInput(input), GpioModeOutput(output), GpioLevelLow(low), GpioLevelHigh(high), GpioInterruptRising(rising), - GpioInterruptFalling(falling) {} + GpioInterruptFalling(falling) { + if(!rlb_timestamp_hal) { + rlb_timestamp_hal = this; + } + } void RadioLibHal::init() { @@ -33,3 +39,7 @@ void RadioLibHal::yield() { uint32_t RadioLibHal::pinToInterrupt(uint32_t pin) { return(pin); } + +RadioLibTime_t rlb_time_us() { + return(rlb_timestamp_hal == nullptr ? 0 : rlb_timestamp_hal->micros()); +} diff --git a/src/Hal.h b/src/Hal.h index 291b3473..3676fea2 100644 --- a/src/Hal.h +++ b/src/Hal.h @@ -6,6 +6,9 @@ #include "BuildOpt.h" +/*! \brief Global-scope function that returns timestamp since start (in microseconds). */ +RadioLibTime_t rlb_time_us(); + /*! \class RadioLibHal \brief Hardware abstraction library base interface. diff --git a/src/Module.cpp b/src/Module.cpp index 385f3930..4ed06b46 100644 --- a/src/Module.cpp +++ b/src/Module.cpp @@ -227,7 +227,7 @@ void Module::SPItransfer(uint16_t cmd, uint32_t reg, const uint8_t* dataOut, uin for(size_t n = 0; n < numBytes; n++) { RADIOLIB_DEBUG_SPI_PRINT_NOTAG("%X\t", debugBuffPtr[n]); } - RADIOLIB_DEBUG_SPI_PRINTLN_NOTAG(); + RADIOLIB_DEBUG_SPI_PRINTLN_NOTAG(""); #endif #if !RADIOLIB_STATIC_ONLY @@ -426,7 +426,7 @@ int16_t Module::SPItransferStream(const uint8_t* cmd, uint8_t cmdLen, bool write for(; n < cmdLen; n++) { RADIOLIB_DEBUG_SPI_PRINT_NOTAG("%X\t", cmd[n]); } - RADIOLIB_DEBUG_SPI_PRINTLN_NOTAG(); + RADIOLIB_DEBUG_SPI_PRINTLN_NOTAG(""); // print data bytes RADIOLIB_DEBUG_SPI_PRINT("SI\t"); @@ -436,12 +436,12 @@ int16_t Module::SPItransferStream(const uint8_t* cmd, uint8_t cmdLen, bool write for(; n < buffLen; n++) { RADIOLIB_DEBUG_SPI_PRINT_NOTAG("%X\t", buffOut[n]); } - RADIOLIB_DEBUG_SPI_PRINTLN_NOTAG(); + RADIOLIB_DEBUG_SPI_PRINTLN_NOTAG(""); RADIOLIB_DEBUG_SPI_PRINT("SO\t"); for(n = 0; n < buffLen; n++) { RADIOLIB_DEBUG_SPI_PRINT_NOTAG("%X\t", buffIn[n]); } - RADIOLIB_DEBUG_SPI_PRINTLN_NOTAG(); + RADIOLIB_DEBUG_SPI_PRINTLN_NOTAG(""); #endif #if !RADIOLIB_STATIC_ONLY diff --git a/src/utils/Utils.cpp b/src/utils/Utils.cpp index 11a473c6..2119f316 100644 --- a/src/utils/Utils.cpp +++ b/src/utils/Utils.cpp @@ -1,7 +1,9 @@ #include "Utils.h" +#include "Hal.h" #include #include +#include #include #include @@ -59,7 +61,7 @@ void rlb_hexdump(const char* level, const uint8_t* data, size_t len, uint32_t of sprintf(strPtr++, " "); } if(level) { - RADIOLIB_DEBUG_PRINT("%s", level); + RADIOLIB_DEBUG_PRINT_LVL("", "%s", level); } RADIOLIB_DEBUG_PRINT("%s", str); RADIOLIB_DEBUG_PRINTLN(); @@ -78,14 +80,20 @@ void rlb_hexdump(const char* level, const uint8_t* data, size_t len, uint32_t of #endif } -#if RADIOLIB_DEBUG && defined(RADIOLIB_BUILD_ARDUINO) +#if RADIOLIB_DEBUG // https://github.com/esp8266/Arduino/blob/65579d29081cb8501e4d7f786747bf12e7b37da2/cores/esp8266/Print.cpp#L50 -size_t rlb_printf(const char* format, ...) { +size_t rlb_printf(bool ts, const char* format, ...) { va_list arg; va_start(arg, format); char temp[64]; char* buffer = temp; - size_t len = vsnprintf(temp, sizeof(temp), format, arg); + RadioLibTime_t timestamp = rlb_time_us(); + unsigned long sec = timestamp/1000000UL; + unsigned long usec = timestamp%1000000UL; + size_t len_ts = 0; + if(ts) { len_ts = snprintf(temp, sizeof(temp), "[%lu.%06lu] ", sec, usec); } + size_t len_str = vsnprintf(&temp[len_ts], sizeof(temp) - len_ts, format, arg); + size_t len = len_ts + len_str; va_end(arg); if (len > sizeof(temp) - 1) { buffer = new char[len + 1]; @@ -93,10 +101,15 @@ size_t rlb_printf(const char* format, ...) { return 0; } va_start(arg, format); - vsnprintf(buffer, len + 1, format, arg); + if(ts) { len_ts = snprintf(buffer, len_ts + 1, "[%lu.%06lu] ", sec, usec); } + vsnprintf(buffer + len_ts, len_str + 1, format, arg); va_end(arg); } + #if defined(RADIOLIB_BUILD_ARDUINO) len = RADIOLIB_DEBUG_PORT.write(reinterpret_cast(buffer), len); + #else + len = fwrite(buffer, sizeof(temp[0]), len, RADIOLIB_DEBUG_PORT); + #endif if (buffer != temp) { delete[] buffer; } diff --git a/src/utils/Utils.h b/src/utils/Utils.h index b8c4ac61..c979548f 100644 --- a/src/utils/Utils.h +++ b/src/utils/Utils.h @@ -35,8 +35,8 @@ uint32_t rlb_reflect(uint32_t in, uint8_t bits); */ void rlb_hexdump(const char* level, const uint8_t* data, size_t len, uint32_t offset = 0, uint8_t width = 1, bool be = false); -#if RADIOLIB_DEBUG && defined(RADIOLIB_BUILD_ARDUINO) -size_t rlb_printf(const char* format, ...); +#if RADIOLIB_DEBUG +size_t rlb_printf(bool ts, const char* format, ...); #endif #endif