From c610bf0e3661319d205314c38e790f03e5982813 Mon Sep 17 00:00:00 2001 From: Patrick Mueller Date: Tue, 14 Jul 2020 10:42:27 -0400 Subject: [PATCH] [eventLog] prevent log writing when initialization fails (#71339) resolves https://github.com/elastic/kibana/issues/68309 Previously, if the initialization of the elasticsearch resources failed during initialization, the event logger would still try to write events. Which is somewhat of a catastrophic failure, as typically the logger would try writing to the alias name, but no alias exists, so a new index would be created with the name of the alias. Making it impossible to initialize successfully later until that index was deleted. The core initialization calls already returned success indicators, so this PR just responds to those and prevents the logger from writing to the index if initialization failed. # Conflicts: # x-pack/plugins/event_log/server/es/context.test.ts --- .../event_log/server/es/context.mock.ts | 2 +- .../event_log/server/es/context.test.ts | 19 +++++++++--- x-pack/plugins/event_log/server/es/context.ts | 12 ++++--- .../event_log/server/event_logger.test.ts | 31 +++++++++++++++++-- .../plugins/event_log/server/event_logger.ts | 7 ++++- 5 files changed, 58 insertions(+), 13 deletions(-) diff --git a/x-pack/plugins/event_log/server/es/context.mock.ts b/x-pack/plugins/event_log/server/es/context.mock.ts index 0c9f7b29b64119..8d5483b88c4fab 100644 --- a/x-pack/plugins/event_log/server/es/context.mock.ts +++ b/x-pack/plugins/event_log/server/es/context.mock.ts @@ -17,7 +17,7 @@ const createContextMock = () => { logger: loggingSystemMock.createLogger(), esNames: namesMock.create(), initialize: jest.fn(), - waitTillReady: jest.fn(), + waitTillReady: jest.fn(async () => true), esAdapter: clusterClientAdapterMock.create(), initialized: true, }; diff --git a/x-pack/plugins/event_log/server/es/context.test.ts b/x-pack/plugins/event_log/server/es/context.test.ts index c21c762829fc2e..a88b0028c35e81 100644 --- a/x-pack/plugins/event_log/server/es/context.test.ts +++ b/x-pack/plugins/event_log/server/es/context.test.ts @@ -7,10 +7,9 @@ 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', -})); -export type EsClusterClient = Pick; +jest.mock('../lib/../../../../package.json', () => ({ version: '1.2.3' })); +jest.mock('./init'); +type EsClusterClient = Pick, 'callAsInternalUser' | 'asScoped'>; let logger: Logger; let clusterClient: EsClusterClient; @@ -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); + }); }); diff --git a/x-pack/plugins/event_log/server/es/context.ts b/x-pack/plugins/event_log/server/es/context.ts index 16a460be1793b2..8c967e68299b55 100644 --- a/x-pack/plugins/event_log/server/es/context.ts +++ b/x-pack/plugins/event_log/server/es/context.ts @@ -64,9 +64,9 @@ 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); @@ -74,11 +74,13 @@ class EsContextImpl implements EsContext { }); } + // waits till the ES initialization is done, returns true if it was successful, + // false if it was not successful async waitTillReady(): Promise { return await this.readySignal.wait(); } - private async _initialize() { - await initializeEs(this); + private async _initialize(): Promise { + return await initializeEs(this); } } diff --git a/x-pack/plugins/event_log/server/event_logger.test.ts b/x-pack/plugins/event_log/server/event_logger.test.ts index d4d3df3ef8267c..fde3b2de8dd36e 100644 --- a/x-pack/plugins/event_log/server/event_logger.test.ts +++ b/x-pack/plugins/event_log/server/event_logger.test.ts @@ -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; - let esContext: EsContext; + let esContext: jest.Mocked; 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 () => 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({ diff --git a/x-pack/plugins/event_log/server/event_logger.ts b/x-pack/plugins/event_log/server/event_logger.ts index 1a710a6fa48653..8730870f9620b4 100644 --- a/x-pack/plugins/event_log/server/event_logger.ts +++ b/x-pack/plugins/event_log/server/event_logger.ts @@ -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; + } + await esContext.esAdapter.indexDocument(doc); esContext.logger.debug(`writing to event log complete`); }