Improvement: Clean Up and Standardize Application Logs

## Improvement: Clean Up and Standardize Application Logs

### Problem

The current logging output is difficult to read and understand.

A lot of information is printed without a consistent structure, which makes it hard to:

* Follow the execution flow.
* Understand which log belongs to which request/run/conversation.
* Identify errors quickly.
* Search and filter logs.
* Debug issues in production.
* Distinguish useful information from noisy implementation details.

Currently, logs often feel like everything is simply being dumped into the output rather than intentionally logged.

We should introduce a clear and consistent logging format across Extra.

---

## Goal

Logs should be:

* Structured.
* Consistent.
* Easy to scan.
* Easy to search.
* Useful for debugging.
* Correlated across the same execution flow.
* Free from unnecessary dumps/noise.

A developer should be able to look at the logs and immediately understand:

```text
What happened?
For which request/conversation/run?
Which component produced the log?
What was the result?
If something failed, where and why?
```

---

## Standard Log Format

All logs should follow the same general structure.

For example:

```text
2026-08-20 20:15:32.421 INFO  [orchestrator] run_started conversation_id=abc123 run_id=run456 agent_id=invoices_agent
```

```text
2026-08-20 20:15:32.811 INFO  [tool_registry] tool_started tool=get_invoice run_id=run456
```

```text
2026-08-20 20:15:33.104 INFO  [tool_registry] tool_completed tool=get_invoice run_id=run456 duration_ms=293
```

```text
2026-08-20 20:15:33.220 ERROR [orchestrator] run_failed run_id=run456 error_type=TimeoutError message="Tool execution timed out"
```

The exact implementation can follow the logging framework already used by Extra, but the format should be consistent everywhere.

---

## Correlation Context

Where applicable, logs should include common identifiers so the complete execution can be traced.

For example:

```text
conversation_id
run_id
request_id
agent_id
tool_name
```

Not every field is required on every log, but relevant context should be included consistently.

For example:

```text
request
   ↓
conversation_id=123
   ↓
run_id=456
   ↓
agent
   ↓
tool
```

Searching for:

```text
run_id=456
```

should provide a clear view of the complete execution flow.

---

## Log Levels

Log levels should also be used consistently.

### `INFO`

Important lifecycle events:

```text
run_started
run_completed
tool_started
tool_completed
conversation_created
agent_selected
```

### `DEBUG`

Detailed implementation information useful during development:

```text
resolved configuration
internal state changes
tool arguments metadata
routing decisions
```

Detailed/debug information should not pollute normal production logs.

### `WARN`

Unexpected but recoverable situations:

```text
fallback used
optional configuration missing
retry triggered
deprecated configuration detected
```

### `ERROR`

Failures that require attention:

```text
tool execution failure
LLM request failure
validation failure
unexpected exception
```

---

## Avoid Raw Object Dumps

We should avoid logs like:

```text
INFO request received: {very large object with nested objects, headers, messages, state, config, ...}
```

or:

```text
DEBUG agent state = {...huge state...}
```

Instead, log only the fields that are useful for understanding the event.

For example, instead of:

```text
INFO request={...500 lines...}
```

prefer:

```text
INFO request_received request_id=req123 conversation_id=conv456 message_count=12
```

Large payloads should only be logged intentionally at `DEBUG` level when they are actually needed.

---

## Sensitive Information

The logging cleanup should also ensure we do not accidentally dump sensitive information.

Avoid logging raw:

* Authorization headers.
* Tokens.
* Cookies.
* Secrets.
* Credentials.

If a value is required for debugging, it should be sanitized or masked.

For example:

```text
authorization=<redacted>
```

instead of printing the actual token.

---

## Exceptions

Exception logging should also be standardized.

We should avoid both extremes:

```text
ERROR Something failed
```

with no useful information,

and dumping unnecessary stack traces repeatedly across several layers.

A failure should ideally be logged once at the appropriate boundary with enough context:

```text
ERROR [tool_executor] tool_failed
      tool=get_invoice
      run_id=run456
      error_type=TimeoutError
      message="Request timed out"
```

A stack trace should still be available where appropriate, especially for unexpected exceptions, but should not be duplicated by every layer that catches and rethrows the same error.

---

## Lifecycle Logging

Important flows should have recognizable start/completion events.

For example:

```text
run_started
    ↓
agent_started
    ↓
tool_started
    ↓
tool_completed
    ↓
agent_completed
    ↓
run_completed
```

This will make logs much easier to follow compared with arbitrary messages emitted throughout the code.

Where useful, completion logs should also contain execution duration:

```text
INFO run_completed run_id=run456 duration_ms=1843
```

---

## Development vs Production

The logging infrastructure should support different verbosity levels.

For example:

```text
Development
→ More DEBUG information
→ Easier local debugging

Production
→ INFO/WARN/ERROR
→ Clean, structured logs
→ No unnecessary payload dumps
```

We should not rely on large `print()` statements or ad-hoc debug logging.

---

## Scope

Review the main execution paths and normalize the existing logs, especially around:

* Request handling.
* Conversation lifecycle.
* Run lifecycle.
* Agent execution.
* LLM calls.
* Tool discovery.
* Tool execution.
* MCP execution.
* Validation.
* Approvals.
* Errors and cancellation.

The goal is not simply to change the visual formatter, but to clean up **what we log and how we log it**.

---

## Acceptance Criteria

* A consistent logging format is used across Extra.
* Important logs contain relevant correlation IDs such as `conversation_id`, `run_id`, and `request_id`.
* Log levels are used consistently.
* Main lifecycle events have clear start/completion logs.
* Execution duration is included for important operations where useful.
* Large objects and internal state are not dumped into normal logs.
* Detailed implementation logs are moved to `DEBUG` where appropriate.
* Sensitive values such as tokens and authorization headers are never printed in plain text.
* Exceptions contain enough context to understand what failed.
* The same exception is not unnecessarily logged multiple times by different layers.
* Existing noisy/ad-hoc logging is cleaned up.
* Production logs are easy to scan and filter.
* Tests are added where applicable for log sanitization and formatting behavior.


Navigation Menu

Uh oh!

Improvement: Clean Up and Standardize Application Logs #118