# Query logging

Every SQL statement the MCP server runs is logged, tied to the tool call that
caused it.

## What a request looks like in the log

One question from ChatGPT produces one `tool_call_allowed`, one line per
statement, and one `tool_call_ok`. They share a `requestId`:

```json
{"level":"info","msg":"tool_call_allowed","requestId":"7c1e…","tool":"get_advertiser_report","argumentKeys":["date_range"]}
{"level":"info","msg":"sql_query","requestId":"7c1e…","tool":"get_advertiser_report","seq":1,"connection":"cake:whale","sql":"SELECT adv_id, adv_name, … FROM `whale`.`lucos_ro_advertiser_stats_daily` WHERE stat_date BETWEEN ? AND ? …","paramCount":2,"rowCount":844,"durationMs":312}
{"level":"info","msg":"sql_query","requestId":"7c1e…","tool":"get_advertiser_report","seq":2,"connection":"cake:admin","sql":"SELECT adv_id, camp_id, SUM(advertiser_conversions) … ","paramCount":2,"rowCount":91,"durationMs":47}
{"level":"info","msg":"tool_call_ok","requestId":"7c1e…","tool":"get_advertiser_report","queryCount":2,"durationMs":401}
```

Read top to bottom, that says: one question cost two statements across two
different MySQL instances and took 401 ms. That is the cross-instance merge
([OD-1](./CAKE-OPEN-DECISIONS.md)) visible in the log.

To pull one request out of a busy log:

```bash
grep '"requestId":"7c1e' app.log
```

## Fields

| Field | Meaning |
| --- | --- |
| `requestId` | Groups everything from one tool call. Absent for CLI jobs — see below |
| `tool` | Which tool ran the statement |
| `seq` | Statement number within the request, so order is readable |
| `connection` | `mngt`, `cake:admin` / `cake:whale` / `cake:shorty`, or `adhoc` |
| `sql` | Statement text, whitespace collapsed to one line |
| `sqlTruncated` | Present when the text was over 2000 characters |
| `paramCount` | How many values were bound — **not the values** |
| `rowCount` | Rows returned |
| `durationMs` | Time for that statement |

`tool_call_ok` and `tool_call_error` also carry `queryCount` and a total
`durationMs`.

## What is deliberately not logged

**Bind values.** The statement text is safe to log because every statement is
catalog-authored with `?` placeholders — caller input arrives as bound values,
never as SQL text. The values are the opposite: publisher names, advertiser ids,
IP prefixes, date ranges. That is exactly the material the read-only views and
the redaction layer exist to keep bounded, and writing it to a log file would
route it straight past both. So the count is logged and the values are not.

**Result rows.** Never. `rowCount` only.

**Credentials.** DSNs carry passwords, so connections are logged by *label*
(`cake:shorty`), never by DSN. `server/logger.ts` also redacts any field whose
name looks like a secret or personal data, as a second line of defence.

### The debug escape hatch

`LUCOS_LOG_QUERY_PARAMS=true` logs bind values as well. **Local debugging only.**
It is not safe on staging or production. When it is on, the server emits a
warning at startup naming exactly what it is doing, so it cannot be left enabled
unnoticed.

## How a statement gets logged without every function passing a requestId

The code that runs SQL is several layers below the code that knows the request
id: `runToolCall` → tool executor → connector → `SqlExecutor.query`. Threading a
`requestId` through all of those would mean changing the signature of every
connector and every tool, across four verticals, for a logging concern.

`server/request-context.ts` uses `AsyncLocalStorage` instead. `runToolCall` opens
a store; anything running inside that call can read it, however deep and across
awaits. Nothing in between needs to know it exists.

It is **not** a module-level variable, deliberately. Tool calls run concurrently
in one process — several ChatGPT sessions, SSE connections held open — so a
shared variable would file one user's queries under another user's request. There
is a test for exactly that.

## Where the hook lives

| Connection creator | Used by |
| --- | --- |
| `connectors/sql/executor.ts` → `createMysqlSqlExecutor` | MNGT **and** cake (cake wraps it) |
| `connectors/adhoc/executor.ts` | the ad-hoc query tool, which opens its own connection |

Both are instrumented. Putting the hook at the connection level rather than in
each connector means one place to change, and a new tool cannot bypass it by
accident — it gets logging by virtue of using the executor.

## Lines without a requestId

Normal, not an error. CLI jobs — schema harvest, catalog index — open connections
with no request behind them. The field is omitted rather than filled with a made
up id, so a search for a `requestId` never returns unrelated rows.

---

## The audit file — `logs/queries/`

Alongside the stdout log there is a per-request file, one JSON object per line,
one line per tool call:

```
logs/queries/2026-08-18.jsonl
```

```json
{"ts":"2026-08-18T10:22:31.412Z","requestId":"7c1e…","tool":"get_ivt_report",
 "arguments":{"date_range":{"from":"2026-08-11","to":"2026-08-13"}},
 "queries":[{"seq":1,"connection":"cake:shorty","sql":"SELECT …","paramCount":2,"rowCount":6,"durationMs":312}],
 "ok":true,"durationMs":401,"queryCount":1}
```

Grouped per request rather than per statement, because the question a reader has
is "what did this request do", not "here are four rows to stitch together".

### It records arguments — stdout does not

This is the one deliberate difference between the two logs.

stdout is operational: shipped, broadly readable, and free of caller values by
design. The audit file exists to answer *who asked what*, so it records the tool
arguments — which carry publisher ids, advertiser ids and date ranges.

That makes the file the same class of material as the database it describes. It
is gitignored, it stays on the box, and retention is capped. Treat a copy of it
the way you would treat a database export.

### What "user query" means here

MCP delivers a **tool name and arguments**. The user's English question is turned
into a tool call by ChatGPT and never reaches this server. So `tool` +
`arguments` is the closest thing to the question that exists on our side — you
will not find *"what was invalid traffic last week?"* in this file.

### Settings

| Variable | Default | Purpose |
| --- | --- | --- |
| `LUCOS_QUERY_FILE_LOG` | `true` | `false` disables the file entirely |
| `LUCOS_QUERY_LOG_DIR` | `logs/queries` | Move it off the deploy directory in prod |
| `LUCOS_QUERY_LOG_RETENTION_DAYS` | `30` | Files older than this are deleted at startup |

### Finding it on a server

The directory is created at **startup**, not on the first tool call, and the
server logs its absolute path as it boots:

```json
{"level":"info","msg":"query_file_log_ready","dir":"/opt/lucos/business-mcp.lucos.com/logs/queries","retentionDays":30}
```

```bash
pm2 logs business-mcp-staging --nostream | grep query_file_log_ready
```

That line is the answer to "where are the logs?". It was previously created
lazily, which was indistinguishable from broken - an absent directory could mean
logging was off, misconfigured, or simply waiting for its first request. If the
sink is disabled, a `query_file_log_disabled` warning appears instead, so silence
never means "probably fine".

Note the path is **relative to the process working directory** by default. Under
PM2 that is the repo root (`cwd` is set in `ecosystem.config.cjs`); started by
hand it is wherever you ran the command. The startup line resolves it, so there
is nothing to infer.

### Two things to know before relying on it

**A redeploy can wipe it.** It sits under the repo directory by default, so a
fresh clone, a `git clean -fdx` or a container rebuild takes it with them. If it
matters in production, point `LUCOS_QUERY_LOG_DIR` somewhere that survives.

**Retention runs at startup, not on a timer.** A process that stays up for months
never prunes. That is fine for a service that redeploys regularly; if it is not,
the pruning needs a scheduler.

### It cannot break a tool call

Writes are queued rather than fired in parallel — concurrent appends were
observed landing out of order, and two writes at once risk interleaving inside a
single line. A failed or unserialisable write costs one audit line and a single
warning on stdout, never somebody's answer.