Closed cachedout closed 3 years ago
the below badges are clickable and redirect to their specific view in the CI or DOCS
#### Build stats * Start Time: 2021-08-17T13:51:50.206+0000 * Duration: 27 min 39 sec * Commit: 77b5b5ad231cecbb31a288166a0a8f005b8a2a3e #### Test stats :test_tube: | Test | Results | | ------------ | :-----------------------------: | | Failed | 5 | | Passed | 2051 | | Skipped | 1855 | | Total | 3911 | #### Trends :test_tube: ![Image of Build Times](https://beats-ci.elastic.co/job/Beats/job/beats-tester-mbp/job/PR-204/buildTimeGraph/png) ![Image of Tests](https://beats-ci.elastic.co/job/Beats/job/beats-tester-mbp/job/PR-204/9/testReport/history/countGraph/png?start=0&end=25)
##### `Test Hosts / Matrix - GROUPS = 'centos' / Test / [tester-awslinux] Packaging tests Heartbeat: test-linux-binary : Wait for the output file to be created, should contain HTTP pinging search_regex="scheme":"http", path={{workdir}}/output/heartbeat, timeout=5 – /var/lib/jenkins/workspace/Beats_beats-tester-mbp_PR-204/src/roles/test-linux-binary/tasks/main.yml:74`
``` Timeout when waiting for search string "scheme":"http" in /tmp/output/heartbeat ```
``` { "changed": false, "elapsed": 5, "msg": "Timeout when waiting for search string \"scheme\":\"http\" in /tmp/output/heartbeat" } ```
``` Timeout when waiting for search string "scheme":"http" in /tmp/output/heartbeat ```
``` { "changed": false, "elapsed": 5, "msg": "Timeout when waiting for search string \"scheme\":\"http\" in /tmp/output/heartbeat" } ```
``` Timeout when waiting for search string "scheme":"http" in /tmp/output/heartbeat ```
``` { "changed": false, "elapsed": 5, "msg": "Timeout when waiting for search string \"scheme\":\"http\" in /tmp/output/heartbeat" } ```
``` Timeout when waiting for search string "scheme":"http" in /tmp/output/heartbeat ```
``` { "changed": false, "elapsed": 5, "msg": "Timeout when waiting for search string \"scheme\":\"http\" in /tmp/output/heartbeat" } ```
``` Timeout when waiting for search string "scheme":"http" in /tmp/output/heartbeat ```
``` { "changed": false, "elapsed": 5, "msg": "Timeout when waiting for search string \"scheme\":\"http\" in /tmp/output/heartbeat" } ```
##### `make batch`
script returned exit code 2
``` [2021-08-17T14:17:50.991Z] [2021-08-17T14:17:50.991Z] TASK [test-uninstall : Uninstall auditbeat rpm] ******************************** [2021-08-17T14:17:50.991Z] skipping: [tester-win12-64] [2021-08-17T14:17:50.991Z] [2021-08-17T14:17:50.991Z] TASK [test-uninstall : Uninstall auditbeat rpm] ******************************** [2021-08-17T14:17:50.991Z] skipping: [tester-win12-64] [2021-08-17T14:17:50.991Z] [2021-08-17T14:17:50.991Z] TASK [test-uninstall : Delete directory (darwin)] ****************************** [2021-08-17T14:17:50.991Z] skipping: [tester-win12-64] [2021-08-17T14:17:50.991Z] [2021-08-17T14:17:50.991Z] TASK [test-uninstall : Delete directory (windows)] ***************************** [2021-08-17T14:17:51.687Z] changed: [tester-win12-64] [2021-08-17T14:17:51.687Z] [2021-08-17T14:17:51.687Z] PLAY RECAP ********************************************************************* [2021-08-17T14:17:51.687Z] tester-win12-64 : ok=281 changed=114 unreachable=0 failed=0 skipped=480 rescued=0 ignored=0 [2021-08-17T14:17:51.687Z] [2021-08-17T14:17:52.825Z] make[2]: Leaving directory '/var/lib/jenkins/workspace/Beats_beats-tester-mbp_PR-204/src' [2021-08-17T14:17:52.825Z] vagrant destroy -f tester-win12-64 [2021-08-17T14:17:55.078Z] ==> tester-win12-64: Forcing shutdown of VM... [2021-08-17T14:17:55.778Z] ==> tester-win12-64: Destroying VM and associated drives... [2021-08-17T14:17:57.234Z] make[1]: Leaving directory '/var/lib/jenkins/workspace/Beats_beats-tester-mbp_PR-204/src' [2021-08-17T14:17:57.589Z] Post stage [2021-08-17T14:17:57.614Z] Running in /var/lib/jenkins/workspace/Beats_beats-tester-mbp_PR-204/src [2021-08-17T14:17:57.740Z] Recording test results [2021-08-17T14:17:58.755Z] [Checks API] No suitable checks publisher found. [2021-08-17T14:17:58.883Z] Archiving artifacts [2021-08-17T14:18:00.512Z] + make clean [2021-08-17T14:18:00.512Z] vagrant destroy -f [2021-08-17T14:18:08.250Z] ==> tester-ubuntu2004-64: VM not created. Moving on... [2021-08-17T14:18:08.250Z] ==> tester-debian10-64: VM not created. Moving on... [2021-08-17T14:18:08.250Z] ==> tester-win19-64: VM not created. Moving on... [2021-08-17T14:18:08.250Z] ==> tester-centos8-64: VM not created. Moving on... [2021-08-17T14:18:08.250Z] ==> tester-awslinux2: VM not created. Moving on... [2021-08-17T14:18:08.250Z] ==> tester-ubuntu1804-64: VM not created. Moving on... [2021-08-17T14:18:08.250Z] ==> tester-sles12-64: VM not created. Moving on... [2021-08-17T14:18:08.250Z] ==> tester-debian9-64: VM not created. Moving on... [2021-08-17T14:18:08.250Z] ==> tester-awslinux: VM not created. Moving on... [2021-08-17T14:18:08.250Z] ==> tester-win12-64: VM not created. Moving on... [2021-08-17T14:18:08.250Z] ==> tester-centos7-64: VM not created. Moving on... [2021-08-17T14:18:08.250Z] ==> tester-debian8-64: VM not created. Moving on... [2021-08-17T14:18:08.250Z] rm -r .vagrant [2021-08-17T14:18:09.868Z] Running on Jenkins in /var/lib/jenkins/workspace/Beats_beats-tester-mbp_PR-204 [2021-08-17T14:18:09.988Z] [INFO] getVaultSecret: Getting secrets [2021-08-17T14:18:10.041Z] Masking supported pattern matches of $VAULT_ADDR or $VAULT_ROLE_ID or $VAULT_SECRET_ID [2021-08-17T14:18:10.802Z] + chmod 755 generate-build-data.sh [2021-08-17T14:18:10.802Z] + ./generate-build-data.sh https://beats-ci.elastic.co/blue/rest/organizations/jenkins/pipelines/Beats/beats-tester-mbp/PR-204/ https://beats-ci.elastic.co/blue/rest/organizations/jenkins/pipelines/Beats/beats-tester-mbp/PR-204/runs/9 FAILURE 1580322 [2021-08-17T14:18:10.802Z] INFO: curl https://beats-ci.elastic.co/blue/rest/organizations/jenkins/pipelines/Beats/beats-tester-mbp/PR-204/runs/9/steps/?limit=10000 -o steps-info.json [2021-08-17T14:18:12.145Z] INFO: curl https://beats-ci.elastic.co/blue/rest/organizations/jenkins/pipelines/Beats/beats-tester-mbp/PR-204/runs/9/tests/?status=FAILED -o tests-errors.json [2021-08-17T14:18:12.396Z] INFO: curl https://beats-ci.elastic.co/blue/rest/organizations/jenkins/pipelines/Beats/beats-tester-mbp/PR-204/runs/9/log/ -o pipeline-log.txt [2021-08-17T14:18:12.396Z] INFO: curl https://beats-ci.elastic.co/blue/rest/organizations/jenkins/pipelines/Beats/beats-tester-mbp/PR-204// -o job-info.json [2021-08-17T14:18:12.646Z] jq: error (at job-info.json:0): Cannot index string with string "_links" [2021-08-17T14:18:12.646Z] jq: error (at job-info.json:0): Cannot index string with string "_class" [2021-08-17T14:18:12.646Z] jq: error (at job-info.json:0): Cannot index string with string "downloadable" [2021-08-17T14:18:12.646Z] jq: error (at job-info.json:0): Cannot index string with string "id" [2021-08-17T14:18:12.646Z] jq: error (at job-info.json:0): Cannot index string with string "url" [2021-08-17T14:18:12.646Z] jq: error (at job-info.json:21): Cannot index boolean with string "author" [2021-08-17T14:18:12.646Z] jq: error (at job-info.json:21): Cannot index boolean with string "author" [2021-08-17T14:18:12.646Z] INFO: curl https://beats-ci.elastic.co/blue/rest/organizations/jenkins/pipelines/Beats/beats-tester-mbp/PR-204/runs/9/changeSet/ -o changeSet-info.json [2021-08-17T14:18:12.896Z] jq: error (at changeSet-info.json:30): Cannot index array with string "_links" [2021-08-17T14:18:12.896Z] jq: error (at changeSet-info.json:30): Cannot index array with string "_class" [2021-08-17T14:18:12.897Z] jq: error (at changeSet-info.json:30): Cannot index array with string "actions" [2021-08-17T14:18:12.897Z] jq: error (at changeSet-info.json:30): Cannot index array with string "latestRun" [2021-08-17T14:18:12.897Z] jq: error (at changeSet-info.json:30): Cannot index array with string "permissions" [2021-08-17T14:18:12.897Z] jq: error (at changeSet-info.json:30): Cannot index array with string "parameters" [2021-08-17T14:18:12.897Z] INFO: fetchAndPrepareArtifactsInfo (see artifacts-info.json) [2021-08-17T14:18:12.897Z] INFO: curl https://beats-ci.elastic.co/blue/rest/organizations/jenkins/pipelines/Beats/beats-tester-mbp/PR-204/runs/9/artifacts/ -o artifacts-info.json [2021-08-17T14:18:13.147Z] INFO: fetchAndPrepareTestsInfo (see tests-info.json) [2021-08-17T14:18:13.147Z] INFO: curl https://beats-ci.elastic.co/blue/rest/organizations/jenkins/pipelines/Beats/beats-tester-mbp/PR-204/runs/9/tests/?limit=10000000 -o tests-info.json [2021-08-17T14:18:18.843Z] INFO: fetchAndPrepareTestSummaryReport (see tests-summary.json) [2021-08-17T14:18:18.843Z] INFO: curl https://beats-ci.elastic.co/blue/rest/organizations/jenkins/pipelines/Beats/beats-tester-mbp/PR-204/runs/9/blueTestSummary/ -o tests-summary.json [2021-08-17T14:18:18.843Z] INFO: fetchAndPrepareTestCoverageReport (see tests-coverage.json) [2021-08-17T14:18:18.843Z] INFO: curl https://beats-ci.elastic.co/job/Beats/job/beats-tester-mbp/job/PR-204/9//cobertura/api/json?tree=results\[elements\[name,ratio,denominator,numerator\]\]&depth=3 -o tests-coverage.json [2021-08-17T14:18:19.093Z] Retry 1/3 exited 22, retrying in 1 seconds... [2021-08-17T14:18:20.004Z] Retry 2/3 exited 22, retrying in 2 seconds... [2021-08-17T14:18:22.487Z] Retry 3/3 exited 22, no more retries left. [2021-08-17T14:18:22.487Z] jq: error (at tests-coverage.json:1): null (null) has no keys [2021-08-17T14:18:22.487Z] INFO: fetchAndPrepareBuildInfo (see build-info.json) [2021-08-17T14:18:22.487Z] INFO: curl https://beats-ci.elastic.co/blue/rest/organizations/jenkins/pipelines/Beats/beats-tester-mbp/PR-204/runs/9/ -o build-info.json [2021-08-17T14:18:22.749Z] Archiving artifacts [2021-08-17T14:18:22.781Z] Timeout set to expire in 5 min 0 sec [2021-08-17T14:18:23.114Z] Archiving artifacts [2021-08-17T14:18:23.382Z] [WARN] notifyIfPossible: could not fetch the nextBuild. [2021-08-17T14:18:23.480Z] Copied 1 artifact from "Beats » Pipeline for beats-tester » PR-204" build number 8 [2021-08-17T14:18:24.514Z] Archiving artifacts [2021-08-17T14:18:24.561Z] Timeout set to expire in 5 min 0 sec [2021-08-17T14:18:24.652Z] [INFO] getVaultSecret: Getting secrets [2021-08-17T14:18:24.693Z] Masking supported pattern matches of $VAULT_ADDR or $VAULT_ROLE_ID or $VAULT_SECRET_ID [2021-08-17T14:18:24.968Z] [INFO] sendDataToElasticsearch: sending data... [2021-08-17T14:18:26.799Z] [INFO] getVaultSecret: Getting secrets [2021-08-17T14:18:26.847Z] Masking supported pattern matches of $VAULT_ADDR or $VAULT_ROLE_ID or $VAULT_SECRET_ID [2021-08-17T14:18:27.097Z] [INFO] sendDataToElasticsearch: sending data... [2021-08-17T14:18:27.631Z] [INFO] getVaultSecret: Getting secrets [2021-08-17T14:18:27.674Z] Masking supported pattern matches of $VAULT_ADDR or $VAULT_ROLE_ID or $VAULT_SECRET_ID [2021-08-17T14:18:27.929Z] [INFO] sendDataToElasticsearch: sending data... [2021-08-17T14:18:28.133Z] Running on Jenkins in /var/lib/jenkins/workspace/Beats_beats-tester-mbp_PR-204 [2021-08-17T14:18:28.167Z] [INFO] getVaultSecret: Getting secrets [2021-08-17T14:18:28.206Z] Masking supported pattern matches of $VAULT_ADDR or $VAULT_ROLE_ID or $VAULT_SECRET_ID [2021-08-17T14:18:29.030Z] + chmod 755 generate-build-data.sh [2021-08-17T14:18:29.030Z] + ./generate-build-data.sh https://beats-ci.elastic.co/blue/rest/organizations/jenkins/pipelines/Beats/beats-tester-mbp/PR-204/ https://beats-ci.elastic.co/blue/rest/organizations/jenkins/pipelines/Beats/beats-tester-mbp/PR-204/runs/9 FAILURE 1598559 [2021-08-17T14:18:29.030Z] INFO: curl https://beats-ci.elastic.co/blue/rest/organizations/jenkins/pipelines/Beats/beats-tester-mbp/PR-204/runs/9/steps/?limit=10000 -o steps-info.json ```
These same failures are present in the master branch and should require a fix there. However, I think this is safe to merge now so I'm going to go ahead and do so.
This should fully resolve https://github.com/elastic/observability-robots/issues/579 and is the correct fix for https://github.com/elastic/beats-tester/pull/202
The problem here turned out to be that GCE aggressively sets cache-control headers on objects resulting in Ansible downloading incorrect checksum data.
In ad-hoc testing, I varying times for this cache expiration for a bucket that was configured in a similar way to the current artifact bucket but some of them were as low as ~5 minutes, which would explain why this problem presents itself as a race condition. This pipeline is typically run downstream of the main APM Server pipeline which means that we're racing the cache expiration.
This fix works around the issue by simply passing in the
ignoreCache=1
flag to all requests to GCE.A better solution would be to set Cache-Control metadata on the object during its creation, but in testing this I could not get GCE to respect this setting. As a result, I chose to fix it client-side for the time being.
In the event caching can be reliably disabled on artifacts in the GCE bucket, the workaround in this PR could be reverted.
cc: @adam-stokes @v1v