diff --git a/AMS_Master_Code/Core/Lib/logger/log.c b/AMS_Master_Code/Core/Lib/logger/log.c index 6836961..7af34a2 100644 --- a/AMS_Master_Code/Core/Lib/logger/log.c +++ b/AMS_Master_Code/Core/Lib/logger/log.c @@ -52,16 +52,14 @@ bool log_is_level_enabled(log_level_t level) { /* Main logging function */ void log_message(log_level_t level, const char *msg, ...) { - log_message_t log_msg; - log_msg.level = level; - log_msg.timestamp = HAL_GetTick(); + log_message_t log_msg = {level, HAL_GetTick(), "\n", 0}; /* Format the message prefix (timestamp, log level) */ - size_t prefix_len = 0; + size_t prefix_len = 1; /* Add timestamp if configured */ if (PRINT_TIMESTAMP) { - prefix_len += snprintf(log_msg.message, MAX_MESSAGE_LENGTH, "[%lu] ", log_msg.timestamp); + prefix_len += snprintf(log_msg.message + prefix_len, MAX_MESSAGE_LENGTH, "[%lu] ", log_msg.timestamp); } /* Add log level name */ diff --git a/AMS_Master_Code/Core/Lib/logger/log.h b/AMS_Master_Code/Core/Lib/logger/log.h index f36d71b..6ee2982 100644 --- a/AMS_Master_Code/Core/Lib/logger/log.h +++ b/AMS_Master_Code/Core/Lib/logger/log.h @@ -16,7 +16,7 @@ #include /* Configuration */ -#define MAX_MESSAGE_LENGTH 256 +#define MAX_MESSAGE_LENGTH 384 #define USE_ANSI_ESCAPE_CODES true // if true, log messages will be colored according to their log level #define PRINT_TIMESTAMP false // if true, timestamp (from HAL_GetTick) is printed before each log message @@ -70,6 +70,11 @@ void log_init_all_backends(void); [[gnu::format(printf, 2, 3)]] void log_message(log_level_t level, const char *msg, ...); +#ifdef LOG_PREFIX +#define log_message(level, fmt, ...) \ + log_message(level, LOG_PREFIX fmt, ##__VA_ARGS__) +#endif + [[gnu::format(printf, 2, 3)]] void log_message_cont(log_level_t level, const char *msg, ...); diff --git a/AMS_Master_Code/Core/Lib/logger/swo_log.h b/AMS_Master_Code/Core/Lib/logger/swo_log.h index 8857f93..47aaaba 100644 --- a/AMS_Master_Code/Core/Lib/logger/swo_log.h +++ b/AMS_Master_Code/Core/Lib/logger/swo_log.h @@ -11,6 +11,10 @@ #ifndef __SWO_LOG_H #define __SWO_LOG_H +#ifdef SWO_LOG_PREFIX +#define LOG_PREFIX SWO_LOG_PREFIX +#endif + #include "log.h" #include "swo_log_backend.h" diff --git a/AMS_Master_Code/Core/Src/print_master_status.c b/AMS_Master_Code/Core/Src/print_master_status.c index e7c4b20..af02ed1 100644 --- a/AMS_Master_Code/Core/Src/print_master_status.c +++ b/AMS_Master_Code/Core/Src/print_master_status.c @@ -1,4 +1,5 @@ #include "imd_monitoring.h" +#include "log.h" #include "main.h" #include "soc_estimation.h" #include "stm32h7xx_hal.h" @@ -8,49 +9,62 @@ #include "battery.h" #define DEBUG_CHANNEL 1 // channel to output messages on -#include "swo_log.h" +#include "swo_log_backend.h" void print_master_status() { - debug_clear_console(); + auto backend = swo_log_get_backend(); - debug_log(LOG_LEVEL_INFO, "------ AMS_Master on %s (%s), compiled at %s ------", COMMIT_BRANCH, + if (!backend->is_enabled(LOG_LEVEL_INFO)) { + return; // No need to print if the backend is not enabled for this log level + } + + log_message_t log_msg = {}; + + #define swo_write(...) \ + snprintf(log_msg.message, sizeof(log_msg.message), __VA_ARGS__); \ + backend->write(&log_msg); \ + + // clear the console + backend->clear(); + + swo_write("------ AMS_Master on %s (%s), compiled at %s ------", COMMIT_BRANCH, COMMIT_HASH, COMPILE_DATE); - debug_log(LOG_LEVEL_INFO, "\nGeneral:"); - debug_log(LOG_LEVEL_INFO, " State: %s", TSStateToString(ts_state.current_state)); - debug_log(LOG_LEVEL_INFO, " Target: %s", TSStateToString(ts_state.target_state)); - debug_log(LOG_LEVEL_INFO, " Err Source: %s", ts_state.error_source == 0 ? "NONE" : (ts_state.error_source == 0b11 ? "SHUNT, SLAVE" : (ts_state.error_source == 0b01 ? "SHUNT" : "SLAVE"))); - debug_log(LOG_LEVEL_INFO, " Err type: %s", ts_state.error_type == 0 ? "NONE" : (ts_state.error_type == 0x01 ? "SLAVE_TIMEOUT" : (ts_state.error_type == 0x02 ? "SLAVE_PANIC" : (ts_state.error_type == 0x03 ? "SHUNT_TIMEOUT" : (ts_state.error_type == 0x04 ? "SHUNT_OVERCURRENT" : (ts_state.error_type == 0x05 ? "SHUNT_OVERTEMP" : "UNKNOWN")))))); - debug_log(LOG_LEVEL_INFO, " HV active: %s", hv_active ? "YES" : "NO"); + swo_write( "\nGeneral:"); + swo_write( " State: %s", TSStateToString(ts_state.current_state)); + swo_write( " Target: %s", TSStateToString(ts_state.target_state)); + swo_write( " Err Source: %s", ts_state.error_source == 0 ? "NONE" : (ts_state.error_source == 0b11 ? "SHUNT, SLAVE" : (ts_state.error_source == 0b01 ? "SHUNT" : "SLAVE"))); + swo_write(" Err type: %s", ts_state.error_type == 0 ? "NONE" : (ts_state.error_type == 0x01 ? "SLAVE_TIMEOUT" : (ts_state.error_type == 0x02 ? "SLAVE_PANIC" : (ts_state.error_type == 0x03 ? "SHUNT_TIMEOUT" : (ts_state.error_type == 0x04 ? "SHUNT_OVERCURRENT" : (ts_state.error_type == 0x05 ? "SHUNT_OVERTEMP" : "UNKNOWN")))))); + swo_write(" HV active: %s", hv_active ? "YES" : "NO"); - debug_log(LOG_LEVEL_INFO, "\nRelay positions:"); - debug_log(LOG_LEVEL_INFO, " SDC: %s", sdc_closed ? "CLOSED" : "OPEN"); - debug_log(LOG_LEVEL_INFO, " Air-: %s", neg_air_closed ? "CLOSED" : "OPEN"); - debug_log(LOG_LEVEL_INFO, " Air+: %s", pos_air_closed ? "CLOSED" : "OPEN"); - debug_log(LOG_LEVEL_INFO, " Precharge: %s", precharge_closed ? "CLOSED" : "OPEN"); - debug_log(LOG_LEVEL_INFO, " Precharge/Air+ sense: %s", pre_and_air_open ? "HIGH" : "LOW"); + swo_write("\nRelay positions:"); + swo_write(" SDC: %s", sdc_closed ? "CLOSED" : "OPEN"); + swo_write(" Air-: %s", neg_air_closed ? "CLOSED" : "OPEN"); + swo_write(" Air+: %s", pos_air_closed ? "CLOSED" : "OPEN"); + swo_write(" Precharge: %s", precharge_closed ? "CLOSED" : "OPEN"); + swo_write(" Precharge/Air+ sense: %s", pre_and_air_open ? "HIGH" : "LOW"); - debug_log(LOG_LEVEL_INFO, "\nIMD data:"); - debug_log(LOG_LEVEL_INFO, " State: %s", IMDStateToString(imd_data.state)); - debug_log(LOG_LEVEL_INFO, " R_iso: %lu kOhm", imd_data.r_iso); - debug_log(LOG_LEVEL_INFO, " Frequency: %lu Hz", imd_data.freq); - debug_log(LOG_LEVEL_INFO, " Duty cycle: %lu %%", imd_data.duty_cycle); - debug_log(LOG_LEVEL_INFO, " Last high: %lu ms", imd_data.last_high); - debug_log(LOG_LEVEL_INFO, " OK: %s", imd_data.ok ? "YES" : "NO"); + swo_write("\nIMD data:"); + swo_write(" State: %s", IMDStateToString(imd_data.state)); + swo_write(" R_iso: %lu kOhm", imd_data.r_iso); + swo_write(" Frequency: %lu Hz", imd_data.freq); + swo_write(" Duty cycle: %lu %%", imd_data.duty_cycle); + swo_write(" Last high: %lu ms", imd_data.last_high); + swo_write(" OK: %s", imd_data.ok ? "YES" : "NO"); - debug_log(LOG_LEVEL_INFO, "\nShunt data:"); - debug_log(LOG_LEVEL_INFO, " Voltage: %ld mV", shunt_data.voltage_bat); - debug_log(LOG_LEVEL_INFO, " Current: %ld mA", shunt_data.current); - debug_log(LOG_LEVEL_INFO, " Power: %ld W", shunt_data.power); - debug_log(LOG_LEVEL_INFO, " Energy: %ld Ws", shunt_data.energy); - debug_log(LOG_LEVEL_INFO, " Temp: %ld °C", shunt_data.busbartemp / 10); - debug_log(LOG_LEVEL_INFO, " Time delta: %lu ms", HAL_GetTick() - shunt_data.last_message); + swo_write("\nShunt data:"); + swo_write(" Voltage: %ld mV", shunt_data.voltage_bat); + swo_write(" Current: %ld mA", shunt_data.current); + swo_write(" Power: %ld W", shunt_data.power); + swo_write(" Energy: %ld Ws", shunt_data.energy); + swo_write(" Temp: %ld °C", shunt_data.busbartemp / 10); + swo_write(" Time delta: %lu ms", HAL_GetTick() - shunt_data.last_message); - debug_log(LOG_LEVEL_INFO, "\nBattery data:"); - debug_log(LOG_LEVEL_INFO, " Min/Max voltage: %d mV / %d mV", min_voltage, max_voltage); - debug_log(LOG_LEVEL_INFO, " Min/Max temp: %d °C / %d °C", min_temp, max_temp); - debug_log(LOG_LEVEL_INFO, " SoC: %.2f %%", current_soc); - debug_log(LOG_LEVEL_INFO, " Module data: Min V | Max V | Std Dev | Min T | Max T"); + swo_write("\nBattery data:"); + swo_write(" Min/Max voltage: %d mV / %d mV", min_voltage, max_voltage); + swo_write(" Min/Max temp: %d °C / %d °C", min_temp, max_temp); + swo_write(" SoC: %.2f %%", current_soc); + swo_write(" Module data: Min V | Max V | Std Dev | Min T | Max T"); auto max_std_dev = 0.0f; for (size_t i = 0; i < N_BMS; i++) { if (module_std_deviation[i] > max_std_dev) { @@ -62,20 +76,20 @@ void print_master_status() { #define COLOR_MIN "\033[38;5;75m" //blue for min #define COLOR_MAX "\033[38;5;203m" //red for max #define COLOR_RESET "\033[0m" - debug_log(LOG_LEVEL_INFO, " %2zu: %s%5d mV%s | %s%5d mV%s | %s%.2f mV%s | %s%3d °C%s | %s%3d °C%s", i, + swo_write(" %2zu: %s%5d mV%s | %s%5d mV%s | %s%.2f mV%s | %s%3d °C%s | %s%3d °C%s", i, (module_voltages[i].min == min_voltage) ? COLOR_MIN : "", (module_voltages[i].min), COLOR_RESET, (module_voltages[i].max == max_voltage) ? COLOR_MAX : "", (module_voltages[i].max), COLOR_RESET, (module_std_deviation[i] > max_std_dev) ? COLOR_MAX : "", module_std_deviation[i], COLOR_RESET, (module_temps[i].min == min_temp) ? COLOR_MIN : "", (module_temps[i].min), COLOR_RESET, (module_temps[i].max == max_temp) ? COLOR_MAX : "", (module_temps[i].max), COLOR_RESET); #else - debug_log(LOG_LEVEL_INFO, " %2zu: %5d mV | %5d mV | %.2f mV | %3d °C | %3d °C", i, + swo_write(" %2zu: %5d mV | %5d mV | %.2f mV | %3d °C | %3d °C", i, module_voltages[i].min, module_voltages[i].max, module_std_deviation[i], module_temps[i].min, module_temps[i].max); #endif } - debug_log(LOG_LEVEL_INFO, "\n------ Updated at %lu ------", HAL_GetTick()); + swo_write("\n------ Updated at %lu ------", HAL_GetTick()); } diff --git a/AMS_Master_Code/Core/Src/print_module_status.c b/AMS_Master_Code/Core/Src/print_module_status.c index 7f3cc9f..d83c167 100644 --- a/AMS_Master_Code/Core/Src/print_module_status.c +++ b/AMS_Master_Code/Core/Src/print_module_status.c @@ -5,57 +5,71 @@ #include #define DEBUG_CHANNEL 2 // channel to output messages on -#include "swo_log.h" +#include "swo_log_backend.h" void print_battery_info() { - debug_clear_console(); - debug_log(LOG_LEVEL_INFO, "------ AMS_Master on %s (%s), compiled at %s ------\n", COMMIT_BRANCH, + auto backend = swo_log_get_backend(); + + if (!backend->is_enabled(LOG_LEVEL_INFO)) { + return; // No need to print if the backend is not enabled for this log level + } + + log_message_t log_msg = {}; + + #define swo_write(...) \ + snprintf(log_msg.message, sizeof(log_msg.message), __VA_ARGS__); \ + backend->write(&log_msg); \ + + // clear the console + backend->clear(); + + swo_write("------ AMS_Master on %s (%s), compiled at %s ------\n", COMMIT_BRANCH, COMMIT_HASH, COMPILE_DATE); for (size_t i = 0; i < N_BMS; i++) { - debug_log(LOG_LEVEL_INFO, "Module %d status:", i); - debug_log(LOG_LEVEL_INFO, " BMS ID: 0x%08lx%08lx", (uint32_t)(modules[i].bmsID >> 32), (uint32_t)(modules[i].bmsID & 0xFFFFFFFF)); + swo_write("Module %d status:", i); + swo_write(" BMS ID: 0x%08lx%08lx", (uint32_t)(modules[i].bmsID >> 32), (uint32_t)(modules[i].bmsID & 0xFFFFFFFF)); // Print cell voltages in 4x4 format - debug_log(LOG_LEVEL_INFO, " Cell voltages (mV):"); - debug_log(LOG_LEVEL_INFO, " C0: %4d C1: %4d C2: %4d C3: %4d", + swo_write(" Cell voltages (mV):"); + swo_write(" C0: %4d C1: %4d C2: %4d C3: %4d", modules[i].cellVoltages[0], modules[i].cellVoltages[1], modules[i].cellVoltages[2], modules[i].cellVoltages[3]); - debug_log(LOG_LEVEL_INFO, " C4: %4d C5: %4d C6: %4d C7: %4d", + swo_write(" C4: %4d C5: %4d C6: %4d C7: %4d", modules[i].cellVoltages[4], modules[i].cellVoltages[5], modules[i].cellVoltages[6], modules[i].cellVoltages[7]); - debug_log(LOG_LEVEL_INFO, " C8: %4d C9: %4d C10: %4d C11: %4d", + swo_write(" C8: %4d C9: %4d C10: %4d C11: %4d", modules[i].cellVoltages[8], modules[i].cellVoltages[9], modules[i].cellVoltages[10], modules[i].cellVoltages[11]); - debug_log(LOG_LEVEL_INFO, " C12: %4d C13: %4d C14: %4d C15: %4d", + swo_write(" C12: %4d C13: %4d C14: %4d C15: %4d", modules[i].cellVoltages[12], modules[i].cellVoltages[13], modules[i].cellVoltages[14], modules[i].cellVoltages[15]); // Print GPIO values - debug_log(LOG_LEVEL_INFO, " GPIO voltages (mV):"); - debug_log(LOG_LEVEL_INFO, + swo_write(" GPIO voltages (mV):"); + swo_write( " G0: %4d G1: %4d G2: %4d G3: %4d G4: %4d", modules[i].auxVoltages[0], modules[i].auxVoltages[1], modules[i].auxVoltages[2], modules[i].auxVoltages[3], modules[i].auxVoltages[4]); - debug_log(LOG_LEVEL_INFO, + swo_write( " G5: %4d G6: %4d G7: %4d G8: %4d G9: %4d", modules[i].auxVoltages[5], modules[i].auxVoltages[6], modules[i].auxVoltages[7], modules[i].auxVoltages[8], modules[i].auxVoltages[9]); // Print temperatures - debug_log(LOG_LEVEL_INFO, " GPIO as temperatures (°C):"); - debug_log(LOG_LEVEL_INFO, + swo_write(" GPIO as temperatures (°C):"); + swo_write( " G0: %4d G1: %4d G2: %4d G3: %4d G4: %4d", cellTemps[i][0], cellTemps[i][1], cellTemps[i][2], cellTemps[i][3], cellTemps[i][4]); - debug_log(LOG_LEVEL_INFO, + swo_write( " G5: %4d G6: %4d G7: %4d G8: %4d G9: %4d", cellTemps[i][5], cellTemps[i][6], cellTemps[i][7], cellTemps[i][8], cellTemps[i][9]); - debug_log(LOG_LEVEL_INFO, + swo_write( " Internal temp: %d, VAnalog: %d, VDigital: %d, VRef: %d", modules[i].internalDieTemp, modules[i].analogSupplyVoltage, modules[i].digitalSupplyVoltage, modules[i].refVoltage); @@ -126,18 +140,11 @@ void print_battery_info() { hasFlags = true; } - debug_log(LOG_LEVEL_INFO, " Status flags: %s", + swo_write(" Status flags: %s", hasFlags ? flagBuffer : "[none]"); - debug_log(LOG_LEVEL_INFO, " Conversion counter: %d", + swo_write(" Conversion counter: %d", modules[i].status.CCTS); - - // Check for over/under voltage - if (modules[i].overVoltage || modules[i].underVoltage) { - debug_log(LOG_LEVEL_WARNING, - " Module %d voltage issues - OV: 0x%08lX, UV: 0x%08lX", i, - modules[i].overVoltage, modules[i].underVoltage); - } } - debug_log(LOG_LEVEL_INFO, "\n------ Updated at %lu ------", HAL_GetTick()); + swo_write("\n------ Updated at %lu ------", HAL_GetTick()); } \ No newline at end of file