Repository navigation
Fix missing HTTP access logs when api-server omits the core app - #72026
Conversation
ColtenOuO
left a comment
There was a problem hiding this comment.
LGTM overall.
Just a small suggestion: If you want to update your branch with the latest main, consider using rebase instead of merge.
This helps keep the commit history cleaner and easier to follow.
4314b3b to
a433742
Compare
|
Thanks for the review! Rebased onto latest |
a433742 to
0921739
Compare
jason810496
left a comment
There was a problem hiding this comment.
I'm not sure whether this is a bug or a intentional purpose?
Since the Execution API is more sensitive (it's directly related to the Task Execution), so it makes sense to have all the access logging. For the case of core API, I personally think it's fine to not have the access logging for all the routes.
cc @pierrejeambrun What do you think? Thanks.
|
Thanks for the review! It only affects all three places that disable the built-in access loggers ( |
0921739 to
5c35105
Compare
2aae5c1 to
afc7c94
Compare
|
Thanks for the review! Made the changes. |
7feebc6 to
aa2d4db
Compare
An api-server started without the core app -- for example `--apps execution`, the shape used to run the Task Execution API as its own deployment -- served requests but recorded none of them. That leaves the component every running task depends on for heartbeats, state transitions and XComs with no per-request telemetry, which is the primary signal for diagnosing heartbeat stalls. Both server backends disable their own access logger, and the built-in access loggers are muted in the logging config, all on the premise that HttpAccessLogMiddleware handles access logging. That premise only held while the middleware was installed by the core app branch, so no configuration could recover the records. Installing it for every apps selection makes the premise true again instead of adding a fourth conditional that would give execution-only deployments a different log format from every other deployment.
aa2d4db to
28b773a
Compare
Backport successfully created: v3-3-testNote: As of Merging PRs targeted for Airflow 3.X In matter of doubt please ask in #release-management Slack channel.
|
…re app (#72026) (#72808) * Fix missing HTTP access logs when api-server omits the core app An api-server started without the core app -- for example `--apps execution`, the shape used to run the Task Execution API as its own deployment -- served requests but recorded none of them. That leaves the component every running task depends on for heartbeats, state transitions and XComs with no per-request telemetry, which is the primary signal for diagnosing heartbeat stalls. Both server backends disable their own access logger, and the built-in access loggers are muted in the logging config, all on the premise that HttpAccessLogMiddleware handles access logging. That premise only held while the middleware was installed by the core app branch, so no configuration could recover the records. Installing it for every apps selection makes the premise true again instead of adding a fourth conditional that would give execution-only deployments a different log format from every other deployment. * Lock in HttpAccessLog outermost ordering with a positional assertion * Trim redundant caveat from init_middlewares ordering note --------- (cherry picked from commit 860233f) Co-authored-by: manish1337 <[email protected]> Co-authored-by: pierrejeambrun <[email protected]>
…he#72026) * Fix missing HTTP access logs when api-server omits the core app An api-server started without the core app -- for example `--apps execution`, the shape used to run the Task Execution API as its own deployment -- served requests but recorded none of them. That leaves the component every running task depends on for heartbeats, state transitions and XComs with no per-request telemetry, which is the primary signal for diagnosing heartbeat stalls. Both server backends disable their own access logger, and the built-in access loggers are muted in the logging config, all on the premise that HttpAccessLogMiddleware handles access logging. That premise only held while the middleware was installed by the core app branch, so no configuration could recover the records. Installing it for every apps selection makes the premise true again instead of adding a fourth conditional that would give execution-only deployments a different log format from every other deployment. * Lock in HttpAccessLog outermost ordering with a positional assertion * Trim redundant caveat from init_middlewares ordering note --------- Co-authored-by: pierrejeambrun <[email protected]>
`/execution` carries every task heartbeat, state transition and XCom, making it the busiest surface the API server has, and it emitted no metrics at all. Two things kept it out. The middleware was registered from `init_middlewares`, which `create_app` only calls for the core app, so `airflow api-server --apps execution` -- the shape used to run the execution API as its own deployment -- installed nothing, and no configuration could recover the metrics. The path prefix allowlist also covered only `/api/v2` and `/ui`. Install the middleware for every `--apps` selection from a new `init_api_metrics`, the shape apache#72026 settled on after the identical gap left execution-only deployments with no access logs, and add `/execution` to the allowlist. Registering it on the outer app rather than inside the execution sub-app keeps a single instance, so a request cannot be counted twice, and keeps it outside `GZipMiddleware` so execution API durations include compression time the way core API durations already do. A mounted sub-app declares its routes relative to the mount point, so the route tag now carries `root_path`. Without it, `/execution/task-instances/{id}/run` would be tagged `/task-instances/{id}/run` and collide with any core route sharing that template.
`/execution` carries every task heartbeat, state transition and XCom, making it the busiest surface the API server has, and it emitted no metrics at all. Two things kept it out. The middleware was registered from `init_middlewares`, which `create_app` only calls for the core app, so `airflow api-server --apps execution` -- the shape used to run the execution API as its own deployment -- installed nothing, and no configuration could recover the metrics. The path prefix allowlist also covered only `/api/v2` and `/ui`. Install the middleware for every `--apps` selection from a new `init_api_metrics`, the shape apache#72026 settled on after the identical gap left execution-only deployments with no access logs, and add `/execution` to the allowlist. Registering it on the outer app rather than inside the execution sub-app keeps a single instance, so a request cannot be counted twice, and keeps it outside `GZipMiddleware` so execution API durations include compression time the way core API durations already do. A mounted sub-app declares its routes relative to the mount point, so the route tag now carries `root_path`. Without it, `/execution/task-instances/{id}/run` would be tagged `/task-instances/{id}/run` and collide with any core route sharing that template.
* add metrics * allow user define the mapping themself * Move API metrics config validation into configuration parser * Simplify REST API metrics tagging Remove the configurable path-to-surface mapping and emit metrics only for core API and UI routes. Use normalized route templates with method and status family tags to keep metric cardinality bounded. * Report REST API request duration under a milliseconds metric name Stats.timing records milliseconds on every supported backend, so publishing the timer as http_request_duration_seconds would have left every consumer of the metric wrong by a factor of 1000. Route tagging also kept a fallback that reverse-looked-up the endpoint in scope["router"].routes whenever scope["route"] was absent. Only FastAPI's APIRoute populates scope["route"], and all 151 routes under /api/v2 and /ui are APIRoute, so that branch was unreachable. For a mounted sub-app -- the one case it was meant to cover -- scope["router"] stays the root router, so the lookup could not have succeeded there either. The tests built a plain Starlette app, which never sets scope["route"], and so covered only that dead branch instead of the path the API server actually takes. * Bound the REST API metrics method tag to methods the API serves The router rejects a method mismatch with 405 before any authentication dependency runs, and uvicorn's h11 parser accepts any token as a method. That let an anonymous client create a new metric series per request just by inventing method names, defeating the bounded-cardinality goal of these metrics. Only the five methods registered on API routes now get their own tag value; everything else is recorded as OTHER, so the series count is fixed by the route table rather than by whatever clients send. * Cover the Task SDK execution API in the REST API metrics `/execution` carries every task heartbeat, state transition and XCom, making it the busiest surface the API server has, and it emitted no metrics at all. Two things kept it out. The middleware was registered from `init_middlewares`, which `create_app` only calls for the core app, so `airflow api-server --apps execution` -- the shape used to run the execution API as its own deployment -- installed nothing, and no configuration could recover the metrics. The path prefix allowlist also covered only `/api/v2` and `/ui`. Install the middleware for every `--apps` selection from a new `init_api_metrics`, the shape #72026 settled on after the identical gap left execution-only deployments with no access logs, and add `/execution` to the allowlist. Registering it on the outer app rather than inside the execution sub-app keeps a single instance, so a request cannot be counted twice, and keeps it outside `GZipMiddleware` so execution API durations include compression time the way core API durations already do. A mounted sub-app declares its routes relative to the mount point, so the route tag now carries `root_path`. Without it, `/execution/task-instances/{id}/run` would be tagged `/task-instances/{id}/run` and collide with any core route sharing that template. * Build the API metrics test app once per module Review feedback: every test rebuilt the whole FastAPI app just to issue one request, so the app construction cost was paid once per test case for no benefit. A module-scoped fixture is enough -- the middleware under test holds no state, and each test still gets its own client. * Document that REST API metric tags need a tagging backend Review feedback: the metric tables promised a breakdown by method, route and status_family without saying that classic StatsD drops tags, so an operator reading the docs would configure statsd_on and then wonder why they only ever see one aggregate series.
An
api-serverstarted without the core app — for example--apps execution, the shape used to runthe Task Execution API as its own deployment — serves requests normally but emits no access log
lines at all.
Three separate places disable the built-in access loggers, all resting on the premise that
HttpAccessLogMiddlewarehandles access logging:AirflowUvicornWorker.CONFIG_KWARGS—access_log: Falseapi_server_commanduvicorn.access/gunicorn.accessmuted (handlers: [],propagate: False) inlogging_configThat premise only held while the middleware was installed inside the
"core" in apps_listbranch ofcreate_app, so an--appsselection withoutcorehad no access-log producer at all — and becausethe loggers are muted at the logging-config level too, no configuration could bring the records back.
This installs the middleware for every
appsselection, which makes the premise true again ratherthan adding a fourth conditional. The alternative — enabling uvicorn's own access log when
coreisabsent — needs three coordinated conditionals across three files and would give execution-only
deployments a different log format from every other deployment.
For anyone running the Task Execution API as its own deployment, this restores per-request telemetry
(latency, status codes, endpoint counts) for the component every running task depends on for
heartbeats, state transitions and XComs.
Verification
Started a real
api-serverand issued a marked request, before and after the change:--appsexecutioncoreallcore/allis unchanged:[HttpAccessLogMiddleware, GZipMiddleware, JWTRefreshMiddleware].[execution]without the fix and passes with it.airflow-core/tests/unit/api_fastapi(3750),providers/fab(536) andproviders/common/compat(197) pass. The
test_hitl.pyand example-Dag failures seen locally also fail on unmodifiedmain, so they are unrelated.Note for reviewers: #64523 (open) also edits
init_middlewaresto add a metrics middleware, so thetwo may conflict textually.
Was generative AI tooling used to co-author this PR?
Generated-by: Claude Code (Opus 5) following the guidelines