# Logs: Latency and First Message

## Where to look

1. **Terminal** (when you run `uv run python src/agent.py dev`): real-time `[LATENCY]` and `[EVENT]` lines.
2. **JSON logs** in `logs/*.json`: per-session config and per-message latency (LLM, TTS, e2e).

---

## 1. Latency: STT, TTS, LLM – where is most time spent?

### In the terminal

Each user→bot turn prints:

- **`[LATENCY] User turn (speaking + STT final): X ms`**  
  Time from user started speaking until final transcript. This is **user speech + STT** (we don’t log “STT only”).
- **`[LATENCY] LLM (user_commit -> agent_response): X ms`**  
  Time from final user transcript to assistant text ready → **LLM**.
- **`[LATENCY] TTS (agent_response -> first audio): X ms`**  
  Time from assistant text to first audio chunk → **TTS**.
- **`[LATENCY] End-to-end (user_commit -> first audio): X ms`**  
  Full turn: user commit → first bot audio.

So in the terminal you can see **LLM vs TTS** per turn. The “User turn” line is **STT + speaking**, not STT alone.

### In the JSON logs

For each **bot** message, the log may include:

- **`latency_llm_ms`** – LLM time (user commit → agent text).
- **`latency_tts_ms`** – TTS time (agent text → first audio).
- **`latency_e2e_ms`** – End-to-end (user commit → first audio).

Example:

```json
{
  "type": "bot",
  "response": "['Hello! How can I help?']",
  "latency_llm_ms": 420,
  "latency_tts_ms": 180,
  "latency_e2e_ms": 610
}
```

So:

- **LLM** = `latency_llm_ms`
- **TTS** = `latency_tts_ms`
- **STT** is not stored as a separate number; it’s included in the time until “user commit” (user turn in the terminal).

To see **where most time is spent**, compare `latency_llm_ms` vs `latency_tts_ms` in the JSON, or the `[LATENCY] LLM` vs `[LATENCY] TTS` lines in the terminal.

---

## 2. First message – did the bot speak first?

### In the terminal

If a first message is configured and used, you’ll see:

- **`First message spoken: <text>`**  
  The bot said that text as soon as the session started (before any user input).

If you don’t see that line, either no first message was set or it was empty.

### In the JSON logs

- **`config.first_message`**  
  If present, a first message was configured for that session. The first bot message in `messages` may be that greeting (or the LLM reply if the user spoke first).

So:

- **Terminal**: “First message spoken: …” → first message **was** used.
- **JSON**: `config.first_message` → first message **was** configured; first bot entry may be that line.
