From fb94c64e41e4bf6438b489a8d813889d88fc72e7 Mon Sep 17 00:00:00 2001 From: gorbit99 Date: Thu, 8 May 2025 23:51:10 +0200 Subject: [PATCH 1/2] Added log ids to logs --- src/FSHelper.cpp | 26 ++- src/LEDManager.h | 2 - src/batterymonitor.cpp | 2 +- src/batterymonitor.h | 6 +- src/configuration/Configuration.cpp | 107 ++++++++--- src/configuration/Configuration.h | 24 ++- src/debugging/TimeTaken.cpp | 1 + src/debugging/TimeTaken.h | 7 +- src/logging/Level.h | 6 +- src/logging/Logger.cpp | 70 ------- src/logging/Logger.h | 150 ++++++++++----- src/main.cpp | 12 +- .../GyroTemperatureCalibrator.cpp | 13 +- .../GyroTemperatureCalibrator.h | 14 +- src/network/connection.cpp | 53 ++++-- src/network/connection.h | 19 +- src/network/wifihandler.cpp | 47 ++++- src/network/wifiprovisioning.cpp | 12 +- src/sensorinterface/SPIImpl.h | 8 +- src/sensors/ErroneousSensor.cpp | 1 + src/sensors/SensorBuilder.cpp | 10 +- src/sensors/SensorBuilder.h | 4 + src/sensors/SensorManager.cpp | 5 +- src/sensors/SensorManager.h | 17 +- src/sensors/bmi160sensor.cpp | 176 +++++++++++++----- src/sensors/bmi160sensor.h | 1 + src/sensors/bno055sensor.cpp | 9 +- src/sensors/bno080sensor.cpp | 14 +- src/sensors/icm20948sensor.cpp | 141 ++++++++++---- src/sensors/mpu6050sensor.cpp | 41 +++- src/sensors/mpu9250sensor.cpp | 97 +++++++--- src/sensors/sensor.cpp | 9 +- src/sensors/sensor.h | 33 +++- src/sensors/softfusion/CalibrationBase.h | 3 - .../softfusion/SoftfusionCalibration.h | 55 ++++-- src/sensors/softfusion/drivers/bmi270.h | 20 +- src/sensors/softfusion/drivers/icm42688.h | 10 +- src/sensors/softfusion/drivers/icm45605.h | 5 +- src/sensors/softfusion/drivers/icm45686.h | 5 +- src/sensors/softfusion/drivers/icm45base.h | 6 +- .../softfusion/drivers/lsm6ds-common.h | 6 +- src/sensors/softfusion/drivers/lsm6ds3trc.h | 10 +- src/sensors/softfusion/drivers/lsm6dso.h | 5 +- src/sensors/softfusion/drivers/lsm6dsr.h | 5 +- src/sensors/softfusion/drivers/lsm6dsv.h | 5 +- src/sensors/softfusion/drivers/mpu6050.h | 7 +- .../runtimecalibration/RuntimeCalibration.h | 31 +-- src/sensors/softfusion/softfusionsensor.h | 36 +++- src/serial/serialcommands.cpp | 134 +++++++++---- src/status/StatusManager.cpp | 5 +- src/status/StatusManager.h | 6 +- 51 files changed, 1068 insertions(+), 423 deletions(-) diff --git a/src/FSHelper.cpp b/src/FSHelper.cpp index c30932df4..02cb7b987 100644 --- a/src/FSHelper.cpp +++ b/src/FSHelper.cpp @@ -27,12 +27,22 @@ namespace SlimeVR { namespace Utils { -SlimeVR::Logging::Logger m_Logger("FSHelper"); + +enum class FSLogs { + FailedToCreateDir = 0, + FailedToRemoveDir = 1, +}; + +SlimeVR::Logging::Logger m_Logger("FSHelper", "fs"); bool ensureDirectory(const char* directory) { if (!LittleFS.exists(directory)) { if (!LittleFS.mkdir(directory)) { - m_Logger.error("Failed to create directory: %s", directory); + m_Logger.error( + FSLogs::FailedToCreateDir, + "Failed to create directory: %s", + directory + ); return false; } } @@ -43,12 +53,20 @@ bool ensureDirectory(const char* directory) { if (!isDirectory) { if (!LittleFS.remove(directory)) { - m_Logger.error("Failed to remove directory: %s", directory); + m_Logger.error( + FSLogs::FailedToRemoveDir, + "Failed to remove directory: %s", + directory + ); return false; } if (!LittleFS.mkdir(directory)) { - m_Logger.error("Failed to create directory: %s", directory); + m_Logger.error( + FSLogs::FailedToCreateDir, + "Failed to create directory: %s", + directory + ); return false; } } diff --git a/src/LEDManager.h b/src/LEDManager.h index 1d30cb2bd..854891efe 100644 --- a/src/LEDManager.h +++ b/src/LEDManager.h @@ -89,8 +89,6 @@ class LEDManager { unsigned long m_LastUpdate = millis(); uint8_t m_Pin; - - Logging::Logger m_Logger = Logging::Logger("LEDManager"); }; } // namespace SlimeVR diff --git a/src/batterymonitor.cpp b/src/batterymonitor.cpp index f6dcdddfe..a7e30f4f6 100644 --- a/src/batterymonitor.cpp +++ b/src/batterymonitor.cpp @@ -38,7 +38,7 @@ void BatteryMonitor::Setup() { } } if (address == 0) { - m_Logger.error("MCP3021 not found on I2C bus"); + m_Logger.error(Logs::MCPNotFound, "MCP3021 not found on I2C bus"); } #endif } diff --git a/src/batterymonitor.h b/src/batterymonitor.h index e6a38b06e..358ac910a 100644 --- a/src/batterymonitor.h +++ b/src/batterymonitor.h @@ -92,7 +92,11 @@ class BatteryMonitor { float voltage = -1; float level = -1; - SlimeVR::Logging::Logger m_Logger = SlimeVR::Logging::Logger("BatteryMonitor"); + enum class Logs { + MCPNotFound = 0, + }; + + SlimeVR::Logging::Logger m_Logger{"BatteryMonitor", "battery"}; }; #endif // SLIMEVR_BATTERYMONITOR_H_ diff --git a/src/configuration/Configuration.cpp b/src/configuration/Configuration.cpp index 4e14e9328..1c43022e3 100644 --- a/src/configuration/Configuration.cpp +++ b/src/configuration/Configuration.cpp @@ -42,23 +42,26 @@ void Configuration::setup() { bool status = LittleFS.begin(); if (!status) { - this->m_Logger.warn("Could not mount LittleFS, formatting"); + m_Logger.warn(Logs::CouldNotMountFS, "Could not mount LittleFS, formatting"); status = LittleFS.format(); if (!status) { - this->m_Logger.warn("Could not format LittleFS, aborting"); + m_Logger.warn( + Logs::CouldNotFormatFS, + "Could not format LittleFS, aborting" + ); return; } status = LittleFS.begin(); if (!status) { - this->m_Logger.error("Could not mount LittleFS, aborting"); + m_Logger.error(Logs::CouldNotMountFS, "Could not mount LittleFS, aborting"); return; } } if (LittleFS.exists("/config.bin")) { - m_Logger.trace("Found configuration file"); + m_Logger.trace(Logs::FoundConfigFile, "Found configuration file"); auto file = LittleFS.open("/config.bin", "r"); @@ -66,6 +69,7 @@ void Configuration::setup() { if (m_Config.version < CURRENT_CONFIGURATION_VERSION) { m_Logger.debug( + Logs::ConfigOutdated, "Configuration is outdated: v%d < v%d", m_Config.version, CURRENT_CONFIGURATION_VERSION @@ -73,6 +77,7 @@ void Configuration::setup() { if (!runMigrations(m_Config.version)) { m_Logger.error( + Logs::FailedToMigrateConfig, "Failed to migrate configuration from v%d to v%d", m_Config.version, CURRENT_CONFIGURATION_VERSION @@ -80,14 +85,21 @@ void Configuration::setup() { return; } } else { - m_Logger.info("Found up-to-date configuration v%d", m_Config.version); + m_Logger.info( + Logs::FoundUpToDate, + "Found up-to-date configuration v%d", + m_Config.version + ); } file.seek(0); file.read((uint8_t*)&m_Config, sizeof(DeviceConfig)); file.close(); } else { - m_Logger.info("No configuration file found, creating new one"); + m_Logger.info( + Logs::NoConfigFile, + "No configuration file found, creating new one" + ); m_Config.version = CURRENT_CONFIGURATION_VERSION; save(); } @@ -96,7 +108,7 @@ void Configuration::setup() { m_Loaded = true; - m_Logger.info("Loaded configuration"); + m_Logger.info(Logs::LoadedConfig, "Loaded configuration"); #ifdef DEBUG_CONFIGURATION print(); @@ -113,7 +125,7 @@ void Configuration::save() { char path[17]; sprintf(path, DIR_CALIBRATIONS "/%zu", i); - m_Logger.trace("Saving sensor config data for %d", i); + m_Logger.trace(Logs::SavingSensorConfig, "Saving sensor config data for %d", i); File file = LittleFS.open(path, "w"); file.write((uint8_t*)&config, sizeof(SensorConfig)); @@ -121,7 +133,8 @@ void Configuration::save() { sprintf(path, DIR_TOGGLES "/%zu", i); - m_Logger.trace("Saving sensor toggle state for %d", i); + m_Logger + .trace(Logs::SavingSensorToggle, "Saving sensor toggle state for %d", i); file = LittleFS.open(path, "w"); file.write((uint8_t*)&m_SensorToggles[i], sizeof(SensorToggleState)); @@ -134,7 +147,7 @@ void Configuration::save() { file.close(); } - m_Logger.debug("Saved configuration"); + m_Logger.debug(Logs::SavedConfig, "Saved configuration"); } void Configuration::reset() { @@ -145,7 +158,7 @@ void Configuration::reset() { m_Config.version = 1; save(); - m_Logger.debug("Reset configuration"); + m_Logger.debug(Logs::ResetConfig, "Reset configuration"); } int32_t Configuration::getVersion() const { return m_Config.version; } @@ -210,6 +223,7 @@ void Configuration::loadSensors() { uint8_t sensorId = strtoul(f.name(), nullptr, 10); m_Logger.debug( + Logs::FoundSensorCalibration, "Found sensor calibration for %s at index %d", calibrationConfigTypeToString(sensorConfig.type), sensorId @@ -232,7 +246,11 @@ void Configuration::loadSensors() { f.read((uint8_t*)&sensorToggleState, sizeof(SensorToggleState)); uint8_t sensorId = strtoul(f.name(), nullptr, 10); - m_Logger.debug("Found sensor toggle state at index %d", sensorId); + m_Logger.debug( + Logs::FoundSensorToggle, + "Found sensor toggle state at index %d", + sensorId + ); setSensorToggles(sensorId, sensorToggleState); }); @@ -260,6 +278,7 @@ bool Configuration::loadTemperatureCalibration( if (f.size() != sizeof(GyroTemperatureCalibrationConfig)) { m_Logger.debug( + Logs::FoundIncompatibleTempCal, "Found incompatible sensor temperature calibration (size mismatch) " "sensorId:%d, skipping", sensorId @@ -272,6 +291,7 @@ bool Configuration::loadTemperatureCalibration( if (storedConfigType != config.type) { m_Logger.debug( + Logs::FoundIncompatibleTempCal, "Found incompatible sensor temperature calibration (expected %s, " "found %s) sensorId:%d, skipping", calibrationConfigTypeToString(config.type), @@ -284,6 +304,7 @@ bool Configuration::loadTemperatureCalibration( f.seek(0); f.read((uint8_t*)&config, sizeof(GyroTemperatureCalibrationConfig)); m_Logger.debug( + Logs::FoundSensorTempCal, "Found sensor temperature calibration for %s sensorId:%d", calibrationConfigTypeToString(config.type), sensorId @@ -302,26 +323,39 @@ bool Configuration::saveTemperatureCalibration( char path[32]; sprintf(path, DIR_TEMPERATURE_CALIBRATIONS "/%d", sensorId); - m_Logger.trace("Saving temperature calibration data for sensorId:%d", sensorId); + m_Logger.trace( + Logs::SavingTempCal, + "Saving temperature calibration data for sensorId:%d", + sensorId + ); File file = LittleFS.open(path, "w"); file.write((uint8_t*)&config, sizeof(GyroTemperatureCalibrationConfig)); file.close(); - m_Logger.debug("Saved temperature calibration data for sensorId:%i", sensorId); + m_Logger.debug( + Logs::SavedTempCal, + "Saved temperature calibration data for sensorId:%i", + sensorId + ); return true; } bool Configuration::runMigrations(int32_t version) { return true; } void Configuration::print() { - m_Logger.info("Configuration:"); - m_Logger.info(" Version: %d", m_Config.version); - m_Logger.info(" %d Sensors:", m_Sensors.size()); + m_Logger.info(Logs::ConfigInfo, "Configuration:"); + m_Logger.info(Logs::ConfigInfo, " Version: %d", m_Config.version); + m_Logger.info(Logs::ConfigInfo, " %d Sensors:", m_Sensors.size()); for (size_t i = 0; i < m_Sensors.size(); i++) { const SensorConfig& c = m_Sensors[i]; - m_Logger.info(" - [%3d] %s", i, calibrationConfigTypeToString(c.type)); + m_Logger.info( + Logs::ConfigInfo, + " - [%3d] %s", + i, + calibrationConfigTypeToString(c.type) + ); switch (c.type) { case SensorConfigType::NONE: @@ -329,45 +363,56 @@ void Configuration::print() { case SensorConfigType::BMI160: m_Logger.info( + Logs::ConfigInfo, " A_B : %f, %f, %f", UNPACK_VECTOR_ARRAY(c.data.bmi160.A_B) ); - m_Logger.info(" A_Ainv :"); + m_Logger.info(Logs::ConfigInfo, " A_Ainv :"); for (uint8_t i = 0; i < 3; i++) { m_Logger.info( + Logs::ConfigInfo, " %f, %f, %f", UNPACK_VECTOR_ARRAY(c.data.bmi160.A_Ainv[i]) ); } m_Logger.info( + Logs::ConfigInfo, " G_off : %f, %f, %f", UNPACK_VECTOR_ARRAY(c.data.bmi160.G_off) ); - m_Logger.info(" Temperature: %f", c.data.bmi160.temperature); + m_Logger.info( + Logs::ConfigInfo, + " Temperature: %f", + c.data.bmi160.temperature + ); break; case SensorConfigType::SFUSION: m_Logger.info( + Logs::ConfigInfo, " A_B : %f, %f, %f", UNPACK_VECTOR_ARRAY(c.data.sfusion.A_B) ); - m_Logger.info(" A_Ainv :"); + m_Logger.info(Logs::ConfigInfo, " A_Ainv :"); for (uint8_t i = 0; i < 3; i++) { m_Logger.info( + Logs::ConfigInfo, " %f, %f, %f", UNPACK_VECTOR_ARRAY(c.data.sfusion.A_Ainv[i]) ); } m_Logger.info( + Logs::ConfigInfo, " G_off : %f, %f, %f", UNPACK_VECTOR_ARRAY(c.data.sfusion.G_off) ); m_Logger.info( + Logs::ConfigInfo, " Temperature: %f", c.data.sfusion.temperature ); @@ -375,14 +420,17 @@ void Configuration::print() { case SensorConfigType::ICM20948: m_Logger.info( + Logs::ConfigInfo, " G: %d, %d, %d", UNPACK_VECTOR_ARRAY(c.data.icm20948.G) ); m_Logger.info( + Logs::ConfigInfo, " A: %d, %d, %d", UNPACK_VECTOR_ARRAY(c.data.icm20948.A) ); m_Logger.info( + Logs::ConfigInfo, " C: %d, %d, %d", UNPACK_VECTOR_ARRAY(c.data.icm20948.C) ); @@ -391,32 +439,37 @@ void Configuration::print() { case SensorConfigType::MPU9250: m_Logger.info( + Logs::ConfigInfo, " A_B : %f, %f, %f", UNPACK_VECTOR_ARRAY(c.data.mpu9250.A_B) ); - m_Logger.info(" A_Ainv:"); + m_Logger.info(Logs::ConfigInfo, " A_Ainv:"); for (uint8_t i = 0; i < 3; i++) { m_Logger.info( + Logs::ConfigInfo, " %f, %f, %f", UNPACK_VECTOR_ARRAY(c.data.mpu9250.A_Ainv[i]) ); } m_Logger.info( + Logs::ConfigInfo, " M_B : %f, %f, %f", UNPACK_VECTOR_ARRAY(c.data.mpu9250.M_B) ); - m_Logger.info(" M_Ainv:"); + m_Logger.info(Logs::ConfigInfo, " M_Ainv:"); for (uint8_t i = 0; i < 3; i++) { m_Logger.info( + Logs::ConfigInfo, " %f, %f, %f", UNPACK_VECTOR_ARRAY(c.data.mpu9250.M_Ainv[i]) ); } m_Logger.info( + Logs::ConfigInfo, " G_off : %f, %f, %f", UNPACK_VECTOR_ARRAY(c.data.mpu9250.G_off) ); @@ -425,10 +478,12 @@ void Configuration::print() { case SensorConfigType::MPU6050: m_Logger.info( + Logs::ConfigInfo, " A_B : %f, %f, %f", UNPACK_VECTOR_ARRAY(c.data.mpu6050.A_B) ); m_Logger.info( + Logs::ConfigInfo, " G_off: %f, %f, %f", UNPACK_VECTOR_ARRAY(c.data.mpu6050.G_off) ); @@ -436,7 +491,11 @@ void Configuration::print() { break; case SensorConfigType::BNO0XX: - m_Logger.info(" magEnabled: %d", c.data.bno0XX.magEnabled); + m_Logger.info( + Logs::ConfigInfo, + " magEnabled: %d", + c.data.bno0XX.magEnabled + ); break; } diff --git a/src/configuration/Configuration.h b/src/configuration/Configuration.h index 7abb458c8..e658ff894 100644 --- a/src/configuration/Configuration.h +++ b/src/configuration/Configuration.h @@ -70,7 +70,29 @@ class Configuration { std::vector m_Sensors; std::vector m_SensorToggles; - Logging::Logger m_Logger = Logging::Logger("Configuration"); + enum class Logs { + CouldNotMountFS = 0, + CouldNotFormatFS = 1, + FoundConfigFile = 2, + ConfigOutdated = 3, + FailedToMigrateConfig = 4, + FoundUpToDate = 5, + NoConfigFile = 6, + LoadedConfig = 7, + SavingSensorConfig = 8, + SavingSensorToggle = 9, + SavedConfig = 10, + ResetConfig = 11, + FoundSensorCalibration = 12, + FoundSensorToggle = 13, + FoundIncompatibleTempCal = 14, + FoundSensorTempCal = 15, + SavingTempCal = 16, + SavedTempCal = 17, + ConfigInfo = 18, + }; + + Logging::Logger m_Logger{"Configuration", "config"}; }; } // namespace Configuration } // namespace SlimeVR diff --git a/src/debugging/TimeTaken.cpp b/src/debugging/TimeTaken.cpp index 1adfcccb6..02a581525 100644 --- a/src/debugging/TimeTaken.cpp +++ b/src/debugging/TimeTaken.cpp @@ -41,6 +41,7 @@ void TimeTakenMeasurer::after() { / static_cast(sinceLastReportMillis) * 100; m_Logger.info( + Logs::TimeTaken, "%s: %.2f%% of the last period taken (%.2f/%lld millis)", name, usedPercentage, diff --git a/src/debugging/TimeTaken.h b/src/debugging/TimeTaken.h index 0c6dd00db..527ada9ae 100644 --- a/src/debugging/TimeTaken.h +++ b/src/debugging/TimeTaken.h @@ -47,7 +47,12 @@ class TimeTakenMeasurer { static constexpr float SecondsBetweenReports = 1.0f; const char* name; - SlimeVR::Logging::Logger m_Logger = SlimeVR::Logging::Logger("TimeTaken"); + + enum class Logs { + TimeTaken = 0, + }; + + SlimeVR::Logging::Logger m_Logger{"TimeTaken", "timetaken"}; uint64_t lastTimeTakenReportMillis = 0; uint64_t timeTakenMicros = 0; diff --git a/src/logging/Level.h b/src/logging/Level.h index b33ca55da..7b5bcd4d3 100644 --- a/src/logging/Level.h +++ b/src/logging/Level.h @@ -7,8 +7,7 @@ #define LOG_LEVEL_ERROR 4 #define LOG_LEVEL_FATAL 5 -namespace SlimeVR { -namespace Logging { +namespace SlimeVR::Logging { enum Level { TRACE = LOG_LEVEL_TRACE, DEBUG = LOG_LEVEL_DEBUG, @@ -19,8 +18,7 @@ enum Level { }; const char* levelToString(Level level); -} // namespace Logging -} // namespace SlimeVR +} // namespace SlimeVR::Logging #define LOGGING_LEVEL_H #endif diff --git a/src/logging/Logger.cpp b/src/logging/Logger.cpp index 4508369be..e69de29bb 100644 --- a/src/logging/Logger.cpp +++ b/src/logging/Logger.cpp @@ -1,70 +0,0 @@ -#include "Logger.h" - -namespace SlimeVR { -namespace Logging { -void Logger::setTag(const char* tag) { - m_Tag = (char*)malloc(strlen(tag) + 1); - strcpy(m_Tag, tag); -} - -void Logger::trace(const char* format, ...) const { - va_list args; - va_start(args, format); - log(TRACE, format, args); - va_end(args); -} - -void Logger::debug(const char* format, ...) const { - va_list args; - va_start(args, format); - log(DEBUG, format, args); - va_end(args); -} - -void Logger::info(const char* format, ...) const { - va_list args; - va_start(args, format); - log(INFO, format, args); - va_end(args); -} - -void Logger::warn(const char* format, ...) const { - va_list args; - va_start(args, format); - log(WARN, format, args); - va_end(args); -} - -void Logger::error(const char* format, ...) const { - va_list args; - va_start(args, format); - log(ERROR, format, args); - va_end(args); -} - -void Logger::fatal(const char* format, ...) const { - va_list args; - va_start(args, format); - log(FATAL, format, args); - va_end(args); -} - -void Logger::log(Level level, const char* format, va_list args) const { - if (level < LOG_LEVEL) { - return; - } - - char buffer[256]; - vsnprintf(buffer, 256, format, args); - - char buf[strlen(m_Prefix) + (m_Tag == nullptr ? 0 : strlen(m_Tag)) + 2]; - strcpy(buf, m_Prefix); - if (m_Tag != nullptr) { - strcat(buf, ":"); - strcat(buf, m_Tag); - } - - Serial.printf("[%-5s] [%s] %s\n", levelToString(level), buf, buffer); -} -} // namespace Logging -} // namespace SlimeVR diff --git a/src/logging/Logger.h b/src/logging/Logger.h index 1db5ac879..b9af5dd69 100644 --- a/src/logging/Logger.h +++ b/src/logging/Logger.h @@ -3,84 +3,130 @@ #include +#include +#include + #include "Level.h" #include "debug.h" -namespace SlimeVR { -namespace Logging { +namespace SlimeVR::Logging { + +template class Logger { public: - Logger(const char* prefix) + explicit Logger(const char* prefix, const char* identifier) : m_Prefix(prefix) - , m_Tag(nullptr){}; - Logger(const char* prefix, const char* tag) + , m_Identifier(identifier){}; + Logger(const char* prefix, const char* identifier, const char* tag) : m_Prefix(prefix) - , m_Tag(nullptr) { - setTag(tag); - }; + , m_Identifier(identifier) + , m_Tag(tag){}; - ~Logger() { - if (m_Tag != nullptr) { - free(m_Tag); - } + void setTag(const char* tag) { m_Tag = tag; } + + void trace(IDType id, const char* format, ...) const + __attribute__((format(printf, 3, 4))) { + va_list args; + va_start(args, format); + log(id, TRACE, format, args); + va_end(args); + } + + void debug(IDType id, const char* format, ...) const + __attribute__((format(printf, 3, 4))) { + va_list args; + va_start(args, format); + log(id, DEBUG, format, args); + va_end(args); } - void setTag(const char* tag); + void info(IDType id, const char* format, ...) const + __attribute__((format(printf, 3, 4))) { + va_list args; + va_start(args, format); + log(id, INFO, format, args); + va_end(args); + } + + void warn(IDType id, const char* format, ...) const + __attribute__((format(printf, 3, 4))) { + va_list args; + va_start(args, format); + log(id, WARN, format, args); + va_end(args); + } - void trace(const char* str, ...) const __attribute__((format(printf, 2, 3))); - void debug(const char* str, ...) const __attribute__((format(printf, 2, 3))); - void info(const char* str, ...) const __attribute__((format(printf, 2, 3))); - void warn(const char* str, ...) const __attribute__((format(printf, 2, 3))); - void error(const char* str, ...) const __attribute__((format(printf, 2, 3))); - void fatal(const char* str, ...) const __attribute__((format(printf, 2, 3))); + void error(IDType id, const char* format, ...) const + __attribute__((format(printf, 3, 4))) { + va_list args; + va_start(args, format); + log(id, ERROR, format, args); + va_end(args); + } + + void fatal(IDType id, const char* format, ...) const + __attribute__((format(printf, 3, 4))) { + va_list args; + va_start(args, format); + log(id, FATAL, format, args); + va_end(args); + } template - inline void traceArray(const char* str, const T* array, size_t size) const { - logArray(TRACE, str, array, size); + inline void traceArray(IDType id, const char* str, const T* array, size_t size) + const { + logArray(id, Level::TRACE, str, array, size); } template - inline void debugArray(const char* str, const T* array, size_t size) const { - logArray(DEBUG, str, array, size); + inline void debugArray(IDType id, const char* str, const T* array, size_t size) + const { + logArray(id, DEBUG, str, array, size); } template - inline void infoArray(const char* str, const T* array, size_t size) const { - logArray(INFO, str, array, size); + inline void infoArray(IDType id, const char* str, const T* array, size_t size) + const { + logArray(id, INFO, str, array, size); } template - inline void warnArray(const char* str, const T* array, size_t size) const { - logArray(WARN, str, array, size); + inline void warnArray(IDType id, const char* str, const T* array, size_t size) + const { + logArray(id, WARN, str, array, size); } template - inline void errorArray(const char* str, const T* array, size_t size) const { - logArray(ERROR, str, array, size); + inline void errorArray(IDType id, const char* str, const T* array, size_t size) + const { + logArray(id, ERROR, str, array, size); } template - inline void fatalArray(const char* str, const T* array, size_t size) const { - logArray(FATAL, str, array, size); + inline void fatalArray(IDType id, const char* str, const T* array, size_t size) + const { + logArray(id, FATAL, str, array, size); } private: - void log(Level level, const char* str, va_list args) const; - - template - void logArray(Level level, const char* str, const T* array, size_t size) const { + void log(IDType id, Level level, const char* format, va_list args) const { if (level < LOG_LEVEL) { return; } - char buf[strlen(m_Prefix) + (m_Tag == nullptr ? 0 : strlen(m_Tag)) + 2]; - strcpy(buf, m_Prefix); - if (m_Tag != nullptr) { - strcat(buf, ":"); - strcat(buf, m_Tag); + printPrefix(id, level); + vprintf(format, args); + } + + template + void logArray(IDType id, Level level, const char* str, const T* array, size_t size) + const { + if (level < LOG_LEVEL) { + return; } - Serial.printf("[%-5s] [%s] %s", levelToString(level), buf, str); + printPrefix(id, level); + Serial.print(str); for (size_t i = 0; i < size; i++) { Serial.print(array[i]); @@ -89,10 +135,26 @@ class Logger { Serial.println(); } + void printPrefix(IDType id, Level level) const { + Serial.printf( + "{%s-%d} [%-5s] [%s", + m_Identifier, + static_cast(id), + levelToString(level), + m_Prefix + ); + + if (m_Tag) { + Serial.printf(":%s", m_Tag->c_str()); + } + + Serial.printf("] "); + } + const char* const m_Prefix; - char* m_Tag; + const char* const m_Identifier; + std::optional m_Tag; }; -} // namespace Logging -} // namespace SlimeVR +} // namespace SlimeVR::Logging #endif diff --git a/src/main.cpp b/src/main.cpp index 0b6746325..b86ad0b62 100644 --- a/src/main.cpp +++ b/src/main.cpp @@ -34,8 +34,13 @@ #include "serial/serialcommands.h" #include "status/TPSCounter.h" +enum class MainLogs { + Starting = 0, + CantClearI2C = 1, +}; + Timer<> globalTimer; -SlimeVR::Logging::Logger logger("SlimeVR"); +SlimeVR::Logging::Logger logger("SlimeVR", "main"); SlimeVR::Sensors::SensorManager sensorManager; SlimeVR::LEDManager ledManager(LED_PIN); SlimeVR::Status::StatusManager statusManager; @@ -64,7 +69,7 @@ void setup() { Serial.println(); Serial.println(); - logger.info("SlimeVR v" FIRMWARE_VERSION " starting up..."); + logger.info(MainLogs::Starting, "SlimeVR v" FIRMWARE_VERSION " starting up..."); statusManager.setStatus(SlimeVR::Status::LOADING, true); @@ -78,7 +83,8 @@ void setup() { // this, check needs to be re-added. auto clearResult = I2CSCAN::clearBus(PIN_IMU_SDA, PIN_IMU_SCL); if (clearResult != 0) { - logger.warn("Can't clear I2C bus, error %d", clearResult); + logger + .warn(MainLogs::CantClearI2C, "Can't clear I2C bus, error %d", clearResult); } // join I2C bus diff --git a/src/motionprocessing/GyroTemperatureCalibrator.cpp b/src/motionprocessing/GyroTemperatureCalibrator.cpp index 8b4cc02eb..0f0a9d829 100644 --- a/src/motionprocessing/GyroTemperatureCalibrator.cpp +++ b/src/motionprocessing/GyroTemperatureCalibrator.cpp @@ -211,11 +211,12 @@ bool GyroTemperatureCalibrator::loadConfig(float newSensitivity) { } } else { m_Logger.warn( + Logs::NoTempCalData, "No temperature calibration data found for sensor %d, ignoring...", sensorId ); - // m_Logger.info("Temperature calibration is advised"); m_Logger.info( + Logs::TempCalWarning, "Temperature calibration is a work-in-progress feature; any changes to its " "parameters or updates will render the saved temperature curve invalid and " "unloadable." @@ -227,18 +228,22 @@ bool GyroTemperatureCalibrator::loadConfig(float newSensitivity) { bool GyroTemperatureCalibrator::saveConfig() { if (configuration.saveTemperatureCalibration(sensorId, config)) { m_Logger.info( - "Saved temperature calibration config (%0.1f%) for sensorId:%i", + Logs::SavedTempCal, + "Saved temperature calibration config (%0.1f%%) for sensorId:%i", config.getCalibrationDonePercent(), sensorId ); if (config.fullyCalibrated()) { configSaved = true; } else { - m_Logger.info("Calibration will resume from this checkpoint after reboot"); + m_Logger.info( + Logs::CalibrationWillResume, + "Calibration will resume from this checkpoint after reboot" + ); } } else { configSaveFailed = true; - m_Logger.error("Something went wrong"); + m_Logger.error(Logs::SomethingWentWrong, "Something went wrong"); } return configSaved; } diff --git a/src/motionprocessing/GyroTemperatureCalibrator.h b/src/motionprocessing/GyroTemperatureCalibrator.h index 352bb0b91..fcd672594 100644 --- a/src/motionprocessing/GyroTemperatureCalibrator.h +++ b/src/motionprocessing/GyroTemperatureCalibrator.h @@ -190,8 +190,7 @@ class GyroTemperatureCalibrator { ) : sensorId(_sensorId) , config(_configType, sensitivity) - , samplesPerStep(_samplesPerStep) - , m_Logger(SlimeVR::Logging::Logger("GyroTemperatureCalibrator")) { + , samplesPerStep(_samplesPerStep) { char buf[4]; sprintf(buf, "%u", _sensorId); m_Logger.setTag(buf); @@ -219,7 +218,16 @@ class GyroTemperatureCalibrator { private: GyroTemperatureCalibrationState state; uint32_t samplesPerStep; - SlimeVR::Logging::Logger m_Logger; + + enum class Logs { + NoTempCalData = 0, + TempCalWarning = 1, + SavedTempCal = 2, + CalibrationWillResume = 3, + SomethingWentWrong = 4, + }; + + SlimeVR::Logging::Logger m_Logger{"GyroTemperatureCalibrator", "gyrotempcal"}; float lastApproximatedTemperature = 0.0f; float lastApproximatedOffsets[3]; diff --git a/src/network/connection.cpp b/src/network/connection.cpp index dd906df26..2601deb31 100644 --- a/src/network/connection.cpp +++ b/src/network/connection.cpp @@ -50,7 +50,7 @@ bool Connection::beginPacket() { // This *technically* should *never* fail, since the underlying UDP // library just returns 1. - m_Logger.warn("UDP beginPacket() failed"); + m_Logger.warn(Logs::BeginPacketFailed, "UDP beginPacket() failed"); } return r > 0; @@ -533,12 +533,18 @@ void Connection::searchForServer() { #ifdef DEBUG_NETWORK m_Logger.trace( + Logs::DebugReceived, "Received %d bytes from %s, port %d", packetSize, m_UDP.remoteIP().toString().c_str(), m_UDP.remotePort() ); - m_Logger.traceArray("UDP packet contents: ", m_Packet, len); + m_Logger.traceArray( + Logs::DebugPacketContents, + "UDP packet contents: ", + m_Packet, + len + ); #endif // Handshake is different, it has 3 in the first byte, not the 4th, and data @@ -546,7 +552,10 @@ void Connection::searchForServer() { if (static_cast(m_Packet[0]) == ReceivePacketType::Handshake) { if (strncmp((char*)m_Packet + 1, "Hey OVR =D 5", 12) != 0) { - m_Logger.error("Received invalid handshake packet"); + m_Logger.error( + Logs::InvalidHandshake, + "Received invalid handshake packet" + ); continue; } @@ -562,6 +571,7 @@ void Connection::searchForServer() { ledManager.off(); m_Logger.debug( + Logs::HandshakeSuccessful, "Handshake successful, server is %s:%d", m_UDP.remoteIP().toString().c_str(), m_UDP.remotePort() @@ -576,7 +586,10 @@ void Connection::searchForServer() { // This makes the LED blink for 20ms every second if (m_LastConnectionAttemptTimestamp + 1000 < now) { m_LastConnectionAttemptTimestamp = now; - m_Logger.info("Searching for the server on the local network..."); + m_Logger.info( + Logs::SearchingServer, + "Searching for the server on the local network..." + ); Connection::sendTrackerDiscovery(); ledManager.on(); } else if (m_LastConnectionAttemptTimestamp + 20 < now) { @@ -632,7 +645,7 @@ void Connection::update() { m_AckedSensorCalibration + MAX_SENSORS_COUNT, false ); - m_Logger.warn("Connection to server timed out"); + m_Logger.warn(Logs::ConnectionTimedOut, "Connection to server timed out"); return; } @@ -647,12 +660,14 @@ void Connection::update() { #ifdef DEBUG_NETWORK m_Logger.trace( + Logs::DebugReceived, "Received %d bytes from %s, port %d", packetSize, m_UDP.remoteIP().toString().c_str(), m_UDP.remotePort() ); - m_Logger.traceArray("UDP packet contents: ", m_Packet, len); + m_Logger + .traceArray(Logs::DebugPacketContents, "UDP packet contents: ", m_Packet, len); #else (void)packetSize; #endif @@ -667,7 +682,10 @@ void Connection::update() { case ReceivePacketType::Handshake: // Assume handshake successful - m_Logger.warn("Handshake received again, ignoring"); + m_Logger.warn( + Logs::HandshakeReceivedAgain, + "Handshake received again, ignoring" + ); break; case ReceivePacketType::Command: @@ -682,7 +700,7 @@ void Connection::update() { case ReceivePacketType::SensorInfo: { if (len < 6) { - m_Logger.warn("Wrong sensor info packet"); + m_Logger.warn(Logs::WrongSensorInfoPacket, "Wrong sensor info packet"); break; } @@ -709,7 +727,10 @@ void Connection::update() { case ReceivePacketType::FeatureFlags: { // Packet type (4) + Packet number (8) + flags (len - 12) if (len < 13) { - m_Logger.warn("Invalid feature flags packet: too short"); + m_Logger.warn( + Logs::InvalidFeatureFlagsPacket, + "Invalid feature flags packet: too short" + ); break; } @@ -721,7 +742,10 @@ void Connection::update() { if (!hadFlags) { #if PACKET_BUNDLING != PACKET_BUNDLING_DISABLED if (m_ServerFeatures.has(ServerFeatures::PROTOCOL_BUNDLE_SUPPORT)) { - m_Logger.debug("Server supports packet bundling"); + m_Logger.debug( + Logs::PacketBundlingSupported, + "Server supports packet bundling" + ); } #endif } @@ -733,7 +757,10 @@ void Connection::update() { // Packet type (4) + Packet number (8) + sensor_id(1) + flag_id (2) + state // (1) if (len < 16) { - m_Logger.warn("Invalid sensor config flag packet: too short"); + m_Logger.warn( + Logs::SensorConfigFlagShort, + "Invalid sensor config flag packet: too short" + ); break; } @@ -751,7 +778,9 @@ void Connection::update() { auto& sensors = sensorManager.getSensors(); if (sensorId >= sensors.size()) { - m_Logger.warn("Invalid sensor config flag packet: invalid sensor id" + m_Logger.warn( + Logs::SensorConfigFlagInvalidId, + "Invalid sensor config flag packet: invalid sensor id" ); break; } diff --git a/src/network/connection.h b/src/network/connection.h index dc7d26c1d..11f0a8041 100644 --- a/src/network/connection.h +++ b/src/network/connection.h @@ -214,7 +214,24 @@ class Connection { void sendAcknowledgeConfigChange(uint8_t sensorId, SensorToggles configType); bool m_Connected = false; - SlimeVR::Logging::Logger m_Logger = SlimeVR::Logging::Logger("UDPConnection"); + + enum class Logs { + BeginPacketFailed = 1, + DebugReceived = 2, + DebugPacketContents = 3, + InvalidHandshake = 4, + HandshakeSuccessful = 5, + SearchingServer = 6, + ConnectionTimedOut = 7, + HandshakeReceivedAgain = 8, + WrongSensorInfoPacket = 9, + InvalidFeatureFlagsPacket = 10, + PacketBundlingSupported = 11, + SensorConfigFlagShort = 12, + SensorConfigFlagInvalidId = 13, + }; + + SlimeVR::Logging::Logger m_Logger{"UDPConnection", "connection"}; WiFiUDP m_UDP; unsigned char m_Packet[128]; // buffer for incoming packets diff --git a/src/network/wifihandler.cpp b/src/network/wifihandler.cpp index b25813842..d42b18cc6 100644 --- a/src/network/wifihandler.cpp +++ b/src/network/wifihandler.cpp @@ -34,8 +34,25 @@ uint8_t wifiState = SLIME_WIFI_NOT_SETUP; bool hadWifi = false; unsigned long last_rssi_sample = 0; +enum class WiFiLogs { + SettingUp = 0, + LoadedCredentials = 1, + CantGetConfig = 2, + Status = 3, + Connected = 4, + ConnectionLost = 5, + CantConnectSaved = 6, + RetryingSavedG = 7, + SkippingSavedG = 8, + CantConnectSavedG = 9, + TryingHardcoded = 10, + CantConnectHardcoded = 11, + TryingHardcodedG = 12, + CantConnectFromAny = 13, +}; + // TODO: Cleanup with proper classes -SlimeVR::Logging::Logger wifiHandlerLogger("WiFiHandler"); +SlimeVR::Logging::Logger wifiHandlerLogger("WiFiHandler", "wifi"); void reportWifiError() { if (lastWifiReportTime + 1000 < millis()) { @@ -68,7 +85,7 @@ void WiFiNetwork::setWiFiCredentials(const char* SSID, const char* pass) { IPAddress WiFiNetwork::getAddress() { return WiFi.localIP(); } void WiFiNetwork::setUp() { - wifiHandlerLogger.info("Setting up WiFi"); + wifiHandlerLogger.info(WiFiLogs::SettingUp, "Setting up WiFi"); WiFi.persistent(true); WiFi.mode(WIFI_STA); #if ESP8266 @@ -79,6 +96,7 @@ void WiFiNetwork::setUp() { #endif WiFi.hostname("SlimeVR FBT Tracker"); wifiHandlerLogger.info( + WiFiLogs::LoadedCredentials, "Loaded credentials for SSID '%s' and pass length %d", WiFi.SSID().c_str(), WiFi.psk().length() @@ -87,7 +105,7 @@ void WiFiNetwork::setUp() { wl_status_t status = WiFi.begin( ); // Should connect to last used access point, see // https://arduino-esp8266.readthedocs.io/en/latest/esp8266wifi/station-class.html#begin - wifiHandlerLogger.debug("Status: %d", status); + wifiHandlerLogger.debug(WiFiLogs::Status, "Status: %d", status); wifiState = SLIME_WIFI_SAVED_ATTEMPT; wifiConnectionTimeout = millis(); @@ -115,7 +133,10 @@ void WiFiNetwork::setUp() { esp_wifi_set_config(WIFI_IF_STA, &conf); WiFi.setSleep(WIFI_PS_MAX_MODEM); } else { - wifiHandlerLogger.error("Unable to get WiFi config, power saving not enabled!"); + wifiHandlerLogger.error( + WiFiLogs::CantGetConfig, + "Unable to get WiFi config, power saving not enabled!" + ); } #endif #endif @@ -127,6 +148,7 @@ void onConnected() { isWifiConnected = true; hadWifi = true; wifiHandlerLogger.info( + WiFiLogs::Connected, "Connected successfully to SSID '%s', IP address %s", WiFi.SSID().c_str(), WiFi.localIP().toString().c_str() @@ -139,7 +161,10 @@ void WiFiNetwork::upkeep() { upkeepProvisioning(); if (WiFi.status() != WL_CONNECTED) { if (isWifiConnected) { - wifiHandlerLogger.warn("Connection to WiFi lost, reconnecting..."); + wifiHandlerLogger.warn( + WiFiLogs::ConnectionLost, + "Connection to WiFi lost, reconnecting..." + ); isWifiConnected = false; } statusManager.setStatus(SlimeVR::Status::WIFI_CONNECTING, true); @@ -163,14 +188,17 @@ void WiFiNetwork::upkeep() { WiFi.begin(); wifiConnectionTimeout = millis(); wifiHandlerLogger.error( + WiFiLogs::CantConnectSaved, "Can't connect from saved credentials, status: %d.", WiFi.status() ); wifiHandlerLogger.debug( + WiFiLogs::RetryingSavedG, "Trying saved credentials with PHY Mode G..." ); } else { wifiHandlerLogger.debug( + WiFiLogs::SkippingSavedG, "Skipping PHY Mode G attempt on 0-length SSID..." ); } @@ -191,10 +219,14 @@ void WiFiNetwork::upkeep() { WiFi.begin(WIFI_CREDS_SSID, WIFI_CREDS_PASSWD); wifiConnectionTimeout = millis(); wifiHandlerLogger.error( + WiFiLogs::CantConnectSavedG, "Can't connect from saved credentials, status: %d.", WiFi.status() ); - wifiHandlerLogger.debug("Trying hardcoded credentials..."); + wifiHandlerLogger.debug( + WiFiLogs::TryingHardcoded, + "Trying hardcoded credentials..." + ); #endif wifiState = SLIME_WIFI_HARDCODE_ATTEMPT; return; @@ -211,10 +243,12 @@ void WiFiNetwork::upkeep() { WiFi.begin(WIFI_CREDS_SSID, WIFI_CREDS_PASSWD); wifiConnectionTimeout = millis(); wifiHandlerLogger.error( + WiFiLogs::CantConnectHardcoded, "Can't connect from saved credentials, status: %d.", WiFi.status() ); wifiHandlerLogger.debug( + WiFiLogs::TryingHardcodedG, "Trying hardcoded credentials with WiFi PHY Mode G..." ); #endif @@ -250,6 +284,7 @@ void WiFiNetwork::upkeep() { && wifiConnectionTimeout + 11000 < millis()) { if (WiFi.status() != WL_IDLE_STATUS) { wifiHandlerLogger.error( + WiFiLogs::CantConnectFromAny, "Can't connect from any credentials, status: %d.", WiFi.status() ); diff --git a/src/network/wifiprovisioning.cpp b/src/network/wifiprovisioning.cpp index ad3f954b1..60faa85d0 100644 --- a/src/network/wifiprovisioning.cpp +++ b/src/network/wifiprovisioning.cpp @@ -29,8 +29,13 @@ // it sucks. // TODO: New implementation: https://github.com/SlimeVR/SlimeVR-Tracker-ESP/issues/71 +enum class ProvisioningLogs { + SmartConfigStarted = 1, +}; + // TODO: Cleanup with proper classes -SlimeVR::Logging::Logger wifiProvisioningLogger("WiFiProvisioning"); +SlimeVR::Logging::Logger + wifiProvisioningLogger("WiFiProvisioning", "provisioning"); bool provisioning = false; void WiFiNetwork::upkeepProvisioning() { @@ -41,7 +46,10 @@ void WiFiNetwork::upkeepProvisioning() { void WiFiNetwork::startProvisioning() { if (WiFi.beginSmartConfig()) { provisioning = true; - wifiProvisioningLogger.info("SmartConfig started"); + wifiProvisioningLogger.info( + ProvisioningLogs::SmartConfigStarted, + "SmartConfig started" + ); } } diff --git a/src/sensorinterface/SPIImpl.h b/src/sensorinterface/SPIImpl.h index 1985de4e5..ce873270c 100644 --- a/src/sensorinterface/SPIImpl.h +++ b/src/sensorinterface/SPIImpl.h @@ -40,6 +40,7 @@ struct SPIImpl : public RegisterInterface { , m_spiSettings(spiSettings) , m_csPin(csPin) { m_Logger.info( + Logs::SPIInfo, "SPI settings: clock: %d, bit order: 0x%02X, data mode: 0x%02X", spiSettings._clock, spiSettings._bitOrder, @@ -138,7 +139,12 @@ struct SPIImpl : public RegisterInterface { SPIClass& m_spiClass; SPISettings m_spiSettings; PinInterface* m_csPin; - SlimeVR::Logging::Logger m_Logger = SlimeVR::Logging::Logger("SPI"); + + enum class Logs { + SPIInfo = 0, + }; + + SlimeVR::Logging::Logger m_Logger{"SPI", "spi"}; }; } // namespace SlimeVR::Sensors diff --git a/src/sensors/ErroneousSensor.cpp b/src/sensors/ErroneousSensor.cpp index 2cddaddc6..80c0dcfb1 100644 --- a/src/sensors/ErroneousSensor.cpp +++ b/src/sensors/ErroneousSensor.cpp @@ -29,6 +29,7 @@ namespace SlimeVR { namespace Sensors { void ErroneousSensor::motionSetup() { m_Logger.error( + Logs::FailedToInitialize, "IMU of type %s failed to initialize", getIMUNameByType(m_ExpectedType) ); diff --git a/src/sensors/SensorBuilder.cpp b/src/sensors/SensorBuilder.cpp index 149393c72..b757ffeb9 100644 --- a/src/sensors/SensorBuilder.cpp +++ b/src/sensors/SensorBuilder.cpp @@ -52,12 +52,14 @@ uint8_t SensorBuilder::buildAllSensors() { auto sensorType = findSensorType(sensorID, __VA_ARGS__); \ if (sensorType == SensorTypeID::Unknown) { \ m_Manager->m_Logger.error( \ + SensorManager::Logs::CantFindSensorType, \ "Can't find sensor type for sensor %d", \ sensorID \ ); \ break; \ } else { \ m_Manager->m_Logger.info( \ + SensorManager::Logs::SensorAutomaticallyDetected, \ "Sensor %d automatically detected with %s", \ sensorID, \ getIMUNameByType(sensorType) \ @@ -69,7 +71,11 @@ uint8_t SensorBuilder::buildAllSensors() { sensor = buildSensor(sensorID, __VA_ARGS__); \ } \ if (sensor->isWorking()) { \ - m_Manager->m_Logger.info("Sensor %d configured", sensorID); \ + m_Manager->m_Logger.info( \ + SensorManager::Logs::SensorConfigured, \ + "Sensor %d configured", \ + sensorID \ + ); \ activeSensorCount++; \ } \ m_Manager->m_Sensors.push_back(std::move(sensor)); \ @@ -149,6 +155,7 @@ std::unique_ptr<::Sensor> SensorBuilder::buildSensorDynamically( // ); default: m_Manager->m_Logger.error( + SensorManager::Logs::UnableToCreateSensor, "Unable to create sensor with type %s (%d)", getIMUNameByType(type), type @@ -214,6 +221,7 @@ std::unique_ptr<::Sensor> SensorBuilder::buildSensorDynamically( // ); default: m_Manager->m_Logger.error( + SensorManager::Logs::UnableToCreateSensor, "Unable to create sensor with type %s (%d)", getIMUNameByType(type), type diff --git a/src/sensors/SensorBuilder.h b/src/sensors/SensorBuilder.h index 72b2e0646..e964895a4 100644 --- a/src/sensors/SensorBuilder.h +++ b/src/sensors/SensorBuilder.h @@ -154,6 +154,7 @@ struct SensorBuilder { int extraParam = 0 ) { m_Manager->m_Logger.trace( + SensorManager::Logs::BuildingSensor, "Building IMU with: id=%d,\n\ address=%s, rotation=%f,\n\ interface=%s, int=%s, extraParam=%d, optional=%d", @@ -176,6 +177,7 @@ struct SensorBuilder { if (!imuInterface.hasSensorOnBus()) { if (!optional) { m_Manager->m_Logger.error( + SensorManager::Logs::MandatoryNotFound, "Mandatory sensor %d not found at address %s", sensorID + 1, imuInterface.toString().c_str() @@ -183,6 +185,7 @@ struct SensorBuilder { return std::make_unique(sensorID, ImuType::TypeID); } else { m_Manager->m_Logger.debug( + SensorManager::Logs::OptionalNotFound, "Optional sensor %d not found at address %s", sensorID + 1, imuInterface.toString().c_str() @@ -192,6 +195,7 @@ struct SensorBuilder { } m_Manager->m_Logger.trace( + SensorManager::Logs::SensorNotFound, "Sensor %d found at address %s", sensorID + 1, imuInterface.toString().c_str() diff --git a/src/sensors/SensorManager.cpp b/src/sensors/SensorManager.cpp index 651bbd307..a63a4d5fd 100644 --- a/src/sensors/SensorManager.cpp +++ b/src/sensors/SensorManager.cpp @@ -29,16 +29,17 @@ namespace SlimeVR::Sensors { void SensorManager::setup() { if (m_MCP.begin_I2C()) { - m_Logger.info("MCP initialized"); + m_Logger.info(Logs::MCPInitialized, "MCP initialized"); } SensorBuilder sensorBuilder = SensorBuilder(this); uint8_t activeSensorCount = sensorBuilder.buildAllSensors(); - m_Logger.info("%d sensor(s) configured", activeSensorCount); + m_Logger.info(Logs::SensorConfigured, "%d sensor(s) configured", activeSensorCount); // Check and scan i2c if no sensors active if (activeSensorCount == 0) { m_Logger.error( + Logs::CantFindI2CDevice, "Can't find I2C device on provided addresses, scanning for all I2C devices " "in the background" ); diff --git a/src/sensors/SensorManager.h b/src/sensors/SensorManager.h index 253a2dde5..c55719201 100644 --- a/src/sensors/SensorManager.h +++ b/src/sensors/SensorManager.h @@ -42,8 +42,6 @@ namespace SlimeVR::Sensors { class SensorManager { public: - SensorManager() - : m_Logger(SlimeVR::Logging::Logger("SensorManager")) {} void setup(); void postSetup(); @@ -58,7 +56,20 @@ class SensorManager { } private: - SlimeVR::Logging::Logger m_Logger; + enum class Logs { + MCPInitialized = 0, + SensorConfigured = 1, + CantFindI2CDevice = 2, + BuildingSensor = 3, + MandatoryNotFound = 4, + OptionalNotFound = 5, + SensorNotFound = 6, + CantFindSensorType = 7, + SensorAutomaticallyDetected = 8, + UnableToCreateSensor = 9, + }; + + SlimeVR::Logging::Logger m_Logger{"SensorManager", "sensormanager"}; std::vector> m_Sensors; Adafruit_MCP23X17 m_MCP; diff --git a/src/sensors/bmi160sensor.cpp b/src/sensors/bmi160sensor.cpp index ae6c0a6e1..bca4afcb3 100644 --- a/src/sensors/bmi160sensor.cpp +++ b/src/sensors/bmi160sensor.cpp @@ -111,6 +111,7 @@ void BMI160Sensor::motionSetup() { if (!imu.testConnection()) { m_Logger.fatal( + Logs::SensorNotDetected, "Can't connect to BMI160 (reported device ID 0x%02x) at address 0x%02x", imu.getDeviceID(), addr @@ -120,6 +121,7 @@ void BMI160Sensor::motionSetup() { } m_Logger.info( + Logs::SensorDetected, "Connected to BMI160 (reported device ID 0x%02x) at address 0x%02x", imu.getDeviceID(), addr @@ -138,18 +140,23 @@ void BMI160Sensor::motionSetup() { case SlimeVR::Configuration::SensorConfigType::NONE: m_Logger.warn( + Logs::NoCalibrationData, "No calibration data found for sensor %d, ignoring...", sensorId ); - m_Logger.info("Calibration is advised"); + m_Logger.info(Logs::NoCalibrationData, "Calibration is advised"); break; default: m_Logger.warn( + Logs::IncompatibleCalibrationData, "Incompatible calibration data found for sensor %d, ignoring...", sensorId ); - m_Logger.info("Calibration is advised"); + m_Logger.info( + Logs::IncompatibleCalibrationData, + "Calibration is advised" + ); } } @@ -159,12 +166,15 @@ void BMI160Sensor::motionSetup() { if (g_az < -0.75f) { ledManager.on(); - m_Logger.info("Flip front to confirm start calibration"); + m_Logger.info( + Logs::CalibrationInstructions, + "Flip front to confirm start calibration" + ); delay(5000); getRemappedAcceleration(&ax, &ay, &az); g_az = (float)az / BMI160_ACCEL_TYPICAL_SENSITIVITY_LSB; if (g_az > 0.75f) { - m_Logger.debug("Starting calibration..."); + m_Logger.debug(Logs::CalibrationInstructions, "Starting calibration..."); startCalibration(0); } @@ -177,16 +187,26 @@ void BMI160Sensor::motionSetup() { = IS_INT16_CLIPPED(ax) || IS_INT16_CLIPPED(ay) || IS_INT16_CLIPPED(az); const bool anyZero = ax == 0 || ay == 0 || az == 0; if (anyClipped || anyZero) { - m_Logger.warn("---------------- WARNING -----------------"); - m_Logger.warn("One or more accelerometer axes may be dead"); m_Logger.warn( + Logs::CalibrationInstructions, + "---------------- WARNING -----------------" + ); + m_Logger.warn( + Logs::CalibrationInstructions, + "One or more accelerometer axes may be dead" + ); + m_Logger.warn( + Logs::CalibrationInstructions, "Acceleration: %i %i %i (Z = %f G)", ax, ay, az, (float)az / BMI160_ACCEL_TYPICAL_SENSITIVITY_LSB ); - m_Logger.warn("---------------- WARNING -----------------"); + m_Logger.warn( + Logs::CalibrationInstructions, + "---------------- WARNING -----------------" + ); } } @@ -227,6 +247,7 @@ void BMI160Sensor::motionSetup() { gscaleY = BMI160_GSCALE * BMI160_CALCULATE_SENSITIVTY_MUL(offsets.y); gscaleZ = BMI160_GSCALE * BMI160_CALCULATE_SENSITIVTY_MUL(offsets.z); m_Logger.debug( + Logs::CustomSensitivityOffsetEnabled, "Custom sensitivity offset enabled: %s %s", offsets.mac, offsets.sensorId == SENSORID_PRIMARY ? "primary" : "aux" @@ -241,15 +262,18 @@ void BMI160Sensor::motionSetup() { isMagCalibrated = hasMagCalibration(); #endif m_Logger.info( + Logs::CalibrationState, "Calibration data for gyro: %s", isGyroCalibrated ? "found" : "not found" ); m_Logger.info( + Logs::CalibrationState, "Calibration data for accel: %s", isAccelCalibrated ? "found" : "not found" ); #if !USE_6_AXIS m_Logger.info( + Logs::CalibrationState, "Calibration data for mag: %s", isMagCalibrated ? "found" : "not found" ); @@ -268,15 +292,15 @@ void BMI160Sensor::motionSetup() { uint8_t err; if (imu.getErrReg(&err)) { if (err & BMI160_ERR_MASK_CHIP_NOT_OPERABLE) { - m_Logger.fatal("Fatal error: chip not operable"); + m_Logger.fatal(Logs::FailedToInitialize, "Fatal error: chip not operable"); return; } else if (err & BMI160_ERR_MASK_ERROR_CODE) { - m_Logger.error("Error code 0x%02x", err); + m_Logger.error(Logs::FailedToInitialize, "Error code 0x%02x", err); } else { - m_Logger.info("Initialized"); + m_Logger.info(Logs::SensorInitialized, "Initialized"); } } else { - m_Logger.error("Failed to get error register value"); + m_Logger.error(Logs::FailedToInitialize, "Failed to get error register value"); } working = true; @@ -384,6 +408,7 @@ void BMI160Sensor::motionLoop() { bool restDetected = sfusion.getRestDetected(); m_Logger.debug( + Logs::DebugStatus, "readFIFO took %0.4f ms, read gyr %i acc %i mag %i rest %i resets " "%i readerrs %i type " SENSOR_FUSION_TYPE_STRING, ((float)cpuUsageMicros / 1e3f), @@ -672,11 +697,17 @@ void BMI160Sensor::onMagRawSample(uint32_t dtMicros, int16_t x, int16_t y, int16 void BMI160Sensor::printTemperatureCalibrationState() { const auto degCtoF = [](float degC) { return (degC * 9.0f / 5.0f) + 32.0f; }; - m_Logger.info("Sensor %i temperature calibration state:", sensorId); m_Logger - .info(" current temp: %0.4f C (%0.4f F)", temperature, degCtoF(temperature)); + .info(Logs::TempCalState, "Sensor %i temperature calibration state:", sensorId); + m_Logger.info( + Logs::TempCalState, + " current temp: %0.4f C (%0.4f F)", + temperature, + degCtoF(temperature) + ); auto printTemperatureRange = [&](const char* label, float min, float max) { m_Logger.info( + Logs::TempCalState, " %s: min %0.4f C max %0.4f C (min %0.4f F max %0.4f F)", label, min, @@ -692,23 +723,36 @@ void BMI160Sensor::printTemperatureCalibrationState() { gyroTempCalibrator->config.maxTemperatureRange ); m_Logger.info( - " done: %0.1f%", + Logs::TempCalState, + " done: %0.1f%%", gyroTempCalibrator->config.getCalibrationDonePercent() ); } void BMI160Sensor::printDebugTemperatureCalibrationState() { m_Logger.info( + Logs::TempCalState, "Sensor %i gyro odr %f hz, sensitivity %f lsb", sensorId, BMI160_ODR_GYR_HZ, BMI160_GYRO_TYPICAL_SENSITIVITY_LSB ); - m_Logger.info("Sensor %i temperature calibration matrix (tempC x y z):", sensorId); - m_Logger.info("BUF %i %i", sensorId, TEMP_CALIBRATION_BUFFER_SIZE); - m_Logger.info("SENS %i %f", sensorId, BMI160_GYRO_TYPICAL_SENSITIVITY_LSB); - m_Logger.info("DATA %i", sensorId); + m_Logger.info( + Logs::TempCalState, + "Sensor %i temperature calibration matrix (tempC x y z):", + sensorId + ); + m_Logger + .info(Logs::TempCalState, "BUF %i %i", sensorId, TEMP_CALIBRATION_BUFFER_SIZE); + m_Logger.info( + Logs::TempCalState, + "SENS %i %f", + sensorId, + BMI160_GYRO_TYPICAL_SENSITIVITY_LSB + ); + m_Logger.info(Logs::TempCalState, "DATA %i", sensorId); for (int i = 0; i < TEMP_CALIBRATION_BUFFER_SIZE; i++) { m_Logger.info( + Logs::TempCalState, "%f %f %f %f", gyroTempCalibrator->config.samples[i].t, gyroTempCalibrator->config.samples[i].x, @@ -716,18 +760,21 @@ void BMI160Sensor::printDebugTemperatureCalibrationState() { gyroTempCalibrator->config.samples[i].z ); } - m_Logger.info("END %i", sensorId); + m_Logger.info(Logs::TempCalState, "END %i", sensorId); m_Logger.info( + Logs::TempCalState, "y = %f + (%fx) + (%fxx) + (%fxxx)", UNPACK_VECTOR_ARRAY(gyroTempCalibrator->config.cx), gyroTempCalibrator->config.cx[3] ); m_Logger.info( + Logs::TempCalState, "y = %f + (%fx) + (%fxx) + (%fxxx)", UNPACK_VECTOR_ARRAY(gyroTempCalibrator->config.cy), gyroTempCalibrator->config.cy[3] ); m_Logger.info( + Logs::TempCalState, "y = %f + (%fx) + (%fxx) + (%fxxx)", UNPACK_VECTOR_ARRAY(gyroTempCalibrator->config.cz), gyroTempCalibrator->config.cz[3] @@ -832,7 +879,7 @@ void BMI160Sensor::startCalibration(int calibrationType) { maybeCalibrateAccel(); maybeCalibrateMag(); - m_Logger.debug("Saving the calibration data"); + m_Logger.debug(Logs::SavingCalibration, "Saving the calibration data"); SlimeVR::Configuration::SensorConfig config; config.type = SlimeVR::Configuration::SensorConfigType::BMI160; @@ -840,13 +887,16 @@ void BMI160Sensor::startCalibration(int calibrationType) { configuration.setSensor(sensorId, config); configuration.save(); - m_Logger.debug("Saved the calibration data"); + m_Logger.debug(Logs::SavedCalibration, "Saved the calibration data"); - m_Logger.info("Calibration data gathered, exiting calibration mode in..."); + m_Logger.info( + Logs::CalibrationInstructions, + "Calibration data gathered, exiting calibration mode in..." + ); constexpr uint8_t POST_CALIBRATION_DELAY_SEC = 3; ledManager.on(); for (uint8_t i = POST_CALIBRATION_DELAY_SEC; i > 0; i--) { - m_Logger.info("%i...", i); + m_Logger.info(Logs::CalibrationInstructions, "%i...", i); delay(1000); } } @@ -857,7 +907,7 @@ void BMI160Sensor::maybeCalibrateGyro() { #endif #if BMI160_CALIBRATION_GYRO_SECONDS == 0 - m_Logger.debug("Skipping gyro calibration"); + m_Logger.debug(Logs::CalibrationInstructions, "Skipping gyro calibration"); return; #endif @@ -865,34 +915,42 @@ void BMI160Sensor::maybeCalibrateGyro() { constexpr uint8_t GYRO_CALIBRATION_DELAY_SEC = 3; constexpr float GYRO_CALIBRATION_DURATION_SEC = BMI160_CALIBRATION_GYRO_SECONDS; m_Logger.info( + Logs::CalibrationInstructions, "Put down the device and wait for baseline gyro reading calibration (%.1f " "seconds)", GYRO_CALIBRATION_DURATION_SEC ); ledManager.on(); for (uint8_t i = GYRO_CALIBRATION_DELAY_SEC; i > 0; i--) { - m_Logger.info("%i...", i); + m_Logger.info(Logs::CalibrationInstructions, "%i...", i); delay(1000); } ledManager.off(); if (!getTemperature(&temperature)) { - m_Logger.error("Error: can't read temperature"); + m_Logger.error(Logs::CalibrationInstructions, "Error: can't read temperature"); } m_Config.temperature = temperature; #ifdef DEBUG_SENSOR - m_Logger.trace("Calibration temperature: %f", temperature); + m_Logger.trace( + Logs::CalibrationInstructions, + "Calibration temperature: %f", + temperature + ); #endif if (!imu.getGyroDrdy()) { - m_Logger.error("Fatal error: gyroscope drdy = 0 (dead?)"); + m_Logger.error( + Logs::CalibrationInstructions, + "Fatal error: gyroscope drdy = 0 (dead?)" + ); return; } ledManager.pattern(100, 100, 3); ledManager.on(); - m_Logger.info("Gyro calibration started..."); + m_Logger.info(Logs::CalibrationInstructions, "Gyro calibration started..."); constexpr uint16_t gyroCalibrationSamples = GYRO_CALIBRATION_DURATION_SEC / (BMI160_ODR_GYR_MICROS / 1e6); @@ -913,6 +971,7 @@ void BMI160Sensor::maybeCalibrateGyro() { #ifdef DEBUG_SENSOR m_Logger.trace( + Logs::CalibrationInstructions, "Gyro calibration results: %f %f %f", UNPACK_VECTOR_ARRAY(m_Config.G_off) ); @@ -925,7 +984,7 @@ void BMI160Sensor::maybeCalibrateAccel() { #endif #if BMI160_ACCEL_CALIBRATION_METHOD == ACCEL_CALIBRATION_METHOD_SKIP - m_Logger.debug("Skipping accelerometer calibration"); + m_Logger.debug(Logs::CalibrationInstructions, "Skipping accelerometer calibration"); return; #endif @@ -933,10 +992,13 @@ void BMI160Sensor::maybeCalibrateAccel() { // Blink calibrating led before user should rotate the sensor #if BMI160_ACCEL_CALIBRATION_METHOD == ACCEL_CALIBRATION_METHOD_ROTATION - m_Logger.info("After 3 seconds, Gently rotate the device while it's gathering data" + m_Logger.info( + Logs::CalibrationInstructions, + "After 3 seconds, Gently rotate the device while it's gathering data" ); #elif BMI160_ACCEL_CALIBRATION_METHOD == ACCEL_CALIBRATION_METHOD_6POINT m_Logger.info( + Logs::CalibrationInstructions, "Put the device into 6 unique orientations (all sides), leave it still and do " "not hold/touch for 3 seconds each" ); @@ -944,7 +1006,7 @@ void BMI160Sensor::maybeCalibrateAccel() { constexpr uint8_t ACCEL_CALIBRATION_DELAY_SEC = 3; ledManager.on(); for (uint8_t i = ACCEL_CALIBRATION_DELAY_SEC; i > 0; i--) { - m_Logger.info("%i...", i); + m_Logger.info(Logs::CalibrationInstructions, "%i...", i); delay(1000); } ledManager.off(); @@ -954,7 +1016,7 @@ void BMI160Sensor::maybeCalibrateAccel() { ledManager.pattern(100, 100, 6); delay(100); ledManager.on(); - m_Logger.debug("Gathering accelerometer data..."); + m_Logger.debug(Logs::CalibrationInstructions, "Gathering accelerometer data..."); for (int i = 0; i < accelCalibrationSamples; i++) { int16_t ax, ay, az; imu.getAcceleration(&ax, &ay, &az); @@ -963,7 +1025,10 @@ void BMI160Sensor::maybeCalibrateAccel() { delay(100); } ledManager.off(); - m_Logger.debug("Calculating accelerometer calibration data..."); + m_Logger.debug( + Logs::CalibrationInstructions, + "Calculating accelerometer calibration data..." + ); #elif BMI160_ACCEL_CALIBRATION_METHOD == ACCEL_CALIBRATION_METHOD_6POINT RestDetectionParams calibrationRestDetectionParams; calibrationRestDetectionParams.restMinTime = 3; @@ -984,8 +1049,9 @@ void BMI160Sensor::maybeCalibrateAccel() { float* accelCalibrationChunk = new float[numSamplesPerPosition * 3]; ledManager.pattern(100, 100, 6); ledManager.on(); - m_Logger.info("Gathering accelerometer data..."); + m_Logger.info(Logs::CalibrationInstructions, "Gathering accelerometer data..."); m_Logger.info( + Logs::CalibrationInstructions, "Waiting for position %i, you can leave the device as is...", numPositionsRecorded + 1 ); @@ -1028,6 +1094,7 @@ void BMI160Sensor::maybeCalibrateAccel() { ledManager.pattern(50, 50, 2); ledManager.on(); m_Logger.info( + Logs::CalibrationInstructions, "Recorded, waiting for position %i...", numPositionsRecorded + 1 ); @@ -1045,7 +1112,10 @@ void BMI160Sensor::maybeCalibrateAccel() { delayMicroseconds(BMI160_ODR_ACC_MICROS); } ledManager.off(); - m_Logger.debug("Calculating accelerometer calibration data..."); + m_Logger.debug( + Logs::CalibrationInstructions, + "Calculating accelerometer calibration data..." + ); delete[] accelCalibrationChunk; #endif @@ -1053,15 +1123,19 @@ void BMI160Sensor::maybeCalibrateAccel() { magneto->current_calibration(A_BAinv); delete magneto; - m_Logger.debug("Finished calculating accelerometer calibration"); - m_Logger.debug("Accelerometer calibration matrix:"); - m_Logger.debug("{"); + m_Logger.debug( + Logs::CalibrationInstructions, + "Finished calculating accelerometer calibration" + ); + m_Logger.debug(Logs::CalibrationInstructions, "Accelerometer calibration matrix:"); + m_Logger.debug(Logs::CalibrationInstructions, "{"); for (int i = 0; i < 3; i++) { m_Config.A_B[i] = A_BAinv[0][i]; m_Config.A_Ainv[0][i] = A_BAinv[1][i]; m_Config.A_Ainv[1][i] = A_BAinv[2][i]; m_Config.A_Ainv[2][i] = A_BAinv[3][i]; m_Logger.debug( + Logs::CalibrationInstructions, " %f, %f, %f, %f", A_BAinv[0][i], A_BAinv[1][i], @@ -1069,7 +1143,7 @@ void BMI160Sensor::maybeCalibrateAccel() { A_BAinv[3][i] ); } - m_Logger.debug("}"); + m_Logger.debug(Logs::CalibrationInstructions, "}"); } void BMI160Sensor::maybeCalibrateMag() { @@ -1079,7 +1153,7 @@ void BMI160Sensor::maybeCalibrateMag() { #endif #if BMI160_CALIBRATION_MAG_SECONDS == 0 - m_Logger.debug("Skipping magnetometer calibration"); + m_Logger.debug(Logs::CalibrationInstructions, "Skipping magnetometer calibration"); return; #endif @@ -1088,18 +1162,19 @@ void BMI160Sensor::maybeCalibrateMag() { constexpr uint8_t MAG_CALIBRATION_DELAY_SEC = 3; constexpr float MAG_CALIBRATION_DURATION_SEC = BMI160_CALIBRATION_MAG_SECONDS; m_Logger.info( + Logs::CalibrationInstructions, "After 3 seconds, rotate the device in figure 8 pattern while it's gathering " "data (%.1f seconds)", MAG_CALIBRATION_DURATION_SEC ); for (uint8_t i = MAG_CALIBRATION_DELAY_SEC; i > 0; i--) { - m_Logger.info("%i...", i); + m_Logger.info(Logs::CalibrationInstructions, "%i...", i); delay(1000); } ledManager.pattern(100, 100, 9); delay(100); ledManager.on(); - m_Logger.debug("Gathering magnetometer data..."); + m_Logger.debug(Logs::CalibrationInstructions, "Gathering magnetometer data..."); constexpr float SAMPLE_DELAY_MS = 100.0f; constexpr uint16_t magCalibrationSamples @@ -1118,20 +1193,27 @@ void BMI160Sensor::maybeCalibrateMag() { delay(SAMPLE_DELAY_MS); } ledManager.off(); - m_Logger.debug("Calculating magnetometer calibration data..."); + m_Logger.debug( + Logs::CalibrationInstructions, + "Calculating magnetometer calibration data..." + ); float M_BAinv[4][3]; magneto->current_calibration(M_BAinv); delete magneto; - m_Logger.debug("[INFO] Magnetometer calibration matrix:"); - m_Logger.debug("{"); + m_Logger.debug( + Logs::CalibrationInstructions, + "[INFO] Magnetometer calibration matrix:" + ); + m_Logger.debug(Logs::CalibrationInstructions, "{"); for (int i = 0; i < 3; i++) { m_Config.M_B[i] = M_BAinv[0][i]; m_Config.M_Ainv[0][i] = M_BAinv[1][i]; m_Config.M_Ainv[1][i] = M_BAinv[2][i]; m_Config.M_Ainv[2][i] = M_BAinv[3][i]; m_Logger.debug( + Logs::CalibrationInstructions, " %f, %f, %f, %f", M_BAinv[0][i], M_BAinv[1][i], @@ -1139,7 +1221,7 @@ void BMI160Sensor::maybeCalibrateMag() { M_BAinv[3][i] ); } - m_Logger.debug("}"); + m_Logger.debug(Logs::CalibrationInstructions, "}"); #endif } diff --git a/src/sensors/bmi160sensor.h b/src/sensors/bmi160sensor.h index bc49d2dd1..72561cf76 100644 --- a/src/sensors/bmi160sensor.h +++ b/src/sensors/bmi160sensor.h @@ -180,6 +180,7 @@ class BMI160Sensor : public Sensor { void resetTemperatureCalibrationState() override final { gyroTempCalibrator->reset(); m_Logger.info( + Logs::TempCalReset, "Temperature calibration state has been reset for sensorId:%i", sensorId ); diff --git a/src/sensors/bno055sensor.cpp b/src/sensors/bno055sensor.cpp index 27953260f..43675d7a7 100644 --- a/src/sensors/bno055sensor.cpp +++ b/src/sensors/bno055sensor.cpp @@ -36,7 +36,11 @@ void BNO055Sensor::motionSetup() { if (!imu.begin(Adafruit_BNO055::OPERATION_MODE_NDOF)) #endif { - m_Logger.fatal("Can't connect to BNO055 at address 0x%02x", addr); + m_Logger.fatal( + Logs::SensorNotDetected, + "Can't connect to BNO055 at address 0x%02x", + addr + ); ledManager.pattern(50, 50, 200); return; } @@ -46,7 +50,8 @@ void BNO055Sensor::motionSetup() { // otherwise it does not work. imu.setAxisRemap(Adafruit_BNO055::REMAP_CONFIG_P0); imu.setAxisSign(Adafruit_BNO055::REMAP_SIGN_P0); - m_Logger.info("Connected to BNO055 at address 0x%02x", addr); + m_Logger + .info(Logs::SensorInitialized, "Connected to BNO055 at address 0x%02x", addr); working = true; m_tpsCounter.reset(); diff --git a/src/sensors/bno080sensor.cpp b/src/sensors/bno080sensor.cpp index b34292c96..3d19e2a11 100644 --- a/src/sensors/bno080sensor.cpp +++ b/src/sensors/bno080sensor.cpp @@ -32,6 +32,7 @@ void BNO080Sensor::motionSetup() { #endif if (!imu.begin(addr, Wire, m_IntPin)) { m_Logger.fatal( + Logs::SensorNotDetected, "Can't connect to %s at address 0x%02x", getIMUNameByType(sensorType), addr @@ -41,6 +42,7 @@ void BNO080Sensor::motionSetup() { } m_Logger.info( + Logs::SensorDetected, "Connected to %s on 0x%02x. " "Info: SW Version Major: 0x%02x " "SW Version Minor: 0x%02x " @@ -252,6 +254,7 @@ void BNO080Sensor::motionLoop() { onTableCalEnabled ); m_Logger.info( + Logs::CalibrationState, "BNO08X calibration satus received: Status: %d, Accel: %d, Gyro: %d, " "Mag: %d, Planar: %d, OnTable: %d", calibrationResponseStatus, @@ -279,6 +282,7 @@ void BNO080Sensor::motionLoop() { } lastError = error; m_Logger.error( + Logs::SensorError, "BNO08X error. Severity: %d, seq: %d, src: %d, err: %d, mod: %d, code: " "%d", error.severity, @@ -299,11 +303,13 @@ void BNO080Sensor::motionLoop() { } m_Logger.error( - "Sensor %d doesn't respond. Last reset reason:", + Logs::SensorTimeout, + "Sensor %d doesn't respond. Last reset reason: %d", sensorId, lastReset ); m_Logger.error( + Logs::SensorTimeout, "Last error: %d, seq: %d, src: %d, err: %d, mod: %d, code: %d", lastError.severity, lastError.error_sequence_number, @@ -336,7 +342,11 @@ void BNO080Sensor::sendData() { ); #ifdef DEBUG_SENSOR - m_Logger.trace("Quaternion: %f, %f, %f, %f", UNPACK_QUATERNION(fusedRotation)); + m_Logger.trace( + Logs::DebugQuat, + "Quaternion: %f, %f, %f, %f", + UNPACK_QUATERNION(fusedRotation) + ); #endif #if SEND_ACCELERATION diff --git a/src/sensors/icm20948sensor.cpp b/src/sensors/icm20948sensor.cpp index 2d66cb301..20bb3c5f9 100644 --- a/src/sensors/icm20948sensor.cpp +++ b/src/sensors/icm20948sensor.cpp @@ -31,8 +31,11 @@ // saved to NVS. Increments through the list then stops; to prevent unwelcome eeprom // wear. int bias_save_periods[] - = {120, 180, 300, 600, 600 -}; // 2min + 3min + 5min + 10min + 10min (no more saves after 30min) + = {120, + 180, + 300, + 600, + 600}; // 2min + 3min + 5min + 10min + 10min (no more saves after 30min) #define ACCEL_SENSITIVITY_4G 8192.0f @@ -108,7 +111,7 @@ void ICM20948Sensor::readFIFOToEnd() { ICM_20948_Status_e readStatus = imu.readDMPdataFromFIFO(&dmpDataTemp); #ifdef DEBUG_SENSOR - { m_Logger.trace("e0x%02x", readStatus); } + { m_Logger.trace(Logs::DebugStatus, "e0x%02x", readStatus); } #endif if (readStatus == ICM_20948_Stat_Ok) { @@ -183,30 +186,42 @@ void ICM20948Sensor::startDMP() { #endif if (imu.initializeDMP() == ICM_20948_Stat_Ok) { - m_Logger.debug("DMP initialized"); + m_Logger.debug(Logs::SensorInitialization, "DMP initialized"); } else { - m_Logger.fatal("Failed to initialize DMP"); + m_Logger.fatal(Logs::SensorInitialization, "Failed to initialize DMP"); return; } #if (USE_6_AXIS) { - m_Logger.debug("Using 6 axis configuration"); + m_Logger.debug(Logs::SensorInitialization, "Using 6 axis configuration"); if (imu.enableDMPSensor(INV_ICM20948_SENSOR_GAME_ROTATION_VECTOR) == ICM_20948_Stat_Ok) { - m_Logger.debug("Enabled DMP sensor for game rotation vector"); + m_Logger.debug( + Logs::SensorInitialization, + "Enabled DMP sensor for game rotation vector" + ); } else { - m_Logger.fatal("Failed to enable DMP sensor for game rotation vector"); + m_Logger.fatal( + Logs::SensorInitialization, + "Failed to enable DMP sensor for game rotation vector" + ); return; } } #else { - m_Logger.debug("Using 9 axis configuration"); + m_Logger.debug(Logs::SensorInitialization, "Using 9 axis configuration"); if (imu.enableDMPSensor(INV_ICM20948_SENSOR_ORIENTATION) == ICM_20948_Stat_Ok) { - m_Logger.debug("Enabled DMP sensor for sensor orientation"); + m_Logger.debug( + Logs::SensorInitialization, + "Enabled DMP sensor for sensor orientation" + ); } else { - m_Logger.fatal("Failed to enable DMP sensor orientation"); + m_Logger.fatal( + Logs::SensorInitialization, + "Failed to enable DMP sensor orientation" + ); return; } } @@ -215,9 +230,15 @@ void ICM20948Sensor::startDMP() { #if (SEND_ACCELERATION) if (imu.enableDMPSensor(INV_ICM20948_SENSOR_RAW_ACCELEROMETER) == ICM_20948_Stat_Ok) { - m_Logger.debug("Enabled DMP sensor for accelerometer"); + m_Logger.debug( + Logs::SensorInitialization, + "Enabled DMP sensor for accelerometer" + ); } else { - m_Logger.fatal("Failed to enable DMP sensor for accelerometer"); + m_Logger.fatal( + Logs::SensorInitialization, + "Failed to enable DMP sensor for accelerometer" + ); return; } #endif @@ -228,9 +249,12 @@ void ICM20948Sensor::startDMP() { { if (imu.setDMPODRrate(DMP_ODR_Reg_Quat6, ICM20948_ODRGYR) == ICM_20948_Stat_Ok) { - m_Logger.debug("Set Quat6 to 100Hz frequency"); + m_Logger.debug(Logs::SensorInitialization, "Set Quat6 to 100Hz frequency"); } else { - m_Logger.fatal("Failed to set Quat6 to 100Hz frequency"); + m_Logger.fatal( + Logs::SensorInitialization, + "Failed to set Quat6 to 100Hz frequency" + ); return; } } @@ -238,9 +262,12 @@ void ICM20948Sensor::startDMP() { { if (imu.setDMPODRrate(DMP_ODR_Reg_Quat9, ICM20948_ODRGYR) == ICM_20948_Stat_Ok) { - m_Logger.debug("Set Quat9 to 100Hz frequency"); + m_Logger.debug(Logs::SensorInitialization, "Set Quat9 to 100Hz frequency"); } else { - m_Logger.fatal("Failed to set Quat9 to 100Hz frequency"); + m_Logger.fatal( + Logs::SensorInitialization, + "Failed to set Quat9 to 100Hz frequency" + ); return; } } @@ -249,42 +276,48 @@ void ICM20948Sensor::startDMP() { #if (SEND_ACCELERATION) if (this->imu.setDMPODRrate(DMP_ODR_Reg_Accel, ICM20948_ODRAXL) == ICM_20948_Stat_Ok) { - this->m_Logger.debug("Set Accel to 100Hz frequency"); + this->m_Logger.debug( + Logs::SensorInitialization, + "Set Accel to 100Hz frequency" + ); } else { - this->m_Logger.fatal("Failed to set Accel to 100Hz frequency"); + this->m_Logger.fatal( + Logs::SensorInitialization, + "Failed to set Accel to 100Hz frequency" + ); return; } #endif // Enable the FIFO if (imu.enableFIFO() == ICM_20948_Stat_Ok) { - m_Logger.debug("FIFO Enabled"); + m_Logger.debug(Logs::SensorInitialization, "FIFO Enabled"); } else { - m_Logger.fatal("Failed to enable FIFO"); + m_Logger.fatal(Logs::SensorInitialization, "Failed to enable FIFO"); return; } // Enable the DMP if (imu.enableDMP() == ICM_20948_Stat_Ok) { - m_Logger.debug("DMP Enabled"); + m_Logger.debug(Logs::SensorInitialization, "DMP Enabled"); } else { - m_Logger.fatal("Failed to enable DMP"); + m_Logger.fatal(Logs::SensorInitialization, "Failed to enable DMP"); return; } // Reset DMP if (imu.resetDMP() == ICM_20948_Stat_Ok) { - m_Logger.debug("Reset DMP"); + m_Logger.debug(Logs::SensorInitialization, "Reset DMP"); } else { - m_Logger.fatal("Failed to reset DMP"); + m_Logger.fatal(Logs::SensorInitialization, "Failed to reset DMP"); return; } // Reset FIFO if (imu.resetFIFO() == ICM_20948_Stat_Ok) { - m_Logger.debug("Reset FIFO"); + m_Logger.debug(Logs::SensorInitialization, "Reset FIFO"); } else { - m_Logger.fatal("Failed to reset FIFO"); + m_Logger.fatal(Logs::SensorInitialization, "Failed to reset FIFO"); return; } } @@ -302,13 +335,18 @@ void ICM20948Sensor::connectSensor() { } else if (addr == 0x69) { isOnSecondAddress = true; } else { - m_Logger.fatal("I2C Address not supported by ICM20948 library: 0x%02x", addr); + m_Logger.fatal( + Logs::SensorInitialization, + "I2C Address not supported by ICM20948 library: 0x%02x", + addr + ); return; } ICM_20948_Status_e imu_err = imu.begin(Wire, isOnSecondAddress); if (imu_err != ICM_20948_Stat_Ok) { m_Logger.fatal( + Logs::SensorNotDetected, "Can't connect to ICM20948 at address 0x%02x, error code: 0x%02x", addr, imu_err @@ -328,7 +366,8 @@ void ICM20948Sensor::checkSensorTimeout() { if (lastData + 2000 < currenttime) { working = false; m_Logger.error( - "Sensor timeout I2C Address 0x%02x delaytime: %d ms", + Logs::SensorTimeout, + "Sensor timeout I2C Address 0x%02x delaytime: %ld ms", addr, currenttime - lastData ); @@ -403,7 +442,7 @@ void ICM20948Sensor::saveCalibration(bool repeat) { { return; } #endif #ifdef DEBUG_SENSOR - m_Logger.trace("Saving Bias"); + m_Logger.trace(Logs::SavingCalibration, "Saving Bias"); #endif imu.GetBiasGyroX(&m_Config.G[0]); @@ -421,10 +460,22 @@ void ICM20948Sensor::saveCalibration(bool repeat) { #endif #ifdef DEBUG_SENSOR - m_Logger.trace("Gyrometer bias: [%d, %d, %d]", UNPACK_VECTOR_ARRAY(m_Config.G)); - m_Logger.trace("Accelerometer bias: [%d, %d, %d]", UNPACK_VECTOR_ARRAY(m_Config.A)); + m_Logger.trace( + Logs::CalibrationState, + "Gyrometer bias: [%d, %d, %d]", + UNPACK_VECTOR_ARRAY(m_Config.G) + ); + m_Logger.trace( + Logs::CalibrationState, + "Accelerometer bias: [%d, %d, %d]", + UNPACK_VECTOR_ARRAY(m_Config.A) + ); #if !USE_6_AXIS - m_Logger.trace("Compass bias: [%d, %d, %d]", UNPACK_VECTOR_ARRAY(m_Config.C)); + m_Logger.trace( + Logs::CalibrationState, + "Compass bias: [%d, %d, %d]", + UNPACK_VECTOR_ARRAY(m_Config.C) + ); #endif #endif @@ -467,25 +518,39 @@ void ICM20948Sensor::loadCalibration() { case SlimeVR::Configuration::SensorConfigType::NONE: m_Logger.warn( + Logs::NoCalibrationData, "No calibration data found for sensor %d, ignoring...", sensorId ); - m_Logger.info("Calibration is advised"); + m_Logger.info(Logs::NoCalibrationData, "Calibration is advised"); break; default: m_Logger.warn( + Logs::IncompatibleCalibrationData, "Incompatible calibration data found for sensor %d, ignoring...", sensorId ); - m_Logger.info("Calibration is advised"); + m_Logger.info(Logs::IncompatibleCalibrationData, "Calibration is advised"); } #ifdef DEBUG_SENSOR - m_Logger.trace("Gyrometer bias: [%d, %d, %d]", UNPACK_VECTOR_ARRAY(m_Config.G)); - m_Logger.trace("Accelerometer bias: [%d, %d, %d]", UNPACK_VECTOR_ARRAY(m_Config.A)); + m_Logger.trace( + Logs::CalibrationState, + "Gyrometer bias: [%d, %d, %d]", + UNPACK_VECTOR_ARRAY(m_Config.G) + ); + m_Logger.trace( + Logs::CalibrationState, + "Accelerometer bias: [%d, %d, %d]", + UNPACK_VECTOR_ARRAY(m_Config.A) + ); #if !USE_6_AXIS - m_Logger.trace("Compass bias: [%d, %d, %d]", UNPACK_VECTOR_ARRAY(m_Config.C)); + m_Logger.trace( + Logs::CalibrationState, + "Compass bias: [%d, %d, %d]", + UNPACK_VECTOR_ARRAY(m_Config.C) + ); #endif #endif diff --git a/src/sensors/mpu6050sensor.cpp b/src/sensors/mpu6050sensor.cpp index e3402e0c3..759d5c94c 100644 --- a/src/sensors/mpu6050sensor.cpp +++ b/src/sensors/mpu6050sensor.cpp @@ -45,6 +45,7 @@ void MPU6050Sensor::motionSetup() { imu.initialize(addr); if (!imu.testConnection()) { m_Logger.fatal( + Logs::SensorNotDetected, "Can't connect to %s (reported device ID 0x%02x) at address 0x%02x", getIMUNameByType(sensorType), imu.getDeviceID(), @@ -54,6 +55,7 @@ void MPU6050Sensor::motionSetup() { } m_Logger.info( + Logs::SensorDetected, "Connected to %s (reported device ID 0x%02x) at address 0x%02x", getIMUNameByType(sensorType), imu.getDeviceID(), @@ -74,18 +76,23 @@ void MPU6050Sensor::motionSetup() { case SlimeVR::Configuration::SensorConfigType::NONE: m_Logger.warn( + Logs::NoCalibrationData, "No calibration data found for sensor %d, ignoring...", sensorId ); - m_Logger.info("Calibration is advised"); + m_Logger.info(Logs::NoCalibrationData, "Calibration is advised"); break; default: m_Logger.warn( + Logs::IncompatibleCalibrationData, "Incompatible calibration data found for sensor %d, ignoring...", sensorId ); - m_Logger.info("Calibration is advised"); + m_Logger.info( + Logs::IncompatibleCalibrationData, + "Calibration is advised" + ); } } #endif @@ -98,7 +105,10 @@ void MPU6050Sensor::motionSetup() { // calibration #else // IMU_MPU6050_RUNTIME_CALIBRATION - m_Logger.debug("Performing startup calibration of accel and gyro..."); + m_Logger.debug( + Logs::CalibrationInstructions, + "Performing startup calibration of accel and gyro..." + ); // Do a quick and dirty calibration. As the imu warms up the offsets will change // a bit, but this will be good-enough delay(1000); // A small sleep to give the users a chance to stop it from moving @@ -111,14 +121,17 @@ void MPU6050Sensor::motionSetup() { ledManager.pattern(50, 50, 5); // turn on the DMP, now that it's ready - m_Logger.debug("Enabling DMP..."); + m_Logger.debug(Logs::SensorInitialization, "Enabling DMP..."); imu.setDMPEnabled(true); // TODO: Add interrupt support // mpuIntStatus = imu.getIntStatus(); // set our DMP Ready flag so the main loop() function knows it's okay to use it - m_Logger.debug("DMP ready! Waiting for first interrupt..."); + m_Logger.debug( + Logs::SensorInitialization, + "DMP ready! Waiting for first interrupt..." + ); dmpReady = true; // get expected DMP packet size for later comparison @@ -130,7 +143,11 @@ void MPU6050Sensor::motionSetup() { // 1 = initial memory load failed // 2 = DMP configuration updates failed // (if it's going to break, usually the code will be 1) - m_Logger.error("DMP Initialization failed (code %d)", devStatus); + m_Logger.error( + Logs::FailedToInitialize, + "DMP Initialization failed (code %d)", + devStatus + ); } m_tpsCounter.reset(); m_dataCounter.reset(); @@ -196,11 +213,15 @@ void MPU6050Sensor::startCalibration(int calibrationType) { #ifdef IMU_MPU6050_RUNTIME_CALIBRATION m_Logger.info( + Logs::CalibrationInstructions, "MPU is using automatic runtime calibration. Place down the device and it " "should automatically calibrate after a few seconds" ); #else //! IMU_MPU6050_RUNTIME_CALIBRATION - m_Logger.info("Put down the device and wait for baseline gyro reading calibration"); + m_Logger.info( + Logs::CalibrationInstructions, + "Put down the device and wait for baseline gyro reading calibration" + ); delay(2000); imu.setDMPEnabled(false); @@ -208,8 +229,8 @@ void MPU6050Sensor::startCalibration(int calibrationType) { imu.CalibrateAccel(6); imu.setDMPEnabled(true); - m_Logger.debug("Gathered baseline gyro reading"); - m_Logger.debug("Starting offset finder"); + m_Logger.debug(Logs::CalibrationInstructions, "Gathered baseline gyro reading"); + m_Logger.debug(Logs::CalibrationInstructions, "Starting offset finder"); switch (calibrationType) { case CALIBRATION_TYPE_INTERNAL_ACCEL: imu.CalibrateAccel(10); @@ -231,7 +252,7 @@ void MPU6050Sensor::startCalibration(int calibrationType) { configuration.setCalibration(sensorId, calibration); configuration.save(); - m_Logger.info("Calibration finished"); + m_Logger.info(Logs::CalibrationInstructions, "Calibration finished"); #endif // !IMU_MPU6050_RUNTIME_CALIBRATION ledManager.off(); diff --git a/src/sensors/mpu9250sensor.cpp b/src/sensors/mpu9250sensor.cpp index 6425d7b73..08c54d188 100644 --- a/src/sensors/mpu9250sensor.cpp +++ b/src/sensors/mpu9250sensor.cpp @@ -48,6 +48,7 @@ void MPU9250Sensor::motionSetup() { imu.initialize(addr); if (!imu.testConnection()) { m_Logger.fatal( + Logs::SensorNotDetected, "Can't connect to MPU9250 (reported device ID 0x%02x) at address 0x%02x", imu.getDeviceID(), addr @@ -56,6 +57,7 @@ void MPU9250Sensor::motionSetup() { } m_Logger.info( + Logs::SensorDetected, "Connected to MPU9250 (reported device ID 0x%02x) at address 0x%02x", imu.getDeviceID(), addr @@ -69,14 +71,17 @@ void MPU9250Sensor::motionSetup() { float g_az = (float)az / 16384; // For 2G sensitivity if (g_az < -0.75f) { ledManager.on(); - m_Logger.info("Flip front to confirm start calibration"); + m_Logger.info( + Logs::CalibrationInstructions, + "Flip front to confirm start calibration" + ); delay(5000); ledManager.off(); imu.getAcceleration(&ax, &ay, &az); g_az = (float)az / 16384; if (g_az > 0.75f) { - m_Logger.debug("Starting calibration..."); + m_Logger.debug(Logs::CalibrationInstructions, "Starting calibration..."); startCalibration(0); } } @@ -94,18 +99,23 @@ void MPU9250Sensor::motionSetup() { case SlimeVR::Configuration::SensorConfigType::NONE: m_Logger.warn( + Logs::NoCalibrationData, "No calibration data found for sensor %d, ignoring...", sensorId ); - m_Logger.info("Calibration is advised"); + m_Logger.info(Logs::NoCalibrationData, "Calibration is advised"); break; default: m_Logger.warn( + Logs::IncompatibleCalibrationData, "Incompatible calibration data found for sensor %d, ignoring...", sensorId ); - m_Logger.info("Calibration is advised"); + m_Logger.info( + Logs::IncompatibleCalibrationData, + "Calibration is advised" + ); } } @@ -115,14 +125,17 @@ void MPU9250Sensor::motionSetup() { ledManager.pattern(50, 50, 5); // turn on the DMP, now that it's ready - m_Logger.debug("Enabling DMP..."); + m_Logger.debug(Logs::SensorInitialization, "Enabling DMP..."); imu.setDMPEnabled(true); // TODO: Add interrupt support // mpuIntStatus = imu.getIntStatus(); // set our DMP Ready flag so the main loop() function knows it's okay to use it - m_Logger.debug("DMP ready! Waiting for first interrupt..."); + m_Logger.debug( + Logs::SensorInitialization, + "DMP ready! Waiting for first interrupt..." + ); dmpReady = true; // get expected DMP packet size for later comparison @@ -133,7 +146,11 @@ void MPU9250Sensor::motionSetup() { // 1 = initial memory load failed // 2 = DMP configuration updates failed // (if it's going to break, usually the code will be 1) - m_Logger.error("DMP Initialization failed (code %d)", devStatus); + m_Logger.error( + Logs::SensorInitialization, + "DMP Initialization failed (code %d)", + devStatus + ); } #else // NOTE: could probably combine these into less total writes, but this should work, @@ -246,7 +263,10 @@ void MPU9250Sensor::startCalibration(int calibrationType) { constexpr int calibrationSamples = 300; // Blink calibrating led before user should rotate the sensor - m_Logger.info("Gently rotate the device while it's gathering magnetometer data"); + m_Logger.info( + Logs::CalibrationInstructions, + "Gently rotate the device while it's gathering magnetometer data" + ); ledManager.pattern(15, 300, 3000 / 310); MagnetoCalibration* magneto = new MagnetoCalibration(); for (int i = 0; i < calibrationSamples; i++) { @@ -258,20 +278,24 @@ void MPU9250Sensor::startCalibration(int calibrationType) { ledManager.off(); delay(250); } - m_Logger.debug("Calculating calibration data..."); + m_Logger.debug(Logs::CalibrationInstructions, "Calculating calibration data..."); float M_BAinv[4][3]; magneto->current_calibration(M_BAinv); delete magneto; - m_Logger.debug("[INFO] Magnetometer calibration matrix:"); - m_Logger.debug("{"); + m_Logger.debug( + Logs::CalibrationInstructions, + "[INFO] Magnetometer calibration matrix:" + ); + m_Logger.debug(Logs::CalibrationInstructions, "{"); for (int i = 0; i < 3; i++) { m_Config.M_B[i] = M_BAinv[0][i]; m_Config.M_Ainv[0][i] = M_BAinv[1][i]; m_Config.M_Ainv[1][i] = M_BAinv[2][i]; m_Config.M_Ainv[2][i] = M_BAinv[3][i]; m_Logger.debug( + Logs::CalibrationInstructions, " %f, %f, %f, %f", M_BAinv[0][i], M_BAinv[1][i], @@ -279,11 +303,14 @@ void MPU9250Sensor::startCalibration(int calibrationType) { M_BAinv[3][i] ); } - m_Logger.debug("}"); + m_Logger.debug(Logs::CalibrationInstructions, "}"); #else - m_Logger.debug("Gathering raw data for device calibration..."); + m_Logger.debug( + Logs::CalibrationInstructions, + "Gathering raw data for device calibration..." + ); constexpr int calibrationSamples = 300; // Reset values Gxyz[0] = 0; @@ -291,7 +318,10 @@ void MPU9250Sensor::startCalibration(int calibrationType) { Gxyz[2] = 0; // Wait for sensor to calm down before calibration - m_Logger.info("Put down the device and wait for baseline gyro reading calibration"); + m_Logger.info( + Logs::CalibrationInstructions, + "Put down the device and wait for baseline gyro reading calibration" + ); delay(2000); union fifo_sample_raw buf; @@ -313,7 +343,13 @@ void MPU9250Sensor::startCalibration(int calibrationType) { Gxyz[2] /= calibrationSamples; #ifdef DEBUG_SENSOR - m_Logger.trace("Gyro calibration results: %f %f %f", Gxyz[0], Gxyz[1], Gxyz[2]); + m_Logger.trace( + Logs::CalibrationInstructions, + "Gyro calibration results: %f %f %f", + Gxyz[0], + Gxyz[1], + Gxyz[2] + ); #endif // TODO: use offset registers? @@ -323,6 +359,7 @@ void MPU9250Sensor::startCalibration(int calibrationType) { // Blink calibrating led before user should rotate the sensor m_Logger.info( + Logs::CalibrationInstructions, "Gently rotate the device while it's gathering accelerometer and magnetometer " "data" ); @@ -344,7 +381,7 @@ void MPU9250Sensor::startCalibration(int calibrationType) { ledManager.off(); delay(250); } - m_Logger.debug("Calculating calibration data..."); + m_Logger.debug(Logs::CalibrationInstructions, "Calculating calibration data..."); float A_BAinv[4][3]; magneto_acc->current_calibration(A_BAinv); @@ -354,15 +391,19 @@ void MPU9250Sensor::startCalibration(int calibrationType) { magneto_mag->current_calibration(M_BAinv); delete magneto_mag; - m_Logger.debug("Finished Calculate Calibration data"); - m_Logger.debug("Accelerometer calibration matrix:"); - m_Logger.debug("{"); + m_Logger.debug( + Logs::CalibrationInstructions, + "Finished Calculate Calibration data" + ); + m_Logger.debug(Logs::CalibrationInstructions, "Accelerometer calibration matrix:"); + m_Logger.debug(Logs::CalibrationInstructions, "{"); for (int i = 0; i < 3; i++) { m_Config.A_B[i] = A_BAinv[0][i]; m_Config.A_Ainv[0][i] = A_BAinv[1][i]; m_Config.A_Ainv[1][i] = A_BAinv[2][i]; m_Config.A_Ainv[2][i] = A_BAinv[3][i]; m_Logger.debug( + Logs::CalibrationInstructions, " %f, %f, %f, %f", A_BAinv[0][i], A_BAinv[1][i], @@ -370,15 +411,19 @@ void MPU9250Sensor::startCalibration(int calibrationType) { A_BAinv[3][i] ); } - m_Logger.debug("}"); - m_Logger.debug("[INFO] Magnetometer calibration matrix:"); - m_Logger.debug("{"); + m_Logger.debug(Logs::CalibrationInstructions, "}"); + m_Logger.debug( + Logs::CalibrationInstructions, + "[INFO] Magnetometer calibration matrix:" + ); + m_Logger.debug(Logs::CalibrationInstructions, "{"); for (int i = 0; i < 3; i++) { m_Config.M_B[i] = M_BAinv[0][i]; m_Config.M_Ainv[0][i] = M_BAinv[1][i]; m_Config.M_Ainv[1][i] = M_BAinv[2][i]; m_Config.M_Ainv[2][i] = M_BAinv[3][i]; m_Logger.debug( + Logs::CalibrationInstructions, " %f, %f, %f, %f", M_BAinv[0][i], M_BAinv[1][i], @@ -386,10 +431,10 @@ void MPU9250Sensor::startCalibration(int calibrationType) { M_BAinv[3][i] ); } - m_Logger.debug("}"); + m_Logger.debug(Logs::CalibrationInstructions, "}"); #endif - m_Logger.debug("Saving the calibration data"); + m_Logger.debug(Logs::SavingCalibration, "Saving the calibration data"); SlimeVR::Configuration::SensorConfig config; config.type = SlimeVR::Configuration::SensorConfigType::MPU9250; @@ -398,9 +443,9 @@ void MPU9250Sensor::startCalibration(int calibrationType) { configuration.save(); ledManager.off(); - m_Logger.debug("Saved the calibration data"); + m_Logger.debug(Logs::SavedCalibration, "Saved the calibration data"); - m_Logger.info("Calibration data gathered"); + m_Logger.info(Logs::SavedCalibration, "Calibration data gathered"); // fifo will certainly have overflown due to magnetometer calibration, reset it. imu.resetFIFO(); } diff --git a/src/sensors/sensor.cpp b/src/sensors/sensor.cpp index a018b5c91..013ea9bb2 100644 --- a/src/sensors/sensor.cpp +++ b/src/sensors/sensor.cpp @@ -62,7 +62,11 @@ void Sensor::sendData() { ); #ifdef DEBUG_SENSOR - m_Logger.trace("Quaternion: %f, %f, %f, %f", UNPACK_QUATERNION(fusedRotation)); + m_Logger.trace( + Logs::DebugQuat, + "Quaternion: %f, %f, %f, %f", + UNPACK_QUATERNION(fusedRotation) + ); #endif #if SEND_ACCELERATION @@ -76,6 +80,7 @@ void Sensor::sendData() { void Sensor::printTemperatureCalibrationUnsupported() { m_Logger.error( + Logs::TempCalNotSupported, "Temperature calibration not supported for IMU %s", getIMUNameByType(sensorType) ); @@ -151,7 +156,7 @@ const char* getIMUNameByType(SensorTypeID imuType) { void Sensor::markRestCalibrationComplete(bool completed) { if (restCalibrationComplete != completed) { - m_Logger.info("Rest calibration completed"); + m_Logger.info(Logs::RestCalCompleted, "Rest calibration completed"); } restCalibrationComplete = completed; } diff --git a/src/sensors/sensor.h b/src/sensors/sensor.h index 72102d2ef..4f6b6d9bc 100644 --- a/src/sensors/sensor.h +++ b/src/sensors/sensor.h @@ -65,7 +65,7 @@ class Sensor { , sensorId(id) , sensorType(type) , sensorOffset({Quat(Vector3(0, 0, 1), rotation)}) - , m_Logger(SlimeVR::Logging::Logger(sensorName)) { + , m_Logger(sensorName, "sensor") { char buf[4]; sprintf(buf, "%u", id); m_Logger.setTag(buf); @@ -137,7 +137,36 @@ class Sensor { void markRestCalibrationComplete(bool completed = true); - mutable SlimeVR::Logging::Logger m_Logger; +public: + enum class Logs { + DebugQuat = 0, + TempCalNotSupported = 1, + RestCalCompleted = 2, + SensorNotDetected = 3, + SecondsRemaining = 4, + SensorTimeout = 5, + NoCalibrationData = 6, + IncompatibleCalibrationData = 7, + FailedToInitialize = 8, + CalibrationInstructions = 9, + TempCalReset = 10, + CRTFailed = 11, + CRTFinished = 12, + SensorInitialized = 13, + FifoOverrun = 14, + DebugStatus = 15, + SensorInitialization = 16, + SavingCalibration = 17, + CalibrationState = 18, + SensorDetected = 19, + CustomSensitivityOffsetEnabled = 20, + TempCalState = 21, + SavedCalibration = 22, + SensorError = 23, + }; + +protected: + mutable SlimeVR::Logging::Logger m_Logger; private: void printTemperatureCalibrationUnsupported(); diff --git a/src/sensors/softfusion/CalibrationBase.h b/src/sensors/softfusion/CalibrationBase.h index bef0d9c59..c47f1aecf 100644 --- a/src/sensors/softfusion/CalibrationBase.h +++ b/src/sensors/softfusion/CalibrationBase.h @@ -40,7 +40,6 @@ class CalibrationBase { SlimeVR::Sensors::SensorFusionRestDetect& fusion, IMU& sensor, uint8_t sensorId, - SlimeVR::Logging::Logger& logger, float TempTs, float AScale, float GScale, @@ -49,7 +48,6 @@ class CalibrationBase { : fusion{fusion} , sensor{sensor} , sensorId{sensorId} - , logger{logger} , TempTs{TempTs} , AScale{AScale} , GScale{GScale} @@ -115,7 +113,6 @@ class CalibrationBase { Sensors::SensorFusionRestDetect& fusion; IMU& sensor; uint8_t sensorId; - SlimeVR::Logging::Logger& logger; float TempTs; float AScale; float GScale; diff --git a/src/sensors/softfusion/SoftfusionCalibration.h b/src/sensors/softfusion/SoftfusionCalibration.h index b054020bb..806bc7e92 100644 --- a/src/sensors/softfusion/SoftfusionCalibration.h +++ b/src/sensors/softfusion/SoftfusionCalibration.h @@ -47,13 +47,12 @@ class SoftfusionCalibrator : public CalibrationBase Sensors::SensorFusionRestDetect& fusion, IMU& sensor, uint8_t sensorId, - SlimeVR::Logging::Logger& logger, float TempTs, float AScale, float GScale, SensorToggleState& toggles ) - : Base{fusion, sensor, sensorId, logger, TempTs, AScale, GScale, toggles} { + : Base{fusion, sensor, sensorId, TempTs, AScale, GScale, toggles} { calibration.T_Ts = TempTs; } @@ -87,7 +86,10 @@ class SoftfusionCalibrator : public CalibrationBase sensor.motionlessCalibration(calibData); std::memcpy(calibration.MotionlessData, &calibData, sizeof(calibData)); } else { - logger.info("Sensor doesn't provide any custom motionless calibration"); + logger.info( + Logs::MotionlessNotSupported, + "Sensor doesn't provide any custom motionless calibration" + ); } } @@ -177,7 +179,7 @@ class SoftfusionCalibrator : public CalibrationBase static constexpr auto AccelCalibRestSeconds = 3; void saveCalibration() { - logger.debug("Saving the calibration data"); + logger.debug(Logs::SavingCalibData, "Saving the calibration data"); SlimeVR::Configuration::SensorConfig calibration{}; calibration.type = SlimeVR::Configuration::SensorConfigType::SFUSION; calibration.data.sfusion = this->calibration; @@ -192,6 +194,7 @@ class SoftfusionCalibrator : public CalibrationBase // Wait for sensor to calm down before calibration logger.info( + Logs::CalibrationInstruction, "Put down the device and wait for baseline gyro reading calibration (%d " "seconds)", GyroCalibDelaySeconds @@ -202,11 +205,15 @@ class SoftfusionCalibrator : public CalibrationBase calibration.temperature = std::get<2>(lastSamples) / IMU::TemperatureSensitivity + IMU::TemperatureBias; - logger.trace("Calibration temperature: %f", calibration.temperature); + logger.trace( + Logs::CalibrationInstruction, + "Calibration temperature: %f", + calibration.temperature + ); ledManager.pattern(100, 100, 3); ledManager.on(); - logger.info("Gyro calibration started..."); + logger.info(Logs::CalibrationInstruction, "Gyro calibration started..."); int32_t sumXYZ[3] = {0}; const auto targetCalib = millis() + 1000 * GyroCalibSeconds; @@ -238,6 +245,7 @@ class SoftfusionCalibrator : public CalibrationBase = static_cast(sumXYZ[2]) / static_cast(sampleCount); logger.info( + Logs::CalibrationInstruction, "Gyro offset after %d samples: %f %f %f", sampleCount, UNPACK_VECTOR_ARRAY(calibration.G_off) @@ -251,6 +259,7 @@ class SoftfusionCalibrator : public CalibrationBase auto magneto = std::make_unique(); logger.info( + Logs::CalibrationInstruction, "Put the device into 6 unique orientations (all sides), leave it still and " "do not hold/touch for %d seconds each", AccelCalibRestSeconds @@ -280,8 +289,9 @@ class SoftfusionCalibrator : public CalibrationBase accelCalibrationChunk.resize(numSamplesPerPosition * 3); ledManager.pattern(100, 100, 6); ledManager.on(); - logger.info("Gathering accelerometer data..."); + logger.info(Logs::CalibrationInstruction, "Gathering accelerometer data..."); logger.info( + Logs::CalibrationInstruction, "Waiting for position %i, you can leave the device as is...", numPositionsRecorded + 1 ); @@ -332,6 +342,7 @@ class SoftfusionCalibrator : public CalibrationBase ledManager.pattern(50, 50, 2); ledManager.on(); logger.info( + Logs::CalibrationInstruction, "Recorded, waiting for position %i...", numPositionsRecorded + 1 ); @@ -351,21 +362,28 @@ class SoftfusionCalibrator : public CalibrationBase ); } ledManager.off(); - logger.debug("Calculating accelerometer calibration data..."); + logger.debug( + Logs::CalibrationInstruction, + "Calculating accelerometer calibration data..." + ); accelCalibrationChunk.resize(0); float A_BAinv[4][3]; magneto->current_calibration(A_BAinv); - logger.debug("Finished calculating accelerometer calibration"); - logger.debug("Accelerometer calibration matrix:"); - logger.debug("{"); + logger.debug( + Logs::CalibrationInstruction, + "Finished calculating accelerometer calibration" + ); + logger.debug(Logs::CalibrationInstruction, "Accelerometer calibration matrix:"); + logger.debug(Logs::CalibrationInstruction, "{"); for (int i = 0; i < 3; i++) { calibration.A_B[i] = A_BAinv[0][i]; calibration.A_Ainv[0][i] = A_BAinv[1][i]; calibration.A_Ainv[1][i] = A_BAinv[2][i]; calibration.A_Ainv[2][i] = A_BAinv[3][i]; logger.debug( + Logs::CalibrationInstruction, " %f, %f, %f, %f", A_BAinv[0][i], A_BAinv[1][i], @@ -373,11 +391,12 @@ class SoftfusionCalibrator : public CalibrationBase A_BAinv[3][i] ); } - logger.debug("}"); + logger.debug(Logs::CalibrationInstruction, "}"); } void calibrateSampleRate(const Base::EatSamplesFn& eatSamplesForSeconds) { logger.debug( + Logs::CalibrationInstruction, "Calibrating IMU sample rate in %d second(s)...", SampleRateCalibDelaySeconds ); @@ -389,7 +408,7 @@ class SoftfusionCalibrator : public CalibrationBase uint32_t tempSamples = 0; const auto calibTarget = millis() + 1000 * SampleRateCalibSeconds; - logger.debug("Counting samples now..."); + logger.debug(Logs::CalibrationInstruction, "Counting samples now..."); uint32_t currentTime; while ((currentTime = millis()) < calibTarget) { sensor.bulkRead( @@ -410,6 +429,7 @@ class SoftfusionCalibrator : public CalibrationBase currentTime - (calibTarget - 1000 * SampleRateCalibSeconds) ); logger.debug( + Logs::CalibrationInstruction, "Collected %d gyro, %d acc samples during %d ms", gyroSamples, accelSamples, @@ -423,6 +443,7 @@ class SoftfusionCalibrator : public CalibrationBase = millisFromStart / (static_cast(tempSamples) * 1000.0f); logger.debug( + Logs::CalibrationInstruction, "Gyro frequency %fHz, accel frequency: %fHz, temperature frequency: %fHz", 1.0 / calibration.G_Ts, 1.0 / calibration.A_Ts, @@ -452,10 +473,16 @@ class SoftfusionCalibrator : public CalibrationBase .T_Ts = 0, }; + enum class Logs { + MotionlessNotSupported = 0, + SavingCalibData = 1, + CalibrationInstruction = 2, + }; + Logging::Logger logger{"SoftfusionCalibration", "softfusioncalib"}; + private: using Base::AScale; using Base::GScale; - using Base::logger; using Base::sensor; using Base::sensorId; using Base::toggles; diff --git a/src/sensors/softfusion/drivers/bmi270.h b/src/sensors/softfusion/drivers/bmi270.h index be2b7805b..b1efe2c1a 100644 --- a/src/sensors/softfusion/drivers/bmi270.h +++ b/src/sensors/softfusion/drivers/bmi270.h @@ -31,6 +31,7 @@ #include "../../../sensorinterface/RegisterInterface.h" #include "bmi270fw.h" +#include "sensors/sensor.h" #include "vqf.h" namespace SlimeVR::Sensors::SoftFusion::Drivers { @@ -69,9 +70,12 @@ struct BMI270 { }; RegisterInterface& m_RegisterInterface; - SlimeVR::Logging::Logger& m_Logger; + SlimeVR::Logging::Logger& m_Logger; int8_t m_zxFactor; - BMI270(RegisterInterface& registerInterface, SlimeVR::Logging::Logger& logger) + BMI270( + RegisterInterface& registerInterface, + SlimeVR::Logging::Logger& logger + ) : m_RegisterInterface(registerInterface) , m_Logger(logger) , m_zxFactor(0) {} @@ -358,7 +362,10 @@ struct BMI270 { while (m_RegisterInterface.readReg(Regs::GyrCrtConf::reg) == Regs::GyrCrtConf::valueRunning) { - m_Logger.info("CRT running. Do not move tracker!"); + m_Logger.info( + Sensor::Logs::CalibrationInstructions, + "CRT running. Do not move tracker!" + ); delay(200); } @@ -377,11 +384,15 @@ struct BMI270 { if (status != 0) { m_Logger.error( + Sensor::Logs::CRTFailed, "CRT failed with status 0x%x. Recalibrate again to enable CRT.", status ); if (status == 0x03) { - m_Logger.error("Reason: tracker was moved during CRT!"); + m_Logger.error( + Sensor::Logs::CRTFailed, + "Reason: tracker was moved during CRT!" + ); } success = false; @@ -390,6 +401,7 @@ struct BMI270 { m_RegisterInterface .readBytes(Regs::GyrUserGain, crt_values.size(), crt_values.data()); m_Logger.debug( + Sensor::Logs::CRTFinished, "CRT finished successfully, result 0x%x, 0x%x, 0x%x", crt_values[0], crt_values[1], diff --git a/src/sensors/softfusion/drivers/icm42688.h b/src/sensors/softfusion/drivers/icm42688.h index a228ab60d..6d58f865b 100644 --- a/src/sensors/softfusion/drivers/icm42688.h +++ b/src/sensors/softfusion/drivers/icm42688.h @@ -27,6 +27,7 @@ #include #include +#include "sensors/sensor.h" #include "vqf.h" namespace SlimeVR::Sensors::SoftFusion::Drivers { @@ -66,10 +67,11 @@ struct ICM42688 { }; RegisterInterface& m_RegisterInterface; - SlimeVR::Logging::Logger& m_Logger; - ICM42688(RegisterInterface& registerInterface, SlimeVR::Logging::Logger& logger) - : m_RegisterInterface(registerInterface) - , m_Logger(logger) {} + ICM42688( + RegisterInterface& registerInterface, + SlimeVR::Logging::Logger& logger + ) + : m_RegisterInterface(registerInterface) {} struct Regs { struct WhoAmI { diff --git a/src/sensors/softfusion/drivers/icm45605.h b/src/sensors/softfusion/drivers/icm45605.h index 2b7f0d064..2c4f66231 100644 --- a/src/sensors/softfusion/drivers/icm45605.h +++ b/src/sensors/softfusion/drivers/icm45605.h @@ -24,6 +24,7 @@ #pragma once #include "icm45base.h" +#include "sensors/sensor.h" #include "vqf.h" namespace SlimeVR::Sensors::SoftFusion::Drivers { @@ -47,8 +48,8 @@ struct ICM45605 : public ICM45Base { .restThAcc = 0.0098f, }; - ICM45605(RegisterInterface& registerInterface, SlimeVR::Logging::Logger& logger) - : ICM45Base{registerInterface, logger} {} + explicit ICM45605(RegisterInterface& registerInterface, Logging::Logger&) + : ICM45Base{registerInterface} {} struct Regs { struct WhoAmI { diff --git a/src/sensors/softfusion/drivers/icm45686.h b/src/sensors/softfusion/drivers/icm45686.h index 9b93500ca..84f25824c 100644 --- a/src/sensors/softfusion/drivers/icm45686.h +++ b/src/sensors/softfusion/drivers/icm45686.h @@ -24,6 +24,7 @@ #pragma once #include "icm45base.h" +#include "sensors/sensor.h" #include "vqf.h" namespace SlimeVR::Sensors::SoftFusion::Drivers { @@ -47,8 +48,8 @@ struct ICM45686 : public ICM45Base { .restThAcc = 0.196f, }; - ICM45686(RegisterInterface& registerInterface, SlimeVR::Logging::Logger& logger) - : ICM45Base{registerInterface, logger} {} + explicit ICM45686(RegisterInterface& registerInterface, Logging::Logger&) + : ICM45Base{registerInterface} {} struct Regs { struct WhoAmI { diff --git a/src/sensors/softfusion/drivers/icm45base.h b/src/sensors/softfusion/drivers/icm45base.h index 57e6dede2..f03f07c4f 100644 --- a/src/sensors/softfusion/drivers/icm45base.h +++ b/src/sensors/softfusion/drivers/icm45base.h @@ -55,10 +55,8 @@ struct ICM45Base { static constexpr bool Uses32BitSensorData = true; RegisterInterface& m_RegisterInterface; - SlimeVR::Logging::Logger& m_Logger; - ICM45Base(RegisterInterface& registerInterface, SlimeVR::Logging::Logger& logger) - : m_RegisterInterface(registerInterface) - , m_Logger(logger) {} + explicit ICM45Base(RegisterInterface& registerInterface) + : m_RegisterInterface(registerInterface) {} struct BaseRegs { static constexpr uint8_t TempData = 0x0c; diff --git a/src/sensors/softfusion/drivers/lsm6ds-common.h b/src/sensors/softfusion/drivers/lsm6ds-common.h index 12c2fcfa2..75fff66a8 100644 --- a/src/sensors/softfusion/drivers/lsm6ds-common.h +++ b/src/sensors/softfusion/drivers/lsm6ds-common.h @@ -28,19 +28,20 @@ #include #include "../../../sensorinterface/RegisterInterface.h" +#include "sensors/sensor.h" namespace SlimeVR::Sensors::SoftFusion::Drivers { struct LSM6DSOutputHandler { LSM6DSOutputHandler( RegisterInterface& registerInterface, - SlimeVR::Logging::Logger& logger + SlimeVR::Logging::Logger& logger ) : m_RegisterInterface(registerInterface) , m_Logger(logger) {} RegisterInterface& m_RegisterInterface; - SlimeVR::Logging::Logger& m_Logger; + SlimeVR::Logging::Logger& m_Logger; #pragma pack(push, 1) struct FifoEntryAligned { @@ -71,6 +72,7 @@ struct LSM6DSOutputHandler { if (fifo_status & FIFO_OVERRUN_LATCHED_MASK) { // FIFO overrun is expected to happen during startup and calibration m_Logger.error( + Sensor::Logs::FifoOverrun, "FIFO OVERRUN! This occuring during normal usage is an issue." ); } diff --git a/src/sensors/softfusion/drivers/lsm6ds3trc.h b/src/sensors/softfusion/drivers/lsm6ds3trc.h index 48a654d2b..b608be4e0 100644 --- a/src/sensors/softfusion/drivers/lsm6ds3trc.h +++ b/src/sensors/softfusion/drivers/lsm6ds3trc.h @@ -28,6 +28,7 @@ #include #include "../../../sensorinterface/RegisterInterface.h" +#include "sensors/sensor.h" #include "vqf.h" namespace SlimeVR::Sensors::SoftFusion::Drivers { @@ -65,8 +66,11 @@ struct LSM6DS3TRC { }; RegisterInterface& m_RegisterInterface; - SlimeVR::Logging::Logger m_Logger; - LSM6DS3TRC(RegisterInterface& registerInterface, SlimeVR::Logging::Logger& logger) + SlimeVR::Logging::Logger m_Logger; + LSM6DS3TRC( + RegisterInterface& registerInterface, + SlimeVR::Logging::Logger& logger + ) : m_RegisterInterface(registerInterface) , m_Logger(logger) {} @@ -131,7 +135,7 @@ struct LSM6DS3TRC { const auto read_result = m_RegisterInterface.readReg16(Regs::FifoStatus); if (read_result & 0x4000) { // overrun! // disable and re-enable fifo to clear it - m_Logger.debug("Fifo overrun, resetting..."); + m_Logger.debug(Sensor::Logs::FifoOverrun, "Fifo overrun, resetting..."); m_RegisterInterface.writeReg(Regs::FifoCtrl5::reg, 0); m_RegisterInterface.writeReg(Regs::FifoCtrl5::reg, Regs::FifoCtrl5::value); return; diff --git a/src/sensors/softfusion/drivers/lsm6dso.h b/src/sensors/softfusion/drivers/lsm6dso.h index 8bab8b60c..f08e7e938 100644 --- a/src/sensors/softfusion/drivers/lsm6dso.h +++ b/src/sensors/softfusion/drivers/lsm6dso.h @@ -101,7 +101,10 @@ struct LSM6DSO : LSM6DSOutputHandler { static constexpr uint8_t FifoData = 0x78; }; - LSM6DSO(RegisterInterface& registerInterface, SlimeVR::Logging::Logger& logger) + LSM6DSO( + RegisterInterface& registerInterface, + SlimeVR::Logging::Logger& logger + ) : LSM6DSOutputHandler(registerInterface, logger) {} bool initialize() { diff --git a/src/sensors/softfusion/drivers/lsm6dsr.h b/src/sensors/softfusion/drivers/lsm6dsr.h index e1ec127d4..ad3fe2020 100644 --- a/src/sensors/softfusion/drivers/lsm6dsr.h +++ b/src/sensors/softfusion/drivers/lsm6dsr.h @@ -100,7 +100,10 @@ struct LSM6DSR : LSM6DSOutputHandler { static constexpr uint8_t FifoData = 0x78; }; - LSM6DSR(RegisterInterface& registerInterface, SlimeVR::Logging::Logger& logger) + LSM6DSR( + RegisterInterface& registerInterface, + SlimeVR::Logging::Logger& logger + ) : LSM6DSOutputHandler(registerInterface, logger) {} bool initialize() { diff --git a/src/sensors/softfusion/drivers/lsm6dsv.h b/src/sensors/softfusion/drivers/lsm6dsv.h index c715d12ff..d5ad247f9 100644 --- a/src/sensors/softfusion/drivers/lsm6dsv.h +++ b/src/sensors/softfusion/drivers/lsm6dsv.h @@ -113,7 +113,10 @@ struct LSM6DSV : LSM6DSOutputHandler { static constexpr uint8_t FifoData = 0x78; }; - LSM6DSV(RegisterInterface& registerInterface, SlimeVR::Logging::Logger& logger) + LSM6DSV( + RegisterInterface& registerInterface, + SlimeVR::Logging::Logger& logger + ) : LSM6DSOutputHandler(registerInterface, logger) {} bool initialize() { diff --git a/src/sensors/softfusion/drivers/mpu6050.h b/src/sensors/softfusion/drivers/mpu6050.h index d422804a9..36c3b3ab1 100644 --- a/src/sensors/softfusion/drivers/mpu6050.h +++ b/src/sensors/softfusion/drivers/mpu6050.h @@ -30,6 +30,7 @@ #include #include "../../../sensorinterface/RegisterInterface.h" +#include "sensors/sensor.h" #include "vqf.h" namespace SlimeVR::Sensors::SoftFusion::Drivers { @@ -78,8 +79,8 @@ struct MPU6050 { }; RegisterInterface& m_RegisterInterface; - SlimeVR::Logging::Logger& m_Logger; - MPU6050(RegisterInterface& i2c, SlimeVR::Logging::Logger& logger) + SlimeVR::Logging::Logger& m_Logger; + MPU6050(RegisterInterface& i2c, SlimeVR::Logging::Logger& logger) : m_RegisterInterface(i2c) , m_Logger(logger) {} @@ -192,7 +193,7 @@ struct MPU6050 { if (status & (1 << MPU6050_INTERRUPT_FIFO_OFLOW_BIT)) { // Overflows make it so we lose track of which packet is which // This necessitates a reset - m_Logger.debug("Fifo overrun, resetting..."); + m_Logger.debug(Sensor::Logs::FifoOverrun, "Fifo overrun, resetting..."); resetFIFO(); return; } diff --git a/src/sensors/softfusion/runtimecalibration/RuntimeCalibration.h b/src/sensors/softfusion/runtimecalibration/RuntimeCalibration.h index e891da85e..8166e44e3 100644 --- a/src/sensors/softfusion/runtimecalibration/RuntimeCalibration.h +++ b/src/sensors/softfusion/runtimecalibration/RuntimeCalibration.h @@ -53,13 +53,12 @@ class RuntimeCalibrator : public Sensor::CalibrationBase sampleRateCalibrationStep{calibration}; MotionlessCalibrationStep motionlessCalibrationStep{ calibration, - sensor - }; + sensor}; GyroBiasCalibrationStep gyroBiasCalibrationStep{calibration}; AccelBiasCalibrationStep accelBiasCalibrationStep{ calibration, - static_cast(Base::AScale) - }; + static_cast(Base::AScale)}; NullCalibrationStep nullCalibrationStep{calibration}; CalibrationStep* currentStep = &nullCalibrationStep; @@ -440,10 +442,15 @@ class RuntimeCalibrator : public Sensor::CalibrationBase logger{"RuntimeCalibration", "runtimecalib"}; + using Base::AScale; using Base::fusion; using Base::GScale; - using Base::logger; using Base::sensor; using Base::sensorId; using Base::toggles; diff --git a/src/sensors/softfusion/softfusionsensor.h b/src/sensors/softfusion/softfusionsensor.h index 87b3e40de..99276a3da 100644 --- a/src/sensors/softfusion/softfusionsensor.h +++ b/src/sensors/softfusion/softfusionsensor.h @@ -78,6 +78,7 @@ class SoftFusionSensor : public Sensor { = m_sensor.m_RegisterInterface.readReg(SensorType::Regs::WhoAmI::reg); if (SensorType::Regs::WhoAmI::value != value) { m_Logger.error( + Logs::SensorNotDetected, "Sensor not detected, expected reg 0x%02x = 0x%02x but got 0x%02x", SensorType::Regs::WhoAmI::reg, SensorType::Regs::WhoAmI::value, @@ -164,7 +165,11 @@ class SoftFusionSensor : public Sensor { #endif auto currentSecondsRemaining = (targetDelay - millis()) / 1000; if (currentSecondsRemaining != lastSecondsRemaining) { - m_Logger.info("%ld...", currentSecondsRemaining + 1); + m_Logger.info( + Logs::SecondsRemaining, + "%ld...", + currentSecondsRemaining + 1 + ); lastSecondsRemaining = currentSecondsRemaining; } m_sensor.bulkRead( @@ -242,6 +247,7 @@ class SoftFusionSensor : public Sensor { working = false; m_status = SensorStatus::SENSOR_ERROR; m_Logger.error( + Logs::SensorTimeout, "Sensor timeout I2C Address 0x%02x delaytime: %d ms", addr, now - m_lastRotationUpdateMillis @@ -341,16 +347,18 @@ class SoftFusionSensor : public Sensor { calibrator.assignCalibration(sensorCalibration); } else if (sensorCalibration.type == SlimeVR::Configuration::SensorConfigType::NONE) { m_Logger.warn( + Logs::NoCalibrationData, "No calibration data found for sensor %d, ignoring...", sensorId ); - m_Logger.info("Calibration is advised"); + m_Logger.info(Logs::NoCalibrationData, "Calibration is advised"); } else { m_Logger.warn( + Logs::IncompatibleCalibrationData, "Incompatible calibration data found for sensor %d, ignoring...", sensorId ); - m_Logger.info("Please recalibrate"); + m_Logger.info(Logs::IncompatibleCalibrationData, "Please recalibrate"); } calibrator.begin(); @@ -370,7 +378,7 @@ class SoftFusionSensor : public Sensor { } if (!initResult) { - m_Logger.error("Sensor failed to initialize!"); + m_Logger.error(Logs::FailedToInitialize, "Sensor failed to initialize!"); m_status = SensorStatus::SENSOR_ERROR; return; } @@ -383,21 +391,31 @@ class SoftFusionSensor : public Sensor { AScale * static_cast(std::get<0>(lastRawSample)[2]) ); m_Logger.info( + Logs::CalibrationInstructions, "Gravity read: %.1f (need < -7.5 to start calibration)", gravity ); if (gravity < -7.5f) { ledManager.on(); - m_Logger.info("Flip front in 5 seconds to start calibration"); + m_Logger.info( + Logs::CalibrationInstructions, + "Flip front in 5 seconds to start calibration" + ); lastRawSample = eatSamplesReturnLast(5000); gravity = static_cast( AScale * static_cast(std::get<0>(lastRawSample)[2]) ); if (gravity > 7.5f) { - m_Logger.debug("Starting calibration..."); + m_Logger.debug( + Logs::CalibrationInstructions, + "Starting calibration..." + ); startCalibration(0); } else { - m_Logger.info("Flip not detected. Skipping calibration."); + m_Logger.info( + Logs::CalibrationInstructions, + "Flip not detected. Skipping calibration." + ); } ledManager.off(); @@ -426,12 +444,10 @@ class SoftFusionSensor : public Sensor { m_fusion, m_sensor, sensorId, - m_Logger, getDefaultTempTs(), AScale, GScale, - toggles - }; + toggles}; SensorStatus m_status = SensorStatus::SENSOR_OFFLINE; uint32_t m_lastPollTime = micros(); diff --git a/src/serial/serialcommands.cpp b/src/serial/serialcommands.cpp index 25caf6d5c..a240f3f39 100644 --- a/src/serial/serialcommands.cpp +++ b/src/serial/serialcommands.cpp @@ -36,7 +36,31 @@ #endif namespace SerialCommands { -SlimeVR::Logging::Logger logger("SerialCommands"); + +enum class CommandsLogs { + ParamTooLong = 1, + TooFewArguments = 2, + Usage = 3, + NewCredentialsSet = 4, + UnrecognizedVariable = 5, + PrintState = 6, + SensorInfo = 7, + BatteryReading = 8, + GitCommit = 9, + NoData = 10, + HadData = 11, + ScanningStarted = 12, + FoundNetworks = 13, + NetworkInfo = 14, + ScanFailed = 15, + Reboot = 16, + FactoryReset = 17, + FactoryResetNotSupported = 18, + FactoryResetHardcodedWarning = 19, + EraseCalibration = 20, +}; + +SlimeVR::Logging::Logger logger("SerialCommands", "commands"); CmdCallback<6> cmdCallbacks; CmdParser cmdParser; @@ -51,6 +75,7 @@ bool lengthCheck( size_t l = text != nullptr ? strlen(text) : 0; if ((l > length)) { logger.error( + CommandsLogs::ParamTooLong, "%s ERROR: %s is longer than %d bytes / Characters", cmd, name, @@ -74,8 +99,14 @@ void cmdSet(CmdParser* parser) { if (parser->getParamCount() != 1) { if (parser->equalCmdParam(1, "WIFI")) { if (parser->getParamCount() < 3) { - logger.error("CMD SET WIFI ERROR: Too few arguments"); - logger.info("Syntax: SET WIFI \"\" \"\""); + logger.error( + CommandsLogs::TooFewArguments, + "CMD SET WIFI ERROR: Too few arguments" + ); + logger.info( + CommandsLogs::Usage, + "Syntax: SET WIFI \"\" \"\"" + ); } else { const char* sc_ssid = parser->getCmdParam(2); const char* sc_pw = parser->getCmdParam(3); @@ -86,12 +117,21 @@ void cmdSet(CmdParser* parser) { } WiFiNetwork::setWiFiCredentials(sc_ssid, sc_pw); - logger.info("CMD SET WIFI OK: New wifi credentials set, reconnecting"); + logger.info( + CommandsLogs::NewCredentialsSet, + "CMD SET WIFI OK: New wifi credentials set, reconnecting" + ); } } else if (parser->equalCmdParam(1, "BWIFI")) { if (parser->getParamCount() < 3) { - logger.error("CMD SET BWIFI ERROR: Too few arguments"); - logger.info("Syntax: SET BWIFI "); + logger.error( + CommandsLogs::TooFewArguments, + "CMD SET BWIFI ERROR: Too few arguments" + ); + logger.info( + CommandsLogs::Usage, + "Syntax: SET BWIFI " + ); } else { const char* b64ssid = parser->getCmdParam(2); const char* b64pass = parser->getCmdParam(3); @@ -132,18 +172,28 @@ void cmdSet(CmdParser* parser) { ppass = NULL; } WiFiNetwork::setWiFiCredentials(ssid, ppass); - logger.info("CMD SET BWIFI OK: New wifi credentials set, reconnecting"); + logger.info( + CommandsLogs::NewCredentialsSet, + "CMD SET BWIFI OK: New wifi credentials set, reconnecting" + ); } } else { - logger.error("CMD SET ERROR: Unrecognized variable to set"); + logger.error( + CommandsLogs::UnrecognizedVariable, + "CMD SET ERROR: Unrecognized variable to set" + ); } } else { - logger.error("CMD SET ERROR: No variable to set"); + logger.error( + CommandsLogs::TooFewArguments, + "CMD SET ERROR: No variable to set" + ); } } void printState() { logger.info( + CommandsLogs::PrintState, "SlimeVR Tracker, board: %d, hardware: %d, protocol: %d, firmware: %s, " "address: %s, mac: %s, status: %d, wifi state: %d", BOARD, @@ -157,6 +207,7 @@ void printState() { ); for (auto& sensor : sensorManager.getSensors()) { logger.info( + CommandsLogs::SensorInfo, "Sensor[%d]: %s (%.3f %.3f %.3f %.3f) is working: %s, had data: %s", sensor->getSensorId(), getIMUNameByType(sensor->getSensorType()), @@ -166,6 +217,7 @@ void printState() { ); } logger.info( + CommandsLogs::BatteryReading, "Battery voltage: %.3f, level: %.1f%%", battery.getVoltage(), battery.getLevel() * 100 @@ -223,7 +275,7 @@ void cmdGet(CmdParser* parser) { printState(); // We don't want to print this on every timed state output - logger.info("Git commit: %s", GIT_REV); + logger.info(CommandsLogs::GitCommit, "Git commit: %s", GIT_REV); } if (parser->equalCmdParam(1, "CONFIG")) { @@ -268,6 +320,7 @@ void cmdGet(CmdParser* parser) { if (parser->equalCmdParam(1, "TEST")) { logger.info( + CommandsLogs::PrintState, "[TEST] Board: %d, hardware: %d, protocol: %d, firmware: %s, address: %s, " "mac: %s, status: %d, wifi state: %d", BOARD, @@ -282,6 +335,7 @@ void cmdGet(CmdParser* parser) { auto& sensor0 = sensorManager.getSensors()[0]; sensor0->motionLoop(); logger.info( + CommandsLogs::SensorInfo, "[TEST] Sensor[0]: %s (%.3f %.3f %.3f %.3f) is working: %s, had data: %s", getIMUNameByType(sensor0->getSensorType()), UNPACK_QUATERNION(sensor0->getFusedRotation()), @@ -289,14 +343,23 @@ void cmdGet(CmdParser* parser) { sensor0->getHadData() ? "true" : "false" ); if (!sensor0->getHadData()) { - logger.error("[TEST] Sensor[0] didn't send any data yet!"); + logger.error( + CommandsLogs::NoData, + "[TEST] Sensor[0] didn't send any data yet!" + ); } else { - logger.info("[TEST] Sensor[0] sent some data, looks working."); + logger.info( + CommandsLogs::HadData, + "[TEST] Sensor[0] sent some data, looks working." + ); } } if (parser->equalCmdParam(1, "WIFISCAN")) { - logger.info("[WSCAN] Scanning for WiFi networks..."); + logger.info( + CommandsLogs::ScanningStarted, + "[WSCAN] Scanning for WiFi networks..." + ); // Scan would fail if connecting, stop connecting before scan if (WiFi.status() != WL_CONNECTED) { @@ -310,9 +373,14 @@ void cmdGet(CmdParser* parser) { int scanRes = WiFi.scanComplete(); if (scanRes >= 0) { - logger.info("[WSCAN] Found %d networks:", scanRes); + logger.info( + CommandsLogs::FoundNetworks, + "[WSCAN] Found %d networks:", + scanRes + ); for (int i = 0; i < scanRes; i++) { logger.info( + CommandsLogs::NetworkInfo, "[WSCAN] %d:\t%02d\t'%s'\t(%d dBm)\t%s", i, WiFi.SSID(i).length(), @@ -323,7 +391,7 @@ void cmdGet(CmdParser* parser) { } WiFi.scanDelete(); } else { - logger.info("[WSCAN] Scan failed!"); + logger.info(CommandsLogs::ScanFailed, "[WSCAN] Scan failed!"); } // Restore conencting state @@ -334,12 +402,12 @@ void cmdGet(CmdParser* parser) { } void cmdReboot(CmdParser* parser) { - logger.info("REBOOT"); + logger.info(CommandsLogs::Reboot, "REBOOT"); ESP.restart(); } void cmdFactoryReset(CmdParser* parser) { - logger.info("FACTORY RESET"); + logger.info(CommandsLogs::FactoryReset, "FACTORY RESET"); configuration.reset(); @@ -350,13 +418,16 @@ void cmdFactoryReset(CmdParser* parser) { nvs_flash_erase(); #else #warning SERIAL COMMAND FACTORY RESET NOT SUPPORTED - logger.info("FACTORY RESET NOT SUPPORTED"); + logger.info(CommandsLogs::FactoryResetNotSupported, "FACTORY RESET NOT SUPPORTED"); return; #endif #if defined(WIFI_CREDS_SSID) && defined(WIFI_CREDS_PASSWD) #warning FACTORY RESET does not clear your hardcoded WiFi credentials! - logger.warn("FACTORY RESET does not clear your hardcoded WiFi credentials!"); + logger.warn( + CommandsLogs::FactoryResetHardcodedWarning, + "FACTORY RESET does not clear your hardcoded WiFi credentials!" + ); #endif delay(3000); @@ -387,27 +458,20 @@ void cmdTemperatureCalibration(CmdParser* parser) { return; } } - logger.info("Usage:"); - logger.info(" TCAL PRINT: print current temperature calibration config"); - logger.info( - " TCAL DEBUG: print debug values for the current temperature calibration " - "profile" - ); - logger.info( - " TCAL RESET: reset current temperature calibration in RAM (does not delete " - "already saved)" - ); - logger.info(" TCAL SAVE: save current temperature calibration to persistent flash" - ); - logger.info("Note:"); logger.info( - " Temperature calibration config saves automatically when calibration percent " - "is at 100%%" + CommandsLogs::Usage, + R"(Usage: + TCAL PRINT: print current temperature calibration config + TCAL DEBUG: print debug values for the current temperature calibration profile + TCAL RESET: reset current temperature calibration in RAM (does not delete already saved + TCAL SAVE: save current temperature calibration to persistent flash +Note: + Temperature calibration config saves automatically when calibration percent is at 100%%)" ); } void cmdDeleteCalibration(CmdParser* parser) { - logger.info("ERASE CALIBRATION"); + logger.info(CommandsLogs::EraseCalibration, "ERASE CALIBRATION"); configuration.eraseSensors(); } diff --git a/src/status/StatusManager.cpp b/src/status/StatusManager.cpp index 4d8919d0b..43063514b 100644 --- a/src/status/StatusManager.cpp +++ b/src/status/StatusManager.cpp @@ -8,7 +8,7 @@ void StatusManager::setStatus(Status status, bool value) { return; } - m_Logger.trace("Added status %s", statusToString(status)); + m_Logger.trace(Logs::AddedStatus, "Added status %s", statusToString(status)); m_Status |= status; } else { @@ -16,7 +16,8 @@ void StatusManager::setStatus(Status status, bool value) { return; } - m_Logger.trace("Removed status %s", statusToString(status)); + m_Logger + .trace(Logs::RemovedStatus, "Removed status %s", statusToString(status)); m_Status &= ~status; } diff --git a/src/status/StatusManager.h b/src/status/StatusManager.h index 06c4b09ea..52e705860 100644 --- a/src/status/StatusManager.h +++ b/src/status/StatusManager.h @@ -15,7 +15,11 @@ class StatusManager { private: uint32_t m_Status; - Logging::Logger m_Logger = Logging::Logger("StatusManager"); + enum class Logs { + AddedStatus = 0, + RemovedStatus = 1, + }; + Logging::Logger m_Logger{"StatusManager", "status"}; }; } // namespace Status } // namespace SlimeVR From 80f4e0e0362d76f0ec379b749280dda48df4d47c Mon Sep 17 00:00:00 2001 From: gorbit99 Date: Fri, 9 May 2025 00:10:26 +0200 Subject: [PATCH 2/2] Formatting --- src/sensors/icm20948sensor.cpp | 7 ++----- .../softfusion/runtimecalibration/RuntimeCalibration.h | 6 ++++-- src/sensors/softfusion/softfusionsensor.h | 3 ++- 3 files changed, 8 insertions(+), 8 deletions(-) diff --git a/src/sensors/icm20948sensor.cpp b/src/sensors/icm20948sensor.cpp index 20bb3c5f9..f7bf1b9fd 100644 --- a/src/sensors/icm20948sensor.cpp +++ b/src/sensors/icm20948sensor.cpp @@ -31,11 +31,8 @@ // saved to NVS. Increments through the list then stops; to prevent unwelcome eeprom // wear. int bias_save_periods[] - = {120, - 180, - 300, - 600, - 600}; // 2min + 3min + 5min + 10min + 10min (no more saves after 30min) + = {120, 180, 300, 600, 600 +}; // 2min + 3min + 5min + 10min + 10min (no more saves after 30min) #define ACCEL_SENSITIVITY_4G 8192.0f diff --git a/src/sensors/softfusion/runtimecalibration/RuntimeCalibration.h b/src/sensors/softfusion/runtimecalibration/RuntimeCalibration.h index 8166e44e3..af902e6ec 100644 --- a/src/sensors/softfusion/runtimecalibration/RuntimeCalibration.h +++ b/src/sensors/softfusion/runtimecalibration/RuntimeCalibration.h @@ -401,11 +401,13 @@ class RuntimeCalibrator : public Sensor::CalibrationBase sampleRateCalibrationStep{calibration}; MotionlessCalibrationStep motionlessCalibrationStep{ calibration, - sensor}; + sensor + }; GyroBiasCalibrationStep gyroBiasCalibrationStep{calibration}; AccelBiasCalibrationStep accelBiasCalibrationStep{ calibration, - static_cast(Base::AScale)}; + static_cast(Base::AScale) + }; NullCalibrationStep nullCalibrationStep{calibration}; CalibrationStep* currentStep = &nullCalibrationStep; diff --git a/src/sensors/softfusion/softfusionsensor.h b/src/sensors/softfusion/softfusionsensor.h index 99276a3da..1e0ed4eee 100644 --- a/src/sensors/softfusion/softfusionsensor.h +++ b/src/sensors/softfusion/softfusionsensor.h @@ -447,7 +447,8 @@ class SoftFusionSensor : public Sensor { getDefaultTempTs(), AScale, GScale, - toggles}; + toggles + }; SensorStatus m_status = SensorStatus::SENSOR_OFFLINE; uint32_t m_lastPollTime = micros();