hashicorp / hashicorp/consul

panic: runtime error: invalid memory address or nil pointer dereference

Open
#16,475 5 comments 0 reactions 0 assignees View on GitHub
Dominant language
Go
Stars
30.1k
Forks
4.6k
Avg merge
1d 18h
Merged PRs (30d)
39

Description

I start the consul servcer on 3 node for a long time,and i register the same service to the 3 consul server and import a kv json file into the consul, then I close the leader node and 1 follower, and I just restart the follower , I find it panic, the log output :

==> Starting Consul agent...
Version: '1.15.0'
Build Date: '2023-02-24 01:39:35 +0000 UTC'
Node ID: '3e21921f-911f-d8f1-f4fc-60f684adf1bd'
Node name: 'R01-P02RD-FGW-008-NM'
Datacenter: 'dc1' (Segment: '')
Server: true (Bootstrap: false)
Client Addr: [0.0.0.0] (HTTP: 8500, HTTPS: 8443, gRPC: 8502, gRPC-TLS: 1, DNS: 8600)
Cluster Addr: 192.168.100.42 (LAN: 8301, WAN: 8302)
Gossip Encryption: true
Auto-Encrypt-TLS: true
HTTPS TLS: Verify Incoming: false, Verify Outgoing: true, Min Version: TLSv1_2
gRPC TLS: Verify Incoming: false, Min Version: TLSv1_2
Internal RPC TLS: Verify Incoming: true, Verify Outgoing: true (Verify Hostname: true), Min Version: TLSv1_2

==> Log data will now stream in as it occurs:

2023-03-01T09:43:06.941+0800 [WARN] agent: skipping file /home/store/zz/consul/config/consul-agent-ca-key.pem, extension must be .hcl or .json, or config format must be set
2023-03-01T09:43:06.941+0800 [WARN] agent: skipping file /home/store/zz/consul/config/consul-agent-ca.pem, extension must be .hcl or .json, or config format must be set
2023-03-01T09:43:06.941+0800 [WARN] agent: skipping file /home/store/zz/consul/config/dc1-server-consul-2-key.pem, extension must be .hcl or .json, or config format must be set
2023-03-01T09:43:06.941+0800 [WARN] agent: skipping file /home/store/zz/consul/config/dc1-server-consul-2.pem, extension must be .hcl or .json, or config format must be set
2023-03-01T09:43:06.943+0800 [DEBUG] agent.grpc.balancer: switching server: target=consul://dc1.3e21921f-911f-d8f1-f4fc-60f684adf1bd/server.dc1 from= to=
2023-03-01T09:43:06.964+0800 [WARN] agent.auto_config: skipping file /home/store/zz/consul/config/consul-agent-ca-key.pem, extension must be .hcl or .json, or config format must be set
2023-03-01T09:43:06.964+0800 [WARN] agent.auto_config: skipping file /home/store/zz/consul/config/consul-agent-ca.pem, extension must be .hcl or .json, or config format must be set
2023-03-01T09:43:06.964+0800 [WARN] agent.auto_config: skipping file /home/store/zz/consul/config/dc1-server-consul-2-key.pem, extension must be .hcl or .json, or config format must be set
2023-03-01T09:43:06.964+0800 [WARN] agent.auto_config: skipping file /home/store/zz/consul/config/dc1-server-consul-2.pem, extension must be .hcl or .json, or config format must be set
2023-03-01T09:43:07.074+0800 [INFO] agent.server.raft: starting restore from snapshot: id=259-32768-1677565937880 last-index=32768 last-term=259 size-in-bytes=19072
2023-03-01T09:43:07.078+0800 [INFO] agent.server.raft: snapshot restore progress: id=259-32768-1677565937880 last-index=32768 last-term=259 size-in-bytes=19072 read-bytes=19072 percent-complete="100.00%"
2023-03-01T09:43:07.078+0800 [INFO] agent.server.raft: restored from snapshot: id=259-32768-1677565937880 last-index=32768 last-term=259 size-in-bytes=19072
2023-03-01T09:43:07.089+0800 [INFO] agent.server.raft: initial configuration: index=33622 servers="[{Suffrage:Voter ID:866bbd62-7fe3-94e6-86ea-2e62a6feca60 Address:192.168.100.41:8300} {Suffrage:Voter ID:3e21921f-911f-d8f1-f4fc-60f684ad
2023-03-01T09:43:07.089+0800 [INFO] agent.server.raft: entering follower state: follower="Node at 192.168.100.42:8300 [Follower]" leader-address= leader-id=
2023-03-01T09:43:07.090+0800 [INFO] agent.server.serf.wan: serf: EventMemberJoin: R01-P02RD-FGW-008-NM.dc1 192.168.100.42
2023-03-01T09:43:07.090+0800 [INFO] agent.server.serf.wan: serf: Attempting re-join to previously known node: R01-P02RD-FGW-007-NM.dc1: 192.168.100.41:8302
2023-03-01T09:43:07.091+0800 [DEBUG] agent.server.memberlist.wan: memberlist: Initiating push/pull sync with: R01-P02RD-FGW-007-NM.dc1 192.168.100.41:8302
2023-03-01T09:43:07.091+0800 [INFO] agent.server.serf.lan: serf: EventMemberJoin: R01-P02RD-FGW-008-NM 192.168.100.42
2023-03-01T09:43:07.091+0800 [INFO] agent.router: Initializing LAN area manager
2023-03-01T09:43:07.091+0800 [INFO] agent.server.serf.lan: serf: Attempting re-join to previously known node: R01-P02RD-FGW-007-NM: 192.168.100.41:8301
2023-03-01T09:43:07.092+0800 [DEBUG] agent.grpc.balancer: switching server: target=consul://dc1.3e21921f-911f-d8f1-f4fc-60f684adf1bd/server.dc1 from= to=dc1-192.168.100.42:8300
2023-03-01T09:43:07.092+0800 [DEBUG] agent.server.memberlist.lan: memberlist: Initiating push/pull sync with: R01-P02RD-FGW-007-NM 192.168.100.41:8301
2023-03-01T09:43:07.092+0800 [INFO] agent.server: Adding LAN server: server="R01-P02RD-FGW-008-NM (Addr: tcp/192.168.100.42:8300) (DC: dc1)"
2023-03-01T09:43:07.092+0800 [INFO] agent.server.autopilot: reconciliation now disabled
2023-03-01T09:43:07.092+0800 [INFO] agent.server: Handled event for server in area: event=member-join server=R01-P02RD-FGW-008-NM.dc1 area=wan
2023-03-01T09:43:07.092+0800 [INFO] agent.server.serf.wan: serf: EventMemberJoin: R01-P02RD-FGW-007-NM.dc1 192.168.100.41
2023-03-01T09:43:07.092+0800 [INFO] agent.server.serf.wan: serf: Re-joined to previously known node: R01-P02RD-FGW-007-NM.dc1: 192.168.100.41:8302
2023-03-01T09:43:07.092+0800 [INFO] agent.server: Handled event for server in area: event=member-join server=R01-P02RD-FGW-007-NM.dc1 area=wan
2023-03-01T09:43:07.093+0800 [INFO] agent.server.serf.lan: serf: EventMemberJoin: R01-P02RD-FGW-007-NM 192.168.100.41
2023-03-01T09:43:07.093+0800 [INFO] agent.server.serf.lan: serf: Re-joined to previously known node: R01-P02RD-FGW-007-NM: 192.168.100.41:8301
2023-03-01T09:43:07.093+0800 [INFO] agent.server: Adding LAN server: server="R01-P02RD-FGW-007-NM (Addr: tcp/192.168.100.41:8300) (DC: dc1)"
2023-03-01T09:43:07.097+0800 [DEBUG] agent.server.autopilot: autopilot is now running
2023-03-01T09:43:07.097+0800 [DEBUG] agent.server.autopilot: state update routine is now running
2023-03-01T09:43:07.097+0800 [INFO] agent.server.cert-manager: initialized server certificate management
2023-03-01T09:43:07.097+0800 [DEBUG] agent.hcp_manager: HCP manager starting
2023-03-01T09:43:07.098+0800 [DEBUG] agent: restored service definition from file: service=service22-id file=/home/store/zz/consul/data/services/44852e95ff1aac4938fd796862eca16dd8b20cbb785aeaad35a30b6eb44ba704
2023-03-01T09:43:07.098+0800 [DEBUG] agent: restored service definition from file: service=test-192.168.100.38-8866-JjHzWXRY file=/home/store/zz/consul/data/services/b07b34401a9cb162d8864ac72b68414b0adfc47a901c64e35406585a00afa6c0
2023-03-01T09:43:07.099+0800 [DEBUG] agent: restored health check from file: check=service22-check file=/home/store/zz/consul/data/checks/93276716fa2905531cdcd208d592a47a709051ba9eb6deaf170665d79917becd
2023-03-01T09:43:07.099+0800 [DEBUG] agent: restored health check from file: check=check-test-192.168.100.38-8866-JjHzWXRY file=/home/store/zz/consul/data/checks/b39b19109a7f11076abbdba5d2fcb5a78409ec8d3b4070a94a5b68c83cdb3648
2023-03-01T09:43:07.099+0800 [DEBUG] agent.dns: recursor enabled
2023-03-01T09:43:07.099+0800 [DEBUG] agent.dns: recursor enabled
2023-03-01T09:43:07.099+0800 [DEBUG] agent.dns: recursor enabled
2023-03-01T09:43:07.100+0800 [INFO] agent: Started DNS server: address=0.0.0.0:8600 network=udp
2023-03-01T09:43:07.100+0800 [INFO] agent: Started DNS server: address=0.0.0.0:8600 network=tcp
2023-03-01T09:43:07.101+0800 [INFO] agent: Starting server: address=[::]:8500 network=tcp protocol=http
2023-03-01T09:43:07.101+0800 [INFO] agent: Starting server: address=[::]:8443 network=tcp protocol=https
2023-03-01T09:43:07.101+0800 [INFO] agent: Started gRPC listeners: port_name=grpc address=[::]:8502 network=tcp
2023-03-01T09:43:07.101+0800 [INFO] agent: Started gRPC listeners: port_name=grpc_tls address=[::]:1 network=tcp
2023-03-01T09:43:07.101+0800 [INFO] agent: Retry join is supported for the following discovery methods: cluster=LAN discovery_methods="aliyun aws azure digitalocean gce hcp k8s linode mdns os packet scaleway softlayer tencentcloud trito
2023-03-01T09:43:07.101+0800 [INFO] agent: Joining cluster...: cluster=LAN
2023-03-01T09:43:07.101+0800 [INFO] agent: (LAN) joining: lan_addresses=["192.168.100.40", "192.168.100.41"]
2023-03-01T09:43:07.101+0800 [INFO] agent: started state syncer
2023-03-01T09:43:07.101+0800 [INFO] agent: Consul agent running!
2023-03-01T09:43:07.101+0800 [DEBUG] agent.server.memberlist.lan: memberlist: Failed to join 192.168.100.40:8301: dial tcp 192.168.100.40:8301: connect: connection refused
2023-03-01T09:43:07.102+0800 [DEBUG] agent.server.memberlist.lan: memberlist: Initiating push/pull sync with: 192.168.100.41:8301
2023-03-01T09:43:07.103+0800 [INFO] agent: (LAN) joined: number_of_nodes=1
2023-03-01T09:43:07.103+0800 [DEBUG] agent: systemd notify failed: error="No socket"
2023-03-01T09:43:07.103+0800 [INFO] agent: Join cluster completed. Synced with initial agents: cluster=LAN num_agents=1
2023-03-01T09:43:07.316+0800 [DEBUG] agent.server.serf.lan: serf: messageJoinType: R01-P02RD-FGW-008-NM
2023-03-01T09:43:07.516+0800 [DEBUG] agent.server.serf.lan: serf: messageJoinType: R01-P02RD-FGW-008-NM
2023-03-01T09:43:07.716+0800 [DEBUG] agent.server.serf.lan: serf: messageJoinType: R01-P02RD-FGW-008-NM
2023-03-01T09:43:07.916+0800 [DEBUG] agent.server.serf.lan: serf: messageJoinType: R01-P02RD-FGW-008-NM
2023-03-01T09:43:08.098+0800 [DEBUG] agent.server.cert-manager: CA config watch fired - updating auto TLS server name: name=server.dc1.peering.ac1c275b-df91-f852-07ef-9bf788760fcd.consul
2023-03-01T09:43:08.098+0800 [DEBUG] agent.server.cert-manager: server management token watch fired - resetting leaf cert watch
2023-03-01T09:43:12.100+0800 [WARN] agent: Check missed TTL, is now critical: check=check-test-192.168.100.38-8866-JjHzWXRY
2023-03-01T09:43:12.345+0800 [DEBUG] agent.server.raft: accepted connection: local-address=192.168.100.42:8300 remote-address=192.168.100.41:56297
2023-03-01T09:43:12.345+0800 [DEBUG] agent.server.raft: lost leadership because received a requestVote with a newer term
2023-03-01T09:43:12.418+0800 [WARN] agent.server.raft: failed to get previous log: previous-index=33649 last-index=33647 error="log not found"
2023-03-01T09:43:12.418+0800 [DEBUG] agent.hcp_manager: HCP triggering status update
2023-03-01T09:43:12.515+0800 [DEBUG] agent.server.serf.lan: serf: messageUserEventType: consul:new-leader
2023-03-01T09:43:12.515+0800 [INFO] agent.server: New leader elected: payload=R01-P02RD-FGW-007-NM
2023-03-01T09:43:12.547+0800 [DEBUG] agent.server.xds_capacity_controller: updating drain rate limit: rate_limit=1
2023-03-01T09:43:12.559+0800 [DEBUG] agent.server.raft: accepted connection: local-address=192.168.100.42:8300 remote-address=192.168.100.41:16221
2023-03-01T09:43:12.715+0800 [DEBUG] agent.server.serf.lan: serf: messageUserEventType: consul:new-leader
2023-03-01T09:43:12.915+0800 [DEBUG] agent.server.serf.lan: serf: messageUserEventType: consul:new-leader
2023-03-01T09:43:13.115+0800 [DEBUG] agent.server.serf.lan: serf: messageUserEventType: consul:new-leader
2023-03-01T09:43:13.588+0800 [DEBUG] agent.server.cert-manager: server management token watch fired - resetting leaf cert watch
2023-03-01T09:43:14.806+0800 [DEBUG] agent.server.cert-manager: got cache update event: correlationID=leaf error=
2023-03-01T09:43:14.806+0800 [DEBUG] agent.server.cert-manager: leaf certificate watch fired - updating auto TLS certificate: uri=spiffe://ac1c275b-df91-f852-07ef-9bf788760fcd.consul/agent/server/dc/dc1
2023-03-01T09:43:16.723+0800 [DEBUG] agent.server.memberlist.lan: memberlist: Stream connection from=192.168.100.41:37138
2023-03-01T09:43:17.278+0800 [DEBUG] agent.acl: dropping check from result due to ACLs: check=check-test-192.168.100.38-8866-JjHzWXRY
2023-03-01T09:43:17.278+0800 [DEBUG] agent.acl: dropping check from result due to ACLs: check=serfHealth
2023-03-01T09:43:17.278+0800 [DEBUG] agent.acl: dropping check from result due to ACLs: check=service22-check
2023-03-01T09:43:17.279+0800 [WARN] agent: Node info update blocked by ACLs: node=3e21921f-911f-d8f1-f4fc-60f684adf1bd accessorID="anonymous token"
2023-03-01T09:43:17.325+0800 [INFO] agent: Synced service: service=service22-id
2023-03-01T09:43:17.341+0800 [INFO] agent: Synced service: service=test-192.168.100.38-8866-JjHzWXRY
2023-03-01T09:43:17.341+0800 [DEBUG] agent: Check in sync: check=service22-check
2023-03-01T09:43:17.341+0800 [DEBUG] agent: Check in sync: check=check-test-192.168.100.38-8866-JjHzWXRY
2023-03-01T09:43:18.525+0800 [DEBUG] agent.acl: dropping check from result due to ACLs: check=check-test-192.168.100.38-8866-JjHzWXRY
2023-03-01T09:43:18.526+0800 [DEBUG] agent.acl: dropping check from result due to ACLs: check=serfHealth
2023-03-01T09:43:18.526+0800 [DEBUG] agent.acl: dropping check from result due to ACLs: check=service22-check
2023-03-01T09:43:18.526+0800 [WARN] agent: Node info update blocked by ACLs: node=3e21921f-911f-d8f1-f4fc-60f684adf1bd accessorID="anonymous token"
2023-03-01T09:43:18.549+0800 [INFO] agent: Synced service: service=service22-id
2023-03-01T09:43:18.565+0800 [INFO] agent: Synced service: service=test-192.168.100.38-8866-JjHzWXRY
2023-03-01T09:43:18.565+0800 [DEBUG] agent: Check in sync: check=service22-check
2023-03-01T09:43:18.565+0800 [DEBUG] agent: Check in sync: check=check-test-192.168.100.38-8866-JjHzWXRY
2023-03-01T09:43:18.565+0800 [DEBUG] agent: Node info in sync
2023-03-01T09:43:18.565+0800 [DEBUG] agent: Service in sync: service=service22-id
2023-03-01T09:43:18.565+0800 [DEBUG] agent: Service in sync: service=test-192.168.100.38-8866-JjHzWXRY
2023-03-01T09:43:18.565+0800 [DEBUG] agent: Check in sync: check=service22-check
2023-03-01T09:43:18.565+0800 [DEBUG] agent: Check in sync: check=check-test-192.168.100.38-8866-JjHzWXRY
panic: runtime error: invalid memory address or nil pointer dereference
[signal SIGSEGV: segmentation violation code=0x1 addr=0x8 pc=0x1a3279d]

goroutine 166 [running]:
github.com/hashicorp/consul/agent/checks.(*CheckAlias).checkServiceExistsOnRemoteServer(0xc000c8b040, 0xc000c8b050)
github.com/hashicorp/consul/agent/checks/alias.go:161 +0x19d
github.com/hashicorp/consul/agent/checks.(*CheckAlias).runQuery.func1(0xc00147a140?)
github.com/hashicorp/consul/agent/checks/alias.go:234 +0x25
github.com/hashicorp/consul/agent/checks.(*CheckAlias).processChecks(0xc000c8b040, {0x0, 0x0, 0x376bce4?}, 0xc000caff50)
github.com/hashicorp/consul/agent/checks/alias.go:281 +0x4a2
github.com/hashicorp/consul/agent/checks.(*CheckAlias).runQuery(0xc000c8b040, 0xc000926480?)
github.com/hashicorp/consul/agent/checks/alias.go:233 +0x2c5
github.com/hashicorp/consul/agent/checks.(*CheckAlias).run(0x42feb70?, 0xc00148e000?)
github.com/hashicorp/consul/agent/checks/alias.go:86 +0x65
created by github.com/hashicorp/consul/agent/checks.(*CheckAlias).Start
github.com/hashicorp/consul/agent/checks/alias.go:61 +0x145

Contributor guide

Open the contributing guide

Research direction

Start by reproducing the described three-node Consul setup: import the KV JSON, stop the leader and one follower, then restart the follower. Capture the complete panic stack trace and compare it with the raft snapshot restoration, follower startup, and leadership-change logs; done means the restart completes without the nil-pointer panic.

Written by the indexing model from the issue text.

Assessment

Tech stack
go
Domain
distributed-systems
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.