fix(logs,traces,metrics): remove duplicate instrumentations and correct performance counters - #212
Merged
Jackson Weber (JacksonWeber) merged 7 commits intoAug 5, 2026
Conversation
…mance counters Three defects surfaced by an end-to-end run that captured the Breeze envelopes actually transmitted to Application Insights. 1. Every bunyan and winston record was transmitted twice. `LogHandler` constructed its own `BunyanInstrumentation` / `WinstonInstrumentation`. `InstrumentationBase` auto-enables an instrumentation whose config has `enabled: true`, so that second copy patched `bunyan` and appended a second `OpenTelemetryBunyanStream` to every logger — even though `LogHandler.getInstrumentations()` was never passed to the `NodeSDK`. The trace instrumentations were unaffected because they unwrap before wrapping; the bunyan instrumentation does not. `createInstrumentations` is now the single owner of all instrumentations, and the dead `getInstrumentations()` accessor is gone. 2. `\Process(??APP_WIN32_PROC??)\% Processor Time Normalized` was always 0. `getNormalizedProcessTime` and `getProcessTime` shared `lastAppCpuUsage`, `lastHrtime` and `lastCpusProcess`, so whichever observable callback ran second measured a near-zero delta. The normalized gauge now keeps its own last-sample state. 3. The first export of `Requests/Sec` and the exception rate was always ~0. `lastRequestRate` was re-initialized to `time: 0` after the constructor had already seeded it with `Date.now()`, so the first collection interval spanned decades. Dropped the re-initialization and seeded `lastExceptionRate` the same way. The logHandler tests that only asserted on the removed accessor now cover `createInstrumentations`, plus a regression test asserting exactly one bunyan instrumentation is created. Verified end to end against a live Application Insights resource: before the fix Kusto reported 2 rows per bunyan message, after the fix 1. The normalized CPU counter went from 0.0000 to 0.13-0.27 and `Requests/Sec` reports ~1.9 on the first export instead of 0. Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>
Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>
Copilot started reviewing on behalf of
Jackson Weber (JacksonWeber)
August 4, 2026 22:04
View session
Contributor
There was a problem hiding this comment.
Pull request overview
This PR fixes duplicated log emission caused by accidentally enabling multiple log instrumentations, and corrects several Windows performance-counter calculations that were producing zero/near-zero values (especially on the first export).
Changes:
- Remove
LogHandler’s instrumentation ownership/accessor to prevent double-enabling bunyan/winston instrumentations. - Fix
% Processor Time Normalizedby keeping separate “last sample” state for the normalized gauge. - Fix first-export rate calculations by seeding
lastRequestRate/lastExceptionRatetimestamps correctly.
Reviewed changes
Copilot reviewed 4 out of 4 changed files in this pull request and generated no comments.
| File | Description |
|---|---|
| test/internal/unit/logs/logHandler.test.ts | Updates tests to validate instrumentation creation via createInstrumentations, and adds a regression test to ensure bunyan instrumentation isn’t duplicated. |
| src/azureMonitor/metrics/performanceCounters.ts | Splits normalized process time state from standard process time state; fixes first-export request/exception rate initialization. |
| src/azureMonitor/logs/handler.ts | Removes dead instrumentation construction/accessor from LogHandler to avoid double-patching and duplicate log records. |
| CHANGELOG.md | Documents the bug fixes in the Unreleased section. |
💡 Add Copilot custom instructions for smarter, more guided reviews. Learn how to get started.
Follow-up to the LogHandler fix in this branch, from a review pass that
caught two problems with the original change.
1. `TraceHandler` had the same dead-code pattern as `LogHandler`: it built
its own HttpInstrumentation / AzureSdk / MongoDB / MySQL / Pg / Redis
instances that were never passed to the NodeSDK. This is worse than it
looks. `instrumentation-http` guards against double-patching with a
per-instance `_httpPatched` flag rather than unwrapping, so with two
instances the unregistered one ends up owning the patch — and because
`registerInstrumentations` never wired it up, it keeps the no-op meter it
was constructed with. Measured with two instances, one registered with a
real MeterProvider:
one instance -> http.server.request.duration, http.client.request.duration
two instances -> no HTTP metrics at all
Spans were unaffected, which is why this went unnoticed. Confirmed end to
end: `http.server.request.duration` and `http.client.request.duration` now
appear in the transmitted telemetry and were completely absent before.
It also double-wrapped `ignoreOutgoingRequestHook`: `createInstrumentations`
and `TraceHandler` both wrapped the hook on the same shared
`instrumentationOptions.http` object, so the Azure Monitor exclusion check
ran twice per outgoing request.
With this removed, `createInstrumentations` really is the single owner of
all instrumentations, as the changelog claims.
2. Corrected the winston claim. Winston was not duplicated: unlike bunyan, its
instrumentation unwraps an existing patch before wrapping
(instrumentation-winston `instrumentation.js` lines 21-30 and 40-45), so a
second instance replaces the first rather than stacking transports. Only
bunyan stacks, because `_addStream` appends unconditionally. Updated the
changelog and the handler comment accordingly.
The handler guard tests now assert that neither handler holds an
instrumentation under any property name, rather than asserting a specific
method was deleted. Both fail against the pre-fix source.
Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>
Jackson Weber (JacksonWeber)
changed the title
Copilot started reviewing on behalf of
Jackson Weber (JacksonWeber)
August 4, 2026 22:57
View session
Jackson Weber (JacksonWeber)
marked this pull request as draft
August 4, 2026 23:09
A controlled A/B run against unmodified main showed the broken counter is not reliably 0: the first export read 28.2576 while the standard process CPU counter read 3.4623 on a 12-core machine, where the correct value is 3.4623/12 = 0.2885. Sharing the last-sample state means the second callback measures a ~zero-length window, so the quotient is garbage in either direction, not consistently zero. Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>
… once Addresses review feedback: with _initializeInstrumentations removed there was no longer anything in this file showing the hook is applied once. The merge lives in createInstrumentations with identical semantics; this adds a self-calibrating regression test that counts how many times the filter inspects the request and compares against a createInstrumentations-only baseline. Against the pre-fix source it fails with 'expected 6 to be 3'. Also shortened the comments added by this branch. Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>
The rationale for these changes belongs in the commit history, PR and changelog, not in the source files. Remaining comments state current invariants only. Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>
Add deterministic coverage for request/exception rate initialization and independent normalized CPU sampling. Reduce the changelog and comments to their minimum. Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>
Jackson Weber (JacksonWeber)
changed the title
Jackson Weber (JacksonWeber)
marked this pull request as ready for review
August 5, 2026 18:48
Radhika Gupta (rads-1996)
approved these changes
Aug 5, 2026
Jackson Weber (JacksonWeber)
added a commit
to Azure/azure-sdk-for-js
that referenced
this pull request
Aug 6, 2026
## What - give standard and normalized process CPU counters independent sampling state - initialize request and exception rate intervals when performance counters are constructed - add deterministic regression coverage for first-interval rates and CPU sampling - align the distro dependency with workspace exporter beta.45 so Turbo builds the exporter first ## Why The standard and normalized CPU callbacks shared their previous CPU/time samples, so whichever callback ran second measured a near-zero interval and could report an inflated value. Request and exception rates also used Unix epoch as the first interval start, making the first export effectively zero. These shared defects were identified while validating microsoft/opentelemetry-distro-javascript#212 against the Azure Monitor distro. The initial CI run also exposed that `@azure/monitor-opentelemetry` still depended on exporter beta.44 while the workspace exporter was beta.45. Because the versions did not match, Turbo omitted the exporter from the dependency graph and the distro build could not resolve its generated types. This PR now aligns the dependency and lockfile importer to beta.45. ## Validation - `pnpm check-format` - `pnpm lint` (0 errors; existing warnings remain) - clean `pnpm turbo build --filter=@azure/monitor-opentelemetry... --token 1`, with exporter beta.45 built first - `npx dev-tool check --tag=local` - `vitest run test/internal/unit/metrics/performanceMetrics.test.ts` --------- Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.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
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.
Summary
Fixes duplicate instrumentation instances and incorrect performance-counter sampling.
Fixes
LogHandlerandTraceHandler.Verification
Controlled A/B run using the same application and workload, changing only the distro package:
mainRequests/SecexportThe telemetry was captured from the payloads sent to a live Application Insights resource.
Tests
npm run test:unit: 939 passed, 5 todo, 1 skipped.npm run build: passed.npm run lint: 0 errors.The performance-counter fixes also apply to
@azure/monitor-opentelemetry, which contains the same sampling logic. The duplicate-instrumentation fixes are specific to this distro.