[Flaky Test]: TestLogIngestionFleetManaged – Failed to remove install directory

[rdner]

Failing test case

TestLogIngestionFleetManaged

Error message

Failed to remove install directory

Build

https://buildkite.com/elastic/elastic-agent/builds/6667#018d5f15-e83c-4be2-80e2-64c2d17dcfa0

OS

Windows

Stacktrace and notes

fixture_install.go:215: 
        	Error Trace:	C:/Users/windows/agent/pkg/testing/fixture_install.go:215
        	            				C:/Program Files/Go/src/testing/testing.go:1169
        	            				C:/Program Files/Go/src/testing/testing.go:1347
        	            				C:/Program Files/Go/src/testing/testing.go:1589
        	Error:      	Received unexpected error:
        	            	error running uninstall command: exit status 1
        	Test:       	TestLogIngestionFleetManaged
        	Messages:   	uninstalling agent failed. Output: "
[    ] Stopping service  [0s] 
                              

[  ==] Successfully stopped service  [0s] 
                                          

[ ===] Stopping upgrade watcher; none found  [0s] 
                                                  

[=   ] Removing service  [0s] 
                                                  

[=   ] Successfully uninstalled service  [0s] 
                                                  

[=   ] Removing install directory  [0s] 
                                                  

[====] Failed to remove install directory  [10s] 
                                                  

[====] Failed to uninstall agent  [10s] Error uninstalling.  Printing logs
{debug 2024-01-31 11:00:03.7594074 +0000 GMT m=+0.396454701 processes Error fetching PID info for 0, skipping: GetInfoForPid: could not get all information for PID 0: error fetching name: OpenProcess failed for pid=0: The parameter is incorrect.
error fetching status: OpenProcess failed for pid=0: The parameter is incorrect. /go/pkg/mod/github.com/elastic/elastic-agent-system-metrics@v0.9.1/metric/system/process/process.go:173 }
{debug 2024-01-31 11:00:03.7603068 +0000 GMT m=+0.397354101 processes Error fetching PID info for 4, skipping: GetInfoForPid: could not get all information for PID 4: error fetching name: GetProcessImageFileName failed for pid=4: GetProcessImageFileName failed: invalid argument /go/pkg/mod/github.com/elastic/elastic-agent-system-metrics@v0.9.1/metric/system/process/process.go:173 }
{debug 2024-01-31 11:00:03.7603938 +0000 GMT m=+0.397441101 processes Non fatal error fetching PID some info for 116, metrics are valid, but partial: FillMetricsRequiringMoreAccess: error fetching process args: Not enough privileges to fetch information: OpenProcess failed: Access is denied. /go/pkg/mod/github.com/elastic/elastic-agent-system-metrics@v0.9.1/metric/system/process/process.go:176 }
{debug 2024-01-31 11:00:03.7613448 +0000 GMT m=+0.398392101 processes Non fatal error fetching PID some info for 364, metrics are valid, but partial: FillMetricsRequiringMoreAccess: error fetching process args: Not enough privileges to fetch information: OpenProcess failed: Access is denied. /go/pkg/mod/github.com/elastic/elastic-agent-system-metrics@v0.9.1/metric/system/process/process.go:176 }
{debug 2024-01-31 11:00:03.7613448 +0000 GMT m=+0.398392101 processes Non fatal error fetching PID some info for 476, metrics are valid, but partial: FillMetricsRequiringMoreAccess: error fetching process args: Not enough privileges to fetch information: OpenProcess failed: Access is denied. /go/pkg/mod/github.com/elastic/elastic-agent-system-metrics@v0.9.1/metric/system/process/process.go:176 }
{debug 2024-01-31 11:00:03.7623309 +0000 GMT m=+0.399378201 processes Non fatal error fetching PID some info for 560, metrics are valid, but partial: FillMetricsRequiringMoreAccess: error fetching process args: Not enough privileges to fetch information: OpenProcess failed: Access is denied. /go/pkg/mod/github.com/elastic/elastic-agent-system-metrics@v0.9.1/metric/system/process/process.go:176 }
{debug 2024-01-31 11:00:03.7623309 +0000 GMT m=+0.399378201 processes Non fatal error fetching PID some info for 568, metrics are valid, but partial: FillMetricsRequiringMoreAccess: error fetching process args: Not enough privileges to fetch information: OpenProcess failed: Access is denied. /go/pkg/mod/github.com/elastic/elastic-agent-system-metrics@v0.9.1/metric/system/process/process.go:176 }
{debug 2024-01-31 11:00:03.7632954 +0000 GMT m=+0.400342701 processes Non fatal error fetching PID some info for 700, metrics are valid, but partial: FillMetricsRequiringMoreAccess: error fetching process args: Not enough privileges to fetch information: OpenProcess failed: Access is denied. /go/pkg/mod/github.com/elastic/elastic-agent-system-metrics@v0.9.1/metric/system/process/process.go:176 }
{debug 2024-01-31 11:00:03.7921051 +0000 GMT m=+0.429152401 processes Non fatal error fetching PID some info for 3104, metrics are valid, but partial: FillMetricsRequiringMoreAccess: error fetching process args: Not enough privileges to fetch information: OpenProcess failed: Access is denied. /go/pkg/mod/github.com/elastic/elastic-agent-system-metrics@v0.9.1/metric/system/process/process.go:176 }
{debug 2024-01-31 11:00:03.7968609 +0000 GMT m=+0.433908201 processes Non fatal error fetching PID some info for 4920, metrics are valid, but partial: FillMetricsRequiringMoreAccess: error fetching process args: Not enough privileges to fetch information: OpenProcess failed: Access is denied. /go/pkg/mod/github.com/elastic/elastic-agent-system-metrics@v0.9.1/metric/system/process/process.go:176 }
{debug 2024-01-31 11:00:03.8087051 +0000 GMT m=+0.445752401 processes Non fatal error fetching PID some info for 2508, metrics are valid, but partial: FillMetricsRequiringMoreAccess: error fetching process args: Not enough privileges to fetch information: OpenProcess failed: Access is denied. /go/pkg/mod/github.com/elastic/elastic-agent-system-metrics@v0.9.1/metric/system/process/process.go:176 }
{debug 2024-01-31 11:00:03.8096899 +0000 GMT m=+0.446737201 processes Non fatal error fetching PID some info for 4748, metrics are valid, but partial: FillMetricsRequiringMoreAccess: error fetching process args: Not enough privileges to fetch information: OpenProcess failed: Access is denied. /go/pkg/mod/github.com/elastic/elastic-agent-system-metrics@v0.9.1/metric/system/process/process.go:176 }
{debug 2024-01-31 11:00:03.8223729 +0000 GMT m=+0.459420201 processes Non fatal error fetching PID some info for 388, metrics are valid, but partial: FillMetricsRequiringMoreAccess: error fetching process args: Not enough privileges to fetch information: OpenProcess failed: Access is denied. /go/pkg/mod/github.com/elastic/elastic-agent-system-metrics@v0.9.1/metric/system/process/process.go:176 }
{debug 2024-01-31 11:00:03.8234031 +0000 GMT m=+0.460450401 processes Non fatal error fetching PID some info for 5136, metrics are valid, but partial: FillMetricsRequiringMoreAccess: error fetching process args: Not enough privileges to fetch information: OpenProcess failed: Access is denied. /go/pkg/mod/github.com/elastic/elastic-agent-system-metrics@v0.9.1/metric/system/process/process.go:176 }
{warn 2024-01-31 11:00:03.9561501 +0000 GMT m=+0.593197401 cfgwarn DEPRECATED: Treating the CommonName field on X.509 certificates as a host name when no Subject Alternative Names are present is going to be removed. Please update your certificates if needed. Will be removed in version: 8.0.0 /go/pkg/mod/github.com/elastic/elastic-agent-libs@v0.7.4/transport/tlscommon/config.go:101 }
{debug 2024-01-31 11:00:03.957143 +0000 GMT m=+0.594190301 state_migration state store C:\\Program Files\\Elastic\\Agent\\data\\elastic-agent-86745f\\state.enc already exists /go/src/github.com/elastic/elastic-agent/internal/pkg/agent/storage/store/state_store.go:159 }
{debug 2024-01-31 11:00:04.0040017 +0000 GMT m=+0.641049001 composable Starting controller for composable inputs /go/src/github.com/elastic/elastic-agent/internal/pkg/composable/controller.go:112 }
{debug 2024-01-31 11:00:04.0040017 +0000 GMT m=+0.641049001 composable Started controller for composable inputs /go/src/github.com/elastic/elastic-agent/internal/pkg/composable/controller.go:155 }
{debug 2024-01-31 11:00:04.0040017 +0000 GMT m=+0.641049001 docker Docker client will negotiate the API version on the first request. /go/pkg/mod/github.com/elastic/elastic-agent-autodiscover@v0.6.6/docker/client.go:49 }
{info 2024-01-31 11:00:04.0040017 +0000 GMT m=+0.641049001 composable.providers.docker Docker provider skipped, unable to connect: protocol not available /go/src/github.com/elastic/elastic-agent/internal/pkg/composable/providers/docker/docker.go:44 }
{debug 2024-01-31 11:00:04.0040017 +0000 GMT m=+0.641049001 composable Variable state changed for composable inputs; debounce started /go/src/github.com/elastic/elastic-agent/internal/pkg/composable/controller.go:191 }
{debug 2024-01-31 11:00:04.0048934 +0000 GMT m=+0.641940701 composable kubernetes_secrets provider skipped, unable to connect: unable to build kube config due to error: invalid configuration: no configuration has been provided, try setting KUBERNETES_MASTER environment variable /go/src/github.com/elastic/elastic-agent/internal/pkg/composable/providers/kubernetessecrets/kubernetes_secrets.go:81 }
{debug 2024-01-31 11:00:04.0048934 +0000 GMT m=+0.641940701 composable.providers.kubernetes Kubernetes provider for resource pod skipped, unable to connect: unable to build kube config due to error: invalid configuration: no configuration has been provided, try setting KUBERNETES_MASTER environment variable /go/src/github.com/elastic/elastic-agent/internal/pkg/composable/providers/kubernetes/kubernetes.go:106 }
{debug 2024-01-31 11:00:04.0048934 +0000 GMT m=+0.641940701 composable.providers.kubernetes Kubernetes provider for resource node skipped, unable to connect: unable to build kube config due to error: invalid configuration: no configuration has been provided, try setting KUBERNETES_MASTER environment variable /go/src/github.com/elastic/elastic-agent/internal/pkg/composable/providers/kubernetes/kubernetes.go:106 }
{debug 2024-01-31 11:00:04.0048934 +0000 GMT m=+0.641940701 composable Kubernetes leaderelection provider skipped, unable to connect: unable to build kube config due to error: invalid configuration: no configuration has been provided, try setting KUBERNETES_MASTER environment variable /go/src/github.com/elastic/elastic-agent/internal/pkg/composable/providers/kubernetesleaderelection/kubernetes_leaderelection.go:53 }
{debug 2024-01-31 11:00:04.1095056 +0000 GMT m=+0.746552901 composable Computing new variable state for composable inputs /go/src/github.com/elastic/elastic-agent/internal/pkg/composable/controller.go:207 }
{debug 2024-01-31 11:00:04.1095056 +0000 GMT m=+0.746552901 composable Stopping controller for composable inputs /go/src/github.com/elastic/elastic-agent/internal/pkg/composable/controller.go:159 }
{debug 2024-01-31 11:00:04.2198811 +0000 GMT m=+0.856928401 composable Stopped controller for composable inputs /go/src/github.com/elastic/elastic-agent/internal/pkg/composable/controller.go:188 }
Error: error uninstalling agent: failed to remove installation directory (C:\\Program Files\\Elastic\\Agent): timed out while removing \"C:\\\\Program Files\\\\Elastic\\\\Agent\". Last error: remove C:\\Program Files\\Elastic\\Agent\\data\\elastic-agent-86745f\\elastic-agent.exe: Access is denied.
For help, please see our troubleshooting guide at https://www.elastic.co/guide/en/fleet/8.13/fleet-troubleshooting.html
"
--- FAIL: TestLogIngestionFleetManaged (182.71s)

Possibly related to #4143
Possible duplicate of #4092

[elasticmachine]

Pinging @elastic/elastic-agent (Team:Elastic-Agent)

[rdner]

Failed again in https://buildkite.com/elastic/elastic-agent/builds/6877#018d80df-a2c7-4837-bfe9-caf8ee19b14a

Same error message.

[rdner]

Looks like a similar failure is here in TestStandaloneUpgradeFailsWhenUpgradeIsInProgress https://buildkite.com/elastic/elastic-agent/builds/6886#018d8418-9066-48d3-a5d5-7bb40d2964c7

[AndersonQ]

I found another flaky test, #4216, that seems to be the same issue:

Error: error uninstalling agent: failed to remove installation directory (C:\Program Files\Elastic\Agent): timed out while removing "C:\\Program Files\\Elastic\\Agent". Last error: remove C:\Program Files\Elastic\Agent\data\elastic-agent-8fa2b9\elastic-agent.exe: Access is denied.

[rdner]

Although we merged a fix, we would not completely avoid this failure until all the versions/snapshots we use for testing contain this fix in them. Every test case where we upgrade or downgrade to a version that does not have this fix might still fail to remove the installation directory.

[rdner]

The issue re-appeared in https://buildkite.com/elastic/elastic-agent/builds/7312#018dc8f8-b861-4e7b-95d4-4be972bf9e59 despite the:

Upgrading from version "8.12.2-SNAPSHOT-a7ac98efd17a5593624b831289e9bc4a91ee412f" to version "8.13.0-SNAPSHOT-ed1c28c7515286f34785e68f48013b3fdb272fb0"

Both of the commit hashes a7ac98e and ed1c28c already include the fix by @leehinman #4224

Furthermore, the failure rate with this message is now close to 90%.

[rdner]

It's still happening rarely:

• https://buildkite.com/elastic/elastic-agent-extended-testing/builds/201
• https://buildkite.com/elastic/elastic-agent-extended-testing/builds/239