From 1c2f0a0506632547f6dfa1287d7fc2f6c6c7014e Mon Sep 17 00:00:00 2001 From: Peter Bochmann Date: Thu, 15 Oct 2026 17:59:49 +0200 Subject: [PATCH] Log why a picture got no thermal frame Every miss now says how old the newest frame was and whether a NUC was running; every pause over 500 ms in the frame stream is logged with the camera's own clock, the polls and getdata answers in it, and NUC_INPROGRESS, which is watched on every poll; a summary of the stream goes out every ten minutes, and the NUC configuration at connect. Adds the SDK's NUC parameters (410-415), for running the NUC on purpose later. Co-Authored-By: Claude Opus 5.5 --- include/fgc/IrbgrabApi.h | 14 +++ src/camera/TarisCameraSource.cpp | 146 ++++++++++++++++++++++++++++--- tests/test_tariscamerasource.cpp | 24 +++++ 3 files changed, 171 insertions(+), 13 deletions(-) diff --git a/include/fgc/IrbgrabApi.h b/include/fgc/IrbgrabApi.h index eb6c104..ec1b958 100644 --- a/include/fgc/IrbgrabApi.h +++ b/include/fgc/IrbgrabApi.h @@ -58,8 +58,16 @@ inline constexpr uint32_t kCameraTempHousing = 217; // Kelvin inline constexpr uint32_t kFramerateHz = 240; inline constexpr uint32_t kFrameWidth = 294; inline constexpr uint32_t kFrameHeight = 295; +// Non-uniformity correction, done in the camera with its own shutter. +inline constexpr uint32_t kNucActive = 410; // R bool: correction applied +inline constexpr uint32_t kNucPerform = 411; // W Int2 {mode, flags}: run one now +inline constexpr uint32_t kNucInProgress = 412; // R bool +inline constexpr uint32_t kNucInterval = 415; // R/W s between automatic ones, 0 = off } // namespace param +// kNucPerform's mode (Int2::value1); value2 takes flags, 0 for none. +inline constexpr int32_t kNucMode1Point = 2; + #pragma pack(push, 1) struct String { char* text; @@ -73,6 +81,10 @@ struct IdxInt32 { int32_t index; int32_t value; }; +struct Int2 { + int32_t value1; + int32_t value2; +}; // Per-frame information (mem_getinfo). struct_size must be set before the call. struct MemInfo { int32_t struct_size; @@ -89,12 +101,14 @@ inline constexpr uint32_t kBaseInt64 = 0x50000000; inline constexpr uint32_t kBaseFloat32 = 0xA0000000; inline constexpr uint32_t kBaseString = 0xF0000000; inline constexpr uint32_t kExIndex = 0x01000000; +inline constexpr uint32_t kExArray2 = 0x02020000; // a pair inline constexpr uint32_t kTypeInt32 = kBaseInt32 | sizeof(int32_t); inline constexpr uint32_t kTypeInt64 = kBaseInt64 | sizeof(int64_t); inline constexpr uint32_t kTypeSingle = kBaseFloat32 | sizeof(float); inline constexpr uint32_t kTypeString = kBaseString | sizeof(String); inline constexpr uint32_t kTypeIdxString = kExIndex | kBaseString | sizeof(IdxString); inline constexpr uint32_t kTypeIdxInt32 = kExIndex | kBaseInt32 | sizeof(IdxInt32); +inline constexpr uint32_t kType2Int32 = kExArray2 | kBaseInt32 | sizeof(Int2); // The entry points, as function pointers so a test can stand in for the SDK. struct Api { diff --git a/src/camera/TarisCameraSource.cpp b/src/camera/TarisCameraSource.cpp index 8e85918..791c840 100644 --- a/src/camera/TarisCameraSource.cpp +++ b/src/camera/TarisCameraSource.cpp @@ -13,6 +13,7 @@ #include #include #include +#include #include #include #include @@ -70,6 +71,11 @@ private: constexpr long long kLogEveryMs = 60000; // repeated trouble: one line a minute constexpr long long kTelemetryEveryMs = 5000; +// Diagnostics for pictures that get no thermal frame: a pause in the frame +// stream this long is logged with what the camera said meanwhile, and a summary +// of the stream goes out this often. +constexpr long long kGapLogMs = 500; +constexpr long long kSummaryEveryMs = 600000; } // namespace @@ -127,6 +133,19 @@ struct TarisCameraSource::Impl { bool zeros_logged = false; std::string last_offline_logged; + // Stream diagnostics (see kGapLogMs). Since the last frame taken: + double last_cam_ts = -1.0; // its MemInfo time, ms + long long polls_since_frame = 0; + std::map codes_since_frame; // getdata answers other than a new frame + bool nuc_in_gap = false; // NUC_INPROGRESS seen set meanwhile + // NUC_INPROGRESS, read on every poll; -1 = the camera does not answer it. + int nuc_state = 0; + long long nuc_started_ms = 0; + // For the summary: + long long sum_frames = 0, sum_gaps = 0, sum_nucs = 0, sum_max_gap = 0; + double sum_cam_span = 0.0; // camera clock covered by sum_frames + long long sum_since_ms = 0; + // ---- shared, under m ------------------------------------------------- std::mutex m; std::condition_variable cv; @@ -137,14 +156,15 @@ struct TarisCameraSource::Impl { CameraDeviceInfo info; std::deque arrivals; // steady ms of recent frames, for fps long long missed_shots = 0; - long long missed_logged_ms = 0; - long long missed_since_log = 0; long long packets_lost = 0; int cal_wanted = -1; // a pending setFeature("CalibProfile") bool cal_done = false; bool cal_ok = false; bool reset_wanted = false; uint64_t connects = 0; + bool nuc_now = false; // NUC_INPROGRESS at the last poll + long long nuc_now_since = 0; // steady ms it went on + long long missed_window = 0; // misses since the last summary std::atomic running{false}; std::atomic gate{false}; @@ -407,9 +427,21 @@ struct TarisCameraSource::Impl { if (!model.empty()) info.model = model; ++connects; } + int32_t nuc_active = -1, nuc_interval = -1; + getInt32(param::kNucActive, nuc_active); + getInt32(param::kNucInterval, nuc_interval); + LOG_INFO << "thermal camera: NUC " << (nuc_active == 1 ? "on" : nuc_active == 0 ? "off" : "?") + << ", automatic every " + << (nuc_interval > 0 ? std::to_string(nuc_interval) + " s" + : nuc_interval == 0 ? std::string("- (off)") : "?"); + kpc = 0.0; scale_tries = 0; last_sdk_ts = -1.0; + last_cam_ts = -1.0; + polls_since_frame = 0; + codes_since_frame.clear(); + nuc_in_gap = false; zeros_logged = false; last_frame_steady = steadyMs(); // grace for the first frame return true; @@ -418,12 +450,15 @@ struct TarisCameraSource::Impl { // ---- frames ------------------------------------------------------------ // Take the newest frame from the SDK, if there is one. void poll() { + ++polls_since_frame; + watchNuc(); // As before every getdata in the vendor's examples: without it the SDK // now and then answers 0x80000001 instead of a frame. setInt32(param::kPollingEnable, 1); Handle mem = 0; const Ret r = api->dev_getdata(dev, kMemIrDigitFrame, &mem); if (!ok(r)) { + ++codes_since_frame[r]; if (r == kErrNucOrLicence) { ++nuc_or_licence; const long long now = steadyMs(); @@ -461,7 +496,10 @@ struct TarisCameraSource::Impl { mi.image_num = -1; mi.timestamp_ms = -1.0; } - if (mi.timestamp_ms >= 0.0 && mi.timestamp_ms == last_sdk_ts) return; // seen it + if (mi.timestamp_ms >= 0.0 && mi.timestamp_ms == last_sdk_ts) { // seen it + ++codes_since_frame[kSuccess]; + return; + } last_sdk_ts = mi.timestamp_ms; const auto* counts = reinterpret_cast(ptr); @@ -493,6 +531,7 @@ struct TarisCameraSource::Impl { f.thermal = t; const long long now = steadyMs(); + noteFrame(now, mi.timestamp_ms); last_frame_steady = now; { std::lock_guard l(m); @@ -545,6 +584,82 @@ struct TarisCameraSource::Impl { } } + // NUC_INPROGRESS on every poll: when the camera corrects itself, and for how + // long - the prime suspect for a picture without a thermal frame. + void watchNuc() { + if (nuc_state < 0) return; + int32_t v = 0; + if (!getInt32(param::kNucInProgress, v)) { + LOG_INFO << "thermal camera: NUC_INPROGRESS not readable; NUC timing not logged"; + nuc_state = -1; + return; + } + const long long now = steadyMs(); + const int on = v != 0; + if (on) nuc_in_gap = true; + if (on && !nuc_state) { + nuc_started_ms = now; + ++sum_nucs; + LOG_INFO << "thermal camera: NUC started"; + } else if (!on && nuc_state) { + LOG_INFO << "thermal camera: NUC finished after " << now - nuc_started_ms << " ms"; + } + if (on != nuc_state) { + std::lock_guard l(m); + nuc_now = on; + nuc_now_since = now; + } + nuc_state = on; + } + + // A new frame: log the pause before it if it was long, and count it. + void noteFrame(long long now, double cam_ts) { + const long long host_gap = now - last_frame_steady; + const double cam_gap = last_cam_ts >= 0.0 && cam_ts >= 0.0 ? cam_ts - last_cam_ts : -1.0; + if (last_cam_ts >= 0.0) { + ++sum_frames; + if (cam_gap > 0.0) sum_cam_span += cam_gap; + sum_max_gap = std::max(sum_max_gap, host_gap); + if (host_gap > kGapLogMs || cam_gap > kGapLogMs) { + ++sum_gaps; + std::string codes; + for (const auto& [code, n] : codes_since_frame) + codes += (codes.empty() ? "" : ", ") + + (code == kSuccess ? std::string("same frame") : describe(code)) + + " x" + std::to_string(n); + LOG_INFO << "thermal camera: frame gap " << host_gap << " ms (camera clock " + << static_cast(cam_gap) << " ms), " << polls_since_frame + << " polls: " << (codes.empty() ? "-" : codes) << "; NUC " + << (nuc_state < 0 ? "unknown" : nuc_in_gap ? "in progress" : "not seen"); + } + } + last_cam_ts = cam_ts; + polls_since_frame = 0; + codes_since_frame.clear(); + nuc_in_gap = nuc_state > 0; + if (now - sum_since_ms >= kSummaryEveryMs) summary(now); + } + + void summary(long long now) { + if (sum_since_ms != 0 && sum_frames > 0) { + long long missed; + { + std::lock_guard l(m); + missed = missed_window; + missed_window = 0; + } + const double fps = sum_cam_span > 0.0 ? sum_frames * 1000.0 / sum_cam_span : 0.0; + LOG_INFO << "thermal camera, last " << (now - sum_since_ms) / 60000 << " min: " + << sum_frames << " frames (" << std::lround(fps * 10) / 10.0 + << " fps by the camera's clock), longest gap " << sum_max_gap << " ms, " + << sum_gaps << " over " << kGapLogMs << " ms, " << sum_nucs << " NUC, " + << missed << " picture(s) without a thermal frame"; + } + sum_frames = sum_gaps = sum_nucs = sum_max_gap = 0; + sum_cam_span = 0.0; + sum_since_ms = now; + } + void telemetry() { float k = 0.f; if (getSingle(param::kCameraTempHousing, k) && k > 0.f) { @@ -706,20 +821,25 @@ bool TarisCameraSource::trigger() { Frame f; { std::lock_guard l(d.m); - const bool fresh = d.latest_seq > d.delivered_seq && - unixMs() - d.latest.timestamp_ms <= d.o.max_frame_age_ms; + const bool new_frame = d.latest_seq > d.delivered_seq; + const long long age = d.latest_seq ? unixMs() - d.latest.timestamp_ms : -1; + const bool fresh = new_frame && age <= d.o.max_frame_age_ms; if (!fresh) { + // Every miss, with what tells its cause apart: the stream paused (and + // whether a NUC was running), or nothing came since the last picture. ++d.missed_shots; - ++d.missed_since_log; + ++d.missed_window; d.info.frames_dropped = d.missed_shots + d.packets_lost; const long long now = steadyMs(); - if (now - d.missed_logged_ms >= kLogEveryMs) { - LOG_WARN << "thermal camera: no fresh frame for " << d.missed_since_log - << " picture(s) in the last minute" - << (d.why_offline.empty() ? "" : " (" + d.why_offline + ")"); - d.missed_logged_ms = now; - d.missed_since_log = 0; - } + std::string why = !d.why_offline.empty() + ? d.why_offline + : "newest frame " + std::to_string(age) + " ms old (limit " + + std::to_string(d.o.max_frame_age_ms) + " ms)" + + (new_frame ? "" : ", none since the last picture") + + (d.nuc_now ? ", NUC in progress for " + + std::to_string(now - d.nuc_now_since) + " ms" + : ", no NUC running"); + LOG_WARN << "thermal camera: no thermal frame for this picture: " << why; return false; } f = d.latest; diff --git a/tests/test_tariscamerasource.cpp b/tests/test_tariscamerasource.cpp index 7576961..f5491fe 100644 --- a/tests/test_tariscamerasource.cpp +++ b/tests/test_tariscamerasource.cpp @@ -35,6 +35,7 @@ struct FakeSdk { uint32_t w = 8, h = 4; Ret no_frame = kErrNotFound; // what getdata says before any frame std::atomic frozen{false}; // stop producing frames (stall) + std::atomic nuc{0}; // NUC_INPROGRESS void push(uint16_t v, uint16_t hot = 0) { std::lock_guard l(m); @@ -98,6 +99,9 @@ Ret fGetParam(Handle, uint32_t what, void* data, uint32_t type) { return kSuccess; } if (what == param::kCameraTempHousing && type == kTypeSingle) { *static_cast(data) = 308.15f; return kSuccess; } + if (what == param::kNucInProgress && type == kTypeInt32) { *static_cast(data) = g->nuc; return kSuccess; } + if (what == param::kNucActive && type == kTypeInt32) { *static_cast(data) = 1; return kSuccess; } + if (what == param::kNucInterval && type == kTypeInt32) { *static_cast(data) = 0; return kSuccess; } return kErrNotSupported; } Ret fSetParam(Handle, uint32_t what, void* data, uint32_t type) { @@ -368,6 +372,26 @@ TEST_CASE("a camera that goes quiet is reconnected") { CHECK(t.sdk.connects >= 2); } +TEST_CASE("a NUC pausing the stream costs that picture, and the stream goes on") { + auto o = fastOptions(); + o.max_frame_age_ms = 50; + Harness t(o); + t.cam.open(); + t.cam.start(); + t.sdk.push(29315); + REQUIRE(t.shot()); + // The camera corrects itself: no new frame while it does. + t.sdk.nuc = 1; + t.sdk.frozen = true; + std::this_thread::sleep_for(std::chrono::milliseconds(120)); + CHECK_FALSE(t.cam.trigger()); + CHECK(t.cam.deviceInfo()[0].frames_dropped >= 1); + t.sdk.nuc = 0; + t.sdk.frozen = false; + t.sdk.push(29400); + CHECK(t.shot()); +} + TEST_CASE("a missing SDK library leaves the camera offline, not the program down") { auto o = fastOptions(); o.library = "libdoes_not_exist_irbgrab.so";