diff --git a/packages/kbn-dev-utils/src/tooling_log/tooling_log_text_writer.ts b/packages/kbn-dev-utils/src/tooling_log/tooling_log_text_writer.ts index 660dae3fa1f55..2e62e880f8655 100644 --- a/packages/kbn-dev-utils/src/tooling_log/tooling_log_text_writer.ts +++ b/packages/kbn-dev-utils/src/tooling_log/tooling_log_text_writer.ts @@ -92,7 +92,15 @@ export class ToolingLogTextWriter implements Writer { } if (this.ignoreSources && msg.source && this.ignoreSources.includes(msg.source)) { - return false; + if (msg.type === 'write') { + const txt = format(msg.args[0], ...msg.args.slice(1)); + // Ensure that Elasticsearch deprecation log messages from Kibana aren't ignored + if (!/\[deprecation\]\[elasticsearch\]/.test(txt)) { + return false; + } + } else { + return false; + } } const prefix = has(MSG_PREFIXES, msg.type) ? MSG_PREFIXES[msg.type] : ''; diff --git a/packages/kbn-pm/dist/index.js b/packages/kbn-pm/dist/index.js index 36b81ca60c098..6723fd745f651 100644 --- a/packages/kbn-pm/dist/index.js +++ b/packages/kbn-pm/dist/index.js @@ -6639,7 +6639,15 @@ class ToolingLogTextWriter { } if (this.ignoreSources && msg.source && this.ignoreSources.includes(msg.source)) { - return false; + if (msg.type === 'write') { + const txt = (0, _util.format)(msg.args[0], ...msg.args.slice(1)); // Ensure that Elasticsearch deprecation log messages from Kibana aren't ignored + + if (!/\[deprecation\]\[elasticsearch\]/.test(txt)) { + return false; + } + } else { + return false; + } } const prefix = has(MSG_PREFIXES, msg.type) ? MSG_PREFIXES[msg.type] : ''; diff --git a/src/core/server/elasticsearch/client/configure_client.test.ts b/src/core/server/elasticsearch/client/configure_client.test.ts index 35fcb5819d015..6db433129195b 100644 --- a/src/core/server/elasticsearch/client/configure_client.test.ts +++ b/src/core/server/elasticsearch/client/configure_client.test.ts @@ -500,5 +500,152 @@ describe('configureClient', () => { `); }); }); + + describe('deprecation warnings from response headers', () => { + it('does not log when no deprecation warning header is returned', () => { + const client = configureClient(createFakeConfig(), { logger, type: 'test', scoped: false }); + + const response = createResponseWithBody({ + seq_no_primary_term: true, + query: { + term: { user: 'kimchy' }, + }, + }); + client.diagnostic.emit('response', new errors.ResponseError(response), response); + + expect(loggingSystemMock.collect(logger).warn).toEqual([]); + expect(loggingSystemMock.collect(logger).error).toEqual([]); + }); + + it('logs error when the client receives an Elasticsearch error response for a deprecated request originating from a user', () => { + const client = configureClient(createFakeConfig(), { logger, type: 'test', scoped: false }); + + const response = createApiResponse({ + statusCode: 400, + warnings: ['GET /_path is deprecated'], + params: { + method: 'GET', + path: '/_path', + querystring: { hello: 'dolly' }, + }, + body: { + error: { + type: 'illegal_argument_exception', + reason: 'request [/_path] contains unrecognized parameter: [name]', + }, + }, + }); + client.diagnostic.emit('response', new errors.ResponseError(response), response); + + expect(loggingSystemMock.collect(logger).warn).toEqual([]); + expect(loggingSystemMock.collect(logger).error[0][0]).toMatch( + 'ES DEPRECATION: GET /_path is deprecated' + ); + expect(loggingSystemMock.collect(logger).error[0][0]).toMatch('Origin:user'); + expect(loggingSystemMock.collect(logger).error[0][0]).toMatch(/Stack trace:\n.*at/); + expect(loggingSystemMock.collect(logger).error[0][0]).toMatch( + /Query:\n.*400\n.*GET \/_path\?hello\=dolly \[illegal_argument_exception\]: request \[\/_path\] contains unrecognized parameter: \[name\]/ + ); + }); + + it('logs warning when the client receives an Elasticsearch error response for a deprecated request originating from kibana', () => { + const client = configureClient(createFakeConfig(), { logger, type: 'test', scoped: false }); + + const response = createApiResponse({ + statusCode: 400, + warnings: ['GET /_path is deprecated'], + // Set the request header to indicate to Elasticsearch that this is a request over which users have no control + requestOptions: { headers: { 'x-elastic-product-origin': 'kibana' } }, + params: { + method: 'GET', + path: '/_path', + querystring: { hello: 'dolly' }, + }, + body: { + error: { + type: 'illegal_argument_exception', + reason: 'request [/_path] contains unrecognized parameter: [name]', + }, + }, + }); + client.diagnostic.emit('response', new errors.ResponseError(response), response); + + expect(loggingSystemMock.collect(logger).error).toEqual([]); + expect(loggingSystemMock.collect(logger).warn[0][0]).toMatch( + 'ES DEPRECATION: GET /_path is deprecated' + ); + expect(loggingSystemMock.collect(logger).warn[0][0]).toMatch('Origin:kibana'); + expect(loggingSystemMock.collect(logger).warn[0][0]).toMatch(/Stack trace:\n.*at/); + expect(loggingSystemMock.collect(logger).warn[0][0]).toMatch( + /Query:\n.*400\n.*GET \/_path\?hello\=dolly \[illegal_argument_exception\]: request \[\/_path\] contains unrecognized parameter: \[name\]/ + ); + }); + + it('logs error when the client receives an Elasticsearch success response for a deprecated request originating from a user', () => { + const client = configureClient(createFakeConfig(), { logger, type: 'test', scoped: false }); + + const response = createApiResponse({ + statusCode: 200, + warnings: ['GET /_path is deprecated'], + params: { + method: 'GET', + path: '/_path', + querystring: { hello: 'dolly' }, + }, + body: { + hits: [ + { + _source: 'may the source be with you', + }, + ], + }, + }); + client.diagnostic.emit('response', null, response); + + expect(loggingSystemMock.collect(logger).warn).toEqual([]); + expect(loggingSystemMock.collect(logger).error[0][0]).toMatch( + 'ES DEPRECATION: GET /_path is deprecated' + ); + expect(loggingSystemMock.collect(logger).error[0][0]).toMatch('Origin:user'); + expect(loggingSystemMock.collect(logger).error[0][0]).toMatch(/Stack trace:\n.*at/); + expect(loggingSystemMock.collect(logger).error[0][0]).toMatch( + /Query:\n.*200\n.*GET \/_path\?hello\=dolly/ + ); + }); + + it('logs warning when the client receives an Elasticsearch success response for a deprecated request originating from kibana', () => { + const client = configureClient(createFakeConfig(), { logger, type: 'test', scoped: false }); + + const response = createApiResponse({ + statusCode: 200, + warnings: ['GET /_path is deprecated'], + // Set the request header to indicate to Elasticsearch that this is a request over which users have no control + requestOptions: { headers: { 'x-elastic-product-origin': 'kibana' } }, + params: { + method: 'GET', + path: '/_path', + querystring: { hello: 'dolly' }, + }, + body: { + hits: [ + { + _source: 'may the source be with you', + }, + ], + }, + }); + client.diagnostic.emit('response', null, response); + + expect(loggingSystemMock.collect(logger).error).toEqual([]); + expect(loggingSystemMock.collect(logger).warn[0][0]).toMatch( + 'ES DEPRECATION: GET /_path is deprecated' + ); + expect(loggingSystemMock.collect(logger).warn[0][0]).toMatch('Origin:kibana'); + expect(loggingSystemMock.collect(logger).warn[0][0]).toMatch(/Stack trace:\n.*at/); + expect(loggingSystemMock.collect(logger).warn[0][0]).toMatch( + /Query:\n.*200\n.*GET \/_path\?hello\=dolly/ + ); + }); + }); }); }); diff --git a/src/core/server/elasticsearch/client/configure_client.ts b/src/core/server/elasticsearch/client/configure_client.ts index 93c404593af3f..9d2570a81af4e 100644 --- a/src/core/server/elasticsearch/client/configure_client.ts +++ b/src/core/server/elasticsearch/client/configure_client.ts @@ -14,6 +14,7 @@ import type { TransportRequestParams, TransportRequestOptions, } from '@elastic/elasticsearch/lib/Transport'; + import { Logger } from '../../logging'; import { parseClientOptions, ElasticsearchClientConfig } from './client_config'; @@ -47,7 +48,7 @@ export const configureClient = ( } const client = new Client({ ...clientOptions, Transport: KibanaTransport }); - addLogging(client, logger.get('query', type)); + addLogging({ client, logger, type }); // --------------------------------------------------------------------------------- // // Hack to disable the "Product check" only in the scoped clients while we // @@ -119,7 +120,9 @@ export function getRequestDebugMeta(event: RequestEvent): { }; } -const addLogging = (client: Client, logger: Logger) => { +const addLogging = ({ client, type, logger }: { client: Client; type: string; logger: Logger }) => { + const queryLogger = logger.get('query', type); + const deprecationLogger = logger.get('deprecation'); client.on('response', (error, event) => { if (event) { const opaqueId = event.meta.request.options.opaqueId; @@ -128,14 +131,46 @@ const addLogging = (client: Client, logger: Logger) => { http: { request: { id: event.meta.request.options.opaqueId } }, } : undefined; // do not clutter logs if opaqueId is not present + let queryMessage = ''; if (error) { if (error instanceof errors.ResponseError) { - logger.debug(`${getResponseMessage(event)} ${getErrorMessage(error)}`, meta); + queryMessage = `${getResponseMessage(event)} ${getErrorMessage(error)}`; } else { - logger.debug(getErrorMessage(error), meta); + queryMessage = getErrorMessage(error); } } else { - logger.debug(getResponseMessage(event), meta); + queryMessage = getResponseMessage(event); + } + + queryLogger.debug(queryMessage, meta); + + if (event.warnings && event.warnings.length > 0) { + // Plugins can explicitly mark requests as originating from a user by + // removing the `'x-elastic-product-origin': 'kibana'` header that's + // added by default. User requests will be shown to users in the + // upgrade assistant UI as an action item that has to be addressed + // before they upgrade. + // Kibana requests will be hidden from the upgrade assistant UI and are + // only logged to help developers maintain their plugins + const requestOrigin = + (event.meta.request.options.headers != null && + (event.meta.request.options.headers[ + 'x-elastic-product-origin' + ] as unknown as string)) === 'kibana' + ? 'kibana' + : 'user'; + + const stackTrace = new Error().stack?.split('\n').slice(5).join('\n'); + + if (requestOrigin === 'kibana') { + deprecationLogger.warn( + `ES DEPRECATION: ${event.warnings}\nOrigin:${requestOrigin}\nStack trace:\n${stackTrace}\nQuery:\n${queryMessage}` + ); + } else { + deprecationLogger.error( + `ES DEPRECATION: ${event.warnings}\nOrigin:${requestOrigin}\nStack trace:\n${stackTrace}\nQuery:\n${queryMessage}` + ); + } } } }); diff --git a/src/core/server/logging/logging_config.ts b/src/core/server/logging/logging_config.ts index f5b75d7bb739c..fcd6e496c92b0 100644 --- a/src/core/server/logging/logging_config.ts +++ b/src/core/server/logging/logging_config.ts @@ -65,7 +65,13 @@ export const config = { defaultValue: new Map(), }), loggers: schema.arrayOf(loggerSchema, { - defaultValue: [], + defaultValue: [ + { + name: 'elasticsearch.deprecation', + level: 'off', + appenders: [], + }, + ], }), root: schema.object( { diff --git a/src/core/test_helpers/kbn_server.ts b/src/core/test_helpers/kbn_server.ts index a2aa453cf55e7..a3763ae69ea41 100644 --- a/src/core/test_helpers/kbn_server.ts +++ b/src/core/test_helpers/kbn_server.ts @@ -105,6 +105,9 @@ export function createRootWithCorePlugins(settings = {}, cliArgs: Partial