fix(tracer): flush telemetry when Stop is called - #5345
Hashim1999164 wants to merge 4 commits into
Conversation
![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: 349e457df7
ℹ️ 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".
Skip StopApp when another product already owns the global client, and flush before closing the log file.
805a5c5 to
dd3b0a8
Compare
|
pushed a follow up for the review notes. StopApp only runs when the tracer actually owns the global telemetry client. if something else owns it we just close the leftover client. also moved the telemetry flush before closing the log file. on the concurrent Stop race thing, bro i dont know that lmao, left stopOnce as is for now. |
|
@codex review |
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. |
🛡️ Codex Security Review · Automatically triggeredSecurity review completed. No security issues were found in this pull request. Reviewed commit: Only the user who started this review can view the report in Codex. ℹ️ About Codex security reviews in GitHubThis is an experimental Codex feature. Security reviews are triggered when:
Once complete, Codex will leave suggestions, or a comment if no findings are found. |
There was a problem hiding this comment.
💡 Codex Review
Here are some automated review suggestions for this pull request.
Reviewed commit: dd3b0a8e60
ℹ️ 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".
StopApp was tearing down the tracer owned global client even after the profiler had started and reused it. Mark the tracer product stopped, flush when the profiler is still up, and only StopApp when nothing else shares the client. Also gate telemetry shutdown with sync.Once so concurrent Stop calls cannot race on the client pointer.
|
pushed a follow up for the shared client case. if the profiler is still running we just mark the tracer product stopped and flush, we do not call StopApp. also wrapped the telemetry shutdown in sync.Once so concurrent Stop cannot race on the client pointer |
|
@darccio any update on this one when you get a chance? |
|
@DataDog review |
|
@Hashim1999164 I'll review it myself this week. |
|
@codex review |
| // Profiler started after us and still shares this client. Mark the | ||
| // tracer product stopped and flush, but leave the app running. |
There was a problem hiding this comment.
In this branch the app is deliberately left running because the profiler still
shares the client, but nothing ever stops it afterwards: profiler.Stop() has no
telemetry teardown at all (no ProductStopped(profilers) and no StopApp anywhere
in the profiler package), so when the profiler is the last product to stop,
app-stopped is never sent and the client's ticker goroutine lives until process
exit. The periodic ticker does keep flushing while the process runs, so this is
bounded (one goroutine + ticker per process), and the gap is pre-existing — in
the profiler-first ordering, main has the same leak. Still worth a TODO here so
the assumption is recorded, with the profiler-side fix as a follow-up PR.
| // Profiler started after us and still shares this client. Mark the | |
| // tracer product stopped and flush, but leave the app running. | |
| // Profiler started after us and still shares this client. Mark the | |
| // tracer product stopped and flush, but leave the app running. | |
| // TODO: profiler.Stop() never stops telemetry, so when the profiler is | |
| // the last product to stop, app-stopped is never sent and the client's | |
| // ticker goroutine lives until process exit. Follow-up: profiler.Stop() | |
| // should send ProductStopped(NamespaceProfilers) and StopApp() when it | |
| // owns the global client. |
There was a problem hiding this comment.
added the TODO as suggested
| client.Close() | ||
| return | ||
| } | ||
| if traceprof.ProfilerEnabled() { |
There was a problem hiding this comment.
This check has a small TOCTOU window against profiler.Start(). SetProfilerEnabled(true)
is the last statement of profiler.Start (profiler/profiler.go:94), after run() has already
called startTelemetry synchronously (profiler/profiler.go:314). If tracer.Stop() executes
in between — profiler's package mu doesn't help, tracer.Stop() never takes it — this
check reads false and StopApp() closes the very client the profiler just registered
ProductStarted(profilers) on, leaving the profiler running with dead telemetry.
This race is pre-existing (main closes the same shared client unconditionally in that
window) and the window is only a handful of statements wide, so not blocking. The cheap
fix is in profiler/profiler.go: set the flag before activeProfiler.run() instead of
after — flush-only is the safe direction during profiler start, since the client
survives and the profiler attaches to it normally. The reverse interleaving is already
fine: if StopApp() completes first, profiler startTelemetry sees GlobalClient() == nil
and starts a fresh app.
There was a problem hiding this comment.
raised SetProfilerEnabled(true) before run() so the window is closed
| client.Close() | ||
| return | ||
| } | ||
| if traceprof.ProfilerEnabled() { |
There was a problem hiding this comment.
This check also trusts a flag that can go stale. In profiler.Start() (profiler/profiler.go:87-89),
when a profiler is already active, the old instance is stopped but neither activeProfiler nor
traceprof.SetProfilerEnabled is reset, and every early return afterwards leaves that state behind:
- Start() ok, then Start() where the new config is disabled (DD_PROFILING_ENABLED flipped
in-process; returns nil, so nothing signals a problem): flag stays true with a stopped
activeProfiler. - Start() ok, then Start() failing in newProfiler (agentless without API key,
AWS_Lambda env, hostname error): same stale state, though at least an error is returned.
In both sequences no profiler is running, but this branch sees ProfilerEnabled() == true,
takes the flush-only path, and leaves the global telemetry client and its ticker goroutine
orphaned until process exit — no app-stopped, and profiler.Stop() afterwards clears the flag
but touches no telemetry. The stale state itself is pre-existing (the branch is unchanged on
main), but this PR is the first consumer that branches on the flag, so main's unconditional
Close() was accidentally correct here while the new check inherits the bug.
The staleness is fixable in five lines, in profiler.Start's stop-old-profiler branch:
if activeProfiler != nil {
activeProfiler.stop()
activeProfiler = nil
traceprof.SetProfilerEnabled(false)
}
That makes the flag strictly track "a profiler is assigned and running" on every early return,
and doesn't widen the (separate) race window between run() and the flag being re-raised. It's
a pre-existing bug so it could be a follow-up PR, but since this change is what makes it
observable, it's worth riding along. No existing test covers Start-then-Start-disabled or
Start-then-Start-error; one should be added with whichever fix lands.
There was a problem hiding this comment.
clearing activeProfiler + SetProfilerEnabled(false) in the stop-old branch now, plus a restart-disabled test
| assert.False(t, telemetryClient.Stopped) | ||
| assert.Equal(t, telemetry.Client(telemetryClient), telemetry.GlobalClient()) |
There was a problem hiding this comment.
These assertions prove StopApp wasn't called on the foreign client — good — but none of the
three tests observe the behavior the PR is named after. assert.Nil(GlobalClient()) in
TestTracerStopFlushesTelemetry proves StopApp ran, not that the queue flushed; and here the
leftover-client Close() (the ticker-leak fix the code comment describes) is unverified,
because RecordClient.Flush() is a no-op (telemetrytest/record.go:216) and Close() records
nothing (record.go:44-46).
RecordClient.Products does record ProductStopped — worth asserting here to pin down that the
tracer's product-stopped still propagates to the foreign-owned client:
| assert.False(t, telemetryClient.Stopped) | |
| assert.Equal(t, telemetry.Client(telemetryClient), telemetry.GlobalClient()) | |
| // Profiler or another product already owns the global client. Stop must | |
| // not call StopApp on it. | |
| assert.False(t, telemetryClient.Stopped) | |
| assert.Equal(t, telemetry.Client(telemetryClient), telemetry.GlobalClient()) | |
| // ProductStopped(tracers) must still propagate to the foreign client | |
| // (ProductStarted set it true during Start; Stop sets it back to false). | |
| assert.False(t, telemetryClient.Products[telemetry.NamespaceTracers]) |
If you also want the flush and leftover-close directly observable, that needs a small
telemetrytest extension (e.g. Flushes int / Closed bool on RecordClient) — happy to review
that as a follow-up.
There was a problem hiding this comment.
added the ProductStopped assert. leaving Flushes/Closed on RecordClient for a follow up
| // Profiler started after the tracer and still shares the client, so Stop | ||
| // must flush without emitting app-stopped / clearing the global client. | ||
| assert.NotNil(t, telemetry.GlobalClient()) | ||
| } |
There was a problem hiding this comment.
The three tests cover tracer-only, foreign-owner, and profiler-still-running, but skip the
fourth ordering: the profiler started after the tracer and then stopped before tracer.Stop()
runs. That's the path where Stop must fall through to StopApp — and it's the one whose
behavior changed (on main the global client survived StopApp-less shutdown, so a
GlobalClient()==nil assertion distinguishes this PR from main). Suggested addition:
| // Profiler started after the tracer and still shares the client, so Stop | |
| // must flush without emitting app-stopped / clearing the global client. | |
| assert.NotNil(t, telemetry.GlobalClient()) | |
| } | |
| // Profiler started after the tracer and still shares the client, so Stop | |
| // must flush without emitting app-stopped / clearing the global client. | |
| assert.NotNil(t, telemetry.GlobalClient()) | |
| } | |
| func TestTracerStopStopsTelemetryAfterProfilerStopped(t *testing.T) { | |
| Start() | |
| defer globalconfig.SetServiceName("") | |
| require.NotNil(t, telemetry.GlobalClient()) | |
| wasEnabled := traceprof.SetProfilerEnabled(true) | |
| defer traceprof.SetProfilerEnabled(wasEnabled) | |
| // The profiler started after the tracer, then stopped before tracer.Stop(). | |
| traceprof.SetProfilerEnabled(false) | |
| Stop() | |
| // Nobody else needs the client anymore, so Stop must fully stop the app. | |
| assert.Nil(t, telemetry.GlobalClient()) | |
| } |
Two other gaps I'd leave for a follow-up rather than this PR: the telemetry-disabled path
(client == nil early return) is hard to test because Disabled() caches the env var in a
package-level sync.Once (internal/telemetry/globalclient.go:135-144) — t.Setenv alone won't
work unless the test runs before anything primes the once — and the stale-flag sequences
from my other comment have no coverage either.
There was a problem hiding this comment.
added TestTracerStopStopsTelemetryAfterProfilerStopped
| } | ||
| appsec.Stop() | ||
| remoteconfig.Stop() | ||
| // Flush telemetry before closing the log file so StopApp diagnostics still land. |
There was a problem hiding this comment.
This block is the tracer/profiler ownership handshake for the global telemetry client, but
nothing ties it to the end-state the codebase already anticipates — the TODO at
tracer.go:264-267 ("Will be fixed when the tracer and profiler share control of the global
telemetry client", APMAPI-1771). The current shape — pointer equality plus
traceprof.ProfilerEnabled() — hard-codes a two-product world: appsec already shares the
global client too (appsec.Stop() queues ProductStopped on it), and any future product
sharing it would need another flag or special case here. A refcount in internal/telemetry
(products register on start, StopApp fires when the last one stops) would also dissolve the
flag race and the profiler-never-stops-telemetry gap from my other comments — worth
considering as the follow-up that retires this TODO.
Until then, a pointer from this block to that plan would help the next refactor find it:
| // Flush telemetry before closing the log file so StopApp diagnostics still land. | |
| // Flush telemetry before closing the log file so StopApp diagnostics still land. | |
| // Interim tracer/profiler ownership handshake for the global telemetry client; | |
| // to be superseded by shared client control (see TODO at newTracer, APMAPI-1771). |
There was a problem hiding this comment.
comment now points at the newTracer APMAPI-1771 TODO
244306a to
2658712
Compare
Record the profiler ownership assumptions, clear the enabled flag when a restart leaves no profiler, raise it before run to close the start race, and cover the stop orderings the review called out.
2658712 to
0c477b2
Compare
|
@darccio pushed a pass for your notes.
happy to do the telemetrytest Flushes/Closed follow up separately if you want that next |
2 participants
Fixes #5249
tracer.Stop was only closing the telemetry client, so the last logs and metrics never flushed.
Stop now calls StopApp when the tracer started a client, which sends app stop, flushes, then closes. If StartApp skipped the tracer client because another product already owned the global client, that leftover still gets Close so the ticker does not leak.