Skip to content

Commit

Permalink
[8.12] [Security Solution] Improve logging for FTR test `retry&#…
Browse files Browse the repository at this point in the history
…x60; function (#176316) (#176497)

# Backport

This will backport the following commits from `main` to `8.12`:
- [[Security Solution] Improve logging for FTR test `retry`
function (#176316)](#176316)

<!--- Backport version: 9.4.3 -->

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

<!--BACKPORT [{"author":{"name":"Juan Pablo
Djeredjian","email":"[email protected]"},"sourceCommit":{"committedDate":"2024-02-08T12:35:54Z","message":"[Security
Solution] Improve logging for FTR test `retry` function (#176316)\n\n##
Summary\r\n\r\n**Fixes:** \r\n-
https://github.com/elastic/kibana/issues/175481\r\n-
https://github.com/elastic/kibana/issues/175250\r\n\r\n\r\n###
Description\r\n\r\nImproves logging for the `retry` FTR integration
testing utility that is\r\nused to wrap helpers that make endpoint calls
or direct Elasticsearch\r\noperations.\r\n\r\nThe previous logging would
only explain that the maximum amount of\r\nretries had been reached,
with the actual error caused in the test being\r\nlost, which proved
hard to debug.\r\n\r\nThese changes catches the error and log it,
allowing us to understand\r\nwhy a retried test failed.\r\n\r\nError now
reported as:\r\n\r\n```\r\n[00:00:19] │ERROR Retrying
installPrebuiltRulesPackageByVersion: Error: expected 500 \"Internal
Server Error\", got 200 \"OK\"\r\n[00:00:19] │ debg --- retry.tryForTime
failed again with the same message...\r\n[00:00:19] │ERROR Reached
maximum number of retries for test: 2/2\r\n[00:00:19] └- ✖ fail: Rules
Management - Prebuilt Rules - Update Prebuilt Rules Package @ess
@serverless @skipInQA update_prebuilt_rules_package should allow user to
install prebuilt rules from scratch, then install new rules and upgrade
existing rules from the new package\r\n[00:00:19] │ Error: \"Reached
maximum number of retries for test: 2/2\"\r\n[00:00:19] │ at block
(retry.ts:72:16)\r\n[00:00:19] │ at runAttempt
(retry_for_success.ts:29:21)\r\n[00:00:19] │ at retryForSuccess
(retry_for_success.ts:79:27)\r\n[00:00:19] │ at RetryService.tryForTime
(retry.ts:23:12)\r\n[00:00:19] │ at retry (retry.ts:62:20)\r\n[00:00:19]
│ at installPrebuiltRulesPackageByVersion
(install_fleet_package_by_url.ts:77:25)\r\n[00:00:19] │ at
Context.<anonymous>
(update_prebuilt_rules_package.ts:106:46)\r\n[00:00:19] │ at
Object.apply (wrap_function.js:73:16)\r\n```\r\nMain error is still
`\"Reached maximum number of retries for test: 2/2\"`,\r\nbut now
additional logging of exactly **what failed in the test**
is\r\nerror-logged as seen above: `ERROR
Retrying\r\ninstallPrebuiltRulesPackageByVersion: Error: expected 500
\"Internal\r\nServer Error\", got 200 \"OK\"`\r\n\r\n**Flaky test run:**
\r\n- Shared 50 and
50:\r\nhttps://buildkite.com/elastic/kibana-flaky-test-suite-runner/builds/5068\r\n-
Ess 100
runs:\r\nhttps://buildkite.com/elastic/kibana-flaky-test-suite-runner/builds/5091\r\n-
Serverless 100
runs:\r\nhttps://buildkite.com/elastic/kibana-flaky-test-suite-runner/builds/5092\r\n\r\n###
For maintainers\r\n\r\n- [ ] This was checked for breaking API changes
and was
[labeled\r\nappropriately](https://www.elastic.co/guide/en/kibana/master/contributing.html#kibana-release-notes-process)","sha":"479a022bd3a8ae79ca9af1eb12a90a26cb53efdf","branchLabelMapping":{"^v8.13.0$":"main","^v(\\d+).(\\d+).\\d+$":"$1.$2"}},"sourcePullRequest":{"labels":["test","release_note:skip","Team:Detections
and Resp","Team: SecuritySolution","Team:Detection Rule
Management","v8.13.0","v8.12.2"],"title":"[Security Solution] Improve
logging for FTR test `retry`
function","number":176316,"url":"https://github.com/elastic/kibana/pull/176316","mergeCommit":{"message":"[Security
Solution] Improve logging for FTR test `retry` function (#176316)\n\n##
Summary\r\n\r\n**Fixes:** \r\n-
https://github.com/elastic/kibana/issues/175481\r\n-
https://github.com/elastic/kibana/issues/175250\r\n\r\n\r\n###
Description\r\n\r\nImproves logging for the `retry` FTR integration
testing utility that is\r\nused to wrap helpers that make endpoint calls
or direct Elasticsearch\r\noperations.\r\n\r\nThe previous logging would
only explain that the maximum amount of\r\nretries had been reached,
with the actual error caused in the test being\r\nlost, which proved
hard to debug.\r\n\r\nThese changes catches the error and log it,
allowing us to understand\r\nwhy a retried test failed.\r\n\r\nError now
reported as:\r\n\r\n```\r\n[00:00:19] │ERROR Retrying
installPrebuiltRulesPackageByVersion: Error: expected 500 \"Internal
Server Error\", got 200 \"OK\"\r\n[00:00:19] │ debg --- retry.tryForTime
failed again with the same message...\r\n[00:00:19] │ERROR Reached
maximum number of retries for test: 2/2\r\n[00:00:19] └- ✖ fail: Rules
Management - Prebuilt Rules - Update Prebuilt Rules Package @ess
@serverless @skipInQA update_prebuilt_rules_package should allow user to
install prebuilt rules from scratch, then install new rules and upgrade
existing rules from the new package\r\n[00:00:19] │ Error: \"Reached
maximum number of retries for test: 2/2\"\r\n[00:00:19] │ at block
(retry.ts:72:16)\r\n[00:00:19] │ at runAttempt
(retry_for_success.ts:29:21)\r\n[00:00:19] │ at retryForSuccess
(retry_for_success.ts:79:27)\r\n[00:00:19] │ at RetryService.tryForTime
(retry.ts:23:12)\r\n[00:00:19] │ at retry (retry.ts:62:20)\r\n[00:00:19]
│ at installPrebuiltRulesPackageByVersion
(install_fleet_package_by_url.ts:77:25)\r\n[00:00:19] │ at
Context.<anonymous>
(update_prebuilt_rules_package.ts:106:46)\r\n[00:00:19] │ at
Object.apply (wrap_function.js:73:16)\r\n```\r\nMain error is still
`\"Reached maximum number of retries for test: 2/2\"`,\r\nbut now
additional logging of exactly **what failed in the test**
is\r\nerror-logged as seen above: `ERROR
Retrying\r\ninstallPrebuiltRulesPackageByVersion: Error: expected 500
\"Internal\r\nServer Error\", got 200 \"OK\"`\r\n\r\n**Flaky test run:**
\r\n- Shared 50 and
50:\r\nhttps://buildkite.com/elastic/kibana-flaky-test-suite-runner/builds/5068\r\n-
Ess 100
runs:\r\nhttps://buildkite.com/elastic/kibana-flaky-test-suite-runner/builds/5091\r\n-
Serverless 100
runs:\r\nhttps://buildkite.com/elastic/kibana-flaky-test-suite-runner/builds/5092\r\n\r\n###
For maintainers\r\n\r\n- [ ] This was checked for breaking API changes
and was
[labeled\r\nappropriately](https://www.elastic.co/guide/en/kibana/master/contributing.html#kibana-release-notes-process)","sha":"479a022bd3a8ae79ca9af1eb12a90a26cb53efdf"}},"sourceBranch":"main","suggestedTargetBranches":["8.12"],"targetPullRequestStates":[{"branch":"main","label":"v8.13.0","branchLabelMappingKey":"^v8.13.0$","isSourceBranch":true,"state":"MERGED","url":"https://github.com/elastic/kibana/pull/176316","number":176316,"mergeCommit":{"message":"[Security
Solution] Improve logging for FTR test `retry` function (#176316)\n\n##
Summary\r\n\r\n**Fixes:** \r\n-
https://github.com/elastic/kibana/issues/175481\r\n-
https://github.com/elastic/kibana/issues/175250\r\n\r\n\r\n###
Description\r\n\r\nImproves logging for the `retry` FTR integration
testing utility that is\r\nused to wrap helpers that make endpoint calls
or direct Elasticsearch\r\noperations.\r\n\r\nThe previous logging would
only explain that the maximum amount of\r\nretries had been reached,
with the actual error caused in the test being\r\nlost, which proved
hard to debug.\r\n\r\nThese changes catches the error and log it,
allowing us to understand\r\nwhy a retried test failed.\r\n\r\nError now
reported as:\r\n\r\n```\r\n[00:00:19] │ERROR Retrying
installPrebuiltRulesPackageByVersion: Error: expected 500 \"Internal
Server Error\", got 200 \"OK\"\r\n[00:00:19] │ debg --- retry.tryForTime
failed again with the same message...\r\n[00:00:19] │ERROR Reached
maximum number of retries for test: 2/2\r\n[00:00:19] └- ✖ fail: Rules
Management - Prebuilt Rules - Update Prebuilt Rules Package @ess
@serverless @skipInQA update_prebuilt_rules_package should allow user to
install prebuilt rules from scratch, then install new rules and upgrade
existing rules from the new package\r\n[00:00:19] │ Error: \"Reached
maximum number of retries for test: 2/2\"\r\n[00:00:19] │ at block
(retry.ts:72:16)\r\n[00:00:19] │ at runAttempt
(retry_for_success.ts:29:21)\r\n[00:00:19] │ at retryForSuccess
(retry_for_success.ts:79:27)\r\n[00:00:19] │ at RetryService.tryForTime
(retry.ts:23:12)\r\n[00:00:19] │ at retry (retry.ts:62:20)\r\n[00:00:19]
│ at installPrebuiltRulesPackageByVersion
(install_fleet_package_by_url.ts:77:25)\r\n[00:00:19] │ at
Context.<anonymous>
(update_prebuilt_rules_package.ts:106:46)\r\n[00:00:19] │ at
Object.apply (wrap_function.js:73:16)\r\n```\r\nMain error is still
`\"Reached maximum number of retries for test: 2/2\"`,\r\nbut now
additional logging of exactly **what failed in the test**
is\r\nerror-logged as seen above: `ERROR
Retrying\r\ninstallPrebuiltRulesPackageByVersion: Error: expected 500
\"Internal\r\nServer Error\", got 200 \"OK\"`\r\n\r\n**Flaky test run:**
\r\n- Shared 50 and
50:\r\nhttps://buildkite.com/elastic/kibana-flaky-test-suite-runner/builds/5068\r\n-
Ess 100
runs:\r\nhttps://buildkite.com/elastic/kibana-flaky-test-suite-runner/builds/5091\r\n-
Serverless 100
runs:\r\nhttps://buildkite.com/elastic/kibana-flaky-test-suite-runner/builds/5092\r\n\r\n###
For maintainers\r\n\r\n- [ ] This was checked for breaking API changes
and was
[labeled\r\nappropriately](https://www.elastic.co/guide/en/kibana/master/contributing.html#kibana-release-notes-process)","sha":"479a022bd3a8ae79ca9af1eb12a90a26cb53efdf"}},{"branch":"8.12","label":"v8.12.2","branchLabelMappingKey":"^v(\\d+).(\\d+).\\d+$","isSourceBranch":false,"state":"NOT_CREATED"}]}]
BACKPORT-->

Co-authored-by: Juan Pablo Djeredjian <[email protected]>
  • Loading branch information
kibanamachine and jpdjere authored Feb 8, 2024
1 parent 45bf1be commit c5a102b
Show file tree
Hide file tree
Showing 7 changed files with 43 additions and 9 deletions.
Original file line number Diff line number Diff line change
Expand Up @@ -61,7 +61,8 @@ export default ({ getService }: FtrProviderContext): void => {
es,
supertest,
'99.0.0',
retry
retry,
log
);

// As opposed to "registry"
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -49,7 +49,8 @@ export default ({ getService }: FtrProviderContext): void => {
const fleetPackageInstallationResponse = await installPrebuiltRulesPackageViaFleetAPI(
es,
supertest,
retry
retry,
log
);

expect(fleetPackageInstallationResponse.items.length).toBe(1);
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -49,6 +49,7 @@ export default ({ getService }: FtrProviderContext): void => {
supertest,
overrideExistingPackage: true,
retryService: retry,
log,
});

// Verify that status is updated after package installation
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -107,7 +107,8 @@ export default ({ getService }: FtrProviderContext): void => {
es,
supertest,
previousVersion,
retry
retry,
log
);

expect(installPreviousPackageResponse._meta.install_source).toBe('registry');
Expand Down Expand Up @@ -160,7 +161,8 @@ export default ({ getService }: FtrProviderContext): void => {
es,
supertest,
currentVersion,
retry
retry,
log
);
expect(installLatestPackageResponse.items.length).toBeGreaterThanOrEqual(0);

Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -6,7 +6,7 @@
*/

import { RetryService } from '@kbn/ftr-common-functional-services';

import type { ToolingLog } from '@kbn/tooling-log';
/**
* Retry wrapper for async supertests, with a maximum number of retries.
* You can pass in a function that executes a supertest test, and make assertions
Expand Down Expand Up @@ -44,15 +44,19 @@ import { RetryService } from '@kbn/ftr-common-functional-services';
export const retry = async <T>({
test,
retryService,
utilityName,
retries = 2,
timeout = 30000,
retryDelay = 200,
log,
}: {
test: () => Promise<T>;
utilityName: string;
retryService: RetryService;
retries?: number;
timeout?: number;
retryDelay?: number;
log: ToolingLog;
}): Promise<T> => {
let retryAttempt = 0;
const response = await retryService.tryForTime(
Expand All @@ -61,12 +65,23 @@ export const retry = async <T>({
if (retryAttempt > retries) {
// Log error message if we reached the maximum number of retries
// but don't throw an error, return it to break the retry loop.
return new Error('Reached maximum number of retries for test.');
const errorMessage = `Reached maximum number of retries for test: ${
retryAttempt - 1
}/${retries}`;
log?.error(errorMessage);
return new Error(JSON.stringify(errorMessage));
}

retryAttempt = retryAttempt + 1;

return test();
// Catch the error thrown by the test and log it, then throw it again
// to cause `tryForTime` to retry.
try {
return await test();
} catch (error) {
log.error(`Retrying ${utilityName}: ${error}`);
throw error;
}
},
undefined,
retryDelay
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -9,6 +9,7 @@ import type SuperTest from 'supertest';
import { InstallPackageResponse } from '@kbn/fleet-plugin/common/types';
import { epmRouteService } from '@kbn/fleet-plugin/common';
import { RetryService } from '@kbn/ftr-common-functional-services';
import type { ToolingLog } from '@kbn/tooling-log';
import expect from 'expect';
import { retry } from '../../retry';
import { refreshSavedObjectIndices } from '../../refresh_index';
Expand All @@ -28,7 +29,8 @@ const ATTEMPT_TIMEOUT = 120000;
export const installPrebuiltRulesPackageViaFleetAPI = async (
es: Client,
supertest: SuperTest.SuperTest<SuperTest.Test>,
retryService: RetryService
retryService: RetryService,
log: ToolingLog
): Promise<InstallPackageResponse> => {
const fleetResponse = await retry<InstallPackageResponse>({
test: async () => {
Expand All @@ -44,9 +46,11 @@ export const installPrebuiltRulesPackageViaFleetAPI = async (

return testResponse.body;
},
utilityName: installPrebuiltRulesPackageViaFleetAPI.name,
retryService,
retries: MAX_RETRIES,
timeout: ATTEMPT_TIMEOUT,
log,
});

await refreshSavedObjectIndices(es);
Expand All @@ -67,7 +71,8 @@ export const installPrebuiltRulesPackageByVersion = async (
es: Client,
supertest: SuperTest.SuperTest<SuperTest.Test>,
version: string,
retryService: RetryService
retryService: RetryService,
log: ToolingLog
): Promise<InstallPackageResponse> => {
const fleetResponse = await retry<InstallPackageResponse>({
test: async () => {
Expand All @@ -83,9 +88,11 @@ export const installPrebuiltRulesPackageByVersion = async (

return testResponse.body;
},
utilityName: installPrebuiltRulesPackageByVersion.name,
retryService,
retries: MAX_RETRIES,
timeout: ATTEMPT_TIMEOUT,
log,
});

await refreshSavedObjectIndices(es);
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -15,6 +15,7 @@ import { InstallPackageResponse } from '@kbn/fleet-plugin/common/types';
import type SuperTest from 'supertest';
import { RetryService } from '@kbn/ftr-common-functional-services';
import expect from 'expect';
import { ToolingLog } from '@kbn/tooling-log';
import { retry } from '../../retry';
import { refreshSavedObjectIndices } from '../../refresh_index';

Expand All @@ -35,12 +36,14 @@ export const installPrebuiltRulesFleetPackage = async ({
version,
overrideExistingPackage,
retryService,
log,
}: {
es: Client;
supertest: SuperTest.SuperTest<SuperTest.Test>;
version?: string;
overrideExistingPackage: boolean;
retryService: RetryService;
log: ToolingLog;
}): Promise<InstallPackageResponse | BulkInstallPackagesResponse> => {
if (version) {
// Install a specific version
Expand All @@ -59,8 +62,10 @@ export const installPrebuiltRulesFleetPackage = async ({
return testResponse.body;
},
retryService,
utilityName: installPrebuiltRulesFleetPackage.name,
retries: MAX_RETRIES,
timeout: ATTEMPT_TIMEOUT,
log,
});

await refreshSavedObjectIndices(es);
Expand Down Expand Up @@ -91,8 +96,10 @@ export const installPrebuiltRulesFleetPackage = async ({
return body;
},
retryService,
utilityName: installPrebuiltRulesFleetPackage.name,
retries: MAX_RETRIES,
timeout: ATTEMPT_TIMEOUT,
log,
});

await refreshSavedObjectIndices(es);
Expand Down

0 comments on commit c5a102b

Please sign in to comment.