# py-09-cli-logging — `askcli`: JSON-lines logging, a request id, and env > file > default

Every service you deploy on this track starts with the same scaffolding before any model code: a
command line with honest exit codes, logs a machine can parse — one JSON object per line, each
stamped with the request it belongs to — and a config loader where the environment beats the file
and the file beats the defaults. You write them once, here, in a package called `askcli`, and
flagship F1 reuses them. The brief is the same text as the page
(`illustrated/0-python/exercise-cli-logging.html`); the concepts are on
`illustrated/0-python/logging-and-config.html`.

## What to implement

`src/askcli/config.py` — `load_config(defaults, path, env) -> Config`:

- `Config` (frozen dataclass: `model_name`, `timeout_s`, `log_level`), `DEFAULTS` and
  `ENV_PREFIX = "ASKCLI_"` are **provided**;
- precedence is **per key**: `ASKCLI_MODEL_NAME` / `ASKCLI_TIMEOUT_S` / `ASKCLI_LOG_LEVEL` beat
  the TOML file, which beats `DEFAULTS`; `path=None` or a missing file means no file layer;
- a key in the file that is not a field raises `ValueError` **naming the key**;
- environment values are strings: `ASKCLI_TIMEOUT_S="5"` must become the float `5.0`.

`src/askcli/logjson.py`:

- the request id's storage — **one value per thread and per asyncio task**, `"-"` outside a
  request;
- `request_scope(request_id)`: a context manager that sets it and restores the previous value on
  exit, even when the block raises; `current_request_id()`;
- `JsonFormatter.format(record)`: **one line** of JSON with `ts` (UTC, ISO 8601, milliseconds),
  `level`, `logger`, `msg` (with its `%`-args filled in) and `request_id`;
- `configure_logging(json_lines=, level=)`: one `StreamHandler` on the `askcli` logger, writing
  to `sys.stderr` looked up at call time, `propagate = False`, idempotent (a second call must not
  leave two handlers).

`src/askcli/cli.py`:

- `build_parser()` for `askcli ask "<prompt>" [--model NAME] [--config PATH] [--json]`;
- `ask(prompt, cfg)`: one request inside `request_scope(<fresh id>)`, logging exactly two lines —
  `request start: '…'` before `backend.complete(prompt, cfg.model_name)` and
  `request done: N answer chars` after — returning the answer;
- `main(argv) -> int`: load the config (`load_config(DEFAULTS, args.config)`), apply `--model` on
  top of every layer, `configure_logging`, `ask`, print the answer on stdout (with `--json`: one
  JSON object with `model` and `answer`), return 0. Bad arguments return 2 — argparse raises
  `SystemExit(2)`; catch it.

`src/askcli/backend.py` (the stand-in model; it logs `model call: …` through the child logger
`askcli.backend`) and `src/askcli/__init__.py` are **provided** — do not edit them. The backend
never receives a request id, yet its line must carry the right one: that is why the id lives in a
`ContextVar` the formatter reads, not in an argument or a global.

## Run it

```
cd exercises/py-09-cli-logging && uv sync && uv run pytest -q

# once the tests pass: uv sync installed an `askcli` launcher
uv run askcli ask "what is a logger tree?" --json
ASKCLI_MODEL_NAME=gpt-mini uv run askcli ask "hi"
uv run askcli ask; echo "exit code $?"
```

Done when `uv run pytest -q` prints **7 passed**. The untouched starter fails all seven.

## The checks

- `test_defaults_apply_when_nothing_else_sets_a_key` — `path=None` and a missing file, `env={}`:
  `Config(model_name='tiny-local', timeout_s=30.0, log_level='INFO')`.
- `test_file_beats_default` — a file with `model_name = "gpt-large"` and `timeout_s = 12.5` wins
  both keys; `log_level` stays the default.
- `test_env_beats_file` — `ASKCLI_MODEL_NAME=gpt-mini` and `ASKCLI_TIMEOUT_S=5` beat the same
  file, `timeout_s` arrives as the float `5.0`, an unprefixed `MODEL_NAME` is ignored.
- `test_unknown_key_in_file_raises` — `modle_name = "gpt-large"` raises `ValueError` naming
  `modle_name`.
- `test_json_flag_prints_one_object_per_line` — `askcli ask "…" --json` writes exactly three
  stderr lines, each one JSON object with the five keys, from `askcli.cli`, `askcli.backend`,
  `askcli.cli`; stdout is one JSON object whose `answer` holds the prompt. Run twice: the second
  run prints three lines too, not six.
- `test_request_id_same_within_a_request_and_distinct_across_threads` — two requests in two
  threads, held in flight at the same time by a barrier inside the model call: exactly two ids,
  never `"-"`, each stamping one start, one model call and one done.
- `test_exit_code_2_on_bad_args_and_0_on_success` — no sub-command, no prompt and an unknown flag
  each give 2; `ask "hi there" --model gpt-mini` gives 0 and prints an answer from `gpt-mini`.