From 274d5de2e0df6a674ef0e57298d9d6ed12e1dbac Mon Sep 17 00:00:00 2001 From: Mikhail Shustov Date: Wed, 16 Sep 2020 10:47:54 +0300 Subject: [PATCH] log request body in new ES client (#77150) * log request body in new ES client * add test case when body is null * update test --- .../client/configure_client.test.ts | 219 +++++++++++++++--- .../elasticsearch/client/configure_client.ts | 25 +- 2 files changed, 200 insertions(+), 44 deletions(-) diff --git a/src/core/server/elasticsearch/client/configure_client.test.ts b/src/core/server/elasticsearch/client/configure_client.test.ts index 716e2fd98a5e1..250cfc18a757d 100644 --- a/src/core/server/elasticsearch/client/configure_client.test.ts +++ b/src/core/server/elasticsearch/client/configure_client.test.ts @@ -16,9 +16,11 @@ * specific language governing permissions and limitations * under the License. */ +import { Buffer } from 'buffer'; +import { Readable } from 'stream'; import { RequestEvent, errors } from '@elastic/elasticsearch'; -import { TransportRequestParams } from '@elastic/elasticsearch/lib/Transport'; +import { TransportRequestParams, RequestBody } from '@elastic/elasticsearch/lib/Transport'; import { parseClientOptionsMock, ClientMock } from './configure_client.test.mocks'; import { loggingSystemMock } from '../../logging/logging_system.mock'; @@ -195,40 +197,184 @@ describe('configureClient', () => { `); }); - it('logs each queries if `logQueries` is true', () => { - const client = configureClient( - createFakeConfig({ - logQueries: true, - }), - { logger, scoped: false } - ); + describe('logs each queries if `logQueries` is true', () => { + function createResponseWithBody(body?: RequestBody) { + return createApiResponse({ + body: {}, + statusCode: 200, + params: { + method: 'GET', + path: '/foo', + querystring: { hello: 'dolly' }, + body, + }, + }); + } + + it('when request body is an object', () => { + const client = configureClient( + createFakeConfig({ + logQueries: true, + }), + { logger, scoped: false } + ); + + const response = createResponseWithBody({ + seq_no_primary_term: true, + query: { + term: { user: 'kimchy' }, + }, + }); + + client.emit('response', null, response); + expect(loggingSystemMock.collect(logger).debug).toMatchInlineSnapshot(` + Array [ + Array [ + "200 + GET /foo?hello=dolly + {\\"seq_no_primary_term\\":true,\\"query\\":{\\"term\\":{\\"user\\":\\"kimchy\\"}}}", + Object { + "tags": Array [ + "query", + ], + }, + ], + ] + `); + }); - const response = createApiResponse({ - body: {}, - statusCode: 200, - params: { - method: 'GET', - path: '/foo', - querystring: { hello: 'dolly' }, - }, + it('when request body is a string', () => { + const client = configureClient( + createFakeConfig({ + logQueries: true, + }), + { logger, scoped: false } + ); + + const response = createResponseWithBody( + JSON.stringify({ + seq_no_primary_term: true, + query: { + term: { user: 'kimchy' }, + }, + }) + ); + + client.emit('response', null, response); + expect(loggingSystemMock.collect(logger).debug).toMatchInlineSnapshot(` + Array [ + Array [ + "200 + GET /foo?hello=dolly + {\\"seq_no_primary_term\\":true,\\"query\\":{\\"term\\":{\\"user\\":\\"kimchy\\"}}}", + Object { + "tags": Array [ + "query", + ], + }, + ], + ] + `); }); - client.emit('response', null, response); + it('when request body is a buffer', () => { + const client = configureClient( + createFakeConfig({ + logQueries: true, + }), + { logger, scoped: false } + ); + + const response = createResponseWithBody( + Buffer.from( + JSON.stringify({ + seq_no_primary_term: true, + query: { + term: { user: 'kimchy' }, + }, + }) + ) + ); + + client.emit('response', null, response); + expect(loggingSystemMock.collect(logger).debug).toMatchInlineSnapshot(` + Array [ + Array [ + "200 + GET /foo?hello=dolly + [buffer]", + Object { + "tags": Array [ + "query", + ], + }, + ], + ] + `); + }); - expect(loggingSystemMock.collect(logger).debug).toMatchInlineSnapshot(` - Array [ + it('when request body is a readable stream', () => { + const client = configureClient( + createFakeConfig({ + logQueries: true, + }), + { logger, scoped: false } + ); + + const response = createResponseWithBody( + // @ts-expect-error definition doesn't know about from + Readable.from( + JSON.stringify({ + seq_no_primary_term: true, + query: { + term: { user: 'kimchy' }, + }, + }) + ) + ); + + client.emit('response', null, response); + expect(loggingSystemMock.collect(logger).debug).toMatchInlineSnapshot(` Array [ - "200 - GET /foo - hello=dolly", - Object { - "tags": Array [ - "query", - ], - }, - ], - ] - `); + Array [ + "200 + GET /foo?hello=dolly + [stream]", + Object { + "tags": Array [ + "query", + ], + }, + ], + ] + `); + }); + + it('when request body is not defined', () => { + const client = configureClient( + createFakeConfig({ + logQueries: true, + }), + { logger, scoped: false } + ); + + const response = createResponseWithBody(); + + client.emit('response', null, response); + expect(loggingSystemMock.collect(logger).debug).toMatchInlineSnapshot(` + Array [ + Array [ + "200 + GET /foo?hello=dolly", + Object { + "tags": Array [ + "query", + ], + }, + ], + ] + `); + }); }); it('properly encode queries', () => { @@ -255,8 +401,7 @@ describe('configureClient', () => { Array [ Array [ "200 - GET /foo - city=M%C3%BCnich", + GET /foo?city=M%C3%BCnich", Object { "tags": Array [ "query", @@ -286,6 +431,12 @@ describe('configureClient', () => { method: 'GET', path: '/foo', querystring: { hello: 'dolly' }, + body: { + seq_no_primary_term: true, + query: { + term: { user: 'kimchy' }, + }, + }, }, }); client.emit('response', new errors.ResponseError(response), response); @@ -294,8 +445,8 @@ describe('configureClient', () => { Array [ Array [ "500 - GET /foo - hello=dolly", + GET /foo?hello=dolly + {\\"seq_no_primary_term\\":true,\\"query\\":{\\"term\\":{\\"user\\":\\"kimchy\\"}}}", Object { "tags": Array [ "query", diff --git a/src/core/server/elasticsearch/client/configure_client.ts b/src/core/server/elasticsearch/client/configure_client.ts index a777344813068..bf07ea604d228 100644 --- a/src/core/server/elasticsearch/client/configure_client.ts +++ b/src/core/server/elasticsearch/client/configure_client.ts @@ -16,9 +16,11 @@ * specific language governing permissions and limitations * under the License. */ - +import { Buffer } from 'buffer'; import { stringify } from 'querystring'; import { Client } from '@elastic/elasticsearch'; +import { RequestBody } from '@elastic/elasticsearch/lib/Transport'; + import { Logger } from '../../logging'; import { parseClientOptions, ElasticsearchClientConfig } from './client_config'; @@ -48,15 +50,11 @@ const addLogging = (client: Client, logger: Logger, logQueries: boolean) => { // definition is wrong, `params.querystring` can be either a string or an object const querystring = convertQueryString(params.querystring); - - logger.debug( - `${event.statusCode}\n${params.method} ${params.path}${ - querystring ? `\n${querystring}` : '' - }`, - { - tags: ['query'], - } - ); + const url = `${params.path}${querystring ? `?${querystring}` : ''}`; + const body = params.body ? `\n${ensureString(params.body)}` : ''; + logger.debug(`${event.statusCode}\n${params.method} ${url}${body}`, { + tags: ['query'], + }); } }); }; @@ -67,3 +65,10 @@ const convertQueryString = (qs: string | Record | undefined): strin } return stringify(qs); }; + +function ensureString(body: RequestBody): string { + if (typeof body === 'string') return body; + if (Buffer.isBuffer(body)) return '[buffer]'; + if ('readable' in body && body.readable && typeof body._read === 'function') return '[stream]'; + return JSON.stringify(body); +}