etcd hangs indefinitely when its stdout/stderr log sink stops being drained
- Dominant language
- Go
- Stars
- 52.3k
- Forks
- 10.5k
- Avg merge
- 3d 1h
- Merged PRs (30d)
- 44
Description
### Bug report criteria
- [x] This bug report is not security related, security issues should be disclosed privately via security@etcd.io.
- [x] This is not a support request or question, support requests or questions should be raised in the etcd [discussion forums](https://github.com/etcd-io/etcd/discussions).
- [x] You have read the etcd [bug reporting guidelines](https://github.com/etcd-io/etcd/blob/main/Documentation/contributor-guide/reporting_bugs.md).
- [x] Existing open issues along with etcd [frequently asked questions](https://etcd.io/docs/latest/faq) have been checked and this is not a duplicate.
### What happened?
Linked to RKE2 issue: https://github.com/rancher/rke2/issues/11056
cc @brandond @piugoyal
When etcd's zap logger writes to `stdout`/`stderr` in a container and the reader on the other end of that pipe stops (the container runtime is killed), etcd doesn't crash or time out - it deadlocks indefinitely. It stays alive but never elects/rejoins a raft leader and all client RPCs eventually time out. It never recovers on its own, even once the network/runtime condition that triggered this is fully restored.
### What did you expect to happen?
Either etcd keeps working (a file-based `log-outputs` sink is still writable and functioning fine the whole time) or it fails visibly (crash/exit), not silently deadlock forever with no crash.
### How can we reproduce it (as minimally and precisely as possible)?
1. Run a 3-node etcd cluster with default `log-outputs` (`stdout`/`stderr`, captured by a container runtime as usual).
2. On the node currently holding etcd leadership, cut network connectivity to its peers for 1-2 minutes, then restore it.
3. Independently of etcd, have whatever supervises it exit and its container runtime get killed as a side effect (in our case: a Kubernetes Lease-holder self-fataling on lease loss, which kills `containerd` as part of its own restart). This stops anything draining the pipe backing etcd's `stdout`/`stderr`. etcd itself is never killed and keeps running as an orphaned process.
4. If the outage is long enough, etcd's goroutines block inside a logging call and the process becomes fully unresponsive, even once the network is fully healthy again and raw TCP to peers on 2380 works.
### Anything else we need to know?
Full writeup with many reproductions across RKE2 versions/clusters: https://github.com/rancher/rke2/issues/11056
In that thread, @brandond independently reproduced this with RKE2 in Docker containers and [diagnosed](https://github.com/rancher/rke2/issues/11056#issuecomment-5379493199) the same mechanism: "This suggests that there is a bug in etcd, in that the etcd logging library (zap) writers are blocking. This will cause the process to deadlock when log writes hang due to the container's stdout/stderr pipes filling. It doesn't crash, the goroutines all just block in calls that would write to the log."
Logs can be available on request.
### Etcd version (please run commands below)
```console
vlado-mgmt-cp-3525a81a39-ndqxl:~ # curl -s http://127.0.0.1:2381/metrics | grep etcd_server_version
# HELP etcd_server_version Which version is running. 1 for 'server_version' label with current version.
# TYPE etcd_server_version gauge
etcd_server_version{server_version="3.5.26"} 1
```
### Etcd configuration (command line flags or environment variables)
Bug reproduces with:
```shell
vlado-mgmt-cp-3525a81a39-ndqxl:~ # cat /var/lib/rancher/rke2/server/db/etcd/config
advertise-client-urls: https://10.16.21.112:2379
auto-compaction-mode: periodic
auto-compaction-retention: 12h0m0s
client-transport-security:
cert-file: /var/lib/rancher/rke2/server/tls/etcd/server-client.crt
client-cert-auth: true
key-file: /var/lib/rancher/rke2/server/tls/etcd/server-client.key
trusted-ca-file: /var/lib/rancher/rke2/server/tls/etcd/server-ca.crt
data-dir: /var/lib/rancher/rke2/server/db/etcd
election-timeout: 5000
experimental-initial-corrupt-check: true
experimental-watch-progress-notify-interval: 5000000000
heartbeat-interval: 500
initial-advertise-peer-urls: https://10.16.21.112:2380
initial-cluster: vlado-mgmt-cp-3525a81a39-jz2kt-9c7bf5df=https://10.16.21.123:2380,vlado-mgmt-cp-3525a81a39-ndqxl-84cd0312=https://10.16.21.112:2380
initial-cluster-state: existing
listen-client-http-urls: https://127.0.0.1:2382
listen-client-urls: https://127.0.0.1:2379,https://10.16.21.112:2379
listen-metrics-urls: http://127.0.0.1:2381,http://10.16.21.112:2381
listen-peer-urls: https://127.0.0.1:2380,https://10.16.21.112:2380
log-outputs:
- stderr
logger: zap
name: vlado-mgmt-cp-3525a81a39-ndqxl-84cd0312
peer-transport-security:
cert-file: /var/lib/rancher/rke2/server/tls/etcd/peer-server-client.crt
client-cert-auth: true
key-file: /var/lib/rancher/rke2/server/tls/etcd/peer-server-client.key
trusted-ca-file: /var/lib/rancher/rke2/server/tls/etcd/peer-ca.crt
quota-backend-bytes: 4294967296
snapshot-count: 10000
socket-options:
reuse-address: true
reuse-port: true
```
OR
```
vlado-mgmt-cp-3525a81a39-ndqxl:~ # cat /var/lib/rancher/rke2/server/db/etcd/config
advertise-client-urls: https://10.16.21.112:2379
auto-compaction-mode: periodic
auto-compaction-retention: 12h0m0s
client-transport-security:
cert-file: /var/lib/rancher/rke2/server/tls/etcd/server-client.crt
client-cert-auth: true
key-file: /var/lib/rancher/rke2/server/tls/etcd/server-client.key
trusted-ca-file: /var/lib/rancher/rke2/server/tls/etcd/server-ca.crt
data-dir: /var/lib/rancher/rke2/server/db/etcd
election-timeout: 5000
experimental-initial-corrupt-check: true
experimental-watch-progress-notify-interval: 5000000000
heartbeat-interval: 500
initial-advertise-peer-urls: https://10.16.21.112:2380
initial-cluster: vlado-mgmt-cp-3525a81a39-jz2kt-9c7bf5df=https://10.16.21.123:2380,vlado-mgmt-cp-3525a81a39-ndqxl-84cd0312=https://10.16.21.112:2380
initial-cluster-state: existing
listen-client-http-urls: https://127.0.0.1:2382
listen-client-urls: https://127.0.0.1:2379,https://10.16.21.112:2379
listen-metrics-urls: http://127.0.0.1:2381,http://10.16.21.112:2381
listen-peer-urls: https://127.0.0.1:2380,https://10.16.21.112:2380
log-outputs:
- stderr
- /var/lib/rancher/rke2/server/db/etcd/etcd-internal.log
logger: zap
name: vlado-mgmt-cp-3525a81a39-ndqxl-84cd0312
peer-transport-security:
cert-file: /var/lib/rancher/rke2/server/tls/etcd/peer-server-client.crt
client-cert-auth: true
key-file: /var/lib/rancher/rke2/server/tls/etcd/peer-server-client.key
trusted-ca-file: /var/lib/rancher/rke2/server/tls/etcd/peer-ca.crt
quota-backend-bytes: 4294967296
snapshot-count: 10000
socket-options:
reuse-address: true
reuse-port: true
```
Bug is no longer reproducing with config:
```shell
$ cat /var/lib/rancher/rke2/server/db/etcd/config
advertise-client-urls: https://10.16.21.112:2379
auto-compaction-mode: periodic
auto-compaction-retention: 12h0m0s
client-transport-security:
cert-file: /var/lib/rancher/rke2/server/tls/etcd/server-client.crt
client-cert-auth: true
key-file: /var/lib/rancher/rke2/server/tls/etcd/server-client.key
trusted-ca-file: /var/lib/rancher/rke2/server/tls/etcd/server-ca.crt
data-dir: /var/lib/rancher/rke2/server/db/etcd
election-timeout: 5000
experimental-initial-corrupt-check: true
experimental-watch-progress-notify-interval: 5000000000
heartbeat-interval: 500
initial-advertise-peer-urls: https://10.16.21.112:2380
initial-cluster: vlado-mgmt-cp-3525a81a39-jz2kt-9c7bf5df=https://10.16.21.123:2380,vlado-mgmt-cp-3525a81a39-ndqxl-84cd0312=https://10.16.21.112:2380
initial-cluster-state: existing
listen-client-http-urls: https://127.0.0.1:2382
listen-client-urls: https://127.0.0.1:2379,https://10.16.21.112:2379
listen-metrics-urls: http://127.0.0.1:2381,http://10.16.21.112:2381
listen-peer-urls: https://127.0.0.1:2380,https://10.16.21.112:2380
log-outputs:
- /var/lib/rancher/rke2/server/db/etcd/etcd-internal.log
logger: zap
name: vlado-mgmt-cp-3525a81a39-ndqxl-84cd0312
peer-transport-security:
cert-file: /var/lib/rancher/rke2/server/tls/etcd/peer-server-client.crt
client-cert-auth: true
key-file: /var/lib/rancher/rke2/server/tls/etcd/peer-server-client.key
trusted-ca-file: /var/lib/rancher/rke2/server/tls/etcd/peer-ca.crt
quota-backend-bytes: 4294967296
snapshot-count: 10000
socket-options:
reuse-address: true
reuse-port: true
```
### Etcd debug information (please run commands below, feel free to obfuscate the IP address or FQDN in the output)
_No response_
### Relevant log output
```Shell
```
Contributor guide
Research direction
Start by reproducing the reported behavior with a three-node etcd cluster using the default stdout/stderr log-outputs, then inspect the zap logger and log-output handling. Compare the failing configuration with the file-only configuration described in the issue. Done means etcd does not become permanently unresponsive when its stdout/stderr reader stops draining, while a writable file sink continues functioning.
Written by the indexing model from the issue text.
Assessment
- Tech stack
- go
- Domain
- backend, distributed-systems
- Issue type
- Bug
- Difficulty
- 4/5
- Estimated time
- 3-5 days
- Activity status
- Active
- Clarity
- Mostly clear
- Newbie friendliness
- 45/100