Log more information on requests that fail at global router level (#165293)

There are certain occasions where Kibana UI shows a blank page (e.g. on
this [failed
test](https://buildkite.com/elastic/kibana-flaky-test-suite-runner/builds/2999)).
Blank pages can happen when browsers are not able to fetch one or more
of the bootstrap resources, e.g. `/bootstrap.js`.
Sometimes, Kibana server-side logs don't contain any information at all
as to what caused the failure.

This PR adds a bit more information in the logs, hoping it will help us
understanding why some of these requests fail sometimes.

---------

Co-authored-by: kibanamachine <42973632+kibanamachine@users.noreply.github.com>
This commit is contained in:
Gerard Soldevila 2023-09-04 14:20:27 +02:00 committed by GitHub
parent 7c0bca23ac
commit 86765b916d
No known key found for this signature in database
GPG key ID: 4AEE18F83AFDEB23
2 changed files with 129 additions and 21 deletions

View file

@ -199,26 +199,38 @@ export class Router<Context extends RequestHandlerContextBase = RequestHandlerCo
const hapiResponseAdapter = new HapiResponseAdapter(responseToolkit);
try {
kibanaRequest = CoreKibanaRequest.from(request, routeSchemas);
} catch (e) {
return hapiResponseAdapter.toBadRequest(e.message);
} catch (error) {
this.log.error(`400 Bad Request - ${request.path}`, {
error,
http: { response: { status_code: 400 } },
});
return hapiResponseAdapter.toBadRequest(error.message);
}
try {
const kibanaResponse = await handler(kibanaRequest, kibanaResponseFactory);
return hapiResponseAdapter.handle(kibanaResponse);
} catch (e) {
// log and capture error
this.log.error(e);
apm.captureError(e);
} catch (error) {
// capture error
apm.captureError(error);
// forward 401 errors from ES client
if (isElasticsearchUnauthorizedError(e)) {
if (isElasticsearchUnauthorizedError(error)) {
this.log.error(`401 Unauthorized - ${request.path}`, {
error,
http: { response: { status_code: 401 } },
});
return hapiResponseAdapter.handle(
kibanaResponseFactory.unauthorized(convertEsUnauthorized(e))
kibanaResponseFactory.unauthorized(convertEsUnauthorized(error))
);
}
// return a generic 500 to avoid error info / stack trace surfacing
this.log.error(`500 Server Error - ${request.path}`, {
error,
http: { response: { status_code: 500 } },
});
return hapiResponseAdapter.toInternalError();
}
}

View file

@ -576,11 +576,19 @@ describe('Handler', () => {
'An internal server error occurred. Check Kibana server logs for details.'
);
expect(loggingSystemMock.collect(logger).error).toMatchInlineSnapshot(`
Array [
Array [
Array [
[Error: unexpected error],
],
]
"500 Server Error - /",
Object {
"error": [Error: unexpected error],
"http": Object {
"response": Object {
"status_code": 500,
},
},
},
],
]
`);
});
@ -617,7 +625,15 @@ describe('Handler', () => {
expect(loggingSystemMock.collect(logger).error).toMatchInlineSnapshot(`
Array [
Array [
[Error: Unauthorized],
"500 Server Error - /",
Object {
"error": [Error: Unauthorized],
"http": Object {
"response": Object {
"status_code": 500,
},
},
},
],
]
`);
@ -639,7 +655,15 @@ describe('Handler', () => {
expect(loggingSystemMock.collect(logger).error).toMatchInlineSnapshot(`
Array [
Array [
[Error: Unexpected result from Route Handler. Expected KibanaResponse, but given: string.],
"500 Server Error - /",
Object {
"error": [Error: Unexpected result from Route Handler. Expected KibanaResponse, but given: string.],
"http": Object {
"response": Object {
"status_code": 500,
},
},
},
],
]
`);
@ -672,6 +696,22 @@ describe('Handler', () => {
message: '[request query.page]: expected value of type [number] but got [string]',
statusCode: 400,
});
expect(loggingSystemMock.collect(logger).error).toMatchInlineSnapshot(`
Array [
Array [
"400 Bad Request - /",
Object {
"error": [Error: [request query.page]: expected value of type [number] but got [string]],
"http": Object {
"response": Object {
"status_code": 400,
},
},
},
],
]
`);
});
it('accept to receive an array payload', async () => {
@ -1145,7 +1185,15 @@ describe('Response factory', () => {
expect(loggingSystemMock.collect(logger).error).toMatchInlineSnapshot(`
Array [
Array [
[Error: expected 'location' header to be set],
"500 Server Error - /",
Object {
"error": [Error: expected 'location' header to be set],
"http": Object {
"response": Object {
"status_code": 500,
},
},
},
],
]
`);
@ -1551,7 +1599,15 @@ describe('Response factory', () => {
expect(loggingSystemMock.collect(logger).error).toMatchInlineSnapshot(`
Array [
Array [
[Error: Unexpected Http status code. Expected from 400 to 599, but given: 200],
"500 Server Error - /",
Object {
"error": [Error: Unexpected Http status code. Expected from 400 to 599, but given: 200],
"http": Object {
"response": Object {
"status_code": 500,
},
},
},
],
]
`);
@ -1620,7 +1676,15 @@ describe('Response factory', () => {
expect(loggingSystemMock.collect(logger).error).toMatchInlineSnapshot(`
Array [
Array [
[Error: expected 'location' header to be set],
"500 Server Error - /",
Object {
"error": [Error: expected 'location' header to be set],
"http": Object {
"response": Object {
"status_code": 500,
},
},
},
],
]
`);
@ -1760,7 +1824,15 @@ describe('Response factory', () => {
expect(loggingSystemMock.collect(logger).error).toMatchInlineSnapshot(`
Array [
Array [
[Error: expected error message to be provided],
"500 Server Error - /",
Object {
"error": [Error: expected error message to be provided],
"http": Object {
"response": Object {
"status_code": 500,
},
},
},
],
]
`);
@ -1786,7 +1858,15 @@ describe('Response factory', () => {
expect(loggingSystemMock.collect(logger).error).toMatchInlineSnapshot(`
Array [
Array [
[Error: expected error message to be provided],
"500 Server Error - /",
Object {
"error": [Error: expected error message to be provided],
"http": Object {
"response": Object {
"status_code": 500,
},
},
},
],
]
`);
@ -1811,7 +1891,15 @@ describe('Response factory', () => {
expect(loggingSystemMock.collect(logger).error).toMatchInlineSnapshot(`
Array [
Array [
[Error: options.statusCode is expected to be set. given options: undefined],
"500 Server Error - /",
Object {
"error": [Error: options.statusCode is expected to be set. given options: undefined],
"http": Object {
"response": Object {
"status_code": 500,
},
},
},
],
]
`);
@ -1836,7 +1924,15 @@ describe('Response factory', () => {
expect(loggingSystemMock.collect(logger).error).toMatchInlineSnapshot(`
Array [
Array [
[Error: Unexpected Http status code. Expected from 100 to 599, but given: 20.],
"500 Server Error - /",
Object {
"error": [Error: Unexpected Http status code. Expected from 100 to 599, but given: 20.],
"http": Object {
"response": Object {
"status_code": 500,
},
},
},
],
]
`);