Feat metric logging - #132
Closed
snigenigmatic wants to merge 9 commits into
Closed
snigenigmatic wants to merge 9 commits into
snigenigmatic wants to merge 9 commits into
Conversation
aditeyabaral
requested changes
Sep 4, 2025
Comment on lines
+8
to
+40
| 200: { | ||
| "description": "Metrics retrieved successfully", | ||
| "content": { | ||
| "application/json": { | ||
| "examples": { | ||
| "metrics_response": { | ||
| "summary": "Current Metrics", | ||
| "description": ( | ||
| "All current application metrics including authentication counts and error rates" | ||
| ), | ||
| "value": { | ||
| "status": True, | ||
| "message": "Metrics retrieved successfully", | ||
| "timestamp": "2025-08-28T15:30:45.123456+05:30", | ||
| "metrics": { | ||
| "auth_success_total": 150, | ||
| "auth_failure_total": 12, | ||
| "validation_error_total": 8, | ||
| "pesu_academy_error_total": 5, | ||
| "unhandled_exception_total": 0, | ||
| "csrf_token_error_total": 2, | ||
| "profile_fetch_error_total": 1, | ||
| "profile_parse_error_total": 0, | ||
| "csrf_token_refresh_success_total": 45, | ||
| "csrf_token_refresh_failure_total": 1, | ||
| }, | ||
| }, | ||
| } | ||
| } | ||
| } | ||
| }, | ||
| } | ||
| }, |
Member
There was a problem hiding this comment.
Create a model for this. The response model will also need an update.
Comment on lines
+23
to
+24
| "auth_success_total": 150, | ||
| "auth_failure_total": 12, |
Member
There was a problem hiding this comment.
We should also track how many auth requests are received, including a split for how many with and without profile data
Comment on lines
+2
to
+5
|
|
||
| from app.metrics import metrics | ||
|
|
||
| __all__ = ["metrics"] |
Member
There was a problem hiding this comment.
Remove this; we should not want to initialize a global collector outside the entry point.
Comment on lines
+131
to
+140
| exc_type = type(exc).__name__.lower() | ||
| if "csrf" in exc_type: | ||
| metrics.inc("csrf_token_error_total") | ||
| elif "profilefetch" in exc_type: | ||
| metrics.inc("profile_fetch_error_total") | ||
| elif "profileparse" in exc_type: | ||
| metrics.inc("profile_parse_error_total") | ||
| elif "authentication" in exc_type: | ||
| metrics.inc("auth_failure_total") | ||
|
|
Member
There was a problem hiding this comment.
There is a much cleaner solution. Look into a middleware layer. Here is some pseudo code to get you started:
@app.middleware("http")
async def metrics_middleware(request: Request, call_next):
metrics.inc("requests_total")
start_time = time.time()
try:
response: Response = await call_next(request)
latency = time.time() - start_time
# Track successes vs failures
if 200 <= response.status_code < 300:
metrics.inc("requests_success")
else:
metrics.inc("requests_failed")
metrics.inc(f"requests_failed_status_{response.status_code}")
# Latency metrics
metrics.inc("request_latency_sum", latency)
# Also add route metrics: route = request.scope.get("route")
return response
except Exception as e:
latency = time.time() - start_time
metrics.inc("requests_failed")
metrics.inc(f"requests_failed_exception_{type(e).__name__}")
metrics.inc("request_latency_sum", latency)
raiseNote, you will need to accordingly increment other metrics like how many with and without profile data by parsing the request.
achyu-dev
requested changes
Sep 6, 2025
achyu-dev
left a comment
achyu-dev
left a comment
Contributor
There was a problem hiding this comment.
Please do the requested changes from @aditeyabaral and me
Contributor
There was a problem hiding this comment.
Are these dependencies necessary to be added ?
…d clean up dependencies
…d clean up dependencies
aditeyabaral
added a commit
that referenced
this pull request
Sep 13, 2026
…hmark output paths, and six bug fixes (#157) * fix: import httpx2 in the benchmark utility The httpx2 migration in #156 removed `httpx` from the project, but `scripts/benchmark/util.py` still imported it. Every benchmark script imports `util`, so all three have been dead on `dev` and `main` since that merge: ModuleNotFoundError: No module named 'httpx' Nothing caught it. Ruff does not resolve third-party imports, no test imports these scripts, and the coverage gate is `--cov=app`. The check I ran after the migration was a grep over `app/`, `tests/`, `pyproject.toml`, `Dockerfile` and `README.md` -- which simply omitted `scripts/`. A rename needs a repo-wide grep, not a directory-by-directory one. Production was never affected: the Dockerfile copies only `app/`. The API is identical, so this is the import and the two call sites. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01VU7YUhP71KSsotWQ1H7CRH * feat: add an in-memory metrics collector Implements #129's collector, with two changes from the sketch in the issue. Families are typed registry objects rather than free strings. A typo in a metric name would otherwise create an orphan series that silently never gets reported; now it raises at the call site, and `FAMILIES` doubles as the single source of HELP and TYPE text shared by every view. Dimensions are labels, not name suffixes. The review on #132 asked for keys like `requests_failed_status_{code}`, but those cannot be rendered as Prometheus -- each string becomes its own family needing its own HELP and TYPE, and `sum by (status)` becomes impossible. `responses_total{status="401"}` aggregates and stays one family however many status codes appear. No lock. Every mutation is a dict read and write with no await between them, so the event loop cannot interleave two increments. The asyncio.Lock in app/pesu.py exists because that code swaps several fields *around* an await, which is a different problem. The docstring records where this stops holding. Unlabelled series are seeded at zero so a freshly started process exposes them before its first request -- otherwise a series springs into existence mid-window and `rate()` reads it as a spike. `process_start_time_seconds` is exposed for the same class of reason: Render restarts wipe these counters, and without it a dashboard cannot tell a restart from a drop in traffic. Nothing imports this yet. 20 tests, 100% coverage of the new module. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01VU7YUhP71KSsotWQ1H7CRH * feat: render metrics in the Prometheus text exposition format This is what unblocks #130: Grafana scrapes Prometheus, not arbitrary JSON, so a JSON-only /metrics would have needed an exporter written later. Hand-rolled rather than pulling in prometheus_client, which is the direct answer to the dependency question raised on #132: **no dependencies are added.** prometheus_client installs a process-global default registry at import time -- precisely the "global collector outside the entry point" the review rejected -- and it would become a second source of truth beside the snapshot we need anyway for the pydantic view. What it buys over these 50 lines is histogram buckets, which we do not expose. The format for counters, gauges and a quantile-less summary is a small, stable grammar that the tests pin exactly. Details that are easy to get wrong, so they are tested: - the media type must carry `version=0.0.4`, or a scraper guesses the format - label values are double-quoted, so `"`, `\` and newline need escaping; HELP text is unquoted, so only `\` and newline do - labels render sorted, which keeps the payload deterministic and diffable - whole numbers render without a decimal point, matching every other exporter 16 tests, 100% coverage of the renderer. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01VU7YUhP71KSsotWQ1H7CRH * feat: add a metrics response model Answers "create a model for this -- the response model will also need an update" from the review of #132. The awkward part is that metric keys are dynamic: the status codes and route templates that appear depend on traffic, so a fixed-field model cannot express them. Resolved by noting that dynamic *keys* do not require dynamic *fields* -- `responses_by_status: dict[str, int]` and `requests_by_route: dict[str, RouteMetricsModel]` validate every value, generate correct OpenAPI `additionalProperties`, and keep `strict=True` meaningful. `from_snapshot` casts every value explicitly. The collector stores floats, and strict mode rejects a float for an int field, so an un-cast value would be a 500 in production rather than a payload. That is the single most likely bug here, which is why the fresh-collector case is its own test. No timestamp field, deliberately: `IST` lives in app/app.py and importing it here would make app.models depend on app.app. `startTimeSeconds` and `uptimeSeconds` carry the same information, need no timezone, and line up with the Prometheus gauge. `averageSeconds` is null rather than absent on a fresh process, so consumers see one stable shape instead of a key that materialises after the first request. 11 tests, 100% coverage of the new module. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01VU7YUhP71KSsotWQ1H7CRH * feat: record request metrics in an HTTP middleware Implements the middleware layer asked for in the review of #132, rather than instrumenting each route by hand. Eight things in the review's pseudo-code do not work as written; the interesting one is the fourth. **The layering.** starlette/applications.py builds the stack as ServerErrorMiddleware -> user middleware -> ExceptionMiddleware -> router. Our `@app.exception_handler(Exception)` becomes ServerErrorMiddleware's handler and so runs *above* this middleware; the RequestValidationError and PESUAcademyError handlers live in ExceptionMiddleware, *below* it. That cuts both ways: - a handled PESUAcademyError is already a response by the time call_next returns, so the `except` branch never sees it -- the pseudo-code assumes it does; - an unhandled exception passes through us but its 500 is rendered above us, so we never see that response either, and the `except` branch has to record the status itself or requests_total silently stops matching sum(responses_total). So: the middleware owns status, route and latency; the exception handlers own the error type, one line each. Different families, so one failed request yields exactly one status sample and one error sample. That is also what recovers the information a status code loses -- CSRFTokenError and ProfileFetchError are both 502, and only errors_total tells them apart. The other corrections: `status < 400` for success, not `< 300`, or /readme's 308 counts every readme hit as a failure; perf_counter rather than time(), since a wall clock can step backwards and poison a cumulative sum; scope["route"] read only after call_next, via getattr, because plain Starlette routes never set it; and latency named for what it measures, which is time to response *start* -- call_next returns at http.response.start and the body streams afterwards. Cardinality is bounded at both attacker-controlled labels: the route is the matched template with unmatched paths collapsed to one bucket, and the method is clamped to the seven known verbs. Keying on the raw path would let a scanner walking /wp-login.php mint a series per probe. The profile split is the one deliberate exception to "middleware, not routes". Reading the body in middleware would consume the downstream receive channel and pull a plaintext-password payload into another layer; how many auth requests arrive is already free from route_requests_total, and only the split needs the body. Cancellation from a client disconnect is left unrecorded, so total exceeds success + failed while requests are in flight. Swallowing it to record would be worse than the undercount. 163 tests, 100% coverage. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01VU7YUhP71KSsotWQ1H7CRH * feat: expose /metrics and /metrics.json Two paths rather than content negotiation on one. Real scrapers send `Accept: application/openmetrics-text;...,text/plain;version=0.0.4;q=0.5,*/*;q=0.1`, curl sends `*/*`, and a browser sends `text/html,...,*/*;q=0.8` -- none of which unambiguously mean JSON, so any resolution of the wildcard surprises half the callers, and getting there needs a hand-rolled q-value parser larger than the renderer. A single path also cannot carry a response_model, so Swagger would show either a misleading schema or none. Split in two, each is documented properly: /metrics declares response_class=PlainTextResponse with a text/plain example, mirroring how app/docs/readme.py documents its text/html body, and /metrics.json declares response_model=MetricsModel -- the second response_model in the codebase after /authenticate, which is what "the response model will also need an update" asked for. JSON deliberately does not live on /metrics: Prometheus has effectively reserved that path. /metrics.json returns the model rather than a JSONResponse, so FastAPI serializes it with by_alias=True and the camelCase keys come for free, with no hand-patched dict of the kind /authenticate needs for its datetime. Both reuse the existing "Monitoring" OpenAPI tag. The most valuable of the 13 new tests is the unhandled-exception one. That path runs through ServerErrorMiddleware, which sits *above* our middleware, so whether a 500 is recorded at all cannot be established by reading the code -- only by driving a real exception through the whole stack. There is also a test asserting the accounting invariants hold end to end: sum(responsesByStatus) == success + failed, and sum(errorsByType) < failed whenever a 404 is in the mix, since the router's 404 runs no handler of ours. 176 tests, 100% coverage. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01VU7YUhP71KSsotWQ1H7CRH * refactor: give the benchmark scripts a shared output path helper Closes #123. Implements the five changes requested on #143, plus the review's "please incorporate similar changes in unauthenticated_csrf_token_expiry.py". Every output path was a bare relative filename, so results landed wherever the script happened to be run from -- in practice cluttering scripts/benchmark/ -- and `analyze_benchmark.py` overwrote distribution.png and timeline.png on every run. `resolve_output_path` in util.py now handles all of it: explicit --output wins, otherwise `{script}_{date}_{time}[_{tag}].{ext}`, with parent directories created either way. The default directory is anchored to the repository root rather than the cwd, so output lands in one place regardless of where the script is invoked. util.py is reused rather than adding a module, since both runners already import it; analyze_benchmark.py now imports it too. Also in scope, because they are in the files being rewritten: - `make_request` ended in an unconditional `response.json()`, so `--route readme` (a 308 to GitHub returning HTML) crashed the sequential runner and was silently swallowed as a *failed request* by the parallel one, skewing the very numbers being measured. This is what #132's author was patching when a reviewer asked "why is this being added?" -- it is a real bug. Non-JSON responses now fall back to the status and the raw text. - `analyze_benchmark.py --files` was not required, so omitting it raised a bare TypeError from a list comprehension instead of an argparse error. - `unauthenticated_csrf_token_expiry.py` wrote its CSV only after the loop ended, and that loop sleeps for hours between requests -- so a Ctrl-C threw away every measurement taken. Rows are now written as they are measured. - Both runners carried a no-op string expression where a docstring cannot go, inside `if __name__ == "__main__":`. - `--route` gained `metrics` and `metrics.json`, now that those exist. Verified against a live server: default naming, --tag, --output-dir and an explicit --output all land where intended, and `--route readme` and `--route metrics` both succeed where they previously could not. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01VU7YUhP71KSsotWQ1H7CRH * docs: document the metrics endpoints and benchmark output README gains rows for /metrics and /metrics.json in the endpoint table and a section for each, following the shape of the /health section. The notes worth having in writing rather than only in code comments: counters reset on restart (which is what process_start_time_seconds is for), status codes and exception classes are recorded separately so CSRFTokenError and ProfileFetchError stay distinguishable despite both being 502, scrapes of /metrics count themselves on purpose, and requests.total can briefly exceed success + failed because arrival and outcome are recorded at different moments. CONTRIBUTING gains a note on where the benchmark scripts now write, since the answer changed in this PR. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01VU7YUhP71KSsotWQ1H7CRH * chore: bump version to 4.2.0 Minor: new functionality that keeps existing APIs working, per the guidance in .github/scripts/check_version_bump.py. Two new endpoints, no change to /authenticate, /health or /readme, and no new dependencies. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01VU7YUhP71KSsotWQ1H7CRH * refactor: serve both metric formats from one /metrics endpoint Replaces /metrics + /metrics.json with a single path selecting the representation by query parameter: `?fmt=prometheus` (the default) or `?fmt=json`. `fmt` is a StrEnum, so FastAPI validates it, Swagger renders a dropdown, and an unrecognised value goes through the existing validation handler -- a 400 with the usual body, which is itself counted like any other failed request rather than being a special case. The default stays Prometheus: a scraper pointed at this path with no query string must get the exposition format. `response_model` is None because the response type depends on the parameter and cannot be declared once. Both shapes are documented under `responses=` instead, which is what Swagger renders from anyway, so the endpoint documents itself as well as the two-path version did. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01VU7YUhP71KSsotWQ1H7CRH * feat: instrument every path in the app Audited each request, response, error and background task, and closed the gaps. The set went from 9 metric families to 23. **The upstream was entirely uninstrumented, which was the biggest hole.** PESU Academy is the only dependency this service has and the only thing that can be slow or down, yet nothing measured it. Every call now goes through one helper that records count, outcome, latency and the upstream status code, labelled by operation: `csrf_fetch`, `login`, `profile_fetch`. When a request is slow, this is what says whether it is us or them. It also distinguishes "the call failed" from "the call succeeded and we could not parse what came back" -- a missing CSRF tag counts as a successful 200, because it is our parsing that failed. **Failures now say whose fault they are.** `failures_total{fault}` splits 4xx from 5xx, so an alert can fire on "our fault" without enumerating statuses. **Authentication says why it failed, not just that it did.** `authentication_results_total{result}` records success, invalid_credentials, csrf_token_error, profile_fetch_error, profile_parse_error and internal_error. Keyed on the exception class, because CSRFTokenError and ProfileFetchError are both 502 and mean entirely different things. **Validation errors say which field.** Bounded by a known-field set, since the request body is caller-controlled and an open label would be a cardinality hole. **Profile parsing says what broke**: key_missing, value_missing, unknown_field, page_structure, no_data, unknown_campus_code. The last one previously only emitted a warning and raised nothing -- an unknown campus code means the PRN format changed, which nothing else would have surfaced. **The internal machinery is visible**: CSRF cache hit/miss (which is the whole point of the prefetch, and previously invisible), prefetch task outcomes, background refresh outcomes, and client lifecycle events where created minus closed is what is still open -- the leak indicator for the bug class this module spent a release learning to avoid. Plus `requests_in_flight`, which explains the one gap in the accounting: total exceeds success + failed by exactly what is still being served. PESUAcademy now takes a collector, defaulting to a private one so a bare PESUAcademy() still works. The singleton is still created only in app/app.py. 202 tests, 100% coverage. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01VU7YUhP71KSsotWQ1H7CRH * fix: stop the CSRF refresh loop fetching a second token at startup Found by the metrics added in the previous commit. An idle process, seconds after boot, reported two `csrf_fetch` calls and two clients created with one already closed: upstream.csrf_fetch.success 2 httpClients {created: 2, closed: 1} `lifespan` prefetches a client and caches it, then starts the refresh loop -- which refreshed *immediately* on its first iteration, fetching a second token and discarding the one just prefetched. Every startup paid an extra upstream round trip for a client it threw away, and on Render, which restarts often, that is every restart. The loop now sleeps before its first refresh, which is all it was ever meant to do: lifespan primes the cache, the loop keeps it fresh afterwards. One fetch, one client, none discarded. The same class of waste as the duplicate prefetch fixed in #156, and invisible for the same reason -- nothing counted the upstream calls. It took about two minutes for the new metrics to surface it, which is a fair argument for them. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01VU7YUhP71KSsotWQ1H7CRH * docs: describe the full metric set, and bump to 4.3.0 README gains a table of what is measured, grouped by area, and a note on the two most useful entries: `upstream`, because it is the only dependency this service has and its latency is measured separately from the API's own, so a slow request can be attributed rather than guessed at; and `httpClients`, where created minus closed is the leak indicator and should sit at one at rest. Minor: new functionality, existing APIs unchanged. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01VU7YUhP71KSsotWQ1H7CRH * fix: three defects found in review, and complete the documentation ## Defects **`requests_in_flight` leaked on every client disconnect.** The decrement sat in the two branches of the middleware rather than in a `finally`, and `except Exception` does not catch `CancelledError` -- so an abandoned request incremented the gauge and never decremented it. On a real server it would have climbed forever, and it is the number documented as explaining the gap between `total` and `success + failed`, so it would have actively misled. The cancellation test asserted total, success and failed but not the gauge, which is why it passed; it now asserts the gauge and fails against the old code. **A label could shadow a positional parameter.** `increment(family, value=...)` and `observe(family, seconds=...)` took their amount as an ordinary parameter, so a family declaring a label named `value` or `seconds` would have had it silently captured as the amount. Both are positional-only now, which immediately caught a test relying on exactly that ambiguity. **A cancelled upstream call was counted as an upstream error.** A disconnect or a shutdown is not PESU Academy failing. It has its own outcome now, so the error rate does not spike on every deploy -- precisely when someone is looking. Also closes the last uninstrumented branch: `profile_field_filtering_total` records whether a caller's field list actually narrowed the response, measured at the branch rather than from the request body, so a caller passing exactly the default list counts as no filtering. `app/metrics/__init__.py` drops its re-export list, which had to be edited every time a family was added; modules are imported directly, as `app.exceptions` already does. ## Documentation **Swagger documented a response that cannot happen.** FastAPI adds a 422 carrying its own `HTTPValidationError` body to every route whose parameters can fail validation -- but this API converts every `RequestValidationError` into a **400** with the same `{status, message, timestamp}` body as every other error. `/metrics` advertised a status it never returns, in a shape it never emits. The schema is now built through an override that drops those, matched on their schema so `/authenticate`'s real 422 (a profile parse failure, using this API's own response model) is kept. `HTTPValidationError` and `ValidationError` go with them. Every response on every route now carries both an example and a schema, which the `/readme` 308 and the `/metrics` text/plain body previously lacked. The `/metrics` examples were hand-written and had drifted; both are generated from a real snapshot now, so the JSON example is complete and round-trips through `MetricsModel`. `tests/unit/test_openapi_docs.py` makes the documentation self-checking: every route documents a success and a 500, every response has an example and a schema, every JSON example validates against the model it claims, the request examples cover all three username forms plus profile and field filtering, and the documented 400, 401 and 200 bodies are compared against real responses. It found both defects above. Validation runs in JSON mode rather than Python mode deliberately -- the models are strict, and strict Python-mode rejects the ISO *string* these responses carry in `timestamp`; JSON mode is the mode a caller parsing the body is in. The two test-only exception routes are now `include_in_schema=False`; they were appearing in the published schema whenever their module was imported. **README** gains a full metrics reference: how collection works and which of the three layers records what, the two accounting identities that hold at all times, the definitions that are easy to assume wrongly (latency is time to response *start*; success is below 400, not 300; summaries expose sum and count, not quantiles; scrapes count themselves), a table explaining every metric, and complete generated examples of both formats. 232 tests, 100% coverage. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01VU7YUhP71KSsotWQ1H7CRH * fix: let ResponseModel parse the responses it describes `timestamp` is declared `datetime` under a model-wide `strict=True`, but the API serializes an ISO string onto the wire. So the published model could not validate a real response: a client holding a decoded dict -- which is what every HTTP library hands back -- got a ValidationError from the schema the API publishes for exactly that purpose. It also made the documentation tests weaker than they looked. They validated examples in JSON mode, where pydantic accepts a string for a datetime because JSON has no datetime type. That passed, but it was working around the problem rather than finding it. `strict=False` on that one field accepts both the datetime the API builds with and the ISO string it returns. Every other field stays strict, which a test now pins. The documentation tests assert **both** modes rather than whichever passes, and a new test round-trips a real `/health` response through the model both ways. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01VU7YUhP71KSsotWQ1H7CRH * refactor: record only the outcome of an authentication, not the reason twice `authentication_results_total` carried six values -- `success`, `internal_error`, and one per failure class -- four of which restated what `errors_total{type}` already recorded about the same event. Three of those four were not even a different vocabulary, just the class name in snake_case: `CSRFTokenError` -> `csrf_token_error`, `ProfileFetchError` -> `profile_fetch_error`, `ProfileParseError` -> `profile_parse_error`. Only `AuthenticationError` -> `invalid_credentials` said anything the class name did not, and the audience for these metrics knows the class names. Worse than redundant, it was a drift risk. The mapping was a hand-written dict read through `.get(type(exc), "other")`, so adding a fifth exception class and forgetting the entry would have left two counters disagreeing about one event -- with the less informative one failing silently, which is the failure mode this PR removes everywhere else. Now `success` or `failure`, and the reason lives in exactly one place. The family survives at all because it answers the one question nothing else can: the login success rate, with success and failure in one family sharing a denominator. Computing that from `errorsByType` would mean subtracting several error classes from a different family -- the fragile cross-family arithmetic this avoids. A test pins `sum(authenticationResults) == authentication.total`. `internal_error` goes with it: a non-PESUAcademyError escaping `authenticate()` is now `failure`, and `errors_total` still names the class, so nothing became unobservable. app/app.py loses the mapping dict and four imports that existed only to feed it. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01VU7YUhP71KSsotWQ1H7CRH * fix: correct the version bump, and three things found re-reading the diff **The version bumped twice in one pull request.** 4.1.0 -> 4.2.0 -> 4.3.0, because the second batch of work read as another feature. One merge to dev is one bump, so this is 4.2.0; 4.3.0 would have skipped a version that never reaches dev. The guidance in `check_version_bump.py` is what led there. It described picking a level by change type -- "minor: new functionality", "patch: a bug fix" -- which invites exactly that reading when a PR contains several kinds of change. It now states the rule in force: raise the minor by one, once per pull request, with major reserved for a backwards-incompatible change. **The OpenAPI override restated FastAPI's argument list.** It called `get_openapi()` with five arguments where FastAPI passes fourteen. Every one missing is None or a default today, so nothing was visibly wrong -- but setting `servers=` or `license_info=` on the app later would have silently vanished from the schema. It now captures and delegates to FastAPI's own builder, so it inherits whatever that grows. **`_upstream_call` recorded in three places.** Latency and outcome were written once per branch. A `finally` with a pessimistic default makes "every call is counted and timed exactly once" structural rather than three copies that have to stay in step -- and anything escaping without setting the outcome is an error, which is the right thing to fail to. **A test still used a label value the app can no longer emit** (`result="invalid_credentials"`). It passed because the collector validates label names, not values, so it was quietly asserting a behaviour that no longer exists. Also guards `FAMILIES` against the drift that made the last two findings possible: a family defined but left out of the registry would be collected into and never exposed, silently. Tests now assert the registry matches the module, that names are unique and valid Prometheus identifiers, that no counter name collides with a summary's `_sum`/`_count` series, and that every HELP line fits the exposition example's line limit. 240 tests, 100% coverage. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01VU7YUhP71KSsotWQ1H7CRH --------- Co-authored-by: Claude Opus 5 <noreply@anthropic.com>
Closed
Member
|
Thanks for this, @snigenigmatic — and sorry it sat so long. The feature has shipped in #157, now merged to What came from your work
What #157 changed, following the review here
You were right about Where it went beyond the original scope, in case it is interesting: the set grew from your ten counters to twenty-three, the biggest addition being the upstream calls to PESU Academy — The metrics also earned their keep within minutes of existing: they showed an idle process making two CSRF fetches at startup and discarding one of the clients, because the refresh loop refreshed immediately instead of sleeping first. Fixed in the same PR. That is the kind of thing this feature was for, and it would not have been visible without it. If you would like to pick something else up, the tracker is open — #130 (Grafana) is now unblocked and builds directly on this. |
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
3 participants
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
#129 - Add metrics logging with thread-safe collector and /metrics endpoint
📌 Description
This PR implements comprehensive metrics logging for the PESUAuth API to enable monitoring and observability of authentication requests, errors, and system performance.
What is the purpose of this PR?
/metricsendpoint to expose collected metrics in JSON formatWhat problem does it solve?
Background:
The API previously had no metrics or monitoring capabilities, making it difficult to assess system health, debug issues, or understand usage patterns. This implementation provides comprehensive tracking without impacting performance.
🧱 Type of Change
🧪 How Has This Been Tested?
tests/unit/)tests/functional/)tests/integration/)Testing Details:
✅ Checklist
scripts/run_tests.py) -pre-commit run --all-files) -.envvars updated (if applicable) - Not applicablescripts/benchmark_auth.py) -🛠️ Affected API Behaviour
app/app.py– Modified/authenticateroute logicNew API Endpoint:
/metrics- New GET endpoint that returns current application metrics in JSON format🧩 Models
app/models/response.py– Used existing response model for metrics endpoint formattingNew Files Added:
app/metrics.py- Core MetricsCollector implementation with thread-safe operationsapp/docs/metrics.py- OpenAPI documentation for the new /metrics endpointtests/unit/test_metrics.py- Comprehensive unit tests for MetricsCollectortests/integration/test_metrics_integration.py- Integration tests for metrics collection🐳 DevOps & Config
Dockerfile– No changes to build process.github/workflows/*.yaml– No CI/CD pipeline changes requiredpyproject.toml/requirements.txt– No new dependencies added.pre-commit-config.yaml– No linting or formatting changes📊 Benchmarks & Analysis
scripts/benchmark_auth.py– No changes to benchmark scriptsscripts/analyze_benchmark.py– No changes to analysis toolsscripts/run_tests.py– No changes to test runner📸 Screenshots / API Demos
🎯 Metrics Endpoint in Action
Live metrics collection showing authentication success/failure tracking
Metrics Endpoint Response Example
{ "status": true, "message": "Metrics retrieved successfully", "timestamp": "2025-08-28T15:30:45.123456+05:30", "metrics": { "auth_success_total": 150, "auth_failure_total": 12, "validation_error_total": 8, "pesu_academy_error_total": 5, "unhandled_exception_total": 0, "csrf_token_error_total": 2, "profile_fetch_error_total": 1, "profile_parse_error_total": 0, "csrf_token_refresh_success_total": 45, "csrf_token_refresh_failure_total": 1 } }🔧 Testing Results Dashboard
Comprehensive test suite covering unit, integration, and functional scenarios
Updated API Endpoints Table
/GET/authenticatePOST/healthGET/readmeGET/metricsGETMetrics Tracked:
auth_success_total- Successful authentication attemptsauth_failure_total- Failed authentication attemptsvalidation_error_total- Request validation failurespesu_academy_error_total- PESU Academy service errorsunhandled_exception_total- Unexpected application errorscsrf_token_error_total- CSRF token extraction failuresprofile_fetch_error_total- Profile page fetch failuresprofile_parse_error_total- Profile parsing errorscsrf_token_refresh_success_total- Successful background CSRF refreshescsrf_token_refresh_failure_total- Failed background CSRF refreshes