Logging, Runtime Events, and testing

Corresponding source

Subject	Source
Turn logs and state trace	nanobot/agent/loop.py::AgentLoop._process_message
Hooks, progress, and observability callbacks	nanobot/agent/hook.py, nanobot/agent/progress_hook.py
User messages and runtime events	nanobot/bus/events.py, nanobot/bus/runtime_events.py
WebSocket event adaptation	nanobot/channels/websocket.py
CLI/Gateway logging entry	nanobot/cli/commands.py::agent, nanobot/cli/gateway.py
Layered tests	tests/agent/, tests/providers/, tests/channels/, tests/tools/, tests/security/, tests/session/

Learning objectives

After this lesson, you should be able to:

• distinguish logs, state traces, runtime events, MessageBus messages, and persistent history;
• choose the smallest observation set for one Turn;
• verify source behavior with adjacent tests instead of reading implementation alone;
• choose an appropriate test layer for a new feature.

Prerequisites

• Complete Persistence, response, and runtime events.
• Run one pytest file or test function.
• Know why a mock/fake Provider controls model output and avoids real-network nondeterminism.

1. Do not conflate five evidence types

Evidence	Question it answers	Primary location
Logs	Which exception or important action occurred at runtime?	loguru.logger calls
StateTraceEntry	How long did each Turn state take, and did it fail?	nanobot/agent/loop.py
RuntimeEvent	Which high-level runtime state should a UI/subscriber observe?	nanobot/bus/runtime_events.py
Inbound/OutboundMessage	How does a business message travel between entry point and core?	nanobot/bus/events.py
Session/Memory files	Which state survives a restart?	persisted workspace files

For example, a running Tool can appear in a log, Agent progress Hook, and checkpoint at once, but those artifacts have different consumers and lifetimes. RuntimeEventBus itself currently defines no Tool-progress event.

2. Logs: A narrative for developers

nanobot uses Loguru. CLI initialization removes the default handler and adds output containing time, level, and source. The agent command provides:

--logs / --no-logs

Relevant locations:

• logger setup near the top of nanobot/cli/commands.py;
• nanobot/cli/commands.py::agent;
• file/service logging setup in nanobot/cli/gateway.py.

When debugging a request, search for stable fragments such as:

• Processing message from
• Registered ... tools
• LLM transient error
• Task cancelled for session
• Error processing message for session
• Shutdown: flushed ... session(s)

Disabling logs does not disable events

--no-logs controls nanobot logger output. It does not remove MessageBus, RuntimeEventBus, or Session persistence.

3. State trace: A local profile of the Turn state machine

TurnContext.trace stores StateTraceEntry records containing:

• state
• duration_ms
• event
• error

AgentLoop._process_message() times each state handler and appends an entry. It is best for answering:

• Did the Turn stop in BUILD, RUN, or SAVE?
• Did one state take unexpectedly long?
• Did the handler raise?

It is not global distributed tracing and does not automatically connect spans inside external Provider or Tool services.

4. Runtime events: Structured state for runtime surfaces

RuntimeEventBus publishes dataclass events. Subscribers such as the WebSocket coordinator convert them to their own protocol. The exact current set is:

• SessionTurnStarted;
• TurnRunStatusChanged;
• TurnCompleted;
• GoalStateChanged;
• RuntimeModelChanged.

Text deltas, reasoning deltas, and Tool start/end are not RuntimeEventBus dataclasses. They travel through AgentHook, ProgressHook, and caller callbacks before SDK, Channel, or WebSocket adapters convert them to their own events.

The governing principle is:

High-level Agent-core state belongs in RuntimeEventBus; fine-grained streaming progress belongs in Hooks/callbacks; WebUI-specific envelopes, sequence numbers, replay, and JSON fields belong at the WebSocket boundary.

This lets SDK, WebUI, and future runtime surfaces reuse the same core semantics without putting a frontend protocol in AgentRunner.

Key locations:

• nanobot/bus/runtime_events.py
• nanobot/agent/hook.py
• nanobot/agent/progress_hook.py
• nanobot/channels/websocket.py

5. Usage and latency

Runner accumulates Provider usage across iterations. If a Provider returns no usage, the current implementation estimates it and sets estimated_tokens. AgentLoop saves _last_usage, and the progress Hook records prompt, completion, and cached tokens.

Turn latency is:

• held by RuntimeEventPublisher and included in TurnCompleted;
• written to the final assistant message during SAVE;
• displayed in the WebUI transcript.

When debugging cost, distinguish Provider-reported tokens from nanobot estimates. estimated_tokens is not a billing fact.

6. Minimal observation set for one Turn

For a beginner, start with four observation points:

flowchart LR
    A["Inbound message<br/>Channel / Session Key"] --> B["Turn trace<br/>state / duration"]
    B --> C["Runner result<br/>stop_reason / Tools / usage"]
    C --> D["Session JSONL<br/>final persistence"]

Add runtime events and WebSocket frames only for a WebUI progress or reconnection problem. Add retry metadata only for a transient Provider failure.

This keeps you from getting lost in dozens of event types.

7. Tests are an executable specification

nanobot tests broadly mirror source responsibility:

Subject	Tests to read first
Turn state and persistence	tests/agent/test_loop_runner_integration.py, test_loop_save_turn.py
Runner core	tests/agent/test_runner_core.py
Tool calling	tests/agent/test_runner_tool_execution.py
Injection	tests/agent/test_runner_injections.py
Runtime events	tests/agent/test_loop_progress.py
Session	tests/session/
Provider	tests/providers/
WebSocket	tests/channels/test_websocket_channel.py
Tool	tests/tools/
Security	tests/security/ and security-related Tool tests

Source explains how behavior is implemented. Tests state more directly which inputs the maintainers expect to produce which observable results.

8. Recommended way to read a test

For one behavior:

1. find the test whose name most closely matches the question;
2. identify the fake Provider, fixture, and initial Session;
3. write down the triggering action;
4. read only assertions and describe the observable contract;
5. return to source and explain why the assertions hold;
6. for a modification experiment, copy only the required test and dependencies into learning-EN/examples or a separate temporary workspace. Do not modify code-EN, and do not start with the entire test suite.

For example, to understand concurrent Tools, begin with:

• tests/agent/test_loop_tool_context.py
• tests/agent/test_runner_tool_execution.py

Then verify Tool.concurrency_safe and _partition_tool_batches().

9. Layered verification

Change type	Minimum verification
Tool-only logic	matching tests/tools/test_*.py
Runner behavior	fake Provider + tests/agent/test_runner_*.py
Loop state/Session	tests/agent/test_loop_*.py + adjacent Session tests
Channel protocol	matching Channel test without a real platform
WebUI data contract	Python WebSocket/API tests + webui frontend tests
Packaging	Python package build + WebUI build/output check

A real DeepSeek request is a final smoke test, not a replacement for deterministic unit tests.

10. Boundaries

Passing tests do not prove production safety

Unit tests commonly control DNS, filesystem, Provider, and time. A real system still needs configuration review, permission boundaries, credential protection, and deployment-layer sandboxing.

Runtime events are not an audit log

They serve runtime progress and UI state and may be short-lived, in-memory, and replayable only within a limited window. Do not rely on them alone for durable auditing.

Self-check

1. For “the model call is slow,” should you inspect logs or state trace first, and why?
2. How should documentation describe token usage when the Provider did not report it?
3. Why should AgentRunner not construct a WebSocket envelope?
4. Why is a real DeepSeek request not the minimum test for a new Tool?

Next: Workspace, Shell, and SSRF security boundaries