diff --git a/.deploy.env b/.deploy.env index 82bf932..8c57d17 100644 --- a/.deploy.env +++ b/.deploy.env @@ -2,4 +2,4 @@ REMOTE_HOST=ggs@10.11.12.111 REMOTE_DIR=/home/ggs/projects/fwt_2a/software CMAKE_ARGS="-DWITH_MQTT=ON -DWITH_VIMBA=ON" -RUN_ARGS="--start" +RUN_ARGS="--init --start --trace serial" diff --git a/README.md b/README.md index 1d000a4..e37e207 100644 --- a/README.md +++ b/README.md @@ -81,9 +81,10 @@ cp config/config.example.ini config.ini # then edit | `--mock-camera` | Use a simulated camera — no Vimba hardware needed. | | `--mock-serial` | Use a simulated motor controller — no serial hardware needed. | | `--log-level ` | `trace`, `debug`, `info`, `warn`, `error`, or `off`. | +| `--trace ` | Verbatim wire tracing; comma list of `serial,mqtt,camera,control,all,none`. | | `-h, --help` | Print options and exit. | -CLI flags override the matching `[Features]` keys in `config.ini`. +CLI flags override the matching `[Features]` / `[Logging]` keys in `config.ini`. ### Interactive commands @@ -100,12 +101,41 @@ While running, the program reads commands from stdin (one per line): | `set camera jxle ` | JPEG XL encoder effort (higher = slower, smaller). | | `set camera display <0\|1>` | Toggle the local preview window. | | `set motorctl ` | Send a raw command string straight to the motor controller. | +| `trace [on\|off]` | Enable/disable a wire-trace category live (e.g. `trace serial`, `trace mqtt off`). | +| `trace all` / `trace off` | Enable every category / silence all of them. | | `exit` | Stop everything and quit (Ctrl-D also works). | A typical first bring-up: `scripts/run.sh --init` to home the gimbal, then type `start` once you've confirmed telemetry looks sane; adjust `set fps` / `set camera jxlq` live as needed. See [docs/configuration.md](docs/configuration.md) for the full `config.ini` reference. +### Verbosity & wire tracing + +Two independent knobs control output: + +- **Log level** (`--log-level`, the `debug` console toggle, `[Logging] level`) gates ordinary + messages: `info` (default) shows discrete events only; `debug` adds per-image saves; `trace` is + the most verbose. At `info` an active capture is nearly silent. +- **Wire-trace categories** (`--trace`, the `trace` console command, `[Logging] trace`) log + **every** message exchanged with a subsystem, verbatim, and are **independent of the level** — + `--trace serial` shows all firmware serial traffic even at `info`. Categories are **off by + default** (the camera one is high-rate). Only `--log-level off` silences them. + +Lines are tagged by category with a `TX`/`RX` direction, so a single subsystem is easy to follow +or `grep`: + +``` +14:02:01.234 [SERIAL] TX kd180 +14:02:01.250 [SERIAL] RX $;1234;0;500;1;1;0;180.5;0;45;27;128; +14:02:02.000 [MQTT] PUB GGS/FWT/Tower/StatusCode 0 +14:02:02.500 [CAMERA] TX trigger cam0 +14:02:02.910 [CAMERA] RX frame cam0 1936x1216 7064576B +14:02:02.000 [CONTROL] motor cmd "p" (auto sweep) +``` + +Example — watch only firmware serial traffic on the device: +`./deploy.sh --run` with `RUN_ARGS="--start --trace serial"`. + ## Test ```bash diff --git a/config/config.example.ini b/config/config.example.ini index ffb58d3..6600426 100644 --- a/config/config.example.ini +++ b/config/config.example.ini @@ -49,3 +49,12 @@ enable_camera = true enable_serial = true mock_camera = false mock_serial = false + +[Logging] +; level: trace|debug|info|warn|error|off (default info). --log-level overrides. +level = info +; Verbatim per-category wire tracing, independent of the level above. Comma list +; of: serial, mqtt, camera, control, all, none. OFF by default. --trace overrides. +; Lines are tagged [SERIAL]/[MQTT]/[CAMERA]/[CONTROL] with TX/RX direction, e.g. +; [SERIAL] TX kd180 / [SERIAL] RX $;1234;0;... +trace = diff --git a/docs/configuration.md b/docs/configuration.md index 1f84b17..7a97bc0 100644 --- a/docs/configuration.md +++ b/docs/configuration.md @@ -40,6 +40,8 @@ Parsed and validated by `ConfigLoader` ([src/core/Config.cpp](../src/core/Config | `Features` | `enable_serial` | bool | `true` | (reserved) | | `Features` | `mock_camera` | bool | `false` | Use the simulated camera | | `Features` | `mock_serial` | bool | `false` | Use the simulated motor controller | +| `Logging` | `level` | enum | `info` | Linear log level (`--log-level` overrides) | +| `Logging` | `trace` | csv | — | Wire-trace categories, off by default (`--trace` overrides) | Camera index → output subfolder defaults to `RGB`, `ACR`, `NIR` (`CameraConfig::labels`). @@ -64,6 +66,7 @@ Parsed by Boost.Program_options ([main.cpp](../main.cpp)). Flags override `[Feat | `--mock-camera` | Use the simulated camera | | `--mock-serial` | Use the simulated motor controller | | `--log-level ` | `trace`/`debug`/`info`/`warn`/`error`/`off` | +| `--trace ` | Verbatim wire trace; comma list `serial,mqtt,camera,control,all,none` | Typical headless dev run: `scripts/run.sh --mock-serial --mock-camera --no-mqtt --start`. @@ -83,6 +86,8 @@ Handled in `Application::Impl::handleCommand`. | `start` | Start camera acquisition + capture | | `stop` | Stop acquisition | | `debug` | Toggle debug logging | +| `trace [on\|off]` | Toggle a wire-trace category (`serial`/`mqtt`/`camera`/`control`) | +| `trace all` / `trace off` | Enable every category / silence all | | `set camera jxlq ` | JPEG XL distance (0 = lossless) | | `set camera jxle ` | JPEG XL effort | | `set camera display <0\|1>` | Toggle OpenCV preview window | @@ -91,6 +96,31 @@ Handled in `Application::Impl::handleCommand`. | `set motorctl ` | Forward a raw command to the motor controller (e.g. `set motorctl kd180`) | | `exit` | Quit (Ctrl-D also works) | +## Logging: level vs. wire-trace categories + +Two **independent** controls, each settable via config (`[Logging]`), CLI, and a console command: + +- **Linear level** — `[Logging] level`, `--log-level`, console `debug`. Filters ordinary messages + (`trace mock_camera; std::optional mock_serial; - std::string log_level; // empty => default + std::string log_level; // empty => default + std::string trace_categories; // comma list (serial,mqtt,camera,control,all); empty => unset }; // Owns the component lifecycle and the control loop. Builds the concrete diff --git a/include/fgc/Config.h b/include/fgc/Config.h index 7bdef58..f5c6f90 100644 --- a/include/fgc/Config.h +++ b/include/fgc/Config.h @@ -45,6 +45,11 @@ struct FeaturesConfig { bool mock_serial = false; // use a simulated motor controller }; +struct LoggingConfig { + std::string level; // trace|debug|info|warn|error|off; empty => default (CLI overrides) + std::string trace; // verbatim wire-trace categories: serial,mqtt,camera,control,all,none +}; + struct AppConfig { GeneralConfig general; NetworkConfig network; @@ -52,6 +57,7 @@ struct AppConfig { CameraConfig camera; PathsConfig paths; FeaturesConfig features; + LoggingConfig logging; // Capture rate in images/second (derived from general.image_interval). double image_rate() const; diff --git a/include/fgc/Logger.h b/include/fgc/Logger.h index ea107b0..a14513e 100644 --- a/include/fgc/Logger.h +++ b/include/fgc/Logger.h @@ -8,6 +8,19 @@ namespace fgc { enum class LogLevel { Trace = 0, Debug, Info, Warn, Error, Off }; +// Wire-tracing categories. Orthogonal to LogLevel: a category emits verbatim +// TX/RX lines and is toggled independently of the linear level, so you can +// watch e.g. all serial traffic without turning everything else to Trace. +// Values are a bitmask (multiple categories enabled at once). +enum class LogCat : unsigned { + None = 0, + Serial = 1u << 0, + Mqtt = 1u << 1, + Camera = 1u << 2, + Control = 1u << 3, + All = Serial | Mqtt | Camera | Control, +}; + // Minimal leveled, thread-safe logger. Each log line is assembled in a // per-statement buffer and written atomically under a shared mutex, so lines // from different threads never interleave. Level filtering is global. @@ -23,6 +36,22 @@ public: // Parse "trace"|"debug"|"info"|"warn"|"error"|"off" (case-insensitive). // Returns false (and leaves the level unchanged) on an unknown string. static bool setLevelFromString(const std::string& s); + + // Wire-trace categories (independent of the linear level above). + static void setCategories(unsigned mask); + static unsigned categories(); + static void enableCategory(LogCat cat); + static void disableCategory(LogCat cat); + static bool categoryEnabled(LogCat cat); + + // Parse a comma list: "serial,mqtt" | "all" | "none" (case-insensitive, + // whitespace-trimmed). Recognized tokens always apply; an unknown token + // sets *ok=false (when ok != nullptr) but does not discard the rest. + static unsigned parseCategories(const std::string& csv, bool* ok = nullptr); + + // Map a single category name to its enum value. Unknown => LogCat::None and + // *ok=false (when ok != nullptr). + static LogCat catFromString(const std::string& name, bool* ok = nullptr); }; // RAII helper that buffers one log line and flushes it on commit(). @@ -30,12 +59,14 @@ public: class LogStream { public: explicit LogStream(LogLevel level); + LogStream(LogLevel level, LogCat cat); // category (wire-trace) line bool pending() const { return enabled_ && !done_; } void commit(); std::ostream& stream() { return buffer_; } private: LogLevel level_; + LogCat cat_ = LogCat::None; // None => gated by level only bool enabled_; bool done_ = false; std::ostringstream buffer_; @@ -55,3 +86,11 @@ private: #define LOG_INFO FGC_LOG_AT(::fgc::LogLevel::Info) #define LOG_WARN FGC_LOG_AT(::fgc::LogLevel::Warn) #define LOG_ERROR FGC_LOG_AT(::fgc::LogLevel::Error) + +// Verbatim wire-trace line for one category. Prints when the category is +// enabled (independent of the linear level, except level Off silences all). +// The message expression is not evaluated when the category is off. +#define LOG_TRACE_CAT(cat) \ + for (::fgc::LogStream _fgc_ls(::fgc::LogLevel::Trace, (cat)); _fgc_ls.pending(); \ + _fgc_ls.commit()) \ + _fgc_ls.stream() diff --git a/include/fgc/mock/MockCameraSource.h b/include/fgc/mock/MockCameraSource.h index 747ef48..1bf5ce0 100644 --- a/include/fgc/mock/MockCameraSource.h +++ b/include/fgc/mock/MockCameraSource.h @@ -22,6 +22,7 @@ public: bool trigger() override { if (!callback_) return false; + LOG_TRACE_CAT(LogCat::Camera) << "TX trigger cam0 (mock)"; Frame f; f.width = width_; f.height = height_; @@ -40,6 +41,8 @@ public: f.data[i + 2] = phase; } } + LOG_TRACE_CAT(LogCat::Camera) + << "RX frame cam0 " << width_ << 'x' << height_ << ' ' << f.data.size() << "B (mock)"; callback_(f); return true; } diff --git a/include/fgc/mock/MockMotorController.h b/include/fgc/mock/MockMotorController.h index 080093b..de35427 100644 --- a/include/fgc/mock/MockMotorController.h +++ b/include/fgc/mock/MockMotorController.h @@ -17,7 +17,7 @@ public: void stop() override { LOG_INFO << "[mock] motor controller stopped"; } void sendCommand(const std::string& cmd) override { - LOG_DEBUG << "[mock] motor cmd: " << cmd; + LOG_TRACE_CAT(LogCat::Serial) << "TX " << cmd; std::lock_guard lock(mutex_); if (cmd.rfind("kd", 0) == 0) { try { diff --git a/include/fgc/mock/NullControlChannel.h b/include/fgc/mock/NullControlChannel.h index 053fa2a..7f7de69 100644 --- a/include/fgc/mock/NullControlChannel.h +++ b/include/fgc/mock/NullControlChannel.h @@ -14,10 +14,13 @@ public: void disconnect() override {} bool connected() const override { return true; } - void publishStatus(int code) override { LOG_DEBUG << "[null] status " << code; } + void publishStatus(int code) override { + LOG_TRACE_CAT(LogCat::Mqtt) << "PUB StatusCode " << code << " (null channel)"; + } void publishCamEvent(const CamEvent& e) override { - LOG_DEBUG << "[null] cam event " << e.camera << " hdg=" << e.heading_decideg - << " t=" << e.timestamp_ms; + LOG_TRACE_CAT(LogCat::Mqtt) << "PUB CamEvent cam=" << e.camera + << " hdg=" << e.heading_decideg << " t=" << e.timestamp_ms + << " (null channel)"; } ControlCommand poll() override { return {}; } diff --git a/main.cpp b/main.cpp index eb817be..b2d3256 100644 --- a/main.cpp +++ b/main.cpp @@ -21,7 +21,9 @@ int main(int argc, char* argv[]) { ("no-mqtt", po::bool_switch(), "disable MQTT (use a null control channel)") ("mock-camera", po::bool_switch(), "use a simulated camera (no hardware)") ("mock-serial", po::bool_switch(), "use a simulated motor controller (no hardware)") - ("log-level", po::value(), "trace|debug|info|warn|error|off"); + ("log-level", po::value(), "trace|debug|info|warn|error|off") + ("trace", po::value(), + "verbatim wire trace, comma list: serial,mqtt,camera,control,all,none"); po::variables_map vm; try { @@ -63,6 +65,7 @@ int main(int argc, char* argv[]) { if (vm["mock-camera"].as()) opts.mock_camera = true; if (vm["mock-serial"].as()) opts.mock_serial = true; if (vm.count("log-level")) opts.log_level = vm["log-level"].as(); + if (vm.count("trace")) opts.trace_categories = vm["trace"].as(); Application app(std::move(cfg), std::move(opts)); return app.run(); diff --git a/src/camera/VimbaCameraSource.cpp b/src/camera/VimbaCameraSource.cpp index e4db695..2d68692 100644 --- a/src/camera/VimbaCameraSource.cpp +++ b/src/camera/VimbaCameraSource.cpp @@ -51,6 +51,8 @@ public: f.cam_id = cam_id_; f.timestamp_ms = nowMs(); f.data.assign(buf, buf + sz); + LOG_TRACE_CAT(LogCat::Camera) + << "RX frame cam" << cam_id_ << ' ' << w << 'x' << h << ' ' << sz << 'B'; if (cb_) cb_(f); } } @@ -129,6 +131,7 @@ void VimbaCameraSource::stop() { bool VimbaCameraSource::trigger() { if (impl_->cameras.empty()) return false; + LOG_TRACE_CAT(LogCat::Camera) << "TX trigger cam0"; for (auto& obs : impl_->observers) SP_DYN_CAST(obs)->resetSettle(); diff --git a/src/core/Application.cpp b/src/core/Application.cpp index aa554f2..814751b 100644 --- a/src/core/Application.cpp +++ b/src/core/Application.cpp @@ -29,6 +29,27 @@ namespace fgc { +namespace { + +// Human-readable list of the enabled wire-trace categories, for echoing back. +std::string traceNames(unsigned mask) { + if (mask == 0) return "none"; + std::string out; + const std::pair all[] = { + {LogCat::Serial, "serial"}, {LogCat::Mqtt, "mqtt"}, + {LogCat::Camera, "camera"}, {LogCat::Control, "control"}, + }; + for (const auto& [cat, name] : all) { + if (mask & static_cast(cat)) { + if (!out.empty()) out += ','; + out += name; + } + } + return out; +} + +} // namespace + struct Application::Impl { Impl(AppConfig c, RuntimeOptions o) : cfg(std::move(c)), opts(std::move(o)) {} @@ -114,9 +135,31 @@ struct Application::Impl { LOG_INFO << "Capture stopped"; } + // `trace off|none`, `trace all`, or `trace [on|off]` — toggle the + // verbatim wire-trace categories (serial/mqtt/camera/control). + void handleTrace(const Command& c) { + if (c.device.empty() || c.device == "off" || c.device == "none") { + Logger::setCategories(0); + } else if (c.device == "all") { + Logger::setCategories(static_cast(LogCat::All)); + } else { + bool ok = true; + LogCat cat = Logger::catFromString(c.device, &ok); + if (!ok) { + LOG_WARN << "unknown trace category: " << c.device; + return; + } + bool on = (c.option != "off"); // "trace serial" / "trace serial on" => enable + if (on) Logger::enableCategory(cat); + else Logger::disableCategory(cat); + } + LOG_INFO << "trace categories: " << traceNames(Logger::categories()); + } + void handleCommand(const std::string& line) { Command c = parseCommand(line); if (c.empty()) return; + LOG_TRACE_CAT(LogCat::Control) << "cmd " << line; if (c.verb == "exit") { running = false; @@ -128,6 +171,8 @@ struct Application::Impl { bool on = Logger::level() != LogLevel::Debug; Logger::setLevel(on ? LogLevel::Debug : LogLevel::Info); LOG_INFO << "debug logging " << (on ? "on" : "off"); + } else if (c.verb == "trace") { + handleTrace(c); } else if (c.verb == "set") { if (c.device == "camera") { if (c.option == "fps" && c.has_value) camera->setFrameRate(c.value); @@ -174,9 +219,28 @@ struct Application::Impl { } int run() { + // Log level: config first, CLI overrides. + if (!cfg.logging.level.empty() && !Logger::setLevelFromString(cfg.logging.level)) + LOG_WARN << "unknown Logging.level '" << cfg.logging.level << "', keeping default"; if (!opts.log_level.empty() && !Logger::setLevelFromString(opts.log_level)) LOG_WARN << "unknown log level '" << opts.log_level << "', keeping default"; + // Wire-trace categories: config first, CLI overrides (replaces, not merges). + if (!cfg.logging.trace.empty()) { + bool ok = true; + unsigned m = Logger::parseCategories(cfg.logging.trace, &ok); + if (!ok) LOG_WARN << "unknown trace category in Logging.trace '" << cfg.logging.trace << "'"; + Logger::setCategories(m); + } + if (!opts.trace_categories.empty()) { + bool ok = true; + unsigned m = Logger::parseCategories(opts.trace_categories, &ok); + if (!ok) LOG_WARN << "unknown trace category in '" << opts.trace_categories << "'"; + Logger::setCategories(m); + } + if (Logger::categories()) + LOG_INFO << "wire trace enabled: " << traceNames(Logger::categories()); + channel = makeChannel(); motor = makeMotor(); camera = makeCamera(); diff --git a/src/core/CaptureScheduler.cpp b/src/core/CaptureScheduler.cpp index 928cf9b..d0705f4 100644 --- a/src/core/CaptureScheduler.cpp +++ b/src/core/CaptureScheduler.cpp @@ -1,5 +1,7 @@ #include "fgc/CaptureScheduler.h" +#include "fgc/Logger.h" + #include namespace fgc { @@ -43,10 +45,12 @@ void CaptureScheduler::tick() { ControlCommand cmd = channel_.poll(); if (cmd.control_code_available) { control_code_ = cmd.control_code; + LOG_TRACE_CAT(LogCat::Control) << "control_code -> " << control_code_; channel_.publishStatus(control_code_); } if (cmd.heading_available) { target_heading_ = cmd.target_heading; + LOG_TRACE_CAT(LogCat::Control) << "target_heading -> " << target_heading_; } // 2. Telemetry. @@ -61,15 +65,19 @@ void CaptureScheduler::tick() { if (t.is_moving == 1) { resetTimer(); trigger_after_stopping_ = true; - if (control_code_ == 0) + if (control_code_ == 0) { + LOG_TRACE_CAT(LogCat::Control) << "motor cmd \"p\" (auto sweep)"; motor_.sendCommand("p"); - else // control_code_ == 1 + } else { // control_code_ == 1 + LOG_TRACE_CAT(LogCat::Control) << "motor cmd \"kd" << target_heading_ << '"'; motor_.sendCommand("kd" + target_heading_); + } } } if (trigger_after_stopping_ && elapsedMs() > 100) { if (shouldTrigger(t)) { + LOG_TRACE_CAT(LogCat::Control) << "trigger decision: is_moving=" << t.is_moving; if (camera_.trigger()) { trigger_after_stopping_ = false; } diff --git a/src/core/Config.cpp b/src/core/Config.cpp index b179f32..80b9013 100644 --- a/src/core/Config.cpp +++ b/src/core/Config.cpp @@ -86,6 +86,9 @@ AppConfig ConfigLoader::fromMap(const std::map& kv) { cfg.features.mock_camera = getBool(kv, "Features.mock_camera", cfg.features.mock_camera); cfg.features.mock_serial = getBool(kv, "Features.mock_serial", cfg.features.mock_serial); + cfg.logging.level = get(kv, "Logging.level", cfg.logging.level); + cfg.logging.trace = get(kv, "Logging.trace", cfg.logging.trace); + // ---- validation ---- if (cfg.general.image_interval <= 0) throw std::runtime_error("General.image_interval must be > 0 (got " + diff --git a/src/core/Logger.cpp b/src/core/Logger.cpp index 852cc7a..1efeacf 100644 --- a/src/core/Logger.cpp +++ b/src/core/Logger.cpp @@ -12,6 +12,7 @@ namespace fgc { namespace { std::atomic g_level{LogLevel::Info}; +std::atomic g_cats{0}; // every wire-trace category OFF by default std::mutex g_mutex; const char* tag(LogLevel l) { @@ -26,6 +27,30 @@ const char* tag(LogLevel l) { return "?????"; } +const char* catTag(LogCat c) { + switch (c) { + case LogCat::Serial: return "SERIAL"; + case LogCat::Mqtt: return "MQTT"; + case LogCat::Camera: return "CAMERA"; + case LogCat::Control: return "CONTROL"; + default: return "TRACE"; + } +} + +std::string lower(const std::string& s) { + std::string v; + for (char c : s) v += static_cast(std::tolower(static_cast(c))); + return v; +} + +// Trim leading/trailing ASCII whitespace. +std::string trim(const std::string& s) { + size_t b = s.find_first_not_of(" \t\r\n"); + if (b == std::string::npos) return ""; + size_t e = s.find_last_not_of(" \t\r\n"); + return s.substr(b, e - b + 1); +} + std::string timestamp() { using namespace std::chrono; auto now = system_clock::now(); @@ -48,8 +73,7 @@ LogLevel Logger::level() { return g_level.load(); } bool Logger::enabled(LogLevel level) { return level >= g_level.load(); } bool Logger::setLevelFromString(const std::string& s) { - std::string v; - for (char c : s) v += static_cast(std::tolower(static_cast(c))); + std::string v = lower(s); if (v == "trace") { setLevel(LogLevel::Trace); return true; } if (v == "debug") { setLevel(LogLevel::Debug); return true; } if (v == "info") { setLevel(LogLevel::Info); return true; } @@ -59,14 +83,60 @@ bool Logger::setLevelFromString(const std::string& s) { return false; } +void Logger::setCategories(unsigned mask) { g_cats.store(mask); } +unsigned Logger::categories() { return g_cats.load(); } +void Logger::enableCategory(LogCat cat) { g_cats.fetch_or(static_cast(cat)); } +void Logger::disableCategory(LogCat cat) { g_cats.fetch_and(~static_cast(cat)); } +bool Logger::categoryEnabled(LogCat cat) { + return (g_cats.load() & static_cast(cat)) != 0; +} + +LogCat Logger::catFromString(const std::string& name, bool* ok) { + std::string v = lower(trim(name)); + if (ok) *ok = true; + if (v == "serial") return LogCat::Serial; + if (v == "mqtt") return LogCat::Mqtt; + if (v == "camera") return LogCat::Camera; + if (v == "control") return LogCat::Control; + if (v == "all") return LogCat::All; + if (v == "none" || v.empty()) return LogCat::None; + if (ok) *ok = false; + return LogCat::None; +} + +unsigned Logger::parseCategories(const std::string& csv, bool* ok) { + if (ok) *ok = true; + unsigned mask = 0; + size_t start = 0; + while (start <= csv.size()) { + size_t comma = csv.find(',', start); + std::string token = csv.substr(start, comma == std::string::npos ? std::string::npos + : comma - start); + std::string t = trim(token); + if (!t.empty()) { + bool tok_ok = true; + mask |= static_cast(catFromString(t, &tok_ok)); + if (!tok_ok && ok) *ok = false; + } + if (comma == std::string::npos) break; + start = comma + 1; + } + return mask; +} + LogStream::LogStream(LogLevel level) : level_(level), enabled_(Logger::enabled(level)) {} +LogStream::LogStream(LogLevel level, LogCat cat) + : level_(level), cat_(cat), + enabled_(Logger::categoryEnabled(cat) && Logger::level() != LogLevel::Off) {} + void LogStream::commit() { done_ = true; if (!enabled_) return; std::ostream& sink = (level_ >= LogLevel::Warn) ? std::cerr : std::cout; + const char* label = (cat_ != LogCat::None) ? catTag(cat_) : tag(level_); std::lock_guard lock(g_mutex); - sink << timestamp() << " [" << tag(level_) << "] " << buffer_.str() << '\n'; + sink << timestamp() << " [" << label << "] " << buffer_.str() << '\n'; sink.flush(); } diff --git a/src/mqtt/MqttControlChannel.cpp b/src/mqtt/MqttControlChannel.cpp index 222f6f0..1049813 100644 --- a/src/mqtt/MqttControlChannel.cpp +++ b/src/mqtt/MqttControlChannel.cpp @@ -74,6 +74,7 @@ void MqttControlChannel::on_failure(const mqtt::token& /*tok*/) { void MqttControlChannel::message_arrived(mqtt::const_message_ptr msg) { const std::string topic = msg->get_topic(); const std::string payload = msg->to_string(); + LOG_TRACE_CAT(LogCat::Mqtt) << "RX " << topic << ' ' << payload; std::lock_guard lock(mutex_); try { if (topic == topic_target_hdg_) { @@ -99,6 +100,7 @@ ControlCommand MqttControlChannel::poll() { void MqttControlChannel::publish(const std::string& topic, const std::string& payload) { if (!client_.is_connected()) return; + LOG_TRACE_CAT(LogCat::Mqtt) << "PUB " << topic << ' ' << payload; try { auto msg = mqtt::make_message(topic, payload); msg->set_qos(kQos); diff --git a/src/serial/SerialMotorController.cpp b/src/serial/SerialMotorController.cpp index ca5f52a..25f8a11 100644 --- a/src/serial/SerialMotorController.cpp +++ b/src/serial/SerialMotorController.cpp @@ -37,8 +37,11 @@ struct SerialMotorController::Impl { std::string line; std::getline(is, line); if (auto t = parseTelemetryLine(line)) { + LOG_TRACE_CAT(LogCat::Serial) << "RX " << line; std::lock_guard lock(mutex); latest = *t; + } else { + LOG_TRACE_CAT(LogCat::Serial) << "RX(unparsed) " << line; } doRead(); }); @@ -85,6 +88,7 @@ void SerialMotorController::stop() { void SerialMotorController::sendCommand(const std::string& cmd) { if (!impl_->connected) return; + LOG_TRACE_CAT(LogCat::Serial) << "TX " << cmd; auto data = std::make_shared(cmd); boost::asio::async_write(impl_->serial, boost::asio::buffer(*data), [data](const boost::system::error_code& ec, std::size_t) { diff --git a/tests/CMakeLists.txt b/tests/CMakeLists.txt index 5752391..4a8737c 100644 --- a/tests/CMakeLists.txt +++ b/tests/CMakeLists.txt @@ -24,6 +24,7 @@ add_executable(fgc_tests test_telemetry.cpp test_command.cpp test_scheduler.cpp + test_logger.cpp ) target_link_libraries(fgc_tests PRIVATE fgc_core doctest::doctest) diff --git a/tests/test_logger.cpp b/tests/test_logger.cpp new file mode 100644 index 0000000..df779d2 --- /dev/null +++ b/tests/test_logger.cpp @@ -0,0 +1,116 @@ +#include + +#include "fgc/Logger.h" + +#include +#include +#include + +using namespace fgc; + +namespace { + +// Run a callable with std::cout redirected to a buffer; return what was written. +template +std::string captureCout(F&& f) { + std::ostringstream oss; + std::streambuf* old = std::cout.rdbuf(oss.rdbuf()); + f(); + std::cout.rdbuf(old); + return oss.str(); +} + +unsigned bits(LogCat c) { return static_cast(c); } + +} // namespace + +TEST_CASE("parseCategories maps names, all/none, and flags unknown tokens") { + bool ok = true; + + CHECK(Logger::parseCategories("serial,mqtt", &ok) == (bits(LogCat::Serial) | bits(LogCat::Mqtt))); + CHECK(ok); + + CHECK(Logger::parseCategories("all", &ok) == bits(LogCat::All)); + CHECK(ok); + + CHECK(Logger::parseCategories("none", &ok) == 0u); + CHECK(ok); + CHECK(Logger::parseCategories("", &ok) == 0u); + CHECK(ok); + + // Case- and whitespace-insensitive. + CHECK(Logger::parseCategories(" SeRiAl , Camera ", &ok) + == (bits(LogCat::Serial) | bits(LogCat::Camera))); + CHECK(ok); + + // Unknown token: ok=false, but recognized tokens still apply. + ok = true; + CHECK(Logger::parseCategories("serial,bogus", &ok) == bits(LogCat::Serial)); + CHECK_FALSE(ok); +} + +TEST_CASE("catFromString round-trips and flags unknown") { + bool ok = true; + CHECK(Logger::catFromString("control", &ok) == LogCat::Control); + CHECK(ok); + CHECK(Logger::catFromString("nope", &ok) == LogCat::None); + CHECK_FALSE(ok); +} + +TEST_CASE("category enable/disable/set round-trip") { + Logger::setCategories(0); + CHECK(Logger::categories() == 0u); + CHECK_FALSE(Logger::categoryEnabled(LogCat::Serial)); + + Logger::enableCategory(LogCat::Serial); + Logger::enableCategory(LogCat::Mqtt); + CHECK(Logger::categoryEnabled(LogCat::Serial)); + CHECK(Logger::categoryEnabled(LogCat::Mqtt)); + CHECK_FALSE(Logger::categoryEnabled(LogCat::Camera)); + + Logger::disableCategory(LogCat::Serial); + CHECK_FALSE(Logger::categoryEnabled(LogCat::Serial)); + CHECK(Logger::categoryEnabled(LogCat::Mqtt)); + + Logger::setCategories(bits(LogCat::All)); + CHECK(Logger::categoryEnabled(LogCat::Camera)); + CHECK(Logger::categoryEnabled(LogCat::Control)); + + Logger::setCategories(0); // leave global state clean for other tests +} + +TEST_CASE("LOG_TRACE_CAT gating is independent of the linear level") { + Logger::setCategories(0); + + SUBCASE("suppressed when category off (even at trace level)") { + Logger::setLevel(LogLevel::Trace); + std::string out = captureCout([] { LOG_TRACE_CAT(LogCat::Serial) << "TX kd180"; }); + CHECK(out.empty()); + } + + SUBCASE("emitted with [SERIAL] tag when category on, at default info level") { + Logger::setLevel(LogLevel::Info); // NOT trace + Logger::enableCategory(LogCat::Serial); + std::string out = captureCout([] { LOG_TRACE_CAT(LogCat::Serial) << "TX kd180"; }); + CHECK(out.find("[SERIAL]") != std::string::npos); + CHECK(out.find("TX kd180") != std::string::npos); + } + + SUBCASE("a different category stays silent") { + Logger::setLevel(LogLevel::Info); + Logger::enableCategory(LogCat::Serial); // serial on, mqtt off + std::string out = captureCout([] { LOG_TRACE_CAT(LogCat::Mqtt) << "PUB t p"; }); + CHECK(out.empty()); + } + + SUBCASE("level Off silences categories too") { + Logger::setLevel(LogLevel::Off); + Logger::enableCategory(LogCat::Serial); + std::string out = captureCout([] { LOG_TRACE_CAT(LogCat::Serial) << "TX x"; }); + CHECK(out.empty()); + } + + // Restore defaults so test ordering can't leak state. + Logger::setCategories(0); + Logger::setLevel(LogLevel::Info); +}