# I Paid for the Embedding. My Logs Never Saw the Request.

> Source: <https://dev.to/yusufoztoprak/i-paid-for-the-embedding-my-logs-never-saw-the-request-20l9>
> Published: 2026-11-05 12:40:14+00:00

*A follow-up to [Counting OpenAI Tokens per Request in FastAPI](https://yusufoztoprak.hashnode.dev/counting-openai-tokens-per-request-in-fastapi-without-touching-my-use-cases).*

I sent a document to evorag while the database was down.

OpenAI was called. The embedding was created. I paid for it.

Then the database write failed. The user got a 500.

My logs showed `embedding.created`. They did not show `request.completed`.

No status. No latency. No token count. The failed request was invisible.

That's the request I most needed to see.

In the last post, I built a logging middleware. This was its core:

```
metrics = start_metrics()
started = time.perf_counter()
response = await call_next(request)
latency_ms = round((time.perf_counter() - started) * 1000, 2)

logger.info("request.completed", ...)
```

I tested the happy path. I never tested a route that raises.

If the route raises, `call_next` raises. Every line below it is skipped. The log never runs.

So my request log had a blind spot. Successful requests were logged. Failed ones disappeared. Including the ones that had already cost money.

This time I wrote the test before the fix. A route that always raises. An assertion that `request.completed` is still logged.

It failed. Zero log records.

The tool is `try`/` finally`. `finally` runs however the `try` block ends: normally, with `return`, or with an exception.

My first attempt:

```
status_code = 500
started = time.perf_counter()
try:
    response = await call_next(request)
    status_code = response.status_code
    response.headers["x-request-id"] = request_id
    return response
finally:
    latency_ms = round((time.perf_counter() - started) * 1000, 2)
    response.headers["x-request-id"] = request_id   # bug 1
    logger.info("request.completed", ...)
    return response                                  # bug 2
```

The test still failed. Both bugs were lines I had left over from the old version.

**Bug 1.** When the route fails, `response` never exists. That line raises `UnboundLocalError`. The log still never runs. Same bug, one line lower.

**Bug 2** is the one worth remembering.

People usually say `finally` doesn't swallow exceptions. That's true. After `finally` finishes, the exception keeps going.

Unless you `return` inside `finally`:

``` python
def demo():
    try:
        raise ValueError("something broke")
    finally:
        return "everything is fine"

demo()  # returns "everything is fine". No error.
```

The exception is silently discarded. In a middleware, that hides the real error from the framework. It's dangerous enough that Python 3.14 emits a warning for it, and ruff flags it too.

```
status_code = 500
started = time.perf_counter()
try:
    response = await call_next(request)
    status_code = response.status_code
    response.headers["x-request-id"] = request_id
    return response
finally:
    latency_ms = round((time.perf_counter() - started) * 1000, 2)
    logger.info(
        "request.completed",
        extra={"fields": {
            "method": request.method,
            "path": request.url.path,
            "status": status_code,
            "latency_ms": latency_ms,
            "embedding_tokens": metrics.embedding_tokens,
            "embedding_cost_usd": metrics.embedding_cost_usd,
        }},
    )
```

`status_code` starts at 500. On success, it's overwritten. On failure, the log says 500.

`finally` only uses variables that exist on every path: `started`, `status_code`, `metrics`. Never `response`.

The test went green.

The last post counted tokens. But I wanted the log to answer a simpler question: what did this request cost?

`text-embedding-3-small` is $0.02 per million tokens, per OpenAI's pricing page. I wrote a small calculator, test first, using `Decimal`. Floats are the wrong type for money.

Now the failed request from the opening shows up properly: status 500, the tokens it used, and what it cost. Before the fix, that money was spent and never recorded anywhere.

`await` is a log line that skips failures.`finally` runs every time. A `return` inside it hides errors. I wrote that bug while fixing another one.
*Code: [github.com/YusufOztoprak/evorag](https://github.com/YusufOztoprak/evorag)*

*I drafted this post with help from Claude; the code, bugs, and measurements are from my own work on evorag.*