Skip to content

fix(telemetry): make ApplicationInsights flush await in-flight requests (fixes flaky test) #2373

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Open
kgilpin wants to merge 1 commit into
base: main
Choose a base branch
from
Open

fix(telemetry): make ApplicationInsights flush await in-flight requests (fixes flaky test) #2373

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
1 commit
Select commit
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
32 changes: 30 additions & 2 deletions packages/telemetry/src/backends/application-insights.ts
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -1,3 +1,4 @@
import type { ClientRequest } from 'node:http';
import * as https from 'node:https';
import os from 'node:os';

Expand All @@ -8,6 +9,8 @@ import type {
TelemetryData,
} from '../types';

const MaxFlushTime = 5000; // 5 seconds

// This key is meant to be publically shared. However, I'm adding a simple
// obfuscation to mitigate key scraping bots on GitHub. The key is split on
// hypens and base64 encoded without padding.
Expand All @@ -26,6 +29,7 @@ export class ApplicationInsightsBackend implements TelemetryBackend {
private readonly productName: string;
private readonly hostname: string;
private readonly uname: string;
private pendingRequests = new Set<ClientRequest>();

constructor(
userId: string,
Expand Down Expand Up @@ -61,9 +65,30 @@ export class ApplicationInsightsBackend implements TelemetryBackend {
this._post([envelope]);
}

// Resolve once all in-flight requests have settled (their response/error
// handlers, including any warning, have run), so callers — and tests — can
// await the full request lifecycle rather than just the request being sent.
flush(callback?: FlushCallback): void {
// No batching, so nothing to flush. Just call callback.
callback?.();
const startTime = process.hrtime.bigint();

const checkPending = () => {
if (this.pendingRequests.size === 0) {
callback?.();
return;
}

const elapsedMs = Number((process.hrtime.bigint() - startTime) / BigInt(1_000_000));
if (elapsedMs > MaxFlushTime) {
console.warn(`ApplicationInsightsBackend: Flush timed out after ${MaxFlushTime}ms`);
this.pendingRequests.forEach((req) => req.destroy());
callback?.();
return;
}

setTimeout(checkPending, 10);
};

checkPending();
}

private _post(envelopes: unknown[]): void {
Expand All @@ -85,10 +110,13 @@ export class ApplicationInsightsBackend implements TelemetryBackend {
if (res.statusCode && (res.statusCode < 200 || res.statusCode >= 300)) {
console.warn(`ApplicationInsightsBackend: Failed to send telemetry event. Status: ${res.statusCode}`);
}
this.pendingRequests.delete(req);
});
});
this.pendingRequests.add(req);
req.on('error', (e) => {
console.warn('Error sending telemetry data to Application Insights', e);
this.pendingRequests.delete(req);
});
req.write(body);
req.end();
Expand Down
13 changes: 9 additions & 4 deletions packages/telemetry/tests/backends/application-insights.spec.ts
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -34,6 +34,7 @@ describe('ApplicationInsightsBackend', () => {
afterEach(() => {
nock.cleanAll();
nock.enableNetConnect();
jest.restoreAllMocks();
});

const waitForRequest = async (scope: nock.Scope) => {
Expand Down Expand Up @@ -118,7 +119,7 @@ describe('ApplicationInsightsBackend', () => {

it('handles https errors', async () => {
nock.cleanAll(); // Don't use the default scope
const errorScope = nock(AI_ENDPOINT).post(AI_PATH).replyWithError('test error');
nock(AI_ENDPOINT).post(AI_PATH).replyWithError('test error');
const warnSpy = jest.spyOn(console, 'warn').mockImplementation();
const backend = new ApplicationInsightsBackend('user-id', 'session-id', 'product-name', {
type: 'application-insights',
Expand All @@ -130,7 +131,9 @@ describe('ApplicationInsightsBackend', () => {

backend.sendEvent(event);

await waitForRequest(errorScope);
// Wait for the request's error handler (and its warning) to run, not just
// for the request to be sent.
await new Promise<void>((resolve) => backend.flush(resolve));

expect(warnSpy).toHaveBeenCalledWith(
'Error sending telemetry data to Application Insights',
Expand All @@ -140,7 +143,7 @@ describe('ApplicationInsightsBackend', () => {

it('logs a warning for non-2xx HTTP responses', async () => {
nock.cleanAll();
const errorScope = nock(AI_ENDPOINT).post(AI_PATH).reply(500, { message: 'Internal Server Error' });
nock(AI_ENDPOINT).post(AI_PATH).reply(500, { message: 'Internal Server Error' });
const warnSpy = jest.spyOn(console, 'warn').mockImplementation();
const backend = new ApplicationInsightsBackend('user-id', 'session-id', 'product-name', {
type: 'application-insights',
Expand All @@ -152,7 +155,9 @@ describe('ApplicationInsightsBackend', () => {

backend.sendEvent(event);

await waitForRequest(errorScope);
// Wait for the response handler (and its warning) to run, not just for the
// request to be sent.
await new Promise<void>((resolve) => backend.flush(resolve));

expect(warnSpy).toHaveBeenCalledWith(
'ApplicationInsightsBackend: Failed to send telemetry event. Status: 500'
Expand Down
Loading