[8.12] [Security Solution] Improve logging for FTR test `retry` 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)](https://github.com/elastic/kibana/pull/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":"jpdjeredjian@gmail.com"},"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 <jpdjeredjian@gmail.com>

x-pack/test/security_solution_api_integration/test_suites/detections_response/default_license/prebuilt_rules/bundled_prebuilt_rules_package/install_latest_bundled_prebuilt_rules.ts

@@ -61,7 +61,8 @@ export default ({ getService }: FtrProviderContext): void => {
         es,
         supertest,
         '99.0.0',
-        retry
+        retry,
+        log
       );
 
       // As opposed to "registry"

x-pack/test/security_solution_api_integration/test_suites/detections_response/default_license/prebuilt_rules/bundled_prebuilt_rules_package/prerelease_packages.ts

@@ -49,7 +49,8 @@ export default ({ getService }: FtrProviderContext): void => {
       const fleetPackageInstallationResponse = await installPrebuiltRulesPackageViaFleetAPI(
         es,
         supertest,
-        retry
+        retry,
+        log
       );
 
       expect(fleetPackageInstallationResponse.items.length).toBe(1);

x-pack/test/security_solution_api_integration/test_suites/detections_response/default_license/prebuilt_rules/management/fleet_integration.ts

@@ -49,6 +49,7 @@ export default ({ getService }: FtrProviderContext): void => {
         supertest,
         overrideExistingPackage: true,
         retryService: retry,
+        log,
       });
 
       // Verify that status is updated after package installation

x-pack/test/security_solution_api_integration/test_suites/detections_response/default_license/prebuilt_rules/update_prebuilt_rules_package/update_prebuilt_rules_package.ts

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

x-pack/test/security_solution_api_integration/test_suites/detections_response/utils/retry.ts

@@ -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
@@ -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(
@@ -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

x-pack/test/security_solution_api_integration/test_suites/detections_response/utils/rules/prebuilt_rules/install_fleet_package_by_url.ts

@@ -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';
@@ -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 () => {
@@ -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);
@@ -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 () => {
@@ -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);

x-pack/test/security_solution_api_integration/test_suites/detections_response/utils/rules/prebuilt_rules/install_prebuilt_rules_fleet_package.ts

@@ -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';
 
@@ -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
@@ -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);
@@ -91,8 +96,10 @@ export const installPrebuiltRulesFleetPackage = async ({
         return body;
       },
       retryService,
+      utilityName: installPrebuiltRulesFleetPackage.name,
       retries: MAX_RETRIES,
       timeout: ATTEMPT_TIMEOUT,
+      log,
     });
 
     await refreshSavedObjectIndices(es);