hashicorp / hashicorp/consul

Cache is sometimes returning very old values for a very long time

Open
#8,980 8 comments 0 reactions 0 assignees View on GitHub
theme/agent-cache
Dominant language
Go
Stars
30.1k
Forks
4.6k
Avg merge
2d 6h
Merged PRs (30d)
43

Description

#### Overview of the Issue

We are using a lot of cached queries for our agents.

On some machines, on Windows (only seen on Windows for now), we sometimes have agents that are never updating their cache. We see this error on a pool of identically configured machines (pool for 200+ machines), it happens randomly on some of those machines.

In such cases, the machine can have stuck results for days.

Requests are doing the following way:

`http://localhost:8500/v1/health/service/?cached&index=`

With header:
`Cache-Control: max-age=60`

We also have those configurations for all of our agents:
```
"cache": {
"entry_fetch_rate": 0.1,
"entry_fetch_max_burst": 4
},
"discovery_max_stale": "5m"
```

It happens regularily, but we did not find any way to reproduce it for now, but the cache is completely staled.
The X-Consul-Index is stuck is in the past (while *all* servers have the new value).

A call with stale on the agents give the following value:

```
http://localhost:8500/v1/health/service/?stale
HTTP/1.1 200 OK
Content-Type: application/json
Vary: Accept-Encoding
X-Consul-Effective-Consistency: stale
X-Consul-Index: 5306733927
X-Consul-Knownleader: true
X-Consul-Lastcontact: 55
Date: Mon, 19 Oct 2020 10:51:40 GMT
Transfer-Encoding: chunked
```

While with cached, it gives the following value:
```
HTTP/1.1 200 OK
Age: 0
Content-Type: application/json
Vary: Accept-Encoding
X-Cache: HIT
X-Consul-Effective-Consistency: leader
X-Consul-Index: 5285318269
X-Consul-Knownleader: true
X-Consul-Lastcontact: 2
Date: Mon, 19 Oct 2020 11:11:07 GMT
Transfer-Encoding: chunked
```

Machine will keep this index forever (5285318269) until the agent is being restarted.

The difference between X-Consul-Index is huge. We had thise error on several different services, happens on ~ 1/200 machines (for now, only seen on Windows agents running 1.8.4, but error might have been older).

We had this on several machines, several different services, no specific relation between those machines (boot-time...)

Metrics of the agent containing cache are:
```
# HELP consul_acl_token_cache_hit consul_acl_token_cache_hit
# TYPE consul_acl_token_cache_hit counter
consul_acl_token_cache_hit 156825
# HELP consul_acl_token_cache_miss consul_acl_token_cache_miss
# TYPE consul_acl_token_cache_miss counter
consul_acl_token_cache_miss 8808
# HELP consul_consul_cache_entries_count consul_consul_cache_entries_count
# TYPE consul_consul_cache_entries_count gauge
consul_consul_cache_entries_count 58
# HELP consul_consul_cache_evict_expired consul_consul_cache_evict_expired
# TYPE consul_consul_cache_evict_expired counter
consul_consul_cache_evict_expired 46
# HELP consul_consul_cache_fetch_error consul_consul_cache_fetch_error
# TYPE consul_consul_cache_fetch_error counter
consul_consul_cache_fetch_error 11
# HELP consul_consul_cache_fetch_success consul_consul_cache_fetch_success
# TYPE consul_consul_cache_fetch_success counter
consul_consul_cache_fetch_success 18663
# HELP consul_consul_cache_health_services_fetch_error consul_consul_cache_health_services_fetch_error
# TYPE consul_consul_cache_health_services_fetch_error counter
consul_consul_cache_health_services_fetch_error 11
# HELP consul_consul_cache_health_services_fetch_success consul_consul_cache_health_services_fetch_success
# TYPE consul_consul_cache_health_services_fetch_success counter
consul_consul_cache_health_services_fetch_success 18663
# HELP consul_consul_cache_health_services_hit consul_consul_cache_health_services_hit
# TYPE consul_consul_cache_health_services_hit counter
consul_consul_cache_health_services_hit 254
# HELP consul_consul_cache_health_services_miss_block consul_consul_cache_health_services_miss_block
# TYPE consul_consul_cache_health_services_miss_block counter
consul_consul_cache_health_services_miss_block 27115
# HELP go_memstats_mcache_inuse_bytes Number of bytes in use by mcache structures.
# TYPE go_memstats_mcache_inuse_bytes gauge
go_memstats_mcache_inuse_bytes 54528
# HELP go_memstats_mcache_sys_bytes Number of bytes used for mcache structures obtained from system.
# TYPE go_memstats_mcache_sys_bytes gauge
go_memstats_mcache_sys_bytes 65536
```

We are mostly using /v1/health/service/ for cached entries, there are a few errors, but not that much, we continue investigating this issue, I'll post updates there, but I really suspect a big cache bug somewhere

Contributor guide

Open the contributing guide

Assessment

This issue has not been assessed yet.

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.