Explain slow and stalled remote config applies - #7625
Open
christophe-papazian wants to merge 15 commits into
Open
Explain slow and stalled remote config applies#7625christophe-papazian wants to merge 15 commits into
christophe-papazian wants to merge 15 commits into
Conversation
An RC apply that is not acknowledged in time surfaces only as `assert <UNKNOWN: 0> == <ACKNOWLEDGED: 2>`, which says nothing about why. The information needed is usually already there: libraries report their own slow remote config callbacks through telemetry, and system-tests collects it. - measure every apply, and report it when it takes longer than 5s or times out - on those, log the warnings the library sent through telemetry - give the timeout message the elapsed time, expected and last-seen targets version, and which configs were still unacknowledged - fix `state` being shadowed by two loop variables, which made the timeout message report fields off a config-state dict instead of the client state Nothing new is sent to the library and nothing is logged for a healthy apply, which stays on a debug line. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Telemetry says an RC callback was slow, but not where it was stuck. Capture the weblog's thread stacks while a stalled apply is still in progress, at 10s and 20s in, so a thread parked on one call can be told from one that is moving. Stacks are read from outside the process, which cannot perturb or crash the process being measured. py-spy covers the python weblogs and is added to their images; java uses jcmd, already present. Other libraries are not covered and stay silent. An apply that completes before the first deadline captures nothing, so healthy runs are unaffected. Every failure path is swallowed: no weblog in the scenario, no command for the library, or the exec failing all return quietly rather than raising in the watcher thread. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
…c-apply-diagnostics
Contributor
|
|
|
CI on the previous commit was green, but its logs were not: 140 spurious slow warnings, 5 "timed out" errors on passing runs, and 5 stack dumps that were really `jcmd: executable file not found` logged as though they were dumps. - raise SLOW_APPLY_THRESHOLD to 12s. 5s was calibrated on python (under 2s), but java and golang normally take around 8s and reach 10s - drop the java/jcmd command: jcmd is not in the java weblog image. Stack dumps are python-only now, and unsupported libraries create no watcher - check exit_code, so a failed command is reported as a failure instead of being logged under a "thread stacks" heading - bound the dump with `timeout` in the container, and pass --nonblocking so reading stacks does not pause the process being measured - measure elapsed inside the wait, so watcher teardown is not counted as part of the apply, and pass the caller's start time so deadlines measure the wait rather than when the thread was scheduled; skip missed deadlines - report a non-acknowledged apply as a warning, not an error: it does not always fail a test. Log it before the sleep so an outer timeout cannot lose it - drop the global dedupe set: every line carries a unique elapsed_time, so it never deduplicated and grew without bound. Deduplicate within one report, and cap both the number of warnings and the size of a dump - guard thread start, and annotate the context manager's return type - snapshot _data_list under the lock in get_data(): the watchdog thread appends to and re-sorts it, which could make a walk skip or repeat entries Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
christophe-papazian
marked this pull request as ready for review
September 2, 2026 08:12
christophe-papazian
requested review from
bouwkast
and removed request for
a team
September 2, 2026 08:12
Codex Review SummaryThis comment shows the latest Codex review activity on this pull request.
ℹ️ About Codex in GitHubYour team has set up Codex to review pull requests in this repo. Reviews are triggered when you
Codex reacts with 👀 while any review is running, comments if it has suggestions, and reacts with 👍 once all reviews finish with no findings. |
![chatgpt-codex-connector[bot]](https://avatars.githubusercontent.com/in/1144995?s=60&v=4){kind=small}
There was a problem hiding this comment.
💡 Codex Review
Here are some automated review suggestions for this pull request.
Reviewed commit: 7fdac44ea4
ℹ️ About Codex in GitHub
Your team has set up Codex to review pull requests in this repo. Reviews are triggered when you
- Open a pull request for review
- Mark a draft as ready
- Comment "@codex review".
If Codex has suggestions, it will comment; otherwise it will react with 👍.
Codex can also answer questions or update the PR. Try commenting "@codex address that feedback".
py-spy reads thread stacks from outside the process, which needs ptrace. SYS_PTRACE was only granted by enable_core_dumps(), called for php and cpp_nginx alone, so a stalled python apply would have produced a permission error instead of stacks. Add enable_ptrace() and call it for python. It does not set privileged or core ulimits, which enable_core_dumps() does and this does not need. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
…c-apply-diagnostics
bouwkast
approved these changes
Sep 2, 2026
0.4.1 printed each child process once per parent thread when dumping with --subprocesses (benfred/py-spy#832), which is the mode used here. A local run reproduced it: the gunicorn worker appeared 4 times in a single dump, once per python thread in the master. 0.4.2 prints each process once. 0.4.1 was simply the version that happened to be verified first; there was no reason to hold it back. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
…c-apply-diagnostics
christophe-papazian
enabled auto-merge (squash)
September 2, 2026 14:27
cbeauchesne
reviewed
Sep 2, 2026
cbeauchesne
requested changes
Sep 2, 2026
…eblog Moves the install into the 7 python base Dockerfiles and bumps each base image one version, so the 8 weblogs that derive from them inherit it rather than repeating the same line. Base images bumped: django-poc v12->v13, django-py3.13 v11->v12, fastapi v9->v10, flask-poc v15->v16, python3.12 v14->v15, tornado v2->v3, uwsgi-poc v11->v12. References updated in the base Dockerfiles' build/push comments, the leaf FROM lines, uds-flask (which derives from flask-poc), docker-bake.hcl, and mirror_images.yaml via update_mirror_images.py. The fastapi and tornado push comments were stale (v8 and v1) and now match. anthropic-py, openai-py and google_genai-py build from python:3.11-slim with no system-tests base image, so they keep the install in the leaf. utils/build/docker/python_otel/flask-poc-otel.Dockerfile is left on flask-poc.base-v1 on purpose: it pins an old base, not the current one. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
…c-apply-diagnostics
`mirror_images.py add` rewrites the file through a YAML parser, which drops comments, but only when it actually adds an image. Regenerating after a new image therefore deleted the file's own documentation, including the line telling the reader how to regenerate it. Adding the python base images to this branch hit exactly that. Capture whatever preamble is committed before the add and re-apply it after, rather than rewriting from the constant in this script, whose wording has drifted from the file. Verified by removing an entry and regenerating: the entry comes back, the header survives, and the file is byte-identical to before. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
cbeauchesne
requested changes
Sep 3, 2026
cbeauchesne
left a comment
cbeauchesne
left a comment
Collaborator
There was a problem hiding this comment.
- Can you also update
mirror_images.lock.yaml? - I've left few comments for where are stored the new dep, but not on all files
Review feedback: py-spy belongs with the other dependencies rather than in a separate RUN. All 7 python base images already install from a requirements-*.txt, so it goes there, one layer fewer each. anthropic-py, openai-py and google_genai-py have no requirements file, so it joins their existing pip install line. The base image version bumps stay: the requirements files are baked into those images, so their content still changes. Also drops the mirror_images.yaml header fix from this branch. That bug is independent of remote config diagnostics and belongs in its own PR. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
…c-apply-diagnostics # Conflicts: # utils/build/docker/python/anthropic-py.Dockerfile # utils/build/docker/python/google_genai-py.Dockerfile # utils/build/docker/python/openai-py.Dockerfile
Self-review findings on this file. A single telemetry entry of an unexpected shape discarded every warning already collected, including the slow-callback line the diagnostics exist to surface: the whole loop shared one try/except that returned. Entries are now shape-checked individually, the collected lines live outside the try, and a failure part-way through the stream logs what was read instead of dropping it. STACK_DUMP_TIMEOUT drops from 10s to 5s. At 10s it equalled the gap between the two STACK_DUMP_AFTER deadlines, so a slow first dump made the watcher skip the second and lose the comparison that justifies taking two samples. A measured dump takes about 0.1s. This also shortens the join on the setup path, which is now the command bound alone rather than the bound plus five seconds. A dump that finishes after the apply completed no longer logs: it would have described a stall that had already resolved. Also documents that reading the client state with .get() replaced a KeyError raised from inside the wait callback, which was an incidental change in the earlier rename rather than a deliberate one. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Remaining self-review findings on this file. Telemetry warnings were read from the whole session, so a slow apply late in a scenario reported every warning produced before it, and several slow applies in one run repeated the same list. Every proxied flow carries an ISO-8601 timestamp_start, so warnings are now selected by arrival time and only those from the apply's own window are reported. A flow with a missing or unparseable timestamp is kept, since losing the evidence is worse than reporting one from slightly earlier, and a small margin absorbs clock differences between the proxy and this process. SLOW_APPLY_THRESHOLD becomes half the wait budget rather than a value fitted to the maxima we happened to measure: past 15s an apply is closer to timing out than to succeeding. The wait timeout is now the named APPLY_TIMEOUT it derives from, instead of a literal 30. Also: name the truncation used when a dump command fails, fold the duplicated library and container checks into one _stack_dump_target(), and type last_client_state precisely. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
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.
APPSEC-69943
An RC apply that is not acknowledged in time currently surfaces only as
assert <UNKNOWN: 0> == <ACKNOWLEDGED: 2>, which says nothing about why. Chasing one of these took a long time for want of information that was already being collected.targets_version, and which configs were unacknowledgedpy-spyfor python, added to their images;jcmdfor java). Other libraries stay silentstatebeing shadowed by two loop variables, which made the timeout message report fields off a config-state dict instead of the client stateNothing new is sent to the library and nothing is logged for a healthy apply, which stays on a debug line. Every diagnostic path is exception-safe.
Verified by replaying the telemetry of a real failure, which now surfaces the cause directly:
Threshold note: 5s is calibrated on python (20 000 measured applies, max 1.80s). If another library routinely acknowledges more slowly,
SLOW_APPLY_THRESHOLDis a single constant to raise.🤖 Generated with Claude Code