Explain slow and stalled remote config applies - #7625
Explain slow and stalled remote config applies#7625christophe-papazian wants to merge 4 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
|
|
🎉 All green!🧪 All tests passed 🔗 Commit SHA: 7fdac44 | Docs | View more details | Give us feedback! |
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>
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".
| _STACK_DUMP_COMMANDS: dict[str, str] = { | ||
| # `timeout` bounds the command so a hung dump cannot extend the apply, and | ||
| # --nonblocking keeps py-spy from pausing the process we are measuring | ||
| "python": f"timeout {STACK_DUMP_TIMEOUT} py-spy dump --pid 1 --subprocesses --nonblocking", |
There was a problem hiding this comment.
When a Python RC apply exceeds 10 seconds, this command exits immediately instead of capturing any stacks because py-spy 0.4.1's dump --help does not list --subprocesses among the dump options; that flag is supported by other py-spy modes such as record. Consequently every scheduled dump reaches the nonzero-exit diagnostic path, defeating the primary stalled-apply investigation feature. Invoke dump without this flag and explicitly select the relevant Python PIDs if subprocess coverage is required.
Useful? React with 👍 / 👎.
| _STACK_DUMP_COMMANDS: dict[str, str] = { | ||
| # `timeout` bounds the command so a hung dump cannot extend the apply, and | ||
| # --nonblocking keeps py-spy from pausing the process we are measuring | ||
| "python": f"timeout {STACK_DUMP_TIMEOUT} py-spy dump --pid 1 --subprocesses --nonblocking", |
There was a problem hiding this comment.
On standard Linux Docker hosts with the usual Yama ptrace restrictions, this stack-dump invocation still fails with permission denied even after the unsupported flag is removed: py-spy's Docker instructions require the target container to have SYS_PTRACE, while the checked WeblogContainer path supplies only security_opt=["seccomp=unconfined"] and adds SYS_PTRACE only for the PHP/C++ core-dump path in utils/_context/containers.py. Grant the capability to Python weblog containers (or use an external privileged profiler), otherwise stalled Python applies produce no stacks in CI.
Useful? React with 👍 / 👎.
1 participant
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