Skip to content
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.

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

Log uncaughtExceptions in our logging system #183530

Merged
merged 2 commits into from
May 16, 2024
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
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
Original file line number Diff line number Diff line change
Expand Up @@ -8,7 +8,7 @@

import { BehaviorSubject } from 'rxjs';

import type { CoreContext } from '@kbn/core-base-server-internal';
import { type CoreContext, CriticalError } from '@kbn/core-base-server-internal';
import type { AnalyticsServicePreboot } from '@kbn/core-analytics-server';

import { EnvironmentService } from './environment_service';
Expand Down Expand Up @@ -127,36 +127,58 @@ describe('UuidService', () => {
warning.name = 'DeprecationWarning';
process.emit('warning', warning);

expect(logger.get('process').warn).not.toHaveBeenCalled();
expect(logger.get('environment').warn).not.toHaveBeenCalled();
});
});

// TODO: From Nodejs v16 emitting an unhandledRejection will kill the process
describe.skip('unhandledRejection warnings', () => {
it('logs warn for an unhandeld promise rejected with an Error', async () => {
describe('unhandledRejection warnings', () => {
it('logs warn for an unhandled promise rejected with an Error', async () => {
await service.preboot({ analytics });

const err = new Error('something went wrong');
process.emit('unhandledRejection', err, new Promise((res, rej) => rej(err)));
process.emit('unhandledRejection', err, new Promise((res, rej) => {}));
Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The problem was not the process.emit, was the actual Promise rejecting 😅


expect(logger.get('process').warn).toHaveBeenCalledTimes(1);
expect(logger.get('environment').warn).toHaveBeenCalledTimes(1);
Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Weird that the test works with both words 🤷

expect(loggingSystemMock.collect(logger).warn[0][0]).toMatch(
/Detected an unhandled Promise rejection: Error: something went wrong\n.*at /
);
});

it('logs warn for an unhandeld promise rejected with a string', async () => {
it('logs warn for an unhandled promise rejected with a string', async () => {
await service.preboot({ analytics });

const err = 'something went wrong';
process.emit('unhandledRejection', err, new Promise((res, rej) => rej(err)));
process.emit('unhandledRejection', err, new Promise((res, rej) => {}));

expect(logger.get('process').warn).toHaveBeenCalledTimes(1);
expect(logger.get('environment').warn).toHaveBeenCalledTimes(1);
expect(loggingSystemMock.collect(logger).warn[0][0]).toMatch(
/Detected an unhandled Promise rejection: "something went wrong"/
);
});
});

describe('uncaughtException warnings', () => {
it('logs warn for an uncaught exception with an Error', async () => {
await service.preboot({ analytics });

const err = new Error('something went wrong');
process.emit('uncaughtExceptionMonitor', err); // Types won't allow me to provide the `origin`

expect(logger.get('environment').warn).toHaveBeenCalledTimes(1);
expect(loggingSystemMock.collect(logger).warn[0][0]).toMatch(
/Detected an undefined: Error: something went wrong\n.*at /
);
});

it('does not log warn for an uncaught exception with a CriticalError', async () => {
await service.preboot({ analytics });

const err = new CriticalError('something went wrong', 'ERROR_CODE', 1234);
process.emit('uncaughtExceptionMonitor', err); // Types won't allow me to provide the `origin`

expect(logger.get('environment').warn).toHaveBeenCalledTimes(0);
});
});
});

describe('#setup()', () => {
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -10,7 +10,7 @@ import { firstValueFrom, of } from 'rxjs';
import { PathConfigType, config as pathConfigDef } from '@kbn/utils';
import type { Logger } from '@kbn/logging';
import type { IConfigService } from '@kbn/config';
import { CoreContext, coreConfigPaths } from '@kbn/core-base-server-internal';
import { CoreContext, coreConfigPaths, CriticalError } from '@kbn/core-base-server-internal';
import type { AnalyticsServicePreboot } from '@kbn/core-analytics-server';
import { HttpConfigType } from './types';
import { PidConfigType, pidConfig as pidConfigDef } from './pid_config';
Expand Down Expand Up @@ -56,7 +56,7 @@ export class EnvironmentService {

public async preboot({ analytics }: EnvironmentServicePrebootDeps) {
// IMPORTANT: This code is based on the assumption that none of the configuration values used
// here is supposed to change during preboot phase and it's safe to read them only once.
// here is supposed to change during preboot phase, and it's safe to read them only once.
const [pathConfig, serverConfig, pidConfig] = await Promise.all([
firstValueFrom(this.configService.atPath<PathConfigType>(pathConfigDef.path)),
firstValueFrom(this.configService.atPath<HttpConfigType>(coreConfigPaths.http)),
Expand All @@ -68,6 +68,14 @@ export class EnvironmentService {
const message = (reason as Error)?.stack ?? JSON.stringify(reason);
this.log.warn(`Detected an unhandled Promise rejection: ${message}`);
});
// Log uncaughtExceptions in our logger before crashing the process: https://github.com/elastic/kibana/issues/183182
process.on('uncaughtExceptionMonitor', (error, origin) => {
Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Using uncaughtExceptionMonitor instead of uncaughtException because, according to the docs, the only difference is that the latter intercepts the exit call.

// CriticalErrors are handled in a different path
if (!(error instanceof CriticalError)) {
const message = error?.stack ?? JSON.stringify(error);
this.log.warn(`Detected an ${origin}: ${message}`);
}
});

await createDataFolder({ pathConfig, logger: this.log });
await writePidFile({ pidConfig, logger: this.log });
Expand Down