Add per-category verbatim wire tracing

This commit is contained in:
pgdalmeida 2026-06-22 22:30:26 +02:00
parent 00d3454bb6
commit 90f689c829
Signed by: pedro.almeida
GPG Key ID: D4A6C394DF13F1D7
20 changed files with 408 additions and 13 deletions

View File

@ -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"

View File

@ -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 <lvl>` | `trace`, `debug`, `info`, `warn`, `error`, or `off`. |
| `--trace <cats>` | 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 <n>` | JPEG XL encoder effort (higher = slower, smaller). |
| `set camera display <0\|1>` | Toggle the local preview window. |
| `set motorctl <raw>` | Send a raw command string straight to the motor controller. |
| `trace <cat> [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

View File

@ -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 =

View File

@ -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 <lvl>` | `trace`/`debug`/`info`/`warn`/`error`/`off` |
| `--trace <cats>` | 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 <cat> [on\|off]` | Toggle a wire-trace category (`serial`/`mqtt`/`camera`/`control`) |
| `trace all` / `trace off` | Enable every category / silence all |
| `set camera jxlq <v>` | JPEG XL distance (0 = lossless) |
| `set camera jxle <v>` | JPEG XL effort |
| `set camera display <0\|1>` | Toggle OpenCV preview window |
@ -91,6 +96,31 @@ Handled in `Application::Impl::handleCommand`.
| `set motorctl <cmd>` | 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<debug<info<warn<error<off`). Default `info`; an active capture is nearly silent at `info`.
- **Wire-trace categories**`[Logging] trace`, `--trace`, console `trace`. Each enabled category
(`serial`, `mqtt`, `camera`, `control`) logs **every** message exchanged with that subsystem,
verbatim. They are **off by default** and **independent of the level**: `--trace serial` prints all
firmware serial traffic even at `info`. Only level `off` silences them. The `camera` category is
high-rate (one line per frame, metadata only — no pixel data).
Precedence at startup: config applies first, then CLI overrides (`--trace` replaces the config set,
it does not merge). At runtime the `trace` console command edits categories incrementally.
Trace lines carry a category tag and a `TX`/`RX` direction so one subsystem is easy to follow/grep:
```
[SERIAL] TX kd180 (command to firmware)
[SERIAL] RX $;1234;0;500;1;1;0;180.5;... (telemetry from firmware; RX(unparsed) on a bad line)
[MQTT] PUB GGS/FWT/Tower/StatusCode 0 / [MQTT] RX GGS/FWT/Tower/target_HDG 180
[CAMERA] TX trigger cam0 / [CAMERA] RX frame cam0 1936x1216 7064576B
[CONTROL] motor cmd "p" (auto sweep) (scheduler decisions + inbound console commands)
```
## Motor command vocabulary (emitted by the software)
| Command | When | Meaning |

View File

@ -19,7 +19,8 @@ struct RuntimeOptions {
std::optional<bool> mock_camera;
std::optional<bool> 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

View File

@ -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;

View File

@ -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()

View File

@ -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;
}

View File

@ -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<std::mutex> lock(mutex_);
if (cmd.rfind("kd", 0) == 0) {
try {

View File

@ -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 {}; }

View File

@ -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<std::string>(), "trace|debug|info|warn|error|off");
("log-level", po::value<std::string>(), "trace|debug|info|warn|error|off")
("trace", po::value<std::string>(),
"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<bool>()) opts.mock_camera = true;
if (vm["mock-serial"].as<bool>()) opts.mock_serial = true;
if (vm.count("log-level")) opts.log_level = vm["log-level"].as<std::string>();
if (vm.count("trace")) opts.trace_categories = vm["trace"].as<std::string>();
Application app(std::move(cfg), std::move(opts));
return app.run();

View File

@ -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<FrameObserver>(obs)->resetSettle();

View File

@ -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<LogCat, const char*> all[] = {
{LogCat::Serial, "serial"}, {LogCat::Mqtt, "mqtt"},
{LogCat::Camera, "camera"}, {LogCat::Control, "control"},
};
for (const auto& [cat, name] : all) {
if (mask & static_cast<unsigned>(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 <cat> [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<unsigned>(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();

View File

@ -1,5 +1,7 @@
#include "fgc/CaptureScheduler.h"
#include "fgc/Logger.h"
#include <chrono>
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;
}

View File

@ -86,6 +86,9 @@ AppConfig ConfigLoader::fromMap(const std::map<std::string, std::string>& 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 " +

View File

@ -12,6 +12,7 @@ namespace fgc {
namespace {
std::atomic<LogLevel> g_level{LogLevel::Info};
std::atomic<unsigned> 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<char>(std::tolower(static_cast<unsigned char>(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<char>(std::tolower(static_cast<unsigned char>(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<unsigned>(cat)); }
void Logger::disableCategory(LogCat cat) { g_cats.fetch_and(~static_cast<unsigned>(cat)); }
bool Logger::categoryEnabled(LogCat cat) {
return (g_cats.load() & static_cast<unsigned>(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<unsigned>(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<std::mutex> lock(g_mutex);
sink << timestamp() << " [" << tag(level_) << "] " << buffer_.str() << '\n';
sink << timestamp() << " [" << label << "] " << buffer_.str() << '\n';
sink.flush();
}

View File

@ -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<std::mutex> 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);

View File

@ -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<std::mutex> 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<std::string>(cmd);
boost::asio::async_write(impl_->serial, boost::asio::buffer(*data),
[data](const boost::system::error_code& ec, std::size_t) {

View File

@ -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)

116
tests/test_logger.cpp Normal file
View File

@ -0,0 +1,116 @@
#include <doctest/doctest.h>
#include "fgc/Logger.h"
#include <iostream>
#include <sstream>
#include <string>
using namespace fgc;
namespace {
// Run a callable with std::cout redirected to a buffer; return what was written.
template <typename F>
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<unsigned>(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);
}