fix: quiet noisy logs, stop false heartbeat errors, and auto-recover PKI DM key failures

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;

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');

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

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<typeof vi.fn> },
+    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<typeof vi.fn>;
+    };
+    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<typeof vi.fn>;
+    };
+    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<typeof vi.fn>;
+    };
+    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;
 

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) => {

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<void> {
   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<void> {
-  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;

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

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

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();
   };