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

[eventLog] prevent log writing when initialization fails #71339

Merged
merged 2 commits into from
Jul 14, 2020
Merged
Show file tree
Hide file tree
Changes from 1 commit
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
2 changes: 1 addition & 1 deletion x-pack/plugins/event_log/server/es/context.mock.ts
Original file line number Diff line number Diff line change
Expand Up @@ -17,7 +17,7 @@ const createContextMock = () => {
logger: loggingSystemMock.createLogger(),
esNames: namesMock.create(),
initialize: jest.fn(),
waitTillReady: jest.fn(),
waitTillReady: jest.fn(async () => Promise.resolve(true)),
Copy link
Contributor

Choose a reason for hiding this comment

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

micro nit.
Isn't this the same as... ?

Suggested change
waitTillReady: jest.fn(async () => Promise.resolve(true)),
waitTillReady: jest.fn(async () => true),

If so, it just seems a little easier to understand and maintain.

Copy link
Member Author

Choose a reason for hiding this comment

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

I should try putting that back to your suggesting - I had some issues trying to get it to fire, so tried "the long way" so I could debug it. thx!

esAdapter: clusterClientAdapterMock.create(),
initialized: true,
};
Expand Down
17 changes: 14 additions & 3 deletions x-pack/plugins/event_log/server/es/context.test.ts
Original file line number Diff line number Diff line change
Expand Up @@ -7,9 +7,8 @@
import { createEsContext } from './context';
import { LegacyClusterClient, Logger } from '../../../../../src/core/server';
import { elasticsearchServiceMock, loggingSystemMock } from '../../../../../src/core/server/mocks';
jest.mock('../lib/../../../../package.json', () => ({
version: '1.2.3',
}));
jest.mock('../lib/../../../../package.json', () => ({ version: '1.2.3' }));
jest.mock('./init');
type EsClusterClient = Pick<jest.Mocked<LegacyClusterClient>, 'callAsInternalUser' | 'asScoped'>;

let logger: Logger;
Expand Down Expand Up @@ -92,4 +91,16 @@ describe('createEsContext', () => {
);
expect(doesIndexTemplateExist).toBeTruthy();
});

test('should handled failed initialization', async () => {
jest.requireMock('./init').initializeEs.mockResolvedValue(false);
const context = createEsContext({
logger,
clusterClientPromise: Promise.resolve(clusterClient),
indexNameRoot: 'test2',
});
context.initialize();
const success = await context.waitTillReady();
expect(success).toBe(false);
});
});
12 changes: 7 additions & 5 deletions x-pack/plugins/event_log/server/es/context.ts
Original file line number Diff line number Diff line change
Expand Up @@ -64,21 +64,23 @@ class EsContextImpl implements EsContext {

setImmediate(async () => {
try {
await this._initialize();
this.logger.debug('readySignal.signal(true)');
this.readySignal.signal(true);
const success = await this._initialize();
this.logger.debug(`readySignal.signal(${success})`);
this.readySignal.signal(success);
} catch (err) {
this.logger.debug('readySignal.signal(false)');
this.readySignal.signal(false);
}
});
}

// waits till the ES initialization is done, returns true if it was successful,
// false if it was not successful
async waitTillReady(): Promise<boolean> {
return await this.readySignal.wait();
}

private async _initialize() {
await initializeEs(this);
private async _initialize(): Promise<boolean> {
return await initializeEs(this);
}
}
31 changes: 29 additions & 2 deletions x-pack/plugins/event_log/server/event_logger.test.ts
Original file line number Diff line number Diff line change
Expand Up @@ -14,25 +14,52 @@ import { delay } from './lib/delay';
import { EVENT_LOGGED_PREFIX } from './event_logger';

const KIBANA_SERVER_UUID = '424-24-2424';
const WRITE_LOG_WAIT_MILLIS = 3000;

describe('EventLogger', () => {
let systemLogger: ReturnType<typeof loggingSystemMock.createLogger>;
let esContext: EsContext;
let esContext: jest.Mocked<EsContext>;
let service: IEventLogService;
let eventLogger: IEventLogger;

beforeEach(() => {
jest.resetAllMocks();
systemLogger = loggingSystemMock.createLogger();
esContext = contextMock.create();
service = new EventLogService({
esContext,
systemLogger,
config: { enabled: true, logEntries: true, indexEntries: false },
config: { enabled: true, logEntries: true, indexEntries: true },
kibanaUUID: KIBANA_SERVER_UUID,
});
eventLogger = service.getLogger({});
});

test('handles successful initialization', async () => {
service.registerProviderActions('test-provider', ['test-action-1']);
eventLogger = service.getLogger({
event: { provider: 'test-provider', action: 'test-action-1' },
});

eventLogger.logEvent({});
await waitForLogEvent(systemLogger);
delay(WRITE_LOG_WAIT_MILLIS); // sleep a bit since event logging is async
expect(esContext.esAdapter.indexDocument).toHaveBeenCalled();
});

test('handles failed initialization', async () => {
service.registerProviderActions('test-provider', ['test-action-1']);
eventLogger = service.getLogger({
event: { provider: 'test-provider', action: 'test-action-1' },
});
esContext.waitTillReady.mockImplementation(async () => Promise.resolve(false));

eventLogger.logEvent({});
await waitForLogEvent(systemLogger);
delay(WRITE_LOG_WAIT_MILLIS); // sleep a bit longer since event logging is async
expect(esContext.esAdapter.indexDocument).not.toHaveBeenCalled();
});

test('method logEvent() writes expected default values', async () => {
service.registerProviderActions('test-provider', ['test-action-1']);
eventLogger = service.getLogger({
Expand Down
7 changes: 6 additions & 1 deletion x-pack/plugins/event_log/server/event_logger.ts
Original file line number Diff line number Diff line change
Expand Up @@ -183,7 +183,12 @@ function indexEventDoc(esContext: EsContext, doc: Doc): void {
// whew, the thing that actually writes the event log document!
async function indexLogEventDoc(esContext: EsContext, doc: unknown) {
esContext.logger.debug(`writing to event log: ${JSON.stringify(doc)}`);
await esContext.waitTillReady();
const success = await esContext.waitTillReady();
if (!success) {
esContext.logger.debug(`event log did not initialize correctly, event not written`);
return;
}

Comment on lines +186 to +191
Copy link
Contributor

Choose a reason for hiding this comment

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

This makes me wonder - we will now be relying on the Event Log not just as a log, but as an operational data source for our product (alert instances over time, their values etc.).

Perhaps failing to index a log event should be a failing operation rather than a NOOP? 🤔

await esContext.esAdapter.indexDocument(doc);
esContext.logger.debug(`writing to event log complete`);
}
Expand Down