logging: compile out LOG_TRACE by default, demote chatty DEBUG lines, drop redundant logs (#11391)

* logging: gate LOG_TRACE behind MESHTASTIC_TRACE_LOGGING, drop redundant reclock logs

LOG_TRACE now compiles out by default so trace-level diagnostics cost no
flash; enable with -DMESHTASTIC_TRACE_LOGGING. Portduino keeps it on for
the traceFilename packet-trace feature.

Remove the 66 caller-side I2C reclock/restore log lines in the telemetry
sensors: ReClockI2C::setClock/restoreClock already log both frequencies
internally (now at trace level, since they fire every sensor read).

Also unify near-duplicate literals (colon/case/punctuation variants) so
linker string dedup applies, and drop an information-free bare 'done'.

Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01LBiZc9sfPrH1MZ2L3Fxgt1

* logging: demote chatty per-packet/per-poll DEBUG lines to trace level

With LOG_TRACE compiled out by default, per-iteration chatter (packet
bookkeeping, sensor poll values, e-ink refresh reasons, GPS pin states,
UI runState traces) now costs no flash on device builds while remaining
one -DMESHTASTIC_TRACE_LOGGING away. 108 lines demoted, 4 information-
free lines removed; failure paths, drop reasons, and one-time init logs
all stay at debug level.

Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01LBiZc9sfPrH1MZ2L3Fxgt1

* logging: address CodeRabbit review on trace-gate PR

- GPS: pass serial-derived buffers as %s args, never as format strings
  (untrusted bytes could contain % directives)
- 0x%08x for packet id / NodeNum per convention (Router, CannedMessage,
  NeighborInfo); unsigned casts for size_t args; %u for uint32_t delta
- EInk: async full-refresh begin/complete back to DEBUG (rare state
  transitions); per-frame SKIPPED lines stay trace

Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01LBiZc9sfPrH1MZ2L3Fxgt1

* logging: gate trace on the flag's value, not its presence

-DMESHTASTIC_TRACE_LOGGING=0 previously *enabled* trace logging because
the gate tested definedness. The flag now defaults per-platform
(portduino 1, else 0) and both backends test the value, so =0 disables,
=1 or a bare -D enables. Also cast tx_after-millis() to uint32_t for %u
(millis() is unsigned long on native).

Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01LBiZc9sfPrH1MZ2L3Fxgt1

* logging: clang-format rewrap after specifier widening

Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01LBiZc9sfPrH1MZ2L3Fxgt1

* Even fewer bytes!

* logging: keep compile-gated debug lines at debug level; fix native-suite-count

Lines already inside default-off #ifdef blocks (GPS_DEBUG,
DEBUG_LOOP_TIMING) cost no flash and should stay visible at debug level
when their gate is enabled, rather than also requiring
MESHTASTIC_TRACE_LOGGING.

test/native-suite-count lags the two test_event_channel_* suites added
by #11045 (develop's Native Suite Count check has the same mismatch);
bump 46 -> 47.

Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01LBiZc9sfPrH1MZ2L3Fxgt1

* gps: route GPS_DEBUG diagnostics through a LOG_DEBUG_GPS() macro (#11414)

Replaces 27 log-only #ifdef GPS_DEBUG blocks across GPS.cpp,
PositionModule, MeshService, and GPSStatus.h with a single-line
LOG_DEBUG_GPS() call (src/gps/GPSLog.h, modeled on LOG_MIGRATION:
value-gated, ((void)0) when off). Blocks containing declarations,
control flow, hexDump, or nested conditionals keep an explicit
'#if GPS_DEBUG' guard. RTC.cpp's per-reading raw time dumps and
per-candidate rejection chatter fold under the same gate; quality
transitions and boot-time seeding stay at debug.

Also fixes the '// define GPS_DEBUG' missing-# typo in two variant
headers and updates all seven commented examples to the value form
('#define GPS_DEBUG 1') required by the value-based gate.


Claude-Session: https://claude.ai/code/session_01LBiZc9sfPrH1MZ2L3Fxgt1

Co-authored-by: Claude <noreply@anthropic.com>

* gps: declare RTC gmtime result as pointer to const (cppcheck)

With the setTime debug dump gated behind GPS_DEBUG, all remaining uses
of t are reads; cppcheck (constVariablePointer) now flags it.

Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01LBiZc9sfPrH1MZ2L3Fxgt1

---------

Co-authored-by: Claude <noreply@anthropic.com>
This commit is contained in:
Jonathan Bennett
2026-08-12 00:05:51 +00:00
committed by GitHub
co-authored by Claude Fable 5
parent c5979a85bf
commit 5baad2e2a8
47 changed files with 216 additions and 310 deletions
-1
View File
@@ -99,7 +99,6 @@ bool EInkDisplay::forceDisplay(uint32_t msecLimit)
// End the update process
endUpdate();
LOG_DEBUG("done");
return true;
}
+13 -13
View File
@@ -157,7 +157,7 @@ bool EInkDynamicDisplay::determineMode()
resetRateLimiting(); // Once determineMode() ends, will have to wait again
hashImage(); // Generate here, so we can still copy it to previousImageHash, even if we skip the comparison check
LOG_DEBUG("determineMode(): "); // Begin log entry
LOG_TRACE("determineMode(): "); // Begin log entry
// Once mode determined, any remaining checks will bypass
checkCosmetic();
@@ -254,7 +254,7 @@ void EInkDynamicDisplay::checkRateLimiting()
if (Throttle::isWithinTimespanMs(previousRunMs, 1000)) {
refresh = SKIPPED;
reason = EXCEEDED_RATELIMIT_FAST;
LOG_DEBUG("refresh=SKIPPED, reason=EXCEEDED_RATELIMIT_FAST, frameFlags=0x%x", frameFlags);
LOG_TRACE("refresh=SKIPPED, reason=EXCEEDED_RATELIMIT_FAST, frameFlags=0x%x", frameFlags);
return;
}
}
@@ -271,7 +271,7 @@ void EInkDynamicDisplay::checkCosmetic()
if (frameFlags & COSMETIC) {
refresh = FULL;
reason = FLAGGED_COSMETIC;
LOG_DEBUG("refresh=FULL, reason=FLAGGED_COSMETIC, frameFlags=0x%x", frameFlags);
LOG_TRACE("refresh=FULL, reason=FLAGGED_COSMETIC, frameFlags=0x%x", frameFlags);
}
}
@@ -286,7 +286,7 @@ void EInkDynamicDisplay::checkDemandingFast()
if (frameFlags & DEMAND_FAST) {
refresh = FAST;
reason = FLAGGED_DEMAND_FAST;
LOG_DEBUG("refresh=FAST, reason=FLAGGED_DEMAND_FAST, frameFlags=0x%x", frameFlags);
LOG_TRACE("refresh=FAST, reason=FLAGGED_DEMAND_FAST, frameFlags=0x%x", frameFlags);
}
}
@@ -306,7 +306,7 @@ void EInkDynamicDisplay::checkFrameMatchesPrevious()
if (frameFlags == BACKGROUND && fastRefreshCount > 0) {
refresh = FULL;
reason = REDRAW_WITH_FULL;
LOG_DEBUG("refresh=FULL, reason=REDRAW_WITH_FULL, frameFlags=0x%x", frameFlags);
LOG_TRACE("refresh=FULL, reason=REDRAW_WITH_FULL, frameFlags=0x%x", frameFlags);
return;
}
#endif
@@ -314,7 +314,7 @@ void EInkDynamicDisplay::checkFrameMatchesPrevious()
// Not redrawn, not COSMETIC, not DEMAND_FAST
refresh = SKIPPED;
reason = FRAME_MATCHED_PREVIOUS;
LOG_DEBUG("refresh=SKIPPED, reason=FRAME_MATCHED_PREVIOUS, frameFlags=0x%x", frameFlags);
LOG_TRACE("refresh=SKIPPED, reason=FRAME_MATCHED_PREVIOUS, frameFlags=0x%x", frameFlags);
}
// Have too many fast-refreshes occurred consecutively, since last full refresh?
@@ -328,7 +328,7 @@ void EInkDynamicDisplay::checkConsecutiveFastRefreshes()
if (frameFlags & UNLIMITED_FAST) {
refresh = FAST;
reason = NO_OBJECTIONS;
LOG_DEBUG("refresh=FAST, reason=UNLIMITED_FAST_MODE_ACTIVE, frameFlags=0x%x", frameFlags);
LOG_TRACE("refresh=FAST, reason=UNLIMITED_FAST_MODE_ACTIVE, frameFlags=0x%x", frameFlags);
return;
}
@@ -336,7 +336,7 @@ void EInkDynamicDisplay::checkConsecutiveFastRefreshes()
if (fastRefreshCount >= EINK_LIMIT_FASTREFRESH) {
refresh = FULL;
reason = EXCEEDED_LIMIT_FASTREFRESH;
LOG_DEBUG("refresh=FULL, reason=EXCEEDED_LIMIT_FASTREFRESH, frameFlags=0x%x", frameFlags);
LOG_TRACE("refresh=FULL, reason=EXCEEDED_LIMIT_FASTREFRESH, frameFlags=0x%x", frameFlags);
}
}
@@ -351,13 +351,13 @@ void EInkDynamicDisplay::checkFastRequested()
// If we want BACKGROUND to use fast. (FULL only when a limit is hit)
refresh = FAST;
reason = BACKGROUND_USES_FAST;
LOG_DEBUG("refresh=FAST, reason=BACKGROUND_USES_FAST, fastRefreshCount=%lu, frameFlags=0x%x", fastRefreshCount,
LOG_TRACE("refresh=FAST, reason=BACKGROUND_USES_FAST, fastRefreshCount=%lu, frameFlags=0x%x", fastRefreshCount,
frameFlags);
#else
// If we do want to use FULL for BACKGROUND updates
refresh = FULL;
reason = FLAGGED_BACKGROUND;
LOG_DEBUG("refresh=FULL, reason=FLAGGED_BACKGROUND");
LOG_TRACE("refresh=FULL, reason=FLAGGED_BACKGROUND");
#endif
}
@@ -365,7 +365,7 @@ void EInkDynamicDisplay::checkFastRequested()
if (frameFlags & RESPONSIVE) {
refresh = FAST;
reason = NO_OBJECTIONS;
LOG_DEBUG("refresh=FAST, reason=NO_OBJECTIONS, fastRefreshCount=%lu, frameFlags=0x%x", fastRefreshCount, frameFlags);
LOG_TRACE("refresh=FAST, reason=NO_OBJECTIONS, fastRefreshCount=%lu, frameFlags=0x%x", fastRefreshCount, frameFlags);
}
}
@@ -430,7 +430,7 @@ void EInkDynamicDisplay::countGhostPixels()
}
}
LOG_DEBUG("ghostPixels=%hu, ", ghostPixelCount);
LOG_TRACE("ghostPixels=%hu, ", ghostPixelCount);
}
// Check if ghost pixel count exceeds the defined limit
@@ -446,7 +446,7 @@ void EInkDynamicDisplay::checkExcessiveGhosting()
if (ghostPixelCount > EINK_LIMIT_GHOSTING_PX) {
refresh = FULL;
reason = EXCEEDED_GHOSTINGLIMIT;
LOG_DEBUG("refresh=FULL, reason=EXCEEDED_GHOSTINGLIMIT, frameFlags=0x%x", frameFlags);
LOG_TRACE("refresh=FULL, reason=EXCEEDED_GHOSTINGLIMIT, frameFlags=0x%x", frameFlags);
}
}
@@ -24,4 +24,4 @@ build_flags =
-D HAS_BUTTON=0 ; Suppress default ButtonThread
lib_deps =
# renovate: datasource=github-tags depName=GFX_Root packageName=ZinggJM/GFX_Root
https://github.com/ZinggJM/GFX_Root/archive/3195764e352a0d2567c8d277ac408ca7293a99b0.zip ; Used by InkHUD as a "slimmer" version of AdafruitGFX
https://github.com/ZinggJM/GFX_Root.git#3195764e352a0d2567c8d277ac408ca7293a99b0 ; Used by InkHUD as a "slimmer" version of AdafruitGFX
+1 -1
View File
@@ -96,7 +96,7 @@ template <typename T> class FlashData
f.close();
} else {
LOG_ERROR("Can't open / read %s", filename.c_str());
LOG_ERROR("Can't open/read %s", filename.c_str());
okay = false;
}
#else