From 4e6eab0a67c2cb53b54e24817bea40b0dec47a31 Mon Sep 17 00:00:00 2001 From: Joey Stanford Date: Sat, 8 Aug 2026 21:51:16 -0600 Subject: [PATCH 1/2] fix(logging): drop low-value noisy logs and false heartbeat errors Reduce log/support-bundle noise from hot paths that fire on timers or on every successful IPC while healthy, and stop a false-positive error: - MeshCore MQTT: log PINGREQ/PINGRESP once per connection (the pingReqLogged/pingRespLogged gates always logged); reset on reconnect. - Meshtastic SDK: skip routine TRACE [iMeshDevice] chatter and periodic DEBUG Ping heartbeats in forwardRendererConsoleMessage; keep INFO/WARN/ERROR and decode-failure TRACE lines (Foreign LoRa). - reticulumPeerStore: log full refresh only when slow (elapsed > 2000ms); drop the peers.size gate that logged every refresh at scale. - Remove routine processWaitingMessages start/done/skipped/empty debug, per-success IPC mqtt:publishMeshcorePacketLog debug, and clearDiagnostics debug; keep timeouts and real failures. - Fix duplicate "[renderer] Unhandled rejection: Packet does not exist" on Meshtastic heartbeat: both unhandledrejection listeners are at_target on window (fire in registration order, not capture-first), so the app-lifetime renderer logger logged before the per-session capture handler could preventDefault. Add a session-swallow ref-count so the renderer logger defers to the session handler. Adds tests for PING once-only (+reconnect reset), the SDK line filter, and the session-swallow deferral. --- src/main/index.ts | 1 - src/main/log-service.test.ts | 62 +++++++++++++++++ src/main/log-service.ts | 22 ++++++ src/main/meshcore-mqtt-adapter.test.ts | 68 +++++++++++++++++++ src/main/meshcore-mqtt-adapter.ts | 20 ++++-- .../hooks/meshcore/meshcoreConnSideEffects.ts | 45 ------------ .../meshtastic/meshtasticConfigureRetry.ts | 26 +++++++ .../meshtasticSdkRoutingErrorConsoleHook.ts | 6 ++ .../lib/rendererUnhandledRejection.test.ts | 37 ++++++++++ .../lib/rendererUnhandledRejection.ts | 16 ++++- src/renderer/stores/diagnosticsStore.ts | 1 - src/renderer/stores/reticulumPeerStore.ts | 2 +- 12 files changed, 251 insertions(+), 55 deletions(-) diff --git a/src/main/index.ts b/src/main/index.ts index f959f8843..23389acac 100644 --- a/src/main/index.ts +++ b/src/main/index.ts @@ -3247,7 +3247,6 @@ ipcMain.handle('mqtt:publishMeshcore', (event, args) => { ipcMain.handle('mqtt:publishMeshcorePacketLog', (event, args) => { assertIpcSender(event, 'mqtt:publishMeshcorePacketLog'); try { - console.debug('[IPC] mqtt:publishMeshcorePacketLog'); validateMqttPublishMeshcorePacketLogArgs(args); const a = args as { origin: string; diff --git a/src/main/log-service.test.ts b/src/main/log-service.test.ts index 5d7f7402b..cee4d6d32 100644 --- a/src/main/log-service.test.ts +++ b/src/main/log-service.test.ts @@ -352,6 +352,68 @@ describe('stripConsoleStyles (via appendLine + getRecentLines)', () => { }); }); +describe('isDroppableMeshtasticSdkLogLine', () => { + it('drops routine SDK TRACE [iMeshDevice] chatter', async () => { + const { isDroppableMeshtasticSdkLogLine } = await import('./log-service'); + expect( + isDroppableMeshtasticSdkLogLine( + '03:39:57:239 TRACE [iMeshDevice] HandleMeshPacket Received STORE_FORWARD_APP packet', + ), + ).toBe(true); + expect( + isDroppableMeshtasticSdkLogLine( + '01:25:29:719 TRACE [iMeshDevice] HandleFromRadio Received Queue Status', + ), + ).toBe(true); + }); + + it('drops periodic DEBUG [iMeshDevice] Ping heartbeats', async () => { + const { isDroppableMeshtasticSdkLogLine } = await import('./log-service'); + expect( + isDroppableMeshtasticSdkLogLine( + '01:25:29:561 DEBUG [iMeshDevice] Ping Send heartbeat ping to radio', + ), + ).toBe(true); + }); + + it('keeps INFO / WARN / ERROR SDK lines', async () => { + const { isDroppableMeshtasticSdkLogLine } = await import('./log-service'); + expect( + isDroppableMeshtasticSdkLogLine( + '00:56:01:200 WARN [iMeshDevice] HandleFromRadio Unhandled payload variant: deviceuiConfig', + ), + ).toBe(false); + expect( + isDroppableMeshtasticSdkLogLine( + '00:56:01:185 INFO [iMeshDevice] HandleFromRadio Received Node info for this device', + ), + ).toBe(false); + }); + + it('keeps non-Ping DEBUG lines', async () => { + const { isDroppableMeshtasticSdkLogLine } = await import('./log-service'); + expect( + isDroppableMeshtasticSdkLogLine( + '00:56:01:222 DEBUG [iMeshDevice] GetMetadata Received metadata packet', + ), + ).toBe(false); + }); + + it('keeps TRACE decode-failure lines needed by Foreign LoRa detection', async () => { + const { isDroppableMeshtasticSdkLogLine } = await import('./log-service'); + expect( + isDroppableMeshtasticSdkLogLine( + 'TRACE [iMeshDevice] HandleMeshPacket decode failed rssi -120 snr -8 3c 01 02', + ), + ).toBe(false); + }); + + it('keeps unrelated renderer/main lines', async () => { + const { isDroppableMeshtasticSdkLogLine } = await import('./log-service'); + expect(isDroppableMeshtasticSdkLogLine('[main] [MeshCore MQTT] PINGREQ sent')).toBe(false); + }); +}); + describe('formatRuntimeLogTag', () => { it('includes platform, arch, electron, node, packaged, and buildChannel fields', async () => { const { formatRuntimeLogTag } = await import('./log-service'); diff --git a/src/main/log-service.ts b/src/main/log-service.ts index 5f2a2ade8..e7a7b226f 100644 --- a/src/main/log-service.ts +++ b/src/main/log-service.ts @@ -384,6 +384,27 @@ export function patchMainConsole(): void { patchStream(process.stderr, 'warn', 'stderr'); } +/** + * Failure-context markers used by Foreign LoRa detection (see + * `src/renderer/lib/foreignLoraDetection.ts`). A TRACE line containing any of these + * is preserved so overheard decode-failure frames still reach the renderer. + */ +const SDK_FAILURE_CONTEXT_REGEX = + /packet.?dropped|crc.?err|crc.?fail|crc.?bad|bad.?crc|decode.?fail|decode.?error|corrupt.?packet|bad.?packet|invalid.?packet|preamble|rx.?error|lora.?err/i; + +/** + * True for high-volume `@meshtastic/core` console noise with no triage value: + * routine `TRACE [iMeshDevice]` chatter and periodic `DEBUG [iMeshDevice] Ping` + * heartbeats. INFO/WARN/ERROR and decode-failure TRACE lines are kept. + */ +export function isDroppableMeshtasticSdkLogLine(message: string): boolean { + if (/\bDEBUG \[iMeshDevice\] Ping\b/.test(message)) return true; + if (/\bTRACE \[iMeshDevice\]/.test(message) && !SDK_FAILURE_CONTEXT_REGEX.test(message)) { + return true; + } + return false; +} + /** * Renderer console-message (Electron 40+): single event object with message, level, lineNumber, sourceId. * level is 'info' | 'warning' | 'error' | 'debug'. @@ -406,5 +427,6 @@ export function forwardRendererConsoleMessage(details: { ? sanitizeLogMessage(`renderer:${path.basename(details.sourceId)}:${line}`) : 'renderer'; const msg = sanitizeLogMessage(stripConsoleStyles(details.message)); + if (isDroppableMeshtasticSdkLogLine(msg)) return; appendLine(mapped, src, msg); } diff --git a/src/main/meshcore-mqtt-adapter.test.ts b/src/main/meshcore-mqtt-adapter.test.ts index 5c025ffb4..0a53e989f 100644 --- a/src/main/meshcore-mqtt-adapter.test.ts +++ b/src/main/meshcore-mqtt-adapter.test.ts @@ -73,6 +73,74 @@ describe('MeshcoreMqttAdapter — topicPrefix wildcards', () => { ); }); +describe('MeshcoreMqttAdapter — PING logging', () => { + let adapter: MeshcoreMqttAdapter; + + beforeEach(async () => { + const mqtt = await import('mqtt'); + vi.mocked(mqtt.connect).mockClear(); + adapter = new MeshcoreMqttAdapter(); + adapter.on('error', () => {}); + }); + + afterEach(() => { + adapter.disconnect(); + vi.restoreAllMocks(); + }); + + const lastHandler = ( + client: { on: ReturnType }, + name: string, + ): ((packet: { cmd: string }) => void) => { + const hits = client.on.mock.calls.filter((c: unknown[]) => c[0] === name); + return hits[hits.length - 1]?.[1] as (packet: { cmd: string }) => void; + }; + + it('logs PINGREQ and PINGRESP only once per connection', async () => { + const debugSpy = vi.spyOn(console, 'debug').mockImplementation(() => {}); + const mqttMod = await import('mqtt'); + adapter.connect({ ...BASE_SETTINGS }); + const client = vi.mocked(mqttMod.connect).mock.results.at(-1)!.value as { + on: ReturnType; + }; + const onSend = lastHandler(client, 'packetsend'); + const onReceive = lastHandler(client, 'packetreceive'); + + onSend({ cmd: 'pingreq' }); + onSend({ cmd: 'pingreq' }); + onSend({ cmd: 'pingreq' }); + onReceive({ cmd: 'pingresp' }); + onReceive({ cmd: 'pingresp' }); + + const reqLogs = debugSpy.mock.calls.filter((c) => String(c[0]).includes('PINGREQ')); + const respLogs = debugSpy.mock.calls.filter((c) => String(c[0]).includes('PINGRESP')); + expect(reqLogs).toHaveLength(1); + expect(respLogs).toHaveLength(1); + }); + + it('re-logs PINGREQ once after a reconnect (flags reset)', async () => { + const debugSpy = vi.spyOn(console, 'debug').mockImplementation(() => {}); + const mqttMod = await import('mqtt'); + + adapter.connect({ ...BASE_SETTINGS }); + let client = vi.mocked(mqttMod.connect).mock.results.at(-1)!.value as { + on: ReturnType; + }; + lastHandler(client, 'packetsend')({ cmd: 'pingreq' }); + lastHandler(client, 'packetsend')({ cmd: 'pingreq' }); + + adapter.disconnect(); + adapter.connect({ ...BASE_SETTINGS }); + client = vi.mocked(mqttMod.connect).mock.results.at(-1)!.value as { + on: ReturnType; + }; + lastHandler(client, 'packetsend')({ cmd: 'pingreq' }); + + const reqLogs = debugSpy.mock.calls.filter((c) => String(c[0]).includes('PINGREQ')); + expect(reqLogs).toHaveLength(2); + }); +}); + describe('MeshcoreMqttAdapter — clientId', () => { let adapter: MeshcoreMqttAdapter; diff --git a/src/main/meshcore-mqtt-adapter.ts b/src/main/meshcore-mqtt-adapter.ts index 9c0ab4251..3afa7fa09 100644 --- a/src/main/meshcore-mqtt-adapter.ts +++ b/src/main/meshcore-mqtt-adapter.ts @@ -311,6 +311,8 @@ export class MeshcoreMqttAdapter extends EventEmitter { settings.tlsInsecure === true, ); this.firstMessageLogged = false; + this.pingReqLogged = false; + this.pingRespLogged = false; this.setStatus('connecting'); this.connectAbortByWatchdog = false; this.client = mqtt.connect(connectOpts); @@ -405,16 +407,22 @@ export class MeshcoreMqttAdapter extends EventEmitter { this.scheduleTokenRefresh(); }); this.client.on('packetsend', (packet) => { - if (packet.cmd === 'pingreq') { - this.pingReqLogged = false; - console.debug('[MeshCore MQTT] PINGREQ sent', new Date().toISOString()); + if (packet.cmd === 'pingreq' && !this.pingReqLogged) { + this.pingReqLogged = true; + console.debug( + '[MeshCore MQTT] PINGREQ sent (first this session)', + new Date().toISOString(), + ); } }); this.client.on('packetreceive', (packet) => { this.lastPacketReceivedAt = Date.now(); - if (packet.cmd === 'pingresp') { - this.pingRespLogged = false; - console.debug('[MeshCore MQTT] PINGRESP received', new Date().toISOString()); + if (packet.cmd === 'pingresp' && !this.pingRespLogged) { + this.pingRespLogged = true; + console.debug( + '[MeshCore MQTT] PINGRESP received (first this session)', + new Date().toISOString(), + ); } }); this.client.on('message', (topic, payload) => { diff --git a/src/renderer/hooks/meshcore/meshcoreConnSideEffects.ts b/src/renderer/hooks/meshcore/meshcoreConnSideEffects.ts index 1f828cfde..ba54e39ed 100644 --- a/src/renderer/hooks/meshcore/meshcoreConnSideEffects.ts +++ b/src/renderer/hooks/meshcore/meshcoreConnSideEffects.ts @@ -243,18 +243,8 @@ async function drainWaitingMessagesManual( deps.setWaitingMessagesCount(total); deps.setWaitingMessagesSyncProgress({ processed: 0, total }); } else if (total === 0) { - console.debug('[meshcoreConnSideEffects] processWaitingMessages empty queue (manual sync)'); return; } - console.debug( - '[meshcoreConnSideEffects] processWaitingMessages start ' + - JSON.stringify({ - count: total, - showSyncBanner: true, - connectionType: deps.connectionType, - mode: 'manual', - }), - ); for (const m of arr) { if (!deps.meshcoreHookMountedRef.current) break; await ingestMeshcoreWaitingMessageItem(m, state, deps); @@ -317,14 +307,6 @@ async function drainWaitingMessagesSilent( deps: MeshcoreWaitingMessagesDrainDeps, ): Promise { const attemptId = beginMeshcoreSilentBulkAttempt(); - console.debug( - '[meshcoreConnSideEffects] processWaitingMessages start ' + - JSON.stringify({ - showSyncBanner: false, - connectionType: deps.connectionType, - mode: 'silent-bulk', - }), - ); try { const msgs = await withTimeout( @@ -339,7 +321,6 @@ async function drainWaitingMessagesSilent( if (!deps.meshcoreHookMountedRef.current) return; const arr = normalizeMeshcoreWaitingMessageBatch(msgs); if (arr.length === 0) { - console.debug('[meshcoreConnSideEffects] processWaitingMessages empty queue (silent bulk)'); return; } state.syncTotal = arr.length; @@ -382,14 +363,6 @@ async function drainWaitingMessagesSilent( state.syncTotal = 0; state.progressActive = true; deps.setWaitingMessagesSyncProgress({ processed: 0, total: 0 }); - console.debug( - '[meshcoreConnSideEffects] processWaitingMessages start ' + - JSON.stringify({ - showSyncBanner: false, - connectionType: deps.connectionType, - mode: 'silent-fallback', - }), - ); if (!deps.meshcoreHookMountedRef.current) return; await drainWaitingMessagesIncremental(conn, state, deps); return; @@ -408,7 +381,6 @@ async function runMeshcoreWaitingMessagesDrain( options: { showSyncBanner: boolean }, deps: MeshcoreWaitingMessagesDrainDeps, ): Promise { - const startedAt = Date.now(); const state: MeshcoreWaitingMessagesDrainState = { processed: 0, bannerActive: false, @@ -429,22 +401,6 @@ async function runMeshcoreWaitingMessagesDrain( } else { await drainWaitingMessagesSilent(conn, state, deps); } - console.debug( - '[meshcoreConnSideEffects] processWaitingMessages done ' + - JSON.stringify({ - count: state.processed, - durationMs: Date.now() - startedAt, - showSyncBanner: options.showSyncBanner, - connectionType: deps.connectionType, - mode: options.showSyncBanner - ? 'manual' - : state.syncTotal > 0 - ? 'silent-bulk' - : state.processed > 0 || state.progressActive - ? 'silent-fallback' - : 'silent', - }), - ); } finally { if (silentDrainUiActive) { deps.setWaitingMessagesSilentDrainActive(false); @@ -646,7 +602,6 @@ export function attachMeshcoreConnSideEffects( } else { requestMeshcoreWaitingMessagesFollowUp(); } - console.debug('[meshcoreConnSideEffects] processWaitingMessages skipped (in flight)'); return getMeshcoreProcessWaitingMessagesInFlight()!; } const showSyncBanner = options?.showSyncBanner !== false; diff --git a/src/renderer/lib/meshtastic/meshtasticConfigureRetry.ts b/src/renderer/lib/meshtastic/meshtasticConfigureRetry.ts index 2ed6935e8..fb420bba6 100644 --- a/src/renderer/lib/meshtastic/meshtasticConfigureRetry.ts +++ b/src/renderer/lib/meshtastic/meshtasticConfigureRetry.ts @@ -11,6 +11,32 @@ const CONFIGURE_RETRYABLE_PATTERN = /packet does not exist/i; let lateConfigureRetryableSwallowUntilMs = 0; +/** + * Ref-count of installed Meshtastic session unhandled-rejection swallow handlers. While > 0, the + * capture-phase handler owns `Packet does not exist` teardown-race rejects, so the app-lifetime + * renderer logger must defer instead of logging them as errors (both listeners are at_target on + * `window`, so registration order — not the capture flag — decides who runs first). + */ +let sessionRejectionSwallowDepth = 0; + +export function beginMeshtasticSessionRejectionSwallow(): void { + sessionRejectionSwallowDepth++; +} + +export function endMeshtasticSessionRejectionSwallow(): void { + sessionRejectionSwallowDepth = Math.max(0, sessionRejectionSwallowDepth - 1); +} + +/** True while a Meshtastic session rejection-swallow handler is installed. */ +export function isMeshtasticSessionRejectionSwallowActive(): boolean { + return sessionRejectionSwallowDepth > 0; +} + +/** Test-only: reset the session swallow ref-count. */ +export function resetMeshtasticSessionRejectionSwallowForTests(): void { + sessionRejectionSwallowDepth = 0; +} + export function isMeshtasticConfigureRetryableError(err: unknown): boolean { return CONFIGURE_RETRYABLE_PATTERN.test(errLikeToLogString(err)); } diff --git a/src/renderer/lib/meshtastic/meshtasticSdkRoutingErrorConsoleHook.ts b/src/renderer/lib/meshtastic/meshtasticSdkRoutingErrorConsoleHook.ts index 853f4d2d2..0ffeb533d 100644 --- a/src/renderer/lib/meshtastic/meshtasticSdkRoutingErrorConsoleHook.ts +++ b/src/renderer/lib/meshtastic/meshtasticSdkRoutingErrorConsoleHook.ts @@ -1,6 +1,8 @@ import { errLikeToLogString } from '../errLikeToLogString'; import { armMeshtasticLateConfigureRetryableSwallow, + beginMeshtasticSessionRejectionSwallow, + endMeshtasticSessionRejectionSwallow, isMeshtasticConfigureRetryableError, } from './meshtasticConfigureRetry'; import { @@ -79,8 +81,12 @@ export function installMeshtasticSdkRoutingErrorUnhandledRejectionHandler( }; // Capture phase so preventDefault runs before the bubble-phase renderer logger. window.addEventListener('unhandledrejection', handler, { capture: true }); + // Mark a session swallow active so the app-lifetime renderer logger defers to this handler + // even though at_target listeners fire in registration order (renderer logger is installed first). + beginMeshtasticSessionRejectionSwallow(); return () => { window.removeEventListener('unhandledrejection', handler, { capture: true }); + endMeshtasticSessionRejectionSwallow(); // Late SDK queue rejects can settle after wire-effects teardown removes this handler. armMeshtasticLateConfigureRetryableSwallow(); }; diff --git a/src/renderer/lib/rendererUnhandledRejection.test.ts b/src/renderer/lib/rendererUnhandledRejection.test.ts index 7ffa518e9..32ac3bb8b 100644 --- a/src/renderer/lib/rendererUnhandledRejection.test.ts +++ b/src/renderer/lib/rendererUnhandledRejection.test.ts @@ -3,7 +3,10 @@ import { afterEach, describe, expect, it, vi } from 'vitest'; import { armMeshtasticLateConfigureRetryableSwallow, + beginMeshtasticSessionRejectionSwallow, + endMeshtasticSessionRejectionSwallow, resetMeshtasticLateConfigureRetryableSwallowForTests, + resetMeshtasticSessionRejectionSwallowForTests, } from './meshtastic/meshtasticConfigureRetry'; import { installRendererUnhandledRejectionLogger, @@ -50,6 +53,7 @@ function dispatchUnhandledRejection( describe('installRendererUnhandledRejectionLogger', () => { afterEach(() => { resetMeshtasticLateConfigureRetryableSwallowForTests(); + resetMeshtasticSessionRejectionSwallowForTests(); vi.restoreAllMocks(); }); @@ -97,6 +101,39 @@ describe('installRendererUnhandledRejectionLogger', () => { ); }); + it('defers Packet does not exist to the active session swallow handler (no error log)', () => { + const errorSpy = vi.spyOn(console, 'error').mockImplementation(() => {}); + const debugSpy = vi.spyOn(console, 'debug').mockImplementation(() => {}); + const uninstall = installRendererUnhandledRejectionLogger(); + beginMeshtasticSessionRejectionSwallow(); + + const event = dispatchUnhandledRejection(new Error('Packet does not exist')); + uninstall(); + + expect(event.defaultPrevented).toBe(true); + expect(errorSpy).not.toHaveBeenCalled(); + // The bubble logger defers silently; the capture-phase session handler owns the debug line. + expect(debugSpy).not.toHaveBeenCalled(); + + endMeshtasticSessionRejectionSwallow(); + }); + + it('still logs unrelated rejections while a session swallow handler is active', () => { + const errorSpy = vi.spyOn(console, 'error').mockImplementation(() => {}); + const uninstall = installRendererUnhandledRejectionLogger(); + beginMeshtasticSessionRejectionSwallow(); + + dispatchUnhandledRejection(new Error('genuine failure')); + uninstall(); + + expect(errorSpy).toHaveBeenCalledWith( + '[renderer] Unhandled rejection:', + expect.stringContaining('genuine failure'), + ); + + endMeshtasticSessionRejectionSwallow(); + }); + it('does not log Packet does not exist during armed late-swallow window', () => { const errorSpy = vi.spyOn(console, 'error').mockImplementation(() => {}); const debugSpy = vi.spyOn(console, 'debug').mockImplementation(() => {}); diff --git a/src/renderer/lib/rendererUnhandledRejection.ts b/src/renderer/lib/rendererUnhandledRejection.ts index 7633cf41e..fb058b866 100644 --- a/src/renderer/lib/rendererUnhandledRejection.ts +++ b/src/renderer/lib/rendererUnhandledRejection.ts @@ -1,4 +1,8 @@ -import { shouldSwallowLateMeshtasticConfigureRetryableRejection } from './meshtastic/meshtasticConfigureRetry'; +import { + isMeshtasticConfigureRetryableError, + isMeshtasticSessionRejectionSwallowActive, + shouldSwallowLateMeshtasticConfigureRetryableRejection, +} from './meshtastic/meshtasticConfigureRetry'; /** Log renderer-wide unhandled promise rejections without throwing a second error. */ export function logRendererUnhandledRejection(reason: unknown): void { @@ -13,6 +17,16 @@ export function installRendererUnhandledRejectionLogger(target: Window = window) const handler = (event: PromiseRejectionEvent) => { // Capture-phase Meshtastic handler may have already preventDefault'd queue rejections. if (event.defaultPrevented) return; + // While a Meshtastic session swallow handler is installed, it owns the mid-send + // `Packet does not exist` teardown race. This bubble handler is registered first, so it runs + // before the capture handler at_target — defer (no error log) and let it log + preventDefault. + if ( + isMeshtasticSessionRejectionSwallowActive() && + isMeshtasticConfigureRetryableError(event.reason) + ) { + event.preventDefault(); + return; + } // Only during a short post-teardown window (armed when Meshtastic session handler unsubscribes). if (shouldSwallowLateMeshtasticConfigureRetryableRejection(event.reason)) { console.debug( diff --git a/src/renderer/stores/diagnosticsStore.ts b/src/renderer/stores/diagnosticsStore.ts index 3e70396fb..6c592bc15 100644 --- a/src/renderer/stores/diagnosticsStore.ts +++ b/src/renderer/stores/diagnosticsStore.ts @@ -1584,7 +1584,6 @@ export const useDiagnosticsStore = create((set, get) => ({ clearDiagnostics(options) { const preserveForeignLora = options?.preserveForeignLora === true; - console.debug(`[diagnosticsStore] clearDiagnostics preserveForeignLora=${preserveForeignLora}`); if (diagnosticsDebounce.incrementalAnalysisTimer) clearTimeout(diagnosticsDebounce.incrementalAnalysisTimer); diagnosticsDebounce.incrementalAnalysisTimer = null; diff --git a/src/renderer/stores/reticulumPeerStore.ts b/src/renderer/stores/reticulumPeerStore.ts index 291b6f111..e9c7ef6e2 100644 --- a/src/renderer/stores/reticulumPeerStore.ts +++ b/src/renderer/stores/reticulumPeerStore.ts @@ -1261,7 +1261,7 @@ async function refreshReticulumPeersFromSidecarOnce( } const elapsed = (typeof performance !== 'undefined' ? performance.now() : Date.now()) - started; - if (elapsed > 2000 || peers.size > 2000) { + if (elapsed > 2000) { console.debug( `[reticulumPeerStore] full refresh ${Math.round(elapsed)}ms peers=${peers.size} force=${Boolean(opts.forceRefresh)}`, ); From ee34c903e649437da9371424f939cf10c6b4ee2f Mon Sep 17 00:00:00 2001 From: Joey Stanford Date: Sat, 8 Aug 2026 22:00:09 -0600 Subject: [PATCH 2/2] fix(meshtastic): auto-request recipient key on PKI DM send failure When an outbound DM fails with PKI_SEND_FAIL_PUBLIC_KEY or PKI_UNKNOWN_PUBKEY the recipient's public key is missing from the NodeDB, so a manual retry would fail identically. Trigger the existing rate-limited NODEINFO request for the recipient node so the key lands in the NodeDB and a retry can succeed. - Add isMeshtasticMissingRecipientKeyError() and an optional onMissingRecipientKey(recipientNodeNum) callback to the routing-error apply context; fire it for DM rows (broadcast rows carry no recipient) after the row is marked failed. - Wire maybeRequestNodeInfoForNode (NODEINFO_APP, 120s/node rate limit) into both the console-log and queue-rejection apply paths. - Tests: NODEINFO requested for PKI missing-key DM rows; not requested for non-key errors, broadcast rows, or unmatched packets; predicate unit test. MAX_RETRANSMIT is unchanged (already fails with manual retry available). --- .../meshtasticRuntimeWireEffects.ts | 2 + .../meshtasticSdkRoutingErrorLog.test.ts | 65 ++++++++++++++++++- .../meshtasticSdkRoutingErrorLog.ts | 14 ++++ 3 files changed, 80 insertions(+), 1 deletion(-) diff --git a/src/renderer/lib/meshtastic/meshtasticRuntimeWireEffects.ts b/src/renderer/lib/meshtastic/meshtasticRuntimeWireEffects.ts index 112e55ab4..0bc1e5147 100644 --- a/src/renderer/lib/meshtastic/meshtasticRuntimeWireEffects.ts +++ b/src/renderer/lib/meshtastic/meshtasticRuntimeWireEffects.ts @@ -834,6 +834,7 @@ export function attachMeshtasticRuntimeWireEffects( myNodeNum: myNodeNumRef.current, identityId: meshtasticIdentityIdRef.current, tempIdToWirePacketId: ackMeshPacketIdByTempIdRef.current, + onMissingRecipientKey: maybeRequestNodeInfoForNode, }); }; @@ -842,6 +843,7 @@ export function attachMeshtasticRuntimeWireEffects( myNodeNum: myNodeNumRef.current, identityId: meshtasticIdentityIdRef.current, tempIdToWirePacketId: ackMeshPacketIdByTempIdRef.current, + onMissingRecipientKey: maybeRequestNodeInfoForNode, }); if (!uiApplied) { const parsed = reason as { id?: number; packetId?: number; error?: number }; diff --git a/src/renderer/lib/meshtastic/meshtasticSdkRoutingErrorLog.test.ts b/src/renderer/lib/meshtastic/meshtasticSdkRoutingErrorLog.test.ts index 9142d478d..ef53b95bd 100644 --- a/src/renderer/lib/meshtastic/meshtasticSdkRoutingErrorLog.test.ts +++ b/src/renderer/lib/meshtastic/meshtasticSdkRoutingErrorLog.test.ts @@ -34,6 +34,7 @@ import { applyMeshtasticOutboundRoutingErrorFromRejection, chatRoutingErrorKeyForSdkErrorName, humanizeMeshtasticSdkQueueRejectionError, + isMeshtasticMissingRecipientKeyError, parseMeshtasticSdkQueueRejection, parseMeshtasticSdkRoutingErrorLog, } from './meshtasticSdkRoutingErrorLog'; @@ -48,6 +49,7 @@ interface SeedRow { channelIndex?: number; timestamp?: number; from?: number; + to?: number; } function clearStoreMessages(): void { @@ -66,7 +68,7 @@ function seedOutbound(rows: SeedRow[]): void { id: String(row.packetId), from: row.from ?? 42, senderName: 'Me', - to: 0xffffffff, + to: row.to ?? 0xffffffff, payload: row.payload ?? 'hello', channelIndex: row.channelIndex ?? 0, timestamp: row.timestamp ?? Date.now(), @@ -271,6 +273,67 @@ describe('meshtasticSdkRoutingErrorLog', () => { ).toBeTruthy(); expect(humanizeMeshtasticSdkQueueRejectionError('x')).toBeNull(); }); + + it('requests recipient NODEINFO on PKI_SEND_FAIL_PUBLIC_KEY for a DM row', () => { + seedOutbound([{ packetId: 669520633, to: 0x1234 }]); + const onMissingRecipientKey = vi.fn(); + const applied = applyMeshtasticOutboundRoutingErrorFromLog( + 'Error received for packet 669520633: PKI_SEND_FAIL_PUBLIC_KEY', + { myNodeNum: 42, identityId: IDENTITY, onMissingRecipientKey }, + ); + expect(applied).toBe(true); + expect(onMissingRecipientKey).toHaveBeenCalledWith(0x1234); + }); + + it('requests recipient NODEINFO on PKI_UNKNOWN_PUBKEY for a DM row', () => { + seedOutbound([{ packetId: 669520633, to: 0xabcd }]); + const onMissingRecipientKey = vi.fn(); + applyMeshtasticOutboundRoutingErrorFromLog( + 'Error received for packet 669520633: PKI_UNKNOWN_PUBKEY', + { myNodeNum: 42, identityId: IDENTITY, onMissingRecipientKey }, + ); + expect(onMissingRecipientKey).toHaveBeenCalledWith(0xabcd); + }); + + it('does not request NODEINFO for non-key routing errors', () => { + seedOutbound([{ packetId: 711859058, to: 0x1234 }]); + const onMissingRecipientKey = vi.fn(); + applyMeshtasticOutboundRoutingErrorFromLog('Packet 711859058 of type packet timed out', { + myNodeNum: 42, + identityId: IDENTITY, + onMissingRecipientKey, + }); + expect(onMissingRecipientKey).not.toHaveBeenCalled(); + }); + + it('does not request NODEINFO for a broadcast row (no recipient)', () => { + seedOutbound([{ packetId: 669520633 }]); + const onMissingRecipientKey = vi.fn(); + const applied = applyMeshtasticOutboundRoutingErrorFromLog( + 'Error received for packet 669520633: PKI_SEND_FAIL_PUBLIC_KEY', + { myNodeNum: 42, identityId: IDENTITY, onMissingRecipientKey }, + ); + expect(applied).toBe(true); + expect(onMissingRecipientKey).not.toHaveBeenCalled(); + }); + + it('does not request NODEINFO when no outbound row matches', () => { + seedOutbound([]); + const onMissingRecipientKey = vi.fn(); + const applied = applyMeshtasticOutboundRoutingErrorFromLog( + 'Error received for packet 669520633: PKI_SEND_FAIL_PUBLIC_KEY', + { myNodeNum: 42, identityId: IDENTITY, onMissingRecipientKey }, + ); + expect(applied).toBe(false); + expect(onMissingRecipientKey).not.toHaveBeenCalled(); + }); + + it('classifies missing recipient key errors', () => { + expect(isMeshtasticMissingRecipientKeyError('PKI_SEND_FAIL_PUBLIC_KEY')).toBe(true); + expect(isMeshtasticMissingRecipientKeyError('PKI_UNKNOWN_PUBKEY')).toBe(true); + expect(isMeshtasticMissingRecipientKeyError('MAX_RETRANSMIT')).toBe(false); + expect(isMeshtasticMissingRecipientKeyError('TIMEOUT')).toBe(false); + }); }); describe('installMeshtasticSdkRoutingErrorConsoleHook', () => { diff --git a/src/renderer/lib/meshtastic/meshtasticSdkRoutingErrorLog.ts b/src/renderer/lib/meshtastic/meshtasticSdkRoutingErrorLog.ts index c916a2e99..4b8f12b70 100644 --- a/src/renderer/lib/meshtastic/meshtasticSdkRoutingErrorLog.ts +++ b/src/renderer/lib/meshtastic/meshtasticSdkRoutingErrorLog.ts @@ -69,6 +69,14 @@ export function humanizeMeshtasticSdkQueueRejectionError(reason: unknown): strin return i18nKey ? i18n.t(i18nKey) : parsed.errorName; } +/** + * True for routing errors that mean we lack a usable public key for the DM recipient. + * Requesting the recipient's NODEINFO can recover the key so a retry succeeds. + */ +export function isMeshtasticMissingRecipientKeyError(errorName: string): boolean { + return errorName === 'PKI_SEND_FAIL_PUBLIC_KEY' || errorName === 'PKI_UNKNOWN_PUBKEY'; +} + export function chatRoutingErrorKeyForSdkErrorName(errorName: string): string | null { switch (errorName) { case 'PKI_SEND_FAIL_PUBLIC_KEY': @@ -98,6 +106,8 @@ export interface ApplyMeshtasticOutboundRoutingErrorContext { identityId: string | null; /** tempId → wire packet id assigned by the SDK (may differ from optimistic id). */ tempIdToWirePacketId?: ReadonlyMap; + /** Invoked with the recipient node num when a DM fails for lack of that node's public key. */ + onMissingRecipientKey?: (recipientNodeNum: number) => void; } function outboundMatchesWirePacketId( @@ -191,6 +201,10 @@ export function applyMeshtasticOutboundRoutingError( } const storeMessageId = resolveStoreMessageId(target, parsed.packetId); updateMessageStatus(identityId, storeMessageId, 'failed', errorText); + // Missing recipient public key: fetch the recipient's NODEINFO so a retry can succeed. + if (isMeshtasticMissingRecipientKeyError(parsed.errorName) && target.to != null) { + ctx.onMissingRecipientKey?.(target.to); + } // The DB row may still hold the optimistic temp packet id (device never acked, // so updateMessagePacketId never ran) — key the update on the row's own id, // not the wire id from the radio NAK, or the UPDATE matches zero rows.