File logging is dead code: setup_logging() is never called, so logger.warning/exception diagnostics from daemonized agents are lost

[huangzesen]

Summary

lingtai_kernel/logging.py ships a full file-logging path (setup_logging(verbose=..., log_dir=...) writing agent.log), but nothing in src/ ever calls setup_logging() with arguments — every one of the ~20 modules that logs goes through get_logger(), which falls back to setup_logging() with defaults: an INFO-level stderr console handler and no file handler. Since agents run as fully detached daemons, operationally important logger.warning(..., exc_info=True) diagnostics (e.g. mail-claim failures in src/lingtai_kernel/services/mail.py) either vanish entirely or land in a stderr capture file that is truncated on every respawn. The fix is to wire setup_logging(log_dir=<working_dir>/logs) into agent boot in src/lingtai/cli.py — or, if the JSONL/SQLite event log is meant to be the only durable sink, delete the dead log_dir/verbose parameters. The current half-state is the worst of both.

Narrative

The kernel has a small package-logging module, src/lingtai_kernel/logging.py. It exposes two functions. setup_logging(verbose, log_dir, logger_name) configures the "lingtai" logger: a console StreamHandler (DEBUG if verbose else INFO), and — if log_dir is given — a FileHandler writing agent.log at DEBUG level:

# src/lingtai_kernel/logging.py:33-40
if log_dir is not None:
    log_path = Path(log_dir)
    log_path.mkdir(parents=True, exist_ok=True)
    fh = logging.FileHandler(log_path / "agent.log")
    fh.setLevel(logging.DEBUG)
    ...

get_logger() returns the configured logger, lazily calling setup_logging() with no arguments if it hasn't run yet (src/lingtai_kernel/logging.py:46-51).

A grep across src/ shows roughly twenty call sites that bind logger = get_logger() at import time or inside hot paths: every LLM adapter (src/lingtai/llm/anthropic/adapter.py:26, src/lingtai/llm/openai/adapter.py:47, src/lingtai/llm/gemini/adapter.py:31, src/lingtai/llm/claude_code/adapter.py:37, src/lingtai/llm/minimax/adapter.py:4, src/lingtai/llm/openai/codex_ws.py:43), the mail service (src/lingtai_kernel/services/mail.py), MCP wiring (src/lingtai/services/mcp.py:18, src/lingtai/agent.py:487-488 and 627-628), all websearch/vision providers, plus kernel internals (src/lingtai_kernel/session.py:50, src/lingtai_kernel/base_agent/turn.py:32, src/lingtai_kernel/base_agent/lifecycle.py:154, src/lingtai_kernel/token_counter.py:15, src/lingtai_kernel/llm_utils.py:14). What the grep does not show is any call to setup_logging() with log_dir or verbose — not in src/lingtai/cli.py's main()/run() (the agent entry point), not in src/lingtai/agent.py, nowhere. The entire file-logging branch and the verbose knob are dead code. The only logging sink that ever exists is the default stderr console handler at INFO.

That would be tolerable for a foreground CLI. But LingTai agents are daemons. When an agent spawns an avatar, src/lingtai/core/avatar/__init__.py:634-673 launches python -m lingtai run <dir> with stdin=DEVNULL, stdout=DEVNULL, start_new_session=True, and stderr redirected to logs/spawn.stderr opened in "wb" mode — i.e. truncated on every spawn/respawn/refresh. So an avatar's logger output survives only until the next relaunch, with %H:%M:%S-only timestamps (no date) from the console formatter. And a primary agent launched by external supervision (the lingtai companion tooling, cron, a shell nohup) has whatever stderr disposition its launcher chose — often nothing at all.

Concretely, consider the pseudo-agent mail claim path. FilesystemMailService implements a careful claim/rollback protocol, and when the own-inbox write fails it logs the one diagnostic that would explain a silently dropped-then-retried message:

# src/lingtai_kernel/services/mail.py:344-349
except OSError:
    logger.warning(
        "failed to write claimed pseudo-agent message %s to own inbox",
        uuid_name,
        exc_info=True,
    )

Today, for a daemonized agent, that warning and its traceback go to a detached process's stderr and are lost (or get clobbered by the next respawn's spawn.stderr truncation). The same is true of every adapter retry warning, MCP spawn failure, and the chat-history restore warning in src/lingtai_kernel/base_agent/lifecycle.py:154. A user whose agent is misbehaving has no agent.log to read, even though the code to produce one has existed all along.

How did the design get here? The repo grew a much richer structured observability stack — logs/events.jsonl, logs/token_ledger.jsonl, and the rebuildable logs/log.sqlite sidecar (see src/lingtai/core/daemon/run_dir.py:34-35 and the lingtai-agent log rebuild/doctor/query subcommands in src/lingtai/cli.py:364-375). Those capture events (tool calls, CLI output, token usage), but they are not a logging sink: none of the logger.warning/logger.exception calls flow into them. setup_logging's file path was presumably meant to be wired into boot and never was. There is even a logs/ directory convention per agent working dir already — agent.log has an obvious home.

Better looks like: run() in src/lingtai/cli.py calls setup_logging(log_dir=working_dir / "logs") before building the agent, with rotation so a long-lived daemon can't fill the disk, and setup_logging made idempotent/reconfigurable so refresh boots and tests don't stack duplicate handlers. Because every module binds the same "lingtai" logger object returned by logging.getLogger(), import-time logger = get_logger() bindings pick up the file handler automatically — no call-site changes needed.

Current behavior

• src/lingtai_kernel/logging.py:9-43 — setup_logging(verbose, log_dir, logger_name) exists; the log_dir branch (lines 33-40) and the verbose parameter are never exercised by any caller in src/.
• src/lingtai_kernel/logging.py:46-51 — get_logger() lazily calls setup_logging() with defaults; this is the only configuration path that ever runs: stderr console handler at INFO, no file handler.
• src/lingtai/cli.py:212- (run()) and :352-428 (main()) — agent boot never calls setup_logging; there is no --verbose flag on the run subcommand (src/lingtai/cli.py:359-360).
• src/lingtai/core/avatar/__init__.py:634-673 (_launch) — children run detached with stdout=DEVNULL and stderr redirected to logs/spawn.stderr, opened "wb" (truncated) per launch.
• src/lingtai_kernel/services/mail.py:344-349 and :456-460 — recovery-path warnings with exc_info=True that currently have no durable destination.
• Latent bug in src/lingtai_kernel/logging.py: the console handler is guarded by if not logger.handlers: (line 25) but the file-handler block is not — calling setup_logging(log_dir=...) twice would attach duplicate FileHandlers. Harmless today only because nobody calls it.

Detailed implementation plan

1. Make setup_logging idempotent and rotation-safe (src/lingtai_kernel/logging.py):

   • Replace the bare FileHandler with logging.handlers.RotatingFileHandler (e.g. maxBytes=5_000_000, backupCount=3) so daemons cannot grow agent.log unboundedly.
   • Guard against duplicate handlers: before adding the file handler, skip if a FileHandler for the same resolved agent.log path is already attached; when re-invoked with verbose, update the existing console handler's level instead of relying on the if not logger.handlers guard silently ignoring it.
   • Add a reset_logging() helper (clears handlers, sets _logger = None) for tests.

   def setup_logging(verbose=False, log_dir=None, logger_name="lingtai"):
       logger = logging.getLogger(logger_name)
       logger.setLevel(logging.DEBUG)
       console = next((h for h in logger.handlers
                       if isinstance(h, logging.StreamHandler)
                       and not isinstance(h, logging.FileHandler)), None)
       if console is None:
           console = logging.StreamHandler()
           console.setFormatter(_console_fmt)
           logger.addHandler(console)
       console.setLevel(logging.DEBUG if verbose else logging.INFO)
       if log_dir is not None:
           target = Path(log_dir) / "agent.log"
           if not any(isinstance(h, logging.FileHandler)
                      and Path(getattr(h, "baseFilename", "")) == target.resolve()
                      for h in logger.handlers):
               target.parent.mkdir(parents=True, exist_ok=True)
               fh = RotatingFileHandler(target, maxBytes=5_000_000, backupCount=3)
               fh.setLevel(logging.DEBUG)
               fh.setFormatter(_file_fmt)
               logger.addHandler(fh)
       ...

2. Wire it into agent boot (src/lingtai/cli.py): in run() (currently starting at line 212), immediately after _clean_signal_files(working_dir) and before load_init(...) (so migration/init warnings are captured too), add:

   from lingtai_kernel.logging import setup_logging
   setup_logging(
       verbose=os.environ.get("LINGTAI_VERBOSE") == "1",
       log_dir=working_dir / "logs",
   )

   Optionally add --verbose to the run subparser (src/lingtai/cli.py:359-360) and OR it with the env var. Do not call setup_logging(log_dir=...) for the check-caps, log, or maintenance subcommands — those are short-lived inspectors and must not create/touch logs/agent.log (lingtai-agent log rebuild scans specific filenames per src/lingtai/core/daemon/run_dir.py:598-611, so agent.log will not confuse the SQLite rebuild, but keeping inspectors write-free is still the right default).

3. Give the file formatter full context: file handler formatter should include date + module, e.g. "%(asctime)s %(levelname)s %(name)s %(module)s: %(message)s" (default asctime already includes the date; keep the terse %H:%M:%S datefmt only on the console handler).

4. Documentation: mention logs/agent.log alongside logs/events.jsonl / logs/log.sqlite in src/lingtai/core/daemon/run_dir.py's layout docstring (lines 30-40) and in the doctor/system-manual references (src/lingtai/intrinsic_skills/lingtai-doctor/scripts/doctor.py "notifications/logs/mail" section can check for its presence), so operators know where daemon diagnostics live.

5. Back-compat: no schema or data migration needed. logs/ already exists per working dir (avatar _launch pre-creates it, src/lingtai/core/avatar/__init__.py:655-658). Existing deployments simply gain a new file. Refresh relaunches (.refresh.taken path in run()) re-enter run() in a fresh process, so the idempotency guard matters mainly within one process (tests, future callers), and rotation handles append-across-restarts.

6. Alternative (if maintainers decide file logging is unwanted): delete the log_dir/verbose parameters and the file branch from setup_logging, collapse it into get_logger(), and instead route logging records into the structured event stream via a custom logging.Handler that appends log events to logs/events.jsonl. Either way, resolve the half-state — pick one and remove the dead surface.

Risks and alternatives

• Duplicate log volume: warnings will now appear on stderr and in agent.log. That is intended (stderr for foreground/spawn.stderr, file for durability); rotation caps the cost. If it bothers anyone, drop the console handler level to WARNING when a file handler is active.
• Disk growth: mitigated by RotatingFileHandler; without rotation this change would be a regression for long-lived daemons, which is why step 1 precedes step 2.
• Handler duplication across refresh/molt: guarded explicitly in step 1; the current unguarded file-handler block would otherwise double-log after any second setup_logging call in-process.
• Multiple agents, one process: setup_logging configures a process-global "lingtai" logger keyed by log_dir; the runtime is one-agent-per-process (_check_duplicate_process, flock), so this is fine today, but the docstring should say so.
• Alternative — route stdlib logging into logs/events.jsonl/SQLite: attractive (single sink, queryable via lingtai-agent log query), but bigger: it needs a JSONL event schema for log records, rebuild-tool awareness, and care that logging inside the event writer can't recurse. Plain rotating agent.log is a 20-line change that makes the existing dead code do its job; the event-stream integration can layer on later.
• Alternative — just delete the dead parameters: smallest diff, but it forfeits the only mechanism for capturing exc_info tracebacks from daemonized agents; spawn.stderr truncation makes stderr non-durable, so deletion is only acceptable together with the event-stream handler above.

Testing plan

• tests/test_logging_setup.py::test_setup_logging_creates_agent_log — call setup_logging(log_dir=tmp_path), emit get_logger().warning("x"), assert tmp_path / "agent.log" exists and contains the message.
• tests/test_logging_setup.py::test_setup_logging_idempotent — call setup_logging(log_dir=tmp_path) twice, emit one warning, assert it appears exactly once in agent.log (guards the current duplicate-FileHandler bug).
• tests/test_logging_setup.py::test_verbose_reconfigures_console_level — call setup_logging() then setup_logging(verbose=True), assert the console handler level is DEBUG (today the second call is a no-op).
• tests/test_logging_setup.py::test_exc_info_traceback_lands_in_file — log with exc_info=True inside an except block; assert the traceback text is present in agent.log (mirrors the services/mail.py claim-failure path).
• tests/test_logging_setup.py::test_rotation_caps_file_size — set a tiny maxBytes via monkeypatch/parameter, write past it, assert agent.log.1 appears.
• tests/test_cli.py::test_run_wires_file_logging — invoke run() against a minimal agent dir fixture (see tests/_agent_dir_helpers.py) far enough to pass boot setup (or monkeypatch build_agent to raise after logging setup), assert working_dir/logs/agent.log was created.
• tests/test_cli.py::test_log_subcommands_do_not_create_agent_log — run lingtai-agent log doctor <dir> on a fixture dir, assert no logs/agent.log is created.
• Update tests/conftest.py to call the new reset_logging() between tests so the module-global _logger and handler state cannot leak across the 200+ existing test files.

Generated by a Claude Fable 5 deep review of the lingtai-kernel codebase.