[8.10] Log more information on requests that fail at global router level (#165293) (#165587)

# Backport

This will backport the following commits from `main` to `8.10`:
- [Log more information on requests that fail at global router level
(#165293)](https://github.com/elastic/kibana/pull/165293)

<!--- Backport version: 8.9.7 -->

### Questions ?
Please refer to the [Backport tool
documentation](https://github.com/sqren/backport)

<!--BACKPORT [{"author":{"name":"Gerard
Soldevila","email":"gerard.soldevila@elastic.co"},"sourceCommit":{"committedDate":"2023-09-04T12:20:27Z","message":"Log
more information on requests that fail at global router level
(#165293)\n\nThere are certain occasions where Kibana UI shows a blank
page (e.g. on\r\nthis
[failed\r\ntest](https://buildkite.com/elastic/kibana-flaky-test-suite-runner/builds/2999)).\r\nBlank
pages can happen when browsers are not able to fetch one or more\r\nof
the bootstrap resources, e.g. `/bootstrap.js`.\r\nSometimes, Kibana
server-side logs don't contain any information at all\r\nas to what
caused the failure.\r\n\r\nThis PR adds a bit more information in the
logs, hoping it will help us\r\nunderstanding why some of these requests
fail sometimes.\r\n\r\n---------\r\n\r\nCo-authored-by: kibanamachine
<42973632+kibanamachine@users.noreply.github.com>","sha":"86765b916dbfc424144735b9c5de904a4e7b7de0","branchLabelMapping":{"^v8.11.0$":"main","^v(\\d+).(\\d+).\\d+$":"$1.$2"}},"sourcePullRequest":{"labels":["bug","Team:Core","release_note:skip","backport:prev-minor","v8.11.0"],"number":165293,"url":"https://github.com/elastic/kibana/pull/165293","mergeCommit":{"message":"Log
more information on requests that fail at global router level
(#165293)\n\nThere are certain occasions where Kibana UI shows a blank
page (e.g. on\r\nthis
[failed\r\ntest](https://buildkite.com/elastic/kibana-flaky-test-suite-runner/builds/2999)).\r\nBlank
pages can happen when browsers are not able to fetch one or more\r\nof
the bootstrap resources, e.g. `/bootstrap.js`.\r\nSometimes, Kibana
server-side logs don't contain any information at all\r\nas to what
caused the failure.\r\n\r\nThis PR adds a bit more information in the
logs, hoping it will help us\r\nunderstanding why some of these requests
fail sometimes.\r\n\r\n---------\r\n\r\nCo-authored-by: kibanamachine
<42973632+kibanamachine@users.noreply.github.com>","sha":"86765b916dbfc424144735b9c5de904a4e7b7de0"}},"sourceBranch":"main","suggestedTargetBranches":[],"targetPullRequestStates":[{"branch":"main","label":"v8.11.0","labelRegex":"^v8.11.0$","isSourceBranch":true,"state":"MERGED","url":"https://github.com/elastic/kibana/pull/165293","number":165293,"mergeCommit":{"message":"Log
more information on requests that fail at global router level
(#165293)\n\nThere are certain occasions where Kibana UI shows a blank
page (e.g. on\r\nthis
[failed\r\ntest](https://buildkite.com/elastic/kibana-flaky-test-suite-runner/builds/2999)).\r\nBlank
pages can happen when browsers are not able to fetch one or more\r\nof
the bootstrap resources, e.g. `/bootstrap.js`.\r\nSometimes, Kibana
server-side logs don't contain any information at all\r\nas to what
caused the failure.\r\n\r\nThis PR adds a bit more information in the
logs, hoping it will help us\r\nunderstanding why some of these requests
fail sometimes.\r\n\r\n---------\r\n\r\nCo-authored-by: kibanamachine
<42973632+kibanamachine@users.noreply.github.com>","sha":"86765b916dbfc424144735b9c5de904a4e7b7de0"}}]}]
BACKPORT-->

Co-authored-by: Gerard Soldevila <gerard.soldevila@elastic.co>
This commit is contained in:
Kibana Machine 2023-09-04 09:27:44 -04:00 committed by GitHub
parent 403d948ad3
commit 18cfd84a54
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,
},
},
},
],
]
`);