Skip to content

Recover Azure App Service agents after overlapping restarts - #12899

Open
Lewis-E wants to merge 9 commits into
masterfrom
lewis.lewis/svls-9057-aas-agent-supervision
Open

Lewis-E wants to merge 9 commits into
masterfrom
lewis.lewis/svls-9057-aas-agent-supervision

Conversation

@Lewis-E

@Lewis-E Lewis-E commented Oct 15, 2026 •

Copy link
Copy Markdown
Contributor

What Does This Do

This makes the tracer's agent supervisor in Azure App Service recover from overlapping restarts, and makes its lifecycle readable in default-level logs. A followup to #12898.

  1. ProcessSupervisor logs each agent start, exit (exit code and run time), and stop at info, with the tracer PID and, (on Java 9+) the agent PID. It also logs when it uses an agent that another process started, when that agent disappears, and when shutdown leaves an agent running. After repeated quick failures these lines drop to debug until the agent stays up.
  2. Restarts back off from 2 s, doubling to a 60 s cap, and never stop. The fault count resets only after the agent has stayed up for 60 s.
  3. While an agent this tracer started is running, the supervisor health-checks it every 10 s and restarts it after 3 failed checks in a row. It never starts a second copy while its own is still running.
  4. A pipe whose instances are all busy counts as present.
  5. The trace agent health check now has an option to send GET /info over a pipe handle of its own, with tracing muted, and waits at most 2 s.

Motivation

On Azure App Service (Windows), an overlapped IIS recycle leaves Java apps without telemetry until someone restarts them (SVLS-9057, escalation SLES-2826).

Background. In App Service, the Datadog site extension doesn't run an agent. Each tracer starts datadog-trace-agent.exe and dogstatsd.exe itself and sends to them over Windows named pipes. The extension picks the two pipe names once, at install, so every worker process on the site uses the same names. Only one process can own a pipe name. An agent started while another agent still holds the name fails to create its pipe, and the trace agent exits at once with "Access is denied". So before starting an agent, a tracer checks whether the pipe already exists, and if it does, it uses the agent that's already there.

During an overlapped IIS recycle, the old and new worker run at the same time, and each worker start also runs several JVMs in a row. So several tracers are checking the same pipes and starting agents on them at once. When one of those agents couldn't start, hung, or kept exiting, the tracer's ProcessSupervisor handled it badly:

  • An agent that couldn't start was given up on for good. After 5 failed starts the supervisor stopped trying, so the app sent nothing until it was restarted, even after the cause went away. For example, the agents run from %HOME%, so they can't start while Azure Storage is unavailable. Restarts now back off up to 60 s and never stop (change 2).
  • A hung agent was never noticed. After starting an agent, the supervisor only waited for it to exit. An agent that stopped answering but kept running also kept its pipe, so traces stopped until the app restarted. A hung agent is the leading explanation for one customer's 27-hour outage. The supervisor now health-checks agents it started and restarts them (changes 3 to 5).
  • An agent that kept exiting was restarted every 2 s, forever. The fault count reset on every start, so there was no backoff. For example, while the old worker's agent still owns the pipe during the overlap, each agent the new worker's tracer starts fails to create the pipe and exits right away. That tracer started a new process every 2 s for as long as the old agent ran. Restarts now back off up to 60 s (change 2).

Additionally:

  • The default logs couldn't show what happened. Starts, exits, exit codes, and use of another worker's agent were debug-only or not logged. Improved logging helps the customer figure out what's happening immediately, and helps us debug and determine a fix.
  • A new JVM truncated the shared tracer log file from 3,522 bytes to 0, so the old JVM's last lines, including its shutdown, were lost. A separate PR Write a per-process tracer log file in Azure App Service #13227 will address this if accepted.

Additional Notes

  • Busy pipes are recognized by the English text of the open error. Note that Azure always gives errors in English as far as I can tell. This still feels a bit fragile and better approaches would be welcome.
  • Any HTTP status from /info counts as healthy.
  • Pipe reads can't time out, so an /info request to a hung agent stays blocked until that agent exits. Later checks fail without sending another request.
  • A slow /info from an agent started by another worker will cause one duplicate start. The duplicate can't create the pipe and exits.
  • The supervisor restarts only an agent it started, and never kills one it didn't. If an adopted trace agent hangs while holding the pipe, the tracer logs it once and keeps retrying on the capped backoff, but traces stay down until that agent exits.
  • On Java 8 the logs show the child agent's PID as unknown, because Java 8 has no public API for it.
  • Tests: ProcessSupervisorTest covers the backoff, the fault-count reset, restarting after failed health checks, adopting an agent it didn't start, and not starting a second agent while one won't stop.
  • The pipe health checks and the busy-pipe check ran in the App Service repro on Windows and have no unit tests. Tests could maybe be added after Experiment with testing of dd-trace-java on GitLab on Windows OS #12311 -- right now there's no windows CI where named pipes could even potentially be created.

Contributor Checklist

Jira ticket: SVLS-9057

@datadog-prod-us1-5

datadog-prod-us1-5 Bot commented Oct 15, 2026 •

Copy link
Copy Markdown
Contributor

🎯 Code Coverage (details)
• Patch Coverage: 44.71%
• Overall Coverage: 59.94% (-0.02%)

This comment will be updated automatically if new data arrives.
🔗 Commit SHA: 92c63d2 | Docs | Give us feedback!

@dd-octo-sts

dd-octo-sts Bot commented Oct 15, 2026 •

Copy link
Copy Markdown
Contributor

🟢 Java Benchmark SLOs — All performance SLOs passed

Suite Status
Startup 🟢 pass

SLO thresholds are defined here based on automatically generated metrics. A warning is raised when results are within 5% of the threshold.

PR vs. master results
Scenario Candidate master Δ (95% CI of mean)
startup:insecure-bank:iast:Agent 14.85 s 14.68 s [+0.4%; +1.9%] (maybe worse)
startup:insecure-bank:tracing:Agent 13.64 s 13.75 s [-1.7%; +0.2%] (no difference)
startup:petclinic:appsec:Agent 17.16 s 16.52 s [-0.7%; +8.4%] (no difference)
startup:petclinic:iast:Agent 16.93 s 17.02 s [-1.3%; +0.3%] (no difference)
startup:petclinic:profiling:Agent 16.67 s 16.85 s [-2.2%; +0.1%] (no difference)
startup:petclinic:sca:Agent 17.09 s 17.00 s [-0.4%; +1.4%] (no difference)
startup:petclinic:tracing:Agent 16.16 s 16.15 s [-0.9%; +1.0%] (no difference)

Commit: 92c63d26 · CI Pipeline · Benchmarking Platform UI


Load and DaCapo benchmarks can be triggered manually in the GitLab pipeline. Results will appear in the Benchmarking Platform UI after completion.

@Lewis-E
Lewis-E force-pushed the lewis.lewis/java-named-pipe-statsd-fixes branch 3 times, most recently from 2254f7d to 0c39b52 Compare October 30, 2026 16:45
@Lewis-E
Lewis-E force-pushed the lewis.lewis/svls-9057-aas-agent-supervision branch from 391843b to 1c4bed4 Compare October 30, 2026 16:48
Base automatically changed from lewis.lewis/java-named-pipe-statsd-fixes to master November 3, 2026 22:13
In Azure App Service the tracer starts and supervises the trace agent and
DogStatsD. Overlapping worker processes during platform restarts can leave
those agents missing or shared, but starts, exits, and stops were only
logged at debug level, so default customer logs could not show what
happened.

- Log each agent start, exit (with exit code and run time), and stop at
  info, with the tracer PID and, on Java 9+, the agent PID.
- Log when an already-running agent not started by this process is used,
  and when that agent goes away.
- After repeated quick failures, move lifecycle lines to debug until the
  agent stays up, so a crash loop does not flood the log.
- Warn when shutdown leaves an agent running.
ProcessSupervisor reset its fault count on every successful start, so an
agent that kept exiting was restarted every 2 seconds forever, while a
start that kept throwing gave up for good after 5 attempts.

- Forget faults only after the process stays up for 60 seconds.
- Back off after each fault, doubling from 2 seconds to a cap of 60
  seconds, and never stop retrying.
- Move repeated start exceptions to debug after the first few, so a
  permanently failing start does not log a stack trace every minute.
Once ProcessSupervisor started an agent it blocked in waitFor() until the
agent exited, so an agent that hung but stayed alive was never checked or
replaced.

- While its own agent runs, wait in keep-alive steps of 10 seconds and
  run the health check after each one.
- After 3 failed health checks in a row, stop that agent and go back
  through the normal start path, after the fault backoff. Log the first
  failed check and the restart once.
- Keep tracking an agent that is still running after a stop request, so
  a restart never starts a second copy next to it.
- Supervisors without a health check keep only waiting for the exit.
On Windows, File.exists() can report false for a named pipe whose
instances are all busy. The supervisor then took a busy agent for a
missing one and started a competing agent, which lost the pipe race and
exited.

When File.exists() reports false on Windows, open the pipe once and close
it again. Only "cannot find the file" means the pipe is absent; "All pipe
instances are busy" and other open errors mean a process is serving it.
The trace agent health check only tested that its pipe existed, so a hung
agent that kept its pipe was trusted forever.

- After the pipe check passes, send a minimal GET /info over a pipe handle
  of the check's own, outside the tracer's HTTP clients, with tracing
  muted.
- Treat any HTTP status line as an answer. A busy pipe counts as present.
- Pipe reads cannot time out, so send the request on a daemon thread and
  give up after 2 seconds. While that request is still blocked, later
  checks fail without sending another one.
- DogStatsD never replies, so its check stays "pipe present".
@Lewis-E
Lewis-E force-pushed the lewis.lewis/svls-9057-aas-agent-supervision branch from 1c4bed4 to 42dd7e4 Compare November 4, 2026 18:14
The supervisor now health checks its own agent while it runs, restarts it
after three failed checks in a row, uses an agent another process
started, and never gives up retrying. Only the backoff arithmetic was
tested, so coverage of these paths was too low for the build to pass.

The new tests start a fake Process from a mocked ProcessBuilder. The fake
returns quickly from timed waits, so health checks that normally run ten
seconds apart run fast, and each test can choose how the process exits or
refuses to stop. They check that the supervisor:

- restarts its own process after exactly three failed health checks;
- keeps its process when a health check passes before the third failure;
- uses a process it did not start, then starts its own once that one
  goes away (this waits out the real ten second healthy interval);
- keeps tracking a process that ignores stop requests instead of
  starting a second copy;
- retries after the process fails to start;
- logs the exit code and starts again after the process exits.
@Lewis-E
Lewis-E force-pushed the lewis.lewis/svls-9057-aas-agent-supervision branch from 1823a62 to d3b4fd3 Compare November 4, 2026 20:01
healthCheck(pipe, true) and healthCheck(pipe, false) didn't say what the
flag meant at the call site. Use answersOnPipe for the trace agent, which
must answer GET /info, and pipePresent for DogStatsD, which never replies
on its pipe. No behavior change.
The supervised agents run only on Windows, where Process.destroy() and
destroyForcibly() both call TerminateProcess, so the forced second attempt
did nothing new. Call destroy() once and wait up to 400 ms, the same total
wait as the two 200 ms waits before. A process that is still running after
that is kept and tracked as before.
@Lewis-E
Lewis-E marked this pull request as ready for review November 5, 2026 16:40
@Lewis-E
Lewis-E requested a review from a team as a code owner November 5, 2026 16:40
@Lewis-E
Lewis-E requested review from bric3 and removed request for a team November 5, 2026 16:40
@chatgpt-codex-connector

chatgpt-codex-connector Bot commented Nov 5, 2026 •

Copy link
Copy Markdown

Codex Review Summary

This comment shows the latest Codex review activity on this pull request.

Review Status Commit Review trigger
📝 Code Review ✅ Completed 2026-11-05T16:47:21.609076Z d3b4fd3 Draft marked ready
ℹ️ 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" or "@codex security review".

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 chatgpt-codex-connector Bot left a comment

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

💡 Codex Review

Here are some automated review suggestions for this pull request.

Reviewed commit: d3b4fd3ff9

ℹ️ About Codex in GitHub

Codex has been enabled to automatically 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 👍.

When you sign up for Codex through ChatGPT, Codex can also answer questions or update the PR, like "@codex address that feedback".

@datadog-prod-us1-5 datadog-prod-us1-5 Bot left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Bits Code Review: FAIL

Localized Windows missing-pipe errors are treated as proof that an agent is running, preventing trace-agent and DogStatsD startup or recovery on affected hosts.

Open Bits AI session

🤖 Bits Code Review · Commit d3b4fd3

- An exit before the process stayed up for 60 s is now a fault whatever
  its exit code, so it backs off and counts toward quiet logging. The
  trace agent exits with 0 at once when APM is disabled, and that used to
  restart about every 100 ms, now with start and exit lines at info.
- Lifecycle logs return to info once the running process has stayed up
  for 60 s, not only after it exits.
- A trace agent /info answer that arrives after the 2 s timeout counts at
  the next check, instead of being dropped by a new request. An agent that
  always answers in just over 2 s was failing every check.
@Lewis-E

Lewis-E commented Nov 5, 2026

Copy link
Copy Markdown
Contributor Author

@DataDog review

@datadog-prod-us1-5 datadog-prod-us1-5 Bot left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Bits Code Review: PASS

More details

Health-triggered restarts remain restricted to agents started by this tracer, preserving agents adopted from overlapping workers. Confidence is limited to static analysis; Windows named-pipe recovery was not exercised at runtime.

Was this helpful? React 👍 or 👎

Open Bits AI session

🤖 Bits Code Review · Commit 92c63d2

This branch has not been deployed

No deployments
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

comp: core Tracer core comp: logging Tracer internal logging type: bug fix Bug fix

Projects

None yet

Development

Successfully merging this pull request may close these issues.

2 participants