elastic / elastic/integrations
[zeek] Investigate buildkite test failures
- Dominant language
- Handlebars
- Stars
- 333
- Forks
- 647
- Avg merge
- 3d 4h
- Merged PRs (30d)
- 209
Description
Affected builds:
- https://github.com/elastic/integrations/issues/16414 ([buildkite](https://buildkite.com/elastic/integrations/builds/35243))
- https://github.com/elastic/integrations/issues/16734 ([buildkite](https://buildkite.com/elastic/integrations/builds/36002))
- https://github.com/elastic/integrations/issues/17103 ([buildkite](https://buildkite.com/elastic/integrations/builds/37008))
- https://github.com/elastic/integrations/issues/17112 ([buildkite](https://buildkite.com/elastic/integrations/builds/37092))
- https://github.com/elastic/integrations/issues/17329 ([buildkite](https://buildkite.com/elastic/integrations/builds/37760))
Initial investigation report:
# Fleet Server API Key Race Condition - Investigation Report
**Date:** January 30, 2026
**Build:** integrations_build_37092
**Component:** Zeek Integration Tests
**Status:** Root Cause Identified
---
## Executive Summary
Integration tests for the Zeek package are failing intermittently with a "context deadline exceeded" error when attempting to assign policies to Elastic Agents. Investigation reveals a **race condition in Fleet Server's API key handling** where newly created API keys are not immediately readable from Elasticsearch, causing agent checkins to hang until the 10-minute timeout expires.
---
## Error Message
```
could not assign policy to agent: error occurred while waiting for the policy to be assigned
to all agents: can't get the agent: could not list agents: could not send request to Kibana API:
Get "https://127.0.0.1:5601/api/fleet/agents/535bb755-c122-473b-86a7-b40a03f7be08":
context deadline exceeded
```
---
## Timeline of Failure
### Fleet Server Log Timeline (Agent 06f15b3d-8115-466a-8107-59c159b1321d)
| Time | Event |
|------|-------|
| 04:58:07.768Z | Agent successfully enrolled |
| 04:58:10.394Z | Fleet Server begins generating output API key |
| 04:58:10.435Z | Fleet Server updates agent record with output key |
| 04:58:11.163Z | **WARN**: "Failed to read API Key roles" - `404 Not Found: api key not found` |
| 05:08:23.468Z | **ERROR**: Request times out after exactly 600 seconds (10 minutes) |
| 05:08:23.468Z | HTTP status 499 (client closed request) |
### Agent Container Log Timeline (Agent 06f15b3d-8115-466a-8107-59c159b1321d)
| Time | Event |
|------|-------|
| 04:58:07.174Z | Agent starts enrollment to Fleet Server |
| 04:58:08.187Z | Agent enrolled successfully |
| 04:58:23.467Z | Agent sends checkin request (reqID: 01KG41VSVBQ66ZHXC8SFCH6WBX) |
| 05:03:22.504Z | No activity - request still pending (5 min elapsed) |
| 05:08:22.520Z | No activity - request still pending (10 min elapsed) |
| 05:08:23.468Z | **ERROR**: "Client.Timeout exceeded while awaiting headers" |
| 05:08:23.469Z | **WARN**: "Possible transient error during checkin" - `request_duration_ns: 600001625561` |
---
## Root Cause Analysis
### Primary Issue: API Key Read-After-Write Race Condition
The Fleet Server creates an API key in Elasticsearch but immediately fails to read it back:
```json
{
"log.level": "warn",
"@timestamp": "2026-01-29T04:58:11.163Z",
"message": "Failed to read API Key roles",
"error.message": "[404 Not Found] {\"api_keys\":[]}: api key not found",
"fleet.apikey.id": "Q7MdCJwBKBjwQVn3tDlb"
}
```
This occurs because:
1. **Elasticsearch eventual consistency**: The API key is created but the index hasn't refreshed yet
2. **No retry mechanism**: Fleet Server doesn't retry the API key read after the initial 404
3. **Request blocks indefinitely**: The agent checkin hangs waiting for policy processing to complete
4. **10-minute timeout**: The checkin context deadline expires, failing the entire operation
### Evidence of 10-Minute Timeout
**Fleet Server side:**
```json
{
"message": "HTTP request error",
"error.message": "processPolicy: failed to prepare output \"default\": failed to prepare elasticsearch output \"default\": context canceled",
"http.response.status_code": 499,
"event.duration": 600000490920
}
```
**Agent side:**
```json
{
"message": "Possible transient error during checkin with fleet-server, retrying",
"error": {
"message": "Post \"https://fleet-server:8220/api/fleet/agents/06f15b3d-8115-466a-8107-59c159b1321d/checkin?\": net/http: request canceled (Client.Timeout exceeded while awaiting headers)"
},
"request_duration_ns": 600001625561,
"failed_checkins": 1
}
```
Both logs show the request duration as exactly **600 seconds (10 minutes)**, which is the default Fleet Server checkin timeout configured in `Server.Timeouts.Write: 600000000000` (600 seconds in nanoseconds).
### Contributing Factors
1. **High concurrent load**: Multiple parallel tests create many agents/API keys simultaneously
2. **Elasticsearch indexing pressure**: High write load can delay index refresh operations
3. **Lack of defensive coding**: Fleet Server assumes API keys are immediately readable after creation
---
## Corroborating Evidence
### Agent Container Logs Show Request Hung
The agent container logs clearly show the checkin request was initiated but received no response for 10 minutes:
```
04:58:23.467Z - Request method: POST, path: /api/fleet/agents/.../checkin
[... 10 minutes of silence ...]
05:08:23.468Z - requester 0/1 to host https://fleet-server:8220/ errored
```
The gap in logs between 04:58:23 and 05:08:23 (with only periodic state saves at 5-minute intervals) proves the agent was blocked waiting for Fleet Server to respond.
### Fleet Server Configuration Shows 10-Minute Write Timeout
From the Fleet Server initialization logs:
```json
{
"Server": {
"Timeouts": {
"Write": 600000000000
}
}
}
```
This 600-second (10-minute) write timeout matches the observed request duration exactly.
---
## Impact
- **Test flakiness**: Zeek integration tests fail intermittently
- **CI/CD reliability**: Build failures require manual re-runs
- **Resource waste**: Failed tests still consume 10+ minutes of CI time waiting for timeouts
---
## Affected Components
| Component | Version | Role |
|-----------|---------|------|
| Fleet Server | 8.17.0 | API key management, policy distribution |
| Elasticsearch | 8.17.0 | API key storage, index refresh timing |
| Elastic Agent | 8.17.0 | Victim of the timeout (not the cause) |
| elastic-package | latest | Test orchestration |
---
## Recommendations
### Short-term Mitigations
1. **Reduce test parallelism**: Running fewer concurrent agent tests may reduce Elasticsearch indexing pressure
2. **Increase Elasticsearch refresh interval awareness**: Consider adding explicit refresh calls after API key creation in test setup
3. **Add retry logic in test framework**: The `elastic-package` tool could retry failed policy assignments
### Long-term Fixes (Fleet Server)
1. **Implement retry with backoff**: Fleet Server should retry API key reads with exponential backoff when receiving 404 responses for recently-created keys
2. **Add explicit index refresh**: After creating an API key, issue a refresh request to the `.security*` index before attempting to read
3. **Improve error messaging**: Surface the underlying "API key not found" error rather than just "context canceled"
4. **Add circuit breaker**: Fail fast with a clear error message if API key reads fail multiple times
### Elasticsearch Tuning (Test Environment)
1. **Reduce refresh interval**: For `.fleet-*` and `.security-*` indices during testing:
```json
PUT /.security*/_settings
{
"index.refresh_interval": "1s"
}
```
2. **Monitor indexing pressure**: Add metrics for index refresh latency in CI environments
---
## Related Issues
This appears to be a manifestation of a known class of issues with Fleet Server and Elasticsearch eventual consistency. Similar issues have been reported when:
- Multiple agents enroll simultaneously
- High-frequency policy updates occur
- Elasticsearch is under heavy load
---
## Appendix A: Key Log Excerpts
### Build Log - Agent Stuck in Updating
```
2025/12/09 01:55:18 DEBUG Wait until the policy (ID: d10d2a33-7517-40f4-b67b-a4cfe82398f2, revision: 2)
is assigned to the agent (ID: 535bb755-c122-473b-86a7-b40a03f7be08)...
2025/12/09 01:55:18 DEBUG Agent 535bb755-c122-473b-86a7-b40a03f7be08 (Host: elastic-agent-31732):
Policy ID d10d2a33-7517-40f4-b67b-a4cfe82398f2 LogLevel: info Status: updating
[... agent remains in "updating" status for 5 minutes ...]
2025/12/09 02:00:22 DEBUG Agent 535bb755-c122-473b-86a7-b40a03f7be08 (Host: elastic-agent-31732):
Policy ID d10d2a33-7517-40f4-b67b-a4cfe82398f2 LogLevel: debug Status: offline
```
### Fleet Server Log - API Key 404
```json
{
"log.level": "warn",
"@timestamp": "2026-01-29T04:58:11.163Z",
"message": "Failed to read API Key roles",
"fleet.agent.id": "06f15b3d-8115-466a-8107-59c159b1321d",
"fleet.apikey.id": "Q7MdCJwBKBjwQVn3tDlb",
"error.message": "[404 Not Found] {\"api_keys\":[]}: api key not found"
}
```
### Fleet Server Log - 10-Minute Timeout
```json
{
"log.level": "error",
"@timestamp": "2026-01-29T05:08:23.468Z",
"message": "fail generate output key",
"fleet.agent.id": "06f15b3d-8115-466a-8107-59c159b1321d",
"error.message": "context canceled",
"event.duration": 600000490920
}
```
### Agent Container Log - Checkin Timeout
```json
{
"log.level": "warn",
"@timestamp": "2026-01-29T05:08:23.469Z",
"message": "Possible transient error during checkin with fleet-server, retrying",
"error": {
"message": "Post \"https://fleet-server:8220/api/fleet/agents/06f15b3d-8115-466a-8107-59c159b1321d/checkin?\": net/http: request canceled (Client.Timeout exceeded while awaiting headers)"
},
"request_duration_ns": 600001625561,
"failed_checkins": 1,
"retry_after_ns": 82620471472
}
```
---
## Appendix B: Files Analyzed
| File | Description |
|------|-------------|
| `integrations_build_37092_check-integrations-zeek.log` | Build log showing test failure |
| `fleet-logs/fleet-server.log` | Fleet Server logs showing API key 404 and timeout |
| `fleet-logs/elastic-agent-20260129.ndjson` | Fleet Server agent bootstrap logs |
| `fleet-logs/elastic-agent-20260129-1.ndjson` | Fleet Server agent runtime logs |
| `container-logs/elastic-agent-1769663303931347883.log` | Agent container logs showing checkin timeout |
---
## Conclusion
The root cause of the Zeek integration test failures is a **race condition in Fleet Server** where API keys created in Elasticsearch are not immediately readable due to index refresh timing. This causes agent checkin requests to block until the 10-minute timeout expires, resulting in the "context deadline exceeded" error.
The issue is exacerbated by high concurrent load during parallel test execution but represents a bug in Fleet Server's error handling that should be addressed with proper retry logic.
**Key Evidence:**
1. Fleet Server logs show "Failed to read API Key roles" with a 404 error immediately after key creation
2. Both Fleet Server and Agent logs show exactly 600-second request duration
3. Agent container logs confirm the checkin request hung with no response for 10 minutes
4. The configured `Write` timeout of 600 seconds matches the observed failure duration exactly
Contributor guide
Assessment
This issue has not been assessed yet.