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

A developer building the evorag retrieval service fixed a blind spot in their FastAPI logging middleware that caused failed requests to go unrecorded, including ones that had already incurred OpenAI embedding costs. The original middleware logged only after call_next returned, so any route that raised skipped the log entirely; the fix wraps the call in try/finally, initializes status_code to 500, and logs only variables guaranteed to exist on every path. The developer also notes that returning inside a finally block silently discards exceptions — a pattern Python 3.14 now warns on and ruff flags — and added a Decimal-based cost calculator for text-embedding-3-small at $0.02 per million tokens.

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.