Skip to content

Commit 4cc2a36

Browse files
committed
fix don't wait for telemetry events
1 parent 1f68c3e commit 4cc2a36

File tree

6 files changed

+93
-57
lines changed

6 files changed

+93
-57
lines changed

src/common/connectionManager.ts

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -82,7 +82,7 @@ export type TestConnectionManager = ConnectionManager & {
8282

8383
export abstract class ConnectionManager {
8484
protected clientName: string;
85-
protected readonly _events;
85+
protected readonly _events: EventEmitter<ConnectionManagerEvents>;
8686
readonly events: Pick<EventEmitter<ConnectionManagerEvents>, "on" | "off" | "once">;
8787
private state: AnyConnectionState;
8888

src/server.ts

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -193,7 +193,7 @@ export class Server {
193193
}
194194
}
195195

196-
this.telemetry.emitEvents([event]).catch(() => {});
196+
this.telemetry.emitEvents([event]);
197197
}
198198

199199
private registerTools(): void {

src/telemetry/telemetry.ts

Lines changed: 60 additions & 41 deletions
Original file line numberDiff line numberDiff line change
@@ -7,16 +7,29 @@ import { MACHINE_METADATA } from "./constants.js";
77
import { EventCache } from "./eventCache.js";
88
import { detectContainerEnv } from "../helpers/container.js";
99
import type { DeviceId } from "../helpers/deviceId.js";
10+
import { EventEmitter } from "stream";
1011

1112
type EventResult = {
1213
success: boolean;
1314
error?: Error;
1415
};
1516

17+
async function timeout(promise: Promise<unknown>, ms: number): Promise<void> {
18+
await Promise.race([new Promise((resolve) => setTimeout(resolve, ms)), promise]);
19+
}
20+
21+
export interface TelemetryEvents {
22+
"events-emitted": [];
23+
"events-send-failed": [];
24+
"events-skipped": [];
25+
}
26+
1627
export class Telemetry {
1728
private isBufferingEvents: boolean = true;
1829
/** Resolves when the setup is complete or a timeout occurs */
1930
public setupPromise: Promise<[string, boolean]> | undefined;
31+
public readonly events: EventEmitter<TelemetryEvents> = new EventEmitter();
32+
2033
private eventCache: EventCache;
2134
private deviceId: DeviceId;
2235

@@ -57,6 +70,12 @@ export class Telemetry {
5770

5871
private async setup(): Promise<void> {
5972
if (!this.isTelemetryEnabled()) {
73+
this.session.logger.info({
74+
id: LogId.telemetryEmitFailure,
75+
context: "telemetry",
76+
message: "Telemetry is disabled.",
77+
noRedaction: true,
78+
});
6079
return;
6180
}
6281

@@ -71,34 +90,22 @@ export class Telemetry {
7190

7291
public async close(): Promise<void> {
7392
this.isBufferingEvents = false;
74-
await this.emitEvents(this.eventCache.getEvents());
93+
await timeout(this.emit([]), 5_000);
7594
}
7695

7796
/**
7897
* Emits events through the telemetry pipeline
7998
* @param events - The events to emit
8099
*/
81-
public async emitEvents(events: BaseEvent[]): Promise<void> {
82-
try {
83-
if (!this.isTelemetryEnabled()) {
84-
this.session.logger.info({
85-
id: LogId.telemetryEmitFailure,
86-
context: "telemetry",
87-
message: "Telemetry is disabled.",
88-
noRedaction: true,
89-
});
90-
return;
91-
}
92-
93-
await this.emit(events);
94-
} catch {
95-
this.session.logger.debug({
96-
id: LogId.telemetryEmitFailure,
97-
context: "telemetry",
98-
message: "Error emitting telemetry events.",
99-
noRedaction: true,
100-
});
100+
public emitEvents(events: BaseEvent[]): void {
101+
if (!this.isTelemetryEnabled()) {
102+
this.events.emit("events-skipped");
103+
return;
101104
}
105+
106+
// Don't wait for events to be sent - we should not block regular server
107+
// operations on telemetry
108+
void this.emit(events);
102109
}
103110

104111
/**
@@ -144,32 +151,44 @@ export class Telemetry {
144151
return;
145152
}
146153

147-
const cachedEvents = this.eventCache.getEvents();
148-
const allEvents = [...cachedEvents, ...events];
154+
try {
155+
const cachedEvents = this.eventCache.getEvents();
156+
const allEvents = [...cachedEvents, ...events];
149157

150-
this.session.logger.debug({
151-
id: LogId.telemetryEmitStart,
152-
context: "telemetry",
153-
message: `Attempting to send ${allEvents.length} events (${cachedEvents.length} cached)`,
154-
});
158+
this.session.logger.debug({
159+
id: LogId.telemetryEmitStart,
160+
context: "telemetry",
161+
message: `Attempting to send ${allEvents.length} events (${cachedEvents.length} cached)`,
162+
});
163+
164+
const result = await this.sendEvents(this.session.apiClient, allEvents);
165+
if (result.success) {
166+
this.eventCache.clearEvents();
167+
this.session.logger.debug({
168+
id: LogId.telemetryEmitSuccess,
169+
context: "telemetry",
170+
message: `Sent ${allEvents.length} events successfully: ${JSON.stringify(allEvents, null, 2)}`,
171+
});
172+
this.events.emit("events-emitted");
173+
return;
174+
}
155175

156-
const result = await this.sendEvents(this.session.apiClient, allEvents);
157-
if (result.success) {
158-
this.eventCache.clearEvents();
159176
this.session.logger.debug({
160-
id: LogId.telemetryEmitSuccess,
177+
id: LogId.telemetryEmitFailure,
161178
context: "telemetry",
162-
message: `Sent ${allEvents.length} events successfully: ${JSON.stringify(allEvents, null, 2)}`,
179+
message: `Error sending event to client: ${result.error instanceof Error ? result.error.message : String(result.error)}`,
163180
});
164-
return;
181+
this.eventCache.appendEvents(events);
182+
this.events.emit("events-send-failed");
183+
} catch (error) {
184+
this.session.logger.debug({
185+
id: LogId.telemetryEmitFailure,
186+
context: "telemetry",
187+
message: `Error emitting telemetry events: ${error instanceof Error ? error.message : String(error)}`,
188+
noRedaction: true,
189+
});
190+
this.events.emit("events-send-failed");
165191
}
166-
167-
this.session.logger.debug({
168-
id: LogId.telemetryEmitFailure,
169-
context: "telemetry",
170-
message: `Error sending event to client: ${result.error instanceof Error ? result.error.message : String(result.error)}`,
171-
});
172-
this.eventCache.appendEvents(events);
173192
}
174193

175194
/**

src/tools/tool.ts

Lines changed: 12 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -82,7 +82,14 @@ export abstract class ToolBase {
8282
});
8383

8484
const result = await this.execute(...args);
85-
await this.emitToolEvent(startTime, result, ...args).catch(() => {});
85+
this.emitToolEvent(startTime, result, ...args);
86+
87+
this.session.logger.debug({
88+
id: LogId.toolExecute,
89+
context: "tool",
90+
message: `Executed tool ${this.name}`,
91+
noRedaction: true,
92+
});
8693
return result;
8794
} catch (error: unknown) {
8895
this.session.logger.error({
@@ -91,7 +98,7 @@ export abstract class ToolBase {
9198
message: `Error executing ${this.name}: ${error as string}`,
9299
});
93100
const toolResult = await this.handleError(error, args[0] as ToolArgs<typeof this.argsShape>);
94-
await this.emitToolEvent(startTime, toolResult, ...args).catch(() => {});
101+
this.emitToolEvent(startTime, toolResult, ...args);
95102
return toolResult;
96103
}
97104
};
@@ -200,11 +207,11 @@ export abstract class ToolBase {
200207
* @param result - Whether the command succeeded or failed
201208
* @param args - The arguments passed to the tool
202209
*/
203-
private async emitToolEvent(
210+
private emitToolEvent(
204211
startTime: number,
205212
result: CallToolResult,
206213
...args: Parameters<ToolCallback<typeof this.argsShape>>
207-
): Promise<void> {
214+
): void {
208215
if (!this.telemetry.isTelemetryEnabled()) {
209216
return;
210217
}
@@ -230,7 +237,7 @@ export abstract class ToolBase {
230237
event.properties.project_id = metadata.projectId;
231238
}
232239

233-
await this.telemetry.emitEvents([event]);
240+
this.telemetry.emitEvents([event]);
234241
}
235242
}
236243

src/transports/streamableHttp.ts

Lines changed: 3 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -124,7 +124,7 @@ export class StreamableHttpRunner extends TransportRunnerBase {
124124
// eslint-disable-next-line @typescript-eslint/no-misused-promises
125125
keepAliveLoop = setInterval(async () => {
126126
try {
127-
this.logger.debug({
127+
server.session.logger.debug({
128128
id: LogId.streamableHttpTransportKeepAlive,
129129
context: "streamableHttpTransport",
130130
message: "Sending ping",
@@ -138,7 +138,7 @@ export class StreamableHttpRunner extends TransportRunnerBase {
138138
} catch (err) {
139139
try {
140140
failedPings++;
141-
this.logger.warning({
141+
server.session.logger.warning({
142142
id: LogId.streamableHttpTransportKeepAliveFailure,
143143
context: "streamableHttpTransport",
144144
message: `Error sending ping (attempt #${failedPings}): ${err instanceof Error ? err.message : String(err)}`,
@@ -162,7 +162,7 @@ export class StreamableHttpRunner extends TransportRunnerBase {
162162
this.logger.error({
163163
id: LogId.streamableHttpTransportSessionCloseFailure,
164164
context: "streamableHttpTransport",
165-
message: `Error closing session: ${error instanceof Error ? error.message : String(error)}`,
165+
message: `Error closing session ${sessionId}: ${error instanceof Error ? error.message : String(error)}`,
166166
});
167167
}
168168
},

tests/unit/telemetry.test.ts

Lines changed: 16 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -61,6 +61,16 @@ describe("Telemetry", () => {
6161
};
6262
}
6363

64+
function emitEventsForTest(events: BaseEvent[]): Promise<void> {
65+
return new Promise((resolve) => {
66+
telemetry.events.once("events-emitted", resolve);
67+
telemetry.events.once("events-send-failed", resolve);
68+
telemetry.events.once("events-skipped", resolve);
69+
70+
telemetry.emitEvents(events);
71+
});
72+
}
73+
6474
// Helper function to verify mock calls to reduce duplication
6575
function verifyMockCalls({
6676
sendEventsCalls = 0,
@@ -145,7 +155,7 @@ describe("Telemetry", () => {
145155

146156
await telemetry.setupPromise;
147157

148-
await telemetry.emitEvents([testEvent]);
158+
await emitEventsForTest([testEvent]);
149159

150160
verifyMockCalls({
151161
sendEventsCalls: 1,
@@ -161,7 +171,7 @@ describe("Telemetry", () => {
161171

162172
await telemetry.setupPromise;
163173

164-
await telemetry.emitEvents([testEvent]);
174+
await emitEventsForTest([testEvent]);
165175

166176
verifyMockCalls({
167177
sendEventsCalls: 1,
@@ -186,7 +196,7 @@ describe("Telemetry", () => {
186196

187197
await telemetry.setupPromise;
188198

189-
await telemetry.emitEvents([newEvent]);
199+
await emitEventsForTest([newEvent]);
190200

191201
verifyMockCalls({
192202
sendEventsCalls: 1,
@@ -223,7 +233,7 @@ describe("Telemetry", () => {
223233
const commonProps = telemetry.getCommonProperties();
224234
expect(commonProps.hosting_mode).toBe("vscode-extension");
225235

226-
await telemetry.emitEvents([createTestEvent()]);
236+
await emitEventsForTest([createTestEvent()]);
227237

228238
const calls = mockApiClient.sendEvents.mock.calls;
229239
expect(calls).toHaveLength(1);
@@ -305,7 +315,7 @@ describe("Telemetry", () => {
305315
it("should not send events", async () => {
306316
const testEvent = createTestEvent();
307317

308-
await telemetry.emitEvents([testEvent]);
318+
await emitEventsForTest([testEvent]);
309319

310320
verifyMockCalls();
311321
});
@@ -330,7 +340,7 @@ describe("Telemetry", () => {
330340
it("should not send events", async () => {
331341
const testEvent = createTestEvent();
332342

333-
await telemetry.emitEvents([testEvent]);
343+
await emitEventsForTest([testEvent]);
334344

335345
verifyMockCalls();
336346
});

0 commit comments

Comments
 (0)