Skip to content

Commit 6a8a2c3

Browse files
authored
fix(node): Make log flushing logic more robust (#15991)
resolves https://linear.app/getsentry/issue/LOGS-18 We got some user feedback that nodejs logging was too inconsistent. This PR improves that. 1. Add a new `flushLogs` client hook that allows us to reset server weight tracking logic more consistently. This also fixes a bug where we didn't reset weight tracking when calling `Sentry.flush`. 2. Add a `process.on('beforeExit'` listener to flush logs. Hooking onto `beforeExit` does not guarantee we flush all logs before exit, but it does increase the chances we do. 4. Add an idle timeout that will flush logs after 5 seconds if no new logs are recorded. This should not leak memory because it is not an interval, but instead a timeout.
1 parent 7f24881 commit 6a8a2c3

File tree

5 files changed

+42
-7
lines changed

5 files changed

+42
-7
lines changed

packages/core/src/client.ts

+12
Original file line numberDiff line numberDiff line change
@@ -670,6 +670,13 @@ export abstract class Client<O extends ClientOptions = ClientOptions> {
670670
*/
671671
public on(hook: 'afterCaptureLog', callback: (log: Log) => void): () => void;
672672

673+
/**
674+
* A hook that is called when the client is flushing logs
675+
*
676+
* @returns {() => void} A function that, when executed, removes the registered callback.
677+
*/
678+
public on(hook: 'flushLogs', callback: () => void): () => void;
679+
673680
/**
674681
* Register a hook on this client.
675682
*/
@@ -827,6 +834,11 @@ export abstract class Client<O extends ClientOptions = ClientOptions> {
827834
*/
828835
public emit(hook: 'afterCaptureLog', log: Log): void;
829836

837+
/**
838+
* Emit a hook event for client flush logs
839+
*/
840+
public emit(hook: 'flushLogs'): void;
841+
830842
/**
831843
* Emit a hook that was previously registered via `on()`.
832844
*/

packages/core/src/logs/exports.ts

+2
Original file line numberDiff line numberDiff line change
@@ -163,6 +163,8 @@ export function _INTERNAL_flushLogsBuffer(client: Client, maybeLogBuffer?: Array
163163
// Clear the log buffer after envelopes have been constructed.
164164
logBuffer.length = 0;
165165

166+
client.emit('flushLogs');
167+
166168
// sendEnvelope should not throw
167169
// eslint-disable-next-line @typescript-eslint/no-floating-promises
168170
client.sendEnvelope(envelope);

packages/core/src/server-runtime-client.ts

+11-3
Original file line numberDiff line numberDiff line change
@@ -25,6 +25,9 @@ import { resolvedSyncPromise } from './utils-hoist/syncpromise';
2525
import { _INTERNAL_flushLogsBuffer } from './logs/exports';
2626
import { isPrimitive } from './utils-hoist';
2727

28+
// TODO: Make this configurable
29+
const DEFAULT_LOG_FLUSH_INTERVAL = 5000;
30+
2831
export interface ServerRuntimeClientOptions extends ClientOptions<BaseTransportOptions> {
2932
platform?: string;
3033
runtime?: { name: string; version?: string };
@@ -37,6 +40,7 @@ export interface ServerRuntimeClientOptions extends ClientOptions<BaseTransportO
3740
export class ServerRuntimeClient<
3841
O extends ClientOptions & ServerRuntimeClientOptions = ServerRuntimeClientOptions,
3942
> extends Client<O> {
43+
private _logFlushIdleTimeout: ReturnType<typeof setTimeout> | undefined;
4044
private _logWeight: number;
4145

4246
/**
@@ -54,9 +58,9 @@ export class ServerRuntimeClient<
5458
if (this._options._experiments?.enableLogs) {
5559
// eslint-disable-next-line @typescript-eslint/no-this-alias
5660
const client = this;
57-
client.on('flush', () => {
58-
_INTERNAL_flushLogsBuffer(client);
61+
client.on('flushLogs', () => {
5962
client._logWeight = 0;
63+
clearTimeout(client._logFlushIdleTimeout);
6064
});
6165

6266
client.on('afterCaptureLog', log => {
@@ -67,7 +71,11 @@ export class ServerRuntimeClient<
6771
// the payload gets too big.
6872
if (client._logWeight >= 800_000) {
6973
_INTERNAL_flushLogsBuffer(client);
70-
client._logWeight = 0;
74+
} else {
75+
// start an idle timeout to flush the logs buffer if no logs are captured for a while
76+
client._logFlushIdleTimeout = setTimeout(() => {
77+
_INTERNAL_flushLogsBuffer(client);
78+
}, DEFAULT_LOG_FLUSH_INTERVAL);
7179
}
7280
});
7381
}

packages/core/test/lib/server-runtime-client.test.ts

+3-3
Original file line numberDiff line numberDiff line change
@@ -4,7 +4,7 @@ import { describe, expect, it, test, vi } from 'vitest';
44
import { Scope, createTransport } from '../../src';
55
import type { ServerRuntimeClientOptions } from '../../src/server-runtime-client';
66
import { ServerRuntimeClient } from '../../src/server-runtime-client';
7-
import { _INTERNAL_captureLog } from '../../src/logs/exports';
7+
import { _INTERNAL_captureLog, _INTERNAL_flushLogsBuffer } from '../../src/logs/exports';
88

99
const PUBLIC_DSN = 'https://username@domain/123';
1010

@@ -256,8 +256,8 @@ describe('ServerRuntimeClient', () => {
256256
_INTERNAL_captureLog({ message: 'test1', level: 'info' }, client);
257257
_INTERNAL_captureLog({ message: 'test2', level: 'info' }, client);
258258

259-
// Trigger flush event
260-
client.emit('flush');
259+
// Trigger flush directly
260+
_INTERNAL_flushLogsBuffer(client);
261261

262262
expect(sendEnvelopeSpy).toHaveBeenCalledTimes(1);
263263
expect(client['_logWeight']).toBe(0); // Weight should be reset after flush

packages/node/src/sdk/client.ts

+14-1
Original file line numberDiff line numberDiff line change
@@ -4,7 +4,7 @@ import { trace } from '@opentelemetry/api';
44
import { registerInstrumentations } from '@opentelemetry/instrumentation';
55
import type { BasicTracerProvider } from '@opentelemetry/sdk-trace-base';
66
import type { DynamicSamplingContext, Scope, ServerRuntimeClientOptions, TraceContext } from '@sentry/core';
7-
import { SDK_VERSION, ServerRuntimeClient, applySdkMetadata, logger } from '@sentry/core';
7+
import { _INTERNAL_flushLogsBuffer, SDK_VERSION, ServerRuntimeClient, applySdkMetadata, logger } from '@sentry/core';
88
import { getTraceContextForScope } from '@sentry/opentelemetry';
99
import { isMainThread, threadId } from 'worker_threads';
1010
import { DEBUG_BUILD } from '../debug-build';
@@ -18,6 +18,7 @@ export class NodeClient extends ServerRuntimeClient<NodeClientOptions> {
1818
private _tracer: Tracer | undefined;
1919
private _clientReportInterval: NodeJS.Timeout | undefined;
2020
private _clientReportOnExitFlushListener: (() => void) | undefined;
21+
private _logOnExitFlushListener: (() => void) | undefined;
2122

2223
public constructor(options: NodeClientOptions) {
2324
const clientOptions: ServerRuntimeClientOptions = {
@@ -40,6 +41,14 @@ export class NodeClient extends ServerRuntimeClient<NodeClientOptions> {
4041
);
4142

4243
super(clientOptions);
44+
45+
if (this.getOptions()._experiments?.enableLogs) {
46+
this._logOnExitFlushListener = () => {
47+
_INTERNAL_flushLogsBuffer(this);
48+
};
49+
50+
process.on('beforeExit', this._logOnExitFlushListener);
51+
}
4352
}
4453

4554
/** Get the OTEL tracer. */
@@ -84,6 +93,10 @@ export class NodeClient extends ServerRuntimeClient<NodeClientOptions> {
8493
process.off('beforeExit', this._clientReportOnExitFlushListener);
8594
}
8695

96+
if (this._logOnExitFlushListener) {
97+
process.off('beforeExit', this._logOnExitFlushListener);
98+
}
99+
87100
return super.close(timeout);
88101
}
89102

0 commit comments

Comments
 (0)