hashicorp / hashicorp/consul

consul context deadline exceeded

Open
#9,173 1 comment 0 reactions 0 assignees View on GitHub
theme/health-checks theme/internals
Dominant language
Go
Stars
30.1k
Forks
4.6k
Avg merge
1d 18h
Merged PRs (30d)
39

Description

#### Overview of the Issue

Consul master node gets warning messages for each server nodes:
[WARN] consul: error getting server health from : context deadline exceeded
We use consul for service discovery:register, deregister, and get service from health endpoint. Also we use it like key value, but very rear.
#### Reproduction Steps

Steps to reproduce this issue, eg:

1. Create a cluster with n client nodes n and n server nodes
1. Run `curl ...`
1. View error

### Consul info for both Client and Server

Client info

consul info
agent:
check_monitors = 0
check_ttls = 0
checks = 99
services = 104
build:
prerelease =
revision = 1e03567d
version = 1.8.5
consul:
acl = disabled
known_servers = 5
server = false
runtime:
arch = amd64
cpu_count = 10
goroutines = 243
max_procs = 3
os = linux
version = go1.14.9
serf_lan:
coordinate_resets = 0
encrypted = true
event_queue = 0
event_time = 16656
failed = 0
health_score = 0
intent_queue = 0
left = 0
member_time = 18571
members = 212
query_queue = 0
query_time = 1

Server info

{
"Config": {
"Datacenter": "XXX",
"NodeName": "consul3",
"NodeID": "47e23f2e-3f2d-ffd7-fd85-66243e2bd257",
"Revision": "1e03567d3",
"Server": true,
"Version": "1.8.5"
},
"DebugConfig": {
"ACLAgentMasterToken": "hidden",
"ACLAgentToken": "hidden",
"ACLDatacenter": "XXX",
"ACLDefaultPolicy": "allow",
"ACLDisabledTTL": "2m0s",
"ACLDownPolicy": "extend-cache",
"ACLEnableKeyListPolicy": false,
"ACLEnableTokenPersistence": false,
"ACLMasterToken": "hidden",
"ACLPolicyTTL": "30s",
"ACLReplicationToken": "hidden",
"ACLRoleTTL": "0s",
"ACLToken": "hidden",
"ACLTokenReplication": false,
"ACLTokenTTL": "30s",
"ACLsEnabled": false,
"AEInterval": "1m0s",
"AdvertiseAddrLAN": "X.X.X.18",
"AdvertiseAddrWAN": "X.X.X.18",
"AllowWriteHTTPFrom": [],
"AutoConfig": {
"Authorizer": {
"AllowReuse": false,
"AuthMethod": {
"ACLAuthMethodEnterpriseFields": {},
"Config": {
"BoundAudiences": null,
"BoundIssuer": "",
"ClaimMappings": null,
"ClockSkewLeeway": 0,
"ExpirationLeeway": 0,
"JWKSCACert": "",
"JWKSURL": "",
"JWTSupportedAlgs": null,
"JWTValidationPubKeys": null,
"ListClaimMappings": null,
"NotBeforeLeeway": 0,
"OIDCDiscoveryCACert": "",
"OIDCDiscoveryURL": ""
},
"Description": "",
"DisplayName": "",
"EnterpriseMeta": {},
"MaxTokenTTL": "0s",
"Name": "Auto Config Authorizer",
"RaftIndex": {
"CreateIndex": 0,
"ModifyIndex": 0
},
"TokenLocality": "",
"Type": "jwt"
},
"ClaimAssertions": [],
"Enabled": false
},
"DNSSANs": [],
"Enabled": false,
"IPSANs": [],
"IntroToken": "hidden",
"IntroTokenFile": "",
"ServerAddresses": []
},
"AutoEncryptAllowTLS": false,
"AutoEncryptDNSSAN": [],
"AutoEncryptIPSAN": [],
"AutoEncryptTLS": false,
"AutopilotCleanupDeadServers": true,
"AutopilotDisableUpgradeMigration": false,
"AutopilotLastContactThreshold": "200ms",
"AutopilotMaxTrailingLogs": 250,
"AutopilotMinQuorum": 0,
"AutopilotRedundancyZoneTag": "",
"AutopilotServerStabilizationTime": "10s",
"AutopilotUpgradeVersionTag": "",
"BindAddr": "0.0.0.0",
"Bootstrap": false,
"BootstrapExpect": 3,
"CAFile": "",
"CAPath": "",
"Cache": {
"EntryFetchMaxBurst": 2,
"EntryFetchRate": 1.7976931348623157e+308
},
"CertFile": "",
"CheckDeregisterIntervalMin": "1m0s",
"CheckOutputMaxSize": 4096,
"CheckReapInterval": "30s",
"CheckUpdateInterval": "5m0s",
"Checks": [],
"ClientAddrs": ["0.0.0.0"],
"ConfigEntryBootstrap": [],
"ConnectCAConfig": {},
"ConnectCAProvider": "",
"ConnectEnabled": false,
"ConnectMeshGatewayWANFederationEnabled": false,
"ConnectSidecarMaxPort": -1,
"ConnectSidecarMinPort": -1,
"ConnectTestCALeafRootChangeSpread": "0s",
"ConsulCoordinateUpdateBatchSize": 128,
"ConsulCoordinateUpdateMaxBatches": 5,
"ConsulCoordinateUpdatePeriod": "5s",
"ConsulRaftElectionTimeout": "5s",
"ConsulRaftHeartbeatTimeout": "5s",
"ConsulRaftLeaderLeaseTimeout": "2.5s",
"ConsulServerHealthInterval": "2s",
"DNSARecordLimit": 0,
"DNSAddrs": [],
"DNSAllowStale": true,
"DNSAltDomain": "",
"DNSCacheMaxAge": "0s",
"DNSDisableCompression": false,
"DNSDomain": "consul.",
"DNSEnableTruncate": false,
"DNSMaxStale": "87600h0m0s",
"DNSNodeMetaTXT": true,
"DNSNodeTTL": "0s",
"DNSOnlyPassing": false,
"DNSPort": -1,
"DNSRecursorTimeout": "2s",
"DNSRecursors": [],
"DNSSOA": {
"Expire": 86400,
"Minttl": 0,
"Refresh": 3600,
"Retry": 600
},
"DNSServiceTTL": {},
"DNSUDPAnswerLimit": 3,
"DNSUseCache": false,
"DataDir": "/var/lib/consul",
"Datacenter": "XXX",
"DefaultQueryTime": "5m0s",
"DevMode": false,
"DisableAnonymousSignature": false,
"DisableCoordinates": false,
"DisableHTTPUnprintableCharFilter": false,
"DisableHostNodeID": true,
"DisableKeyringFile": false,
"DisableRemoteExec": true,
"DisableUpdateCheck": false,
"DiscardCheckOutput": true,
"DiscoveryMaxStale": "0s",
"EnableAgentTLSForChecks": false,
"EnableCentralServiceConfig": false,
"EnableDebug": false,
"EnableLocalScriptChecks": false,
"EnableRemoteScriptChecks": false,
"EnableUI": true,
"EncryptKey": "hidden",
"EncryptVerifyIncoming": true,
"EncryptVerifyOutgoing": true,
"EnterpriseRuntimeConfig": {},
"ExposeMaxPort": 21755,
"ExposeMinPort": 21500,
"GRPCAddrs": [],
"GRPCPort": -1,
"GossipLANGossipInterval": "200ms",
"GossipLANGossipNodes": 3,
"GossipLANProbeInterval": "1s",
"GossipLANProbeTimeout": "500ms",
"GossipLANRetransmitMult": 4,
"GossipLANSuspicionMult": 4,
"GossipWANGossipInterval": "500ms",
"GossipWANGossipNodes": 3,
"GossipWANProbeInterval": "5s",
"GossipWANProbeTimeout": "3s",
"GossipWANRetransmitMult": 4,
"GossipWANSuspicionMult": 6,
"HTTPAddrs": ["tcp://0.0.0.0:13100"],
"HTTPBlockEndpoints": [],
"HTTPMaxConnsPerClient": 200,
"HTTPPort": 13100,
"HTTPResponseHeaders": {},
"HTTPSAddrs": [],
"HTTPSHandshakeTimeout": "5s",
"HTTPSPort": -1,
"HTTPUseCache": true,
"KVMaxValueSize": 524288,
"KeyFile": "hidden",
"LeaveDrainTime": "5s",
"LeaveOnTerm": true,
"Logging": {
"EnableSyslog": false,
"LogFilePath": "/var/log/consul/consul.log",
"LogJSON": false,
"LogLevel": "INFO",
"LogRotateBytes": 0,
"LogRotateDuration": "24h0m0s",
"LogRotateMaxFiles": 4,
"Name": "",
"SyslogFacility": "LOCAL0"
},
"MaxQueryTime": "10m0s",
"NodeID": "47e23f2e-3f2d-ffd7-fd85-66243e2bd257",
"NodeMeta": {},
"NodeName": "consul3",
"NonVotingServer": false,
"PidFile": "",
"PrimaryDatacenter": "XXX",
"PrimaryGateways": [],
"PrimaryGatewaysInterval": "30s",
"RPCAdvertiseAddr": "tcp://X.X.X.18:8510",
"RPCBindAddr": "tcp://0.0.0.0:8510",
"RPCHandshakeTimeout": "5s",
"RPCHoldTimeout": "7s",
"RPCMaxBurst": 1000,
"RPCMaxConnsPerClient": 100,
"RPCProtocol": 2,
"RPCRateLimit": -1,
"RaftProtocol": 0,
"RaftSnapshotInterval": "0s",
"RaftSnapshotThreshold": 0,
"RaftTrailingLogs": 0,
"ReconnectTimeoutLAN": "0s",
"ReconnectTimeoutWAN": "0s",
"RejoinAfterLeave": false,
"RetryJoinIntervalLAN": "30s",
"RetryJoinIntervalWAN": "30s",
"RetryJoinLAN": ["X.X.X.16", "X.X.X.17", "X.X.X.18", "X.X.X.19", "X.X.X.20"],
"RetryJoinMaxAttemptsLAN": 0,
"RetryJoinMaxAttemptsWAN": 0,
"RetryJoinWAN": ["X.X.X.16", "X.X.X.17", "X.X.X.18", "X.X.X.19", "X.X.X.20"],
"Revision": "1e03567d3",
"SegmentLimit": 64,
"SegmentName": "",
"SegmentNameLimit": 64,
"Segments": [],
"SerfAdvertiseAddrLAN": "tcp://X.X.X.18:8502",
"SerfAdvertiseAddrWAN": "tcp://X.X.X.18:8503",
"SerfAllowedCIDRsLAN": [],
"SerfAllowedCIDRsWAN": [],
"SerfBindAddrLAN": "tcp://0.0.0.0:8502",
"SerfBindAddrWAN": "tcp://0.0.0.0:8503",
"SerfPortLAN": 8502,
"SerfPortWAN": 8503,
"ServerMode": true,
"ServerName": "",
"ServerPort": 8510,
"Services": [],
"SessionTTLMin": "0s",
"SkipLeaveOnInt": true,
"StartJoinAddrsLAN": [],
"StartJoinAddrsWAN": [],
"SyncCoordinateIntervalMin": "15s",
"SyncCoordinateRateTarget": 64,
"TLSCipherSuites": [],
"TLSMinVersion": "tls12",
"TLSPreferServerCipherSuites": false,
"TaggedAddresses": {
"lan": "X.X.X.18",
"lan_ipv4": "X.X.X.18",
"wan": "X.X.X.18",
"wan_ipv4": "X.X.X.18"
},
"Telemetry": {
"AllowedPrefixes": [],
"BlockedPrefixes": [],
"CirconusAPIApp": "",
"CirconusAPIToken": "hidden",
"CirconusAPIURL": "",
"CirconusBrokerID": "",
"CirconusBrokerSelectTag": "",
"CirconusCheckDisplayName": "",
"CirconusCheckForceMetricActivation": "",
"CirconusCheckID": "",
"CirconusCheckInstanceID": "",
"CirconusCheckSearchTag": "",
"CirconusCheckTags": "",
"CirconusSubmissionInterval": "",
"CirconusSubmissionURL": "",
"Disable": false,
"DisableHostname": true,
"DogstatsdAddr": "",
"DogstatsdTags": [],
"FilterDefault": true,
"MetricsPrefix": "consul",
"PrometheusRetentionTime": "1h0m0s",
"StatsdAddr": "",
"StatsiteAddr": ""
},
"TranslateWANAddrs": false,
"TxnMaxReqLen": 524288,
"UIContentPath": "/ui/",
"UIDir": "",
"UnixSocketGroup": "",
"UnixSocketMode": "",
"UnixSocketUser": "",
"VerifyIncoming": false,
"VerifyIncomingHTTPS": false,
"VerifyIncomingRPC": false,
"VerifyOutgoing": false,
"VerifyServerHostname": false,
"Version": "1.8.5",
"VersionPrerelease": "",
"Watches": []
},
"Coord": {
"Vec": [0.007492366764438748, 0.007329508749702382, -0.00700746853108616, -0.006964352953281851, 0.002729253749542122, 0.004451782946644716, 0.003654987364322647, 0.0074797407922522225],
"Error": 1.5,
"Adjustment": -0.000043951071407920585,
"Height": 0.004153066692049336
},
"Member": {
"Name": "consul3",
"Addr": "X.X.X.18",
"Port": 8502,
"Tags": {
"acls": "0",
"build": "1.8.5:1e03567d",
"dc": "XXX",
"expect": "3",
"ft_fs": "1",
"id": "47e23f2e-3f2d-ffd7-fd85-66243e2bd257",
"port": "8510",
"raft_vsn": "3",
"role": "consul",
"segment": "",
"vsn": "2",
"vsn_max": "3",
"vsn_min": "2",
"wan_join_port": "8503"
},
"Status": 1,
"ProtocolMin": 1,
"ProtocolMax": 5,
"ProtocolCur": 2,
"DelegateMin": 2,
"DelegateMax": 5,
"DelegateCur": 4
},
"Stats": {
"agent": {
"check_monitors": "0",
"check_ttls": "0",
"checks": "0",
"services": "0"
},
"build": {
"prerelease": "",
"revision": "1e03567d",
"version": "1.8.5"
},
"consul": {
"acl": "disabled",
"bootstrap": "false",
"known_datacenters": "1",
"leader": "true",
"leader_addr": "X.X.X.18:8510",
"server": "true"
},
"raft": {
"applied_index": "7551302",
"commit_index": "7551302",
"fsm_pending": "0",
"last_contact": "0",
"last_log_index": "7551302",
"last_log_term": "36404",
"last_snapshot_index": "7539515",
"last_snapshot_term": "36404",
"latest_configuration": "[{Suffrage:Voter ID:1729c6c8-7958-a0d3-3369-9f1b62a6fa20 Address:X.X.X.20:8510} {Suffrage:Voter ID:17e89bb0-fac5-d9b6-fc64-0c87acbe48d7 Address:X.X.X.19:8510} {Suffrage:Voter ID:533228e6-1e03-86f7-58d3-7e520a7b9a40 Address:X.X.X.17:8510} {Suffrage:Voter ID:95604b2a-0382-d35a-a4bb-92a97ca82795 Address:X.X.X.16:8510} {Suffrage:Voter ID:47e23f2e-3f2d-ffd7-fd85-66243e2bd257 Address:X.X.X.18:8510}]",
"latest_configuration_index": "0",
"num_peers": "4",
"protocol_version": "3",
"protocol_version_max": "3",
"protocol_version_min": "0",
"snapshot_version_max": "1",
"snapshot_version_min": "0",
"state": "Leader",
"term": "36404"
},
"runtime": {
"arch": "amd64",
"cpu_count": "20",
"goroutines": "13224",
"max_procs": "20",
"os": "linux",
"version": "go1.14.9"
},
"serf_lan": {
"coordinate_resets": "0",
"encrypted": "true",
"event_queue": "0",
"event_time": "16656",
"failed": "2",
"health_score": "0",
"intent_queue": "0",
"left": "0",
"member_time": "18570",
"members": "212",
"query_queue": "0",
"query_time": "1"
},
"serf_wan": {
"coordinate_resets": "0",
"encrypted": "true",
"event_queue": "0",
"event_time": "1",
"failed": "0",
"health_score": "0",
"intent_queue": "0",
"left": "0",
"member_time": "3762",
"members": "5",
"query_queue": "0",
"query_time": "1"
}
},
"Meta": {
"consul-network-segment": ""
}
}

### Operating system and Environment details
Ubuntu 18.04.5 LTS

### Log Fragments

```
agent: error getting server health from server: server=consul3 error="context deadline exceeded"
agent: error getting server health from server: server=consul1 error="context deadline exceeded"
agent: error getting server health from server: server=consul2 error="context deadline exceeded"
agent: error getting server health from server: server=consul5 error="context deadline exceeded"
agent: error getting server health from server: server=consul4 error="context deadline exceeded"
agent: error getting server health from server: server=consul5 error="context deadline exceeded"
```

Is it common level of requests for such cluster?
Is there some way to understand what kind of requests we have? I mean some statistics by type or host

![image](https://user-images.githubusercontent.com/8426800/98949424-c03b2600-2508-11eb-9145-d4289e169fe3.png)
![image](https://user-images.githubusercontent.com/8426800/98949528-e791f300-2508-11eb-94ae-802e32ac58b6.png)

Contributor guide

Open the contributing guide

Research direction

The issue names no source files or tests. Start by reproducing the warning in the reported Consul 1.8.5 cluster with the stated client/server topology, then trace the server-health check that emits the message. Done means identifying the cause of the deadline and documenting or validating a concrete fix.

Written by the indexing model from the issue text.

Assessment

Tech stack
go
Domain
distributed-systems, networking
Issue type
Bug
Difficulty
4/5
Estimated time
3-5 days
Activity status
Stale
Clarity
Needs clarification
Newbie friendliness
25/100

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.