feat: add logger and twilio poll backoff

docs/refactor/plan.md

@@ -14,11 +14,12 @@ This is a living note capturing the cleanups underway to keep `warelay` small an
 - Added prompt/wait helpers (`src/cli/{prompt,wait}.ts`) and Twilio sender discovery module (`src/twilio/senders.ts`).
 - Slimmed `src/index.ts` to ~130 LOC.
 - README updated to document direct WhatsApp Web support and Claude output handling.
+- Added zod validation for `~/.warelay/warelay.json` and a `--dry-run` flag for `send`.
+- Introduced a tiny logger (`src/logger.ts`) and backoff retry in Twilio polling.
 
 ## In this pass
-- Added config validation for inbound reply settings (claude output format, command/text shape).
+- Wire more modules to the logger; keep colors/verbosity consistent.
-- Added `--dry-run` for `send` to print the outbound payload without contacting providers.
+- Add minimal retries/backoff for webhook bring-up and port/Tailscale helpers.
-- Documented roadmap (this file).
 
 ## Next candidates (not yet done)
 - Centralize logging/verbosity (runtime-aware logger wrapper).

src/auto-reply/claude.test.ts

@@ -1,6 +1,6 @@
 import { describe, expect, it } from "vitest";
 
-import { parseClaudeJsonText } from "./claude.js";
+import { parseClaudeJson, parseClaudeJsonText } from "./claude.js";
 
 describe("claude JSON parsing", () => {
 	it("extracts text from single JSON object", () => {
@@ -16,5 +16,17 @@ describe("claude JSON parsing", () => {
 	it("returns undefined on invalid JSON", () => {
 		expect(parseClaudeJsonText("not json")).toBeUndefined();
 	});
-});
 
+	it("extracts text from Claude CLI result field and preserves metadata", () => {
+		const sample = {
+			type: "result",
+			subtype: "success",
+			result: "hello from result field",
+			duration_ms: 1234,
+			usage: { server_tool_use: { tool_a: 2 } },
+		};
+		const parsed = parseClaudeJson(JSON.stringify(sample));
+		expect(parsed?.text).toBe("hello from result field");
+		expect(parsed?.parsed).toMatchObject({ duration_ms: 1234 });
+	});
+});

src/auto-reply/claude.ts

@@ -16,6 +16,7 @@ function extractClaudeText(payload: unknown): string | undefined {
 	}
 	if (typeof payload === "object") {
 		const obj = payload as Record<string, unknown>;
+		if (typeof obj.result === "string") return obj.result;
 		if (typeof obj.text === "string") return obj.text;
 		if (typeof obj.completion === "string") return obj.completion;
 		if (typeof obj.output === "string") return obj.output;
@@ -45,17 +46,32 @@ function extractClaudeText(payload: unknown): string | undefined {
 	return undefined;
 }
 
-export function parseClaudeJsonText(raw: string): string | undefined {
+export type ClaudeJsonParseResult = {
-    // Handle a single JSON blob or newline-delimited JSON; return the first extracted text.
+	text?: string;
+	parsed: unknown;
+};
+
+export function parseClaudeJson(raw: string): ClaudeJsonParseResult | undefined {
+	// Handle a single JSON blob or newline-delimited JSON; return the first parsed payload.
+	let firstParsed: unknown;
 	const candidates = [raw, ...raw.split(/\n+/).map((s) => s.trim()).filter(Boolean)];
 	for (const candidate of candidates) {
 		try {
 			const parsed = JSON.parse(candidate);
+			if (firstParsed === undefined) firstParsed = parsed;
 			const text = extractClaudeText(parsed);
-			if (text) return text;
+			if (text) return { parsed, text };
 		} catch {
 			// ignore parse errors; try next candidate
 		}
 	}
+	if (firstParsed !== undefined) {
+		return { parsed: firstParsed, text: extractClaudeText(firstParsed) };
+	}
 	return undefined;
 }
+
+export function parseClaudeJsonText(raw: string): string | undefined {
+	const parsed = parseClaudeJson(raw);
+	return parsed?.text;
+}

src/auto-reply/reply.ts

@@ -1,7 +1,7 @@
 import crypto from "node:crypto";
 import path from "node:path";
 
-import { CLAUDE_BIN, parseClaudeJsonText } from "./claude.js";
+import { CLAUDE_BIN, parseClaudeJson } from "./claude.js";
 import {
 	applyTemplate,
 	type MsgContext,
@@ -39,6 +39,52 @@ type GetReplyOptions = {
 	onReplyStart?: () => Promise<void> | void;
 };
 
+function summarizeClaudeMetadata(payload: unknown): string | undefined {
+	if (!payload || typeof payload !== "object") return undefined;
+	const obj = payload as Record<string, unknown>;
+	const parts: string[] = [];
+
+	if (typeof obj.duration_ms === "number") {
+		parts.push(`duration=${obj.duration_ms}ms`);
+	}
+	if (typeof obj.duration_api_ms === "number") {
+		parts.push(`api=${obj.duration_api_ms}ms`);
+	}
+	if (typeof obj.num_turns === "number") {
+		parts.push(`turns=${obj.num_turns}`);
+	}
+	if (typeof obj.total_cost_usd === "number") {
+		parts.push(`cost=$${obj.total_cost_usd.toFixed(4)}`);
+	}
+
+	const usage = obj.usage;
+	if (usage && typeof usage === "object") {
+		const serverToolUse = (usage as { server_tool_use?: Record<string, unknown> })
+			.server_tool_use;
+		if (serverToolUse && typeof serverToolUse === "object") {
+			const toolCalls = Object.values(serverToolUse).reduce((sum, val) => {
+				if (typeof val === "number") return sum + val;
+				return sum;
+			}, 0);
+			if (toolCalls > 0) parts.push(`tool_calls=${toolCalls}`);
+		}
+	}
+
+	const modelUsage = obj.modelUsage;
+	if (modelUsage && typeof modelUsage === "object") {
+		const models = Object.keys(modelUsage as Record<string, unknown>);
+		if (models.length) {
+			const display =
+				models.length > 2
+					? `${models.slice(0, 2).join(",")}+${models.length - 2}`
+					: models.join(",");
+			parts.push(`models=${display}`);
+		}
+	}
+
+	return parts.length ? parts.join(", ") : undefined;
+}
+
 export async function getReplyFromConfig(
 	ctx: MsgContext,
 	opts?: GetReplyOptions,
@@ -216,18 +262,26 @@ export async function getReplyFromConfig(
 				finalArgv,
 				timeoutMs,
 			);
-			let trimmed = stdout.trim();
+			const rawStdout = stdout.trim();
+			let trimmed = rawStdout;
 			if (stderr?.trim()) {
 				logVerbose(`Command auto-reply stderr: ${stderr.trim()}`);
 			}
 			if (reply.claudeOutputFormat === "json" && trimmed) {
-				// Claude JSON mode: extract the human text for both logging and reply.
+				// Claude JSON mode: extract the human text for both logging and reply while keeping metadata.
-				const extracted = parseClaudeJsonText(trimmed);
+				const parsed = parseClaudeJson(trimmed);
-				if (extracted) {
+				if (parsed?.parsed && isVerbose()) {
+					const summary = summarizeClaudeMetadata(parsed.parsed);
+					if (summary) logVerbose(`Claude JSON meta: ${summary}`);
 					logVerbose(
-						`Claude JSON parsed -> ${extracted.slice(0, 120)}${extracted.length > 120 ? "…" : ""}`,
+						`Claude JSON raw: ${JSON.stringify(parsed.parsed, null, 2)}`,
 					);
-					trimmed = extracted.trim();
+				}
+				if (parsed?.text) {
+					logVerbose(
+						`Claude JSON parsed -> ${parsed.text.slice(0, 120)}${parsed.text.length > 120 ? "…" : ""}`,
+					);
+					trimmed = parsed.text.trim();
 				} else {
 					logVerbose("Claude JSON parse failed; returning raw stdout");
 				}

src/index.ts

@@ -20,7 +20,7 @@ import {
 	setMessagingServiceWebhook as setMessagingServiceWebhookImpl,
 } from "./twilio/update-webhook.js";
 import { listRecentMessages, formatMessageLine, uniqueBySid, sortByDateDesc } from "./twilio/messages.js";
-import { CLAUDE_BIN, parseClaudeJsonText } from "./auto-reply/claude.js";
+import { CLAUDE_BIN } from "./auto-reply/claude.js";
 import { applyTemplate, type MsgContext, type TemplateContext } from "./auto-reply/templating.js";
 import {
 	CONFIG_PATH,

src/logger.ts

@@ -0,0 +1,26 @@
+import { danger, info, success, warn, logVerbose, isVerbose } from "./globals.js";
+import { defaultRuntime, type RuntimeEnv } from "./runtime.js";
+
+export function logInfo(message: string, runtime: RuntimeEnv = defaultRuntime) {
+	runtime.log(info(message));
+}
+
+export function logWarn(message: string, runtime: RuntimeEnv = defaultRuntime) {
+	runtime.log(warn(message));
+}
+
+export function logSuccess(
+	message: string,
+	runtime: RuntimeEnv = defaultRuntime,
+) {
+	runtime.log(success(message));
+}
+
+export function logError(message: string, runtime: RuntimeEnv = defaultRuntime) {
+	runtime.error(danger(message));
+}
+
+export function logDebug(message: string) {
+	// Verbose helper that respects global verbosity flag.
+	if (isVerbose()) logVerbose(message);
+}

src/provider-web.ts

@@ -12,12 +12,13 @@ import {
 } from "@whiskeysockets/baileys";
 import pino from "pino";
 import qrcode from "qrcode-terminal";
-import { danger, info, isVerbose, logVerbose, success, warn } from "./globals.js";
+import { danger, isVerbose, logVerbose, success, warn } from "./globals.js";
 import { ensureDir, jidToE164, toWhatsappJid } from "./utils.js";
 import type { Provider } from "./utils.js";
 import { waitForever } from "./cli/wait.js";
 import { getReplyFromConfig } from "./auto-reply/reply.js";
 import { defaultRuntime, type RuntimeEnv } from "./runtime.js";
+import { logInfo, logWarn } from "./logger.js";
 
 const WA_WEB_AUTH_DIR = path.join(os.homedir(), ".warelay", "credentials");
 
@@ -319,14 +320,13 @@ export async function monitorWebProvider(
 		},
 	});
 
-	console.log(
+	logInfo(
-		info(
+		"📡 Listening for personal WhatsApp Web inbound messages. Leave this running; Ctrl+C to stop.",
-			"📡 Listening for personal WhatsApp Web inbound messages. Leave this running; Ctrl+C to stop.",
+		runtime,
-		),
 	);
 	process.on("SIGINT", () => {
 		void listener.close().finally(() => {
-			console.log("\n👋 Web monitor stopped");
+			logInfo("👋 Web monitor stopped", runtime);
 			runtime.exit(0);
 		});
 	});

src/twilio/monitor.ts

@@ -1,12 +1,12 @@
-import chalk from "chalk";
 import type { MessageInstance } from "twilio/lib/rest/api/v2010/account/message.js";
 
-import { danger, info, logVerbose, warn } from "../globals.js";
+import { danger, warn } from "../globals.js";
 import { sleep, withWhatsAppPrefix } from "../utils.js";
 import { defaultRuntime, type RuntimeEnv } from "../runtime.js";
 import { autoReplyIfConfigured } from "../auto-reply/reply.js";
 import { createClient } from "./client.js";
 import { readEnv } from "../env.js";
+import { logDebug, logInfo, logWarn } from "../logger.js";
 
 type MonitorDeps = {
 	autoReplyIfConfigured: typeof autoReplyIfConfigured;
@@ -58,19 +58,33 @@ export async function monitorTwilio(
 	const deps = opts?.deps ?? defaultDeps;
 	const runtime = opts?.runtime ?? defaultRuntime;
 	const maxIterations = opts?.maxIterations ?? Infinity;
+	let backoffMs = 1_000;
 
 	const env = deps.readEnv(runtime);
 	const from = withWhatsAppPrefix(env.whatsappFrom);
 	const client = opts?.client ?? deps.createClient(env);
-	console.log(
+	logInfo(
 		`📡 Monitoring inbound messages to ${from} (poll ${pollSeconds}s, lookback ${lookbackMinutes}m)`,
+		runtime,
 	);
 
 	let lastSeenSid: string | undefined;
 	let iterations = 0;
 	while (iterations < maxIterations) {
-		const messages =
+		let messages: ListedMessage[] = [];
-			(await deps.listRecentMessages(lookbackMinutes, 50, client)) ?? [];
+		try {
+			messages =
+				(await deps.listRecentMessages(lookbackMinutes, 50, client)) ?? [];
+			backoffMs = 1_000; // reset after success
+		} catch (err) {
+			logWarn(
+				`Twilio polling failed (will retry in ${backoffMs}ms): ${String(err)}`,
+				runtime,
+			);
+			await deps.sleep(backoffMs);
+			backoffMs = Math.min(backoffMs * 2, 10_000);
+			continue;
+		}
 		const inboundOnly = messages.filter((m) => m.direction === "inbound");
 		// Sort newest -> oldest without relying on external helpers (avoids test mocks clobbering imports).
 		const newestFirst = [...inboundOnly].sort(
@@ -95,7 +109,7 @@ async function handleMessages(
 	for (const m of messages) {
 		if (!m.sid) continue;
 		if (lastSeenSid && m.sid === lastSeenSid) break; // stop at previously seen
-		logVerbose(`[${m.sid}] ${m.from ?? "?"} -> ${m.to ?? "?"}: ${m.body ?? ""}`);
+		logDebug(`[${m.sid}] ${m.from ?? "?"} -> ${m.to ?? "?"}: ${m.body ?? ""}`);
 		if (m.direction !== "inbound") continue;
 		if (!m.from || !m.to) continue;
 		try {