Merge pull request 'LLM timeout default 60 s → 180 s (v0.21.4)' (#47) from fix/llm-timeout into main

Production incident: '#rss get lublin' at 9:41 AM failed with 'The operation
was aborted due to timeout' — the LlmService call hit its 60 s cap while the
local OpenAI-compatible server (qwen3.8-27b, uncontrollable reasoning tokens)
was slow/busy. The same endpoint answers a trivial prompt in ~1 s when idle,
so this is latency variance on the server side, not a dead endpoint.

Bump the LLM_TIMEOUT_MS fallback from 60000 to 180000 (3 min headroom for
slow reasoning periods); still env-overridable, only the default changed.

AGENTS.md

@@ -12,7 +12,7 @@
 ## Verification
 
 1. **Local checks** — `npm run build` (nest build) and `npm test` (vitest; no e2e suite yet). Both must pass before a PR is opened.
-2. **Docker** — `docker compose build`, then after `docker compose up -d`: `curl -s -H "Host: bot.dev.kkhost.pl" http://localhost/api/status` returns JSON (`{ connected, myNodeNum, host, port }`). `"connected":false` is normal while the bridge/device is down — the service retries every 5 s. An idle watchdog also force-reconnects an ESTABLISHED-but-silent connection (zombie bridge: outbound works, inbound dead) when no DECODED FRAME arrives from the bridge for `MESH_IDLE_TIMEOUT_MS` ms (default 600000 = 10 min; checked every 30 s — raw non-frame bytes do NOT count), an undecoded frame buffer over `MESH_MAX_FRAME_BUFFER` bytes (default 256000) forces a reconnect as a stream-desync backstop, and the socket has TCP keepalive enabled (30 s).
+2. **Docker** — `docker compose build`, then after `docker compose up -d`: `curl -s -H "Host: bot.dev.kkhost.pl" http://localhost/api/status` returns JSON (`{ connected, myNodeNum, host, port }`). `"connected":false` is normal while the bridge/device is down — the service retries every 5 s. An idle watchdog also force-reconnects an ESTABLISHED-but-silent connection (zombie bridge: outbound works, inbound dead) when no DECODED FRAME arrives from the bridge for `MESH_IDLE_TIMEOUT_MS` ms (default 60000 = 1 min; checked every 30 s — raw non-frame bytes do NOT count), an undecoded frame buffer over `MESH_MAX_FRAME_BUFFER` bytes (default 256000) forces a reconnect as a stream-desync backstop, and the socket has TCP keepalive enabled (30 s). A lazy periodic autoreconnect additionally unconditionally re-establishes every `MESH_RECONNECT_INTERVAL_MS` ms (default 300000 = 5 min) for a fresh sync.
 
 ## API
 
@@ -28,4 +28,4 @@
 - MESHTASTIC.md — rules for Meshtastic communication (owner authority, language, response protocol); read before acting on mesh messages.
 - Hourly cron weather report job (`src/weather`): fetches Open-Meteo current conditions and broadcasts a one-line report to the mesh on the pinned send channel; env `WEATHER_CRON`/`WEATHER_LAT`/`WEATHER_LON`/`WEATHER_CITY`.
 - Channel-2 auto-responder (`src/commands`): event-driven — `CommandService.onRx()` is called by `MeshService` for every decoded rx text (right after the notify gate) and dispatches exact, case-sensitive `#command` matches on `COMMAND_CHANNEL` (env, default 2) through a single-registration-point registry (handlers registered in the constructor via `register(name, fn)`; handler gets `{ text, from?, id? }`, returns a reply string — or an array of lines, sent as one message per line through the same routing — or void = no reply). First command: `#ping` → replies `#pong!`. Replies go through `MeshService.respond(id, reply)`: auto-routed (rx → DM back to the original sender unless the original was a broadcast; tx → its destination), riding the original record's channel with `replyId = id` so the recipient app renders it as a threaded quote — `COMMAND_CHANNEL` is only the trigger/listen gate. Only when the trigger has no packet id does it fall back to legacy sendText routing on `COMMAND_CHANNEL`. A failing handler/respond only logs a warn. DI: provided by `CommandModule`'s factory (injects `MeshService`, attaches itself via `attachCommands()`) — no constructor-level cycle; `forwardRef` was tried and left one side null in NestJS 12's injector. Prefix dispatch (`registerPrefix(name, fn)`) lets one handler own a whole family: the `#rss` subcommands live in `src/rss` (`RssService.handle`, registered as prefix `'rss'` from the CommandModule factory — exact matches still win over prefixes). Subcommands: `#rss help`; `#rss add <url> <name>` (validates URL, fetches with 15 s timeout, requires ≥1 titled item, rejects duplicate names case-insensitively; LLM generates 2-4 lowercase tags from up to 8 latest titles — on LLM failure the source is added with empty tags and the reply says so); `#rss remove <name>`; `#rss tags` (all distinct tags); `#rss sources`; `#rss get <name|#tag>` (LLM headline summary as 3-5 SEPARATE mesh messages: prompt asks for exactly 3-5 lines, one item per line, `<short header>: <one or two short sentences>` with ≤20-char header, no intro/outro/numbering; reply parsed into items — drop empty/separator-less lines, cap at 5, fewer than 3 → send what we got (no retry), zero → no message; each item sent via its own respond() threaded to the trigger packet id, per-line backstop `fitOneLine()` hard-cuts >185-char lines at a word boundary near 180 so every item fits one packet; maxTokens 2500 is headroom because the LLM server's reasoning tokens count against it — see rss.service.ts comment; `#tag` collects items across ALL sources carrying that tag — one dead feed does not sink the summary). Storage: `rss_sources(name TEXT PRIMARY KEY, url, tags, created_at)` table in the EXISTING MESH_DB_PATH file via a second node:sqlite connection (names matched case-insensitively); feed parsing via `fast-xml-parser` (RSS 2.0 + Atom; malformed/no-items → "not a valid feed"); LLM via injected `LlmService.chat()` with explicit maxTokens (50 tags / 2500 summary headroom).
-- LLM client (`src/llm`): `LlmService` wraps the local OpenAI-compatible server (default `http://192.168.1.70:1111/v1`, no auth) with native fetch — plain feature module, no Mesh/Schedule dependency. Methods: `listModels()` → `data[].id`; `chat(messages, { maxTokens?, temperature? })` → `choices[0].message.content` (non-2xx throws with status + body snippet); `summarize(text)` = chat() with system prompt "Summarize the following text concisely." Env: `LLM_API_BASE`, `LLM_MODEL` (default `qwen3.8-27b`), `LLM_TIMEOUT_MS` (default 60000, via `AbortSignal.timeout`).
+- LLM client (`src/llm`): `LlmService` wraps the local OpenAI-compatible server (default `http://192.168.1.70:1111/v1`, no auth) with native fetch — plain feature module, no Mesh/Schedule dependency. Methods: `listModels()` → `data[].id`; `chat(messages, { maxTokens?, temperature? })` → `choices[0].message.content` (non-2xx throws with status + body snippet); `summarize(text)` = chat() with system prompt "Summarize the following text concisely." Env: `LLM_API_BASE`, `LLM_MODEL` (default `qwen3.8-27b`), `LLM_TIMEOUT_MS` (default 180000, via `AbortSignal.timeout`).

CHANGELOG.md

@@ -1,5 +1,15 @@
 # Changelog
 
+## v0.21.4 — 2026-09-26 09:51
+
+- `LLM_TIMEOUT_MS` default raised from 60000 (60 s) to **180000** (3 min): production incident — `#rss get lublin` at 9:41 AM failed with "The operation was aborted due to timeout" because the local OpenAI-compatible server (qwen3.8-27b, uncontrollable reasoning tokens) was slow/busy on that call; the same endpoint answers a trivial prompt in ~1 s when idle, so this is latency variance, not a dead endpoint. Still env-overridable (`LLM_TIMEOUT_MS`), only the fallback changed.
+
+## v0.21.3 — 2026-09-26 09:31
+
+- Idle timeout default lowered from 10 min to **1 min** (`MESH_IDLE_TIMEOUT_MS` fallback `600000` → `60000`) — the v0.21.2 frame-based watchdog works in production (it fired today and the reconnect delivered queued packets), but the bridge/radio side at 192.168.1.4 keeps killing inbound RX within ~20 min of a fresh sync, so a shorter detection window is wanted.
+- New **lazy periodic autoreconnect**: `MESH_RECONNECT_INTERVAL_MS` (new env, default **300000** = 5 min, read at construction) — an interval that unconditionally logs ("periodic reconnect — MESH_RECONNECT_INTERVAL_MS elapsed") and destroys the socket so the existing close→scheduleReconnect loop re-establishes with a fresh sync on schedule. When not connected at tick time, destroy is a no-op and the retry loop owns recovery (no special-casing). Started in `onModuleInit`, cleared in `onModuleDestroy`.
+- Tests: 171 → 172 — periodic reconnect observed end-to-end with an overridden short interval (fake bridge disconnect + re-establish); existing watchdog tests pass unchanged, comments updated to the new 60 s default.
+
 ## v0.21.2 — 2026-09-26 08:47
 
 - Idle watchdog now tracks DECODED FRAMES, not raw bytes (fixes a second production zombie that slipped past v0.21.1): text+telemetry RX was dead for >1 h while TX worked and the watchdog never fired — /proc/net/snmp showed InSegs delta = 2 segments per 30 s, i.e. the bridge peer keeps dribbling small NON-frame bytes (~every 15 s) that kept resetting `lastPacketAt` on every socket chunk even though zero valid Meshtastic frames decoded. The `'data'` handler no longer updates `lastPacketAt` per chunk; it is updated only when `extractFrames` yields ≥1 valid packet (the reset in the `'connect'` handler is unchanged), so a stream that decodes nothing trips the watchdog after `MESH_IDLE_TIMEOUT_MS` even while raw bytes keep arriving.

package.json

@@ -1,6 +1,6 @@
 {
   "name": "mesh-bot",
-  "version": "0.21.2",
+  "version": "0.21.4",
   "description": "",
   "author": "",
   "private": true,

src/llm/llm.service.ts

@@ -12,9 +12,9 @@ export class LlmService {
   private readonly apiBase =
     process.env.LLM_API_BASE ?? 'http://192.168.1.70:1111/v1';
   private readonly model = process.env.LLM_MODEL ?? 'qwen3.8-27b';
-  // local 27B model can be slow — generous default
+  // local 27B model can be slow (uncontrollable reasoning tokens) — generous default: 3 min headroom for slow reasoning periods
   private readonly timeoutMs = parseInt(
-    process.env.LLM_TIMEOUT_MS ?? '60000',
+    process.env.LLM_TIMEOUT_MS ?? '180000',
     10,
   );
 

src/mesh/mesh.service.spec.ts

@@ -258,7 +258,7 @@ describe('MeshService idle watchdog', () => {
     process.env.MESH_HOST = '127.0.0.1';
     process.env.MESH_PORT = String(bridge.port);
     process.env.MESH_RECONNECT_MS = '50'; // fast retry so the re-establishment is observable
-    process.env.MESH_IDLE_TIMEOUT_MS = '100'; // override — the default (600000) would never fire in a test
+    process.env.MESH_IDLE_TIMEOUT_MS = '100'; // override — the default (60000) would never fire in a test
     const svc = new MeshService();
     try {
       svc.onModuleInit();
@@ -285,7 +285,7 @@ describe('MeshService idle watchdog', () => {
     process.env.MESH_HOST = '127.0.0.1';
     process.env.MESH_PORT = String(bridge.port);
     process.env.MESH_RECONNECT_MS = '50'; // fast retry so the re-establishment is observable
-    process.env.MESH_IDLE_TIMEOUT_MS = '100'; // override — the default (600000) would never fire in a test
+    process.env.MESH_IDLE_TIMEOUT_MS = '100'; // override — the default (60000) would never fire in a test
     const svc = new MeshService();
     try {
       svc.onModuleInit();
@@ -376,7 +376,7 @@ describe('MeshService idle watchdog', () => {
     const bridge = await startBridge();
     process.env.MESH_HOST = '127.0.0.1';
     process.env.MESH_PORT = String(bridge.port);
-    delete process.env.MESH_IDLE_TIMEOUT_MS; // default 600000 — a test can't wait that long, so silence must NOT fire
+    delete process.env.MESH_IDLE_TIMEOUT_MS; // default 60000 — a test can't wait that long, so silence must NOT fire
     const svc = new MeshService();
     try {
       svc.onModuleInit();
@@ -414,6 +414,31 @@ describe('MeshService idle watchdog', () => {
   });
 });
 
+describe('MeshService periodic autoreconnect', () => {
+  it('unconditionally reconnects when MESH_RECONNECT_INTERVAL_MS elapses', async () => {
+    const bridge = await startBridge();
+    process.env.MESH_HOST = '127.0.0.1';
+    process.env.MESH_PORT = String(bridge.port);
+    process.env.MESH_RECONNECT_MS = '50'; // fast retry so the re-establishment is observable
+    process.env.MESH_RECONNECT_INTERVAL_MS = '100'; // override — the default (300000) would never elapse in a test
+    const svc = new MeshService();
+    try {
+      svc.onModuleInit();
+      await waitFor(
+        () => bridge.sockets.length === 1 && svc.status().connected,
+      );
+
+      // interval fires → destroy → existing close/retry loop re-establishes with a fresh session
+      await waitFor(() => bridge.sockets.length >= 2 && svc.status().connected);
+    } finally {
+      delete process.env.MESH_RECONNECT_MS;
+      delete process.env.MESH_RECONNECT_INTERVAL_MS;
+      svc.onModuleDestroy();
+      bridge.close();
+    }
+  });
+});
+
 describe('MeshService send', () => {
   it('sends on the test channel (index 3) by default, never primary', async () => {
     const bridge = await startBridge();

src/mesh/mesh.service.ts

@@ -212,7 +212,12 @@ export class MeshService implements OnModuleInit, OnModuleDestroy {
   private readonly pollMs = parseInt(process.env.MESH_POLL_MS ?? '1000', 10);
   // idle watchdog: force a reconnect when an ESTABLISHED connection stops decoding frames — the zombie-bridge case where outbound sends keep working but inbound frame flow is dead (raw non-frame bytes do NOT reset the clock). Read at construction like the other env config.
   private readonly idleTimeoutMs = parseInt(
-    process.env.MESH_IDLE_TIMEOUT_MS ?? '600000',
+    process.env.MESH_IDLE_TIMEOUT_MS ?? '60000',
+    10,
+  );
+  // lazy periodic autoreconnect: unconditionally destroy + re-establish every N ms so a fresh sync happens on schedule — the bridge/radio side tends to kill inbound RX within ~20 min of a fresh sync. Read at construction like the other env config.
+  private readonly reconnectIntervalMs = parseInt(
+    process.env.MESH_RECONNECT_INTERVAL_MS ?? '300000',
     10,
   );
   // cap on undecoded frame buffer: a desynced stream that never forms frames would grow it without bound — force a reconnect instead. Env-overridable so tests can trigger it (Node caps socket 'data' events at ~64 KB).
@@ -270,6 +275,7 @@ export class MeshService implements OnModuleInit, OnModuleDestroy {
   /** epoch ms when the last valid frame was decoded from the bridge; reset on connect — idle watchdog baseline */
   private lastPacketAt = Date.now();
   private idleTimer: NodeJS.Timeout | null = null;
+  private periodicReconnectTimer: NodeJS.Timeout | null = null;
   private shuttingDown = false;
 
   onModuleInit(): void {
@@ -281,6 +287,13 @@ export class MeshService implements OnModuleInit, OnModuleDestroy {
     }
     // idle watchdog: catches established-but-silent connections (zombie bridge) that the connect/retry loop never sees
     this.idleTimer = setInterval(() => this.checkIdle(), IDLE_CHECK_MS);
+    // lazy periodic autoreconnect: unconditional fresh sync on a fixed schedule; when not connected, destroy is a no-op and the retry loop owns recovery
+    this.periodicReconnectTimer = setInterval(() => {
+      this.logger.log(
+        'periodic reconnect — MESH_RECONNECT_INTERVAL_MS elapsed',
+      );
+      this.socket?.destroy();
+    }, this.reconnectIntervalMs);
     this.connect();
   }
 
@@ -289,6 +302,7 @@ export class MeshService implements OnModuleInit, OnModuleDestroy {
     if (this.reconnectTimer) clearTimeout(this.reconnectTimer);
     if (this.pollTimer) clearInterval(this.pollTimer);
     if (this.idleTimer) clearInterval(this.idleTimer);
+    if (this.periodicReconnectTimer) clearInterval(this.periodicReconnectTimer);
     this.socket?.destroy();
     this.db?.close();
   }