b7ecc30f - Add continuous CPU profiling next to the OpenTelemetry SDK - #4532
Draft
TaprootFreak wants to merge 1 commit into
Draft
b7ecc30f - Add continuous CPU profiling next to the OpenTelemetry SDK#4532TaprootFreak wants to merge 1 commit into
TaprootFreak wants to merge 1 commit into
Conversation
Tracing measures how long a request waited; it cannot say what burned the CPU while it ran. Answering that on 2026-07-30 required attaching a V8 profiler to the live production process — a two-minute snapshot bought with a production intervention. startProfiling() mirrors startTracing(): it is inert unless PYROSCOPE_SERVER_ADDRESS is set, so LOC, tests and any environment without a Pyroscope instance boot unchanged. Wall/CPU sampling only — heap profiling is a second sampler with its own cost and stays off. Details worth knowing: - collectCpuTime is required. Without it the wall profiler reports elapsed time, which says little about an event loop that is mostly waiting. With it, the series to chart is wall:cpu:nanoseconds:wall:nanoseconds — note it is a wall:* type, not the process_cpu:* type Go services emit. - The env tag comes from ENVIRONMENT, the variable the app already keys off, so dev and prd stay apart in the shared Pyroscope without introducing a second source of truth. - A profiler failure is logged loudly and swallowed: an observability extra must never be the reason the API fails to boot. console is the only channel available before Nest bootstraps. - Sampling stays at the 100 Hz default. Measured on a CPU-saturated Node process, halving it to 50 Hz changed throughput by less than the run-to-run spread — the cost is in installing the sampler, not in the rate. Measured overhead against no profiler, on a fully CPU-bound loop (worst case; four alternating 25s runs): -4.3 % throughput, +4.6 % CPU per unit of work, +25 MB RSS. The native dependency ships musl prebuilds for linux/arm64 at ABI 115, so the node:20-alpine image needs no toolchain. Note the SDK requires Node >= 20.20.2 and the image currently provides exactly 20.20.2.
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
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.
Why
Tracing tells us how long a request waited. It cannot tell us what burned the CPU while it ran — and that was exactly the question on 2026-07-30, when the event loop sat at 84 % of a core with a p90 delay of 827 ms at 1.2 req/s. Answering it required attaching a V8 profiler to the live production process: a two-minute snapshot, bought with a production intervention, with no history and no before/after.
This adds continuous CPU profiling so the question is answerable at any time, and so a regression becomes visible before someone complains.
What this does
startProfiling()mirrorsstartTracing()insrc/tracing.ts: it does nothing unlessPYROSCOPE_SERVER_ADDRESSis set. LOC, tests and any environment without a profiling backend boot exactly as before. Wall/CPU sampling only — heap profiling is a second sampler with its own cost and stays off until allocation sites are the question.The infrastructure side (backend, data source, transport) is a separate PR in the infrastructure repository; without it nothing receives these profiles.
Details worth a reviewer's attention
collectCpuTimeis not optional. Without it the wall profiler reports elapsed time, which says very little about an event loop that spends most of it waiting. With it, the series carrying real CPU time iswall:cpu:nanoseconds:wall:nanoseconds. Note the type: the Node SDK emitswall:*types, not theprocess_cpu:*types Go services produce. Queryingprocess_cpu:…for this service returns nothing, silently.The
envtag comes fromENVIRONMENT. Both environments push to one backend, the same way they already push to one trace backend, so profiles need a label to keep them apart. Reusing the variable the app already keys off avoids a second source of truth. It is checked explicitly rather than passed through, because the SDK would otherwise reject the undefined tag value with a message that says nothing about where it came from.A profiler failure is logged loudly and swallowed. An observability extra must never be the reason the API fails to boot.
consoleis the only channel that exists at this point — the module runs before Nest bootstraps, soDfxLoggeris unavailable, and OTel'sdiaglogger is a no-op unless a sink is registered, which would turn a failure into silence. Hence the one deliberateno-consoledisable, with the reasoning in place.Sampling stays at the 100 Hz default. The obvious knob for reducing overhead does not work: measured on a CPU-saturated process, halving the rate to 50 Hz changed throughput by less than the run-to-run spread (-4.3 % vs -4.6 %). The cost is in having the sampler installed at all, not in the rate — turning it down would buy resolution loss and nothing else.
Measured overhead
Four alternating 25 s runs of a fully CPU-bound loop (event-loop utilization 1.0 — the worst case for a sampling profiler; a real request mix has idle time to absorb the sampler):
The workload was modelled on the profile that started this: building short-lived objects out of string fields (row parsing) plus the garbage collection that follows.
Native dependency
@datadog/pprofships musl prebuilds forlinux/arm64at ABI 115, so thenode:20-alpineimage needs no toolchain and nothing is compiled at install time. Verified by running a profiling client inside that exact image and confirming the profiles arrived, rather than assuming from the package metadata.One thing to keep an eye on: the SDK declares
engines.node: ">=20.20.2"and the image currently provides exactly20.20.2— correct today, with no headroom. A future SDK bump to>=22would require moving the base image first.Verification
ENVIRONMENT, SDK throwing) each returningfalsewhile the app keeps running. Each case loads its own module copy, because importing the module starts the profiler as a side effect.type-check,lintandprettierclean.src/tracing.ts— not a stand-in — was run against a live instance; profiles arrived labelledservice_name=dfx-api,env=prd, with the three expectedwall:*types and real stack frames.