{"level":"warn","ts":"2026-04-18T17:54:06.428413Z","caller":"embed/config.go:689","msg":"Running http and grpc server on single port. This is not recommended for production."} {"level":"info","ts":"2026-04-18T17:54:06.429080Z","caller":"etcdmain/etcd.go:73","msg":"Running: ","args":["etcd","--advertise-client-urls=https://199.19.213.57:2379","--cert-file=/etc/kubernetes/pki/etcd/server.crt","--client-cert-auth=true","--data-dir=/var/lib/etcd","--experimental-initial-corrupt-check=true","--experimental-watch-progress-notify-interval=5s","--initial-advertise-peer-urls=https://199.19.213.57:2380","--initial-cluster=controller-1=https://199.204.45.19:2380,controller-2=https://199.19.213.57:2380","--initial-cluster-state=existing","--key-file=/etc/kubernetes/pki/etcd/server.key","--listen-client-urls=https://127.0.0.1:2379,https://199.19.213.57:2379","--listen-metrics-urls=http://127.0.0.1:2381","--listen-peer-urls=https://199.19.213.57:2380","--name=controller-2","--peer-cert-file=/etc/kubernetes/pki/etcd/peer.crt","--peer-client-cert-auth=true","--peer-key-file=/etc/kubernetes/pki/etcd/peer.key","--peer-trusted-ca-file=/etc/kubernetes/pki/etcd/ca.crt","--snapshot-count=10000","--tls-min-version=TLS1.3","--trusted-ca-file=/etc/kubernetes/pki/etcd/ca.crt"]} {"level":"warn","ts":"2026-04-18T17:54:06.429728Z","caller":"embed/config.go:689","msg":"Running http and grpc server on single port. This is not recommended for production."} {"level":"info","ts":"2026-04-18T17:54:06.429788Z","caller":"embed/etcd.go:140","msg":"configuring peer listeners","listen-peer-urls":["https://199.19.213.57:2380"]} {"level":"info","ts":"2026-04-18T17:54:06.429861Z","caller":"embed/etcd.go:528","msg":"starting with peer TLS","tls-info":"cert = /etc/kubernetes/pki/etcd/peer.crt, key = /etc/kubernetes/pki/etcd/peer.key, client-cert=, client-key=, trusted-ca = /etc/kubernetes/pki/etcd/ca.crt, client-cert-auth = true, crl-file = ","cipher-suites":[]} {"level":"info","ts":"2026-04-18T17:54:06.430391Z","caller":"embed/etcd.go:148","msg":"configuring client listeners","listen-client-urls":["https://127.0.0.1:2379","https://199.19.213.57:2379"]} {"level":"info","ts":"2026-04-18T17:54:06.430501Z","caller":"embed/etcd.go:323","msg":"starting an etcd server","etcd-version":"3.5.21","git-sha":"a17edfd","go-version":"go1.23.7","go-os":"linux","go-arch":"amd64","max-cpu-set":8,"max-cpu-available":8,"member-initialized":false,"name":"controller-2","data-dir":"/var/lib/etcd","wal-dir":"","wal-dir-dedicated":"","member-dir":"/var/lib/etcd/member","force-new-cluster":false,"heartbeat-interval":"100ms","election-timeout":"1s","initial-election-tick-advance":true,"snapshot-count":10000,"max-wals":5,"max-snapshots":5,"snapshot-catchup-entries":5000,"initial-advertise-peer-urls":["https://199.19.213.57:2380"],"listen-peer-urls":["https://199.19.213.57:2380"],"advertise-client-urls":["https://199.19.213.57:2379"],"listen-client-urls":["https://127.0.0.1:2379","https://199.19.213.57:2379"],"listen-metrics-urls":["http://127.0.0.1:2381"],"cors":["*"],"host-whitelist":["*"],"initial-cluster":"controller-1=https://199.204.45.19:2380,controller-2=https://199.19.213.57:2380","initial-cluster-state":"existing","initial-cluster-token":"etcd-cluster","quota-backend-bytes":2147483648,"max-request-bytes":1572864,"max-concurrent-streams":4294967295,"pre-vote":true,"initial-corrupt-check":true,"corrupt-check-time-interval":"0s","compact-check-time-enabled":false,"compact-check-time-interval":"1m0s","auto-compaction-mode":"periodic","auto-compaction-retention":"0s","auto-compaction-interval":"0s","discovery-url":"","discovery-proxy":"","downgrade-check-interval":"5s"} {"level":"info","ts":"2026-04-18T17:54:06.498272Z","caller":"etcdserver/backend.go:81","msg":"opened backend db","path":"/var/lib/etcd/member/snap/db","took":"67.468827ms"} {"level":"info","ts":"2026-04-18T17:54:06.509852Z","caller":"netutil/netutil.go:112","msg":"resolved URL Host","url":"https://199.19.213.57:2380","host":"199.19.213.57:2380","resolved-addr":"199.19.213.57:2380"} {"level":"info","ts":"2026-04-18T17:54:06.509893Z","caller":"netutil/netutil.go:112","msg":"resolved URL Host","url":"https://199.204.45.19:2380","host":"199.204.45.19:2380","resolved-addr":"199.204.45.19:2380"} {"level":"info","ts":"2026-04-18T17:54:07.131741Z","caller":"etcdserver/raft.go:506","msg":"starting local member","local-member-id":"d41438a8a7449f6c","cluster-id":"2b11a68e27507b05"} {"level":"info","ts":"2026-04-18T17:54:07.132078Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"d41438a8a7449f6c switched to configuration voters=()"} {"level":"info","ts":"2026-04-18T17:54:07.132135Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"d41438a8a7449f6c became follower at term 0"} {"level":"info","ts":"2026-04-18T17:54:07.132153Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"newRaft d41438a8a7449f6c [peers: [], term: 0, commit: 0, applied: 0, lastindex: 0, lastterm: 0]"} {"level":"warn","ts":"2026-04-18T17:54:07.144405Z","caller":"auth/store.go:1241","msg":"simple token is not cryptographically signed"} {"level":"info","ts":"2026-04-18T17:54:07.147678Z","caller":"mvcc/kvstore.go:425","msg":"kvstore restored","current-rev":1} {"level":"info","ts":"2026-04-18T17:54:07.149257Z","caller":"etcdserver/server.go:628","msg":"restore consistentIndex","index":0} {"level":"info","ts":"2026-04-18T17:54:07.151305Z","caller":"etcdserver/quota.go:94","msg":"enabled backend quota with default value","quota-name":"v3-applier","quota-size-bytes":2147483648,"quota-size":"2.1 GB"} {"level":"info","ts":"2026-04-18T17:54:07.153040Z","caller":"rafthttp/pipeline.go:72","msg":"started HTTP pipelining with remote peer","local-member-id":"d41438a8a7449f6c","remote-peer-id":"a847c2e9c7010db6"} {"level":"info","ts":"2026-04-18T17:54:07.153063Z","caller":"rafthttp/transport.go:286","msg":"added new remote peer","local-member-id":"d41438a8a7449f6c","remote-peer-id":"a847c2e9c7010db6","remote-peer-urls":["https://199.204.45.19:2380"]} {"level":"info","ts":"2026-04-18T17:54:07.153084Z","caller":"rafthttp/peer.go:133","msg":"starting remote peer","remote-peer-id":"a847c2e9c7010db6"} {"level":"info","ts":"2026-04-18T17:54:07.153223Z","caller":"rafthttp/pipeline.go:72","msg":"started HTTP pipelining with remote peer","local-member-id":"d41438a8a7449f6c","remote-peer-id":"a847c2e9c7010db6"} {"level":"info","ts":"2026-04-18T17:54:07.153970Z","caller":"rafthttp/stream.go:169","msg":"started stream writer with remote peer","local-member-id":"d41438a8a7449f6c","remote-peer-id":"a847c2e9c7010db6"} {"level":"info","ts":"2026-04-18T17:54:07.155671Z","caller":"rafthttp/stream.go:169","msg":"started stream writer with remote peer","local-member-id":"d41438a8a7449f6c","remote-peer-id":"a847c2e9c7010db6"} {"level":"info","ts":"2026-04-18T17:54:07.156630Z","caller":"rafthttp/peer.go:137","msg":"started remote peer","remote-peer-id":"a847c2e9c7010db6"} {"level":"info","ts":"2026-04-18T17:54:07.156681Z","caller":"rafthttp/transport.go:317","msg":"added remote peer","local-member-id":"d41438a8a7449f6c","remote-peer-id":"a847c2e9c7010db6","remote-peer-urls":["https://199.204.45.19:2380"]} {"level":"info","ts":"2026-04-18T17:54:07.156754Z","caller":"etcdserver/server.go:875","msg":"starting etcd server","local-member-id":"d41438a8a7449f6c","local-server-version":"3.5.21","cluster-version":"to_be_decided"} {"level":"info","ts":"2026-04-18T17:54:07.157247Z","caller":"v3rpc/health.go:61","msg":"grpc service status changed","service":"","status":"SERVING"} {"level":"info","ts":"2026-04-18T17:54:07.159083Z","caller":"embed/etcd.go:762","msg":"starting with client TLS","tls-info":"cert = /etc/kubernetes/pki/etcd/server.crt, key = /etc/kubernetes/pki/etcd/server.key, client-cert=, client-key=, trusted-ca = /etc/kubernetes/pki/etcd/ca.crt, client-cert-auth = true, crl-file = ","cipher-suites":[]} {"level":"info","ts":"2026-04-18T17:54:07.159204Z","caller":"rafthttp/stream.go:395","msg":"started stream reader with remote peer","stream-reader-type":"stream MsgApp v2","local-member-id":"d41438a8a7449f6c","remote-peer-id":"a847c2e9c7010db6"} {"level":"info","ts":"2026-04-18T17:54:07.159399Z","caller":"embed/etcd.go:292","msg":"now serving peer/client/metrics","local-member-id":"d41438a8a7449f6c","initial-advertise-peer-urls":["https://199.19.213.57:2380"],"listen-peer-urls":["https://199.19.213.57:2380"],"advertise-client-urls":["https://199.19.213.57:2379"],"listen-client-urls":["https://127.0.0.1:2379","https://199.19.213.57:2379"],"listen-metrics-urls":["http://127.0.0.1:2381"]} {"level":"info","ts":"2026-04-18T17:54:07.159457Z","caller":"embed/etcd.go:908","msg":"serving metrics","address":"http://127.0.0.1:2381"} {"level":"info","ts":"2026-04-18T17:54:07.159510Z","caller":"etcdserver/server.go:775","msg":"starting initial election tick advance","election-ticks":10} {"level":"info","ts":"2026-04-18T17:54:07.159648Z","caller":"rafthttp/stream.go:395","msg":"started stream reader with remote peer","stream-reader-type":"stream Message","local-member-id":"d41438a8a7449f6c","remote-peer-id":"a847c2e9c7010db6"} {"level":"info","ts":"2026-04-18T17:54:07.159865Z","caller":"fileutil/purge.go:50","msg":"started to purge file","dir":"/var/lib/etcd/member/snap","suffix":"snap.db","max":5,"interval":"30s"} {"level":"info","ts":"2026-04-18T17:54:07.159887Z","caller":"fileutil/purge.go:50","msg":"started to purge file","dir":"/var/lib/etcd/member/snap","suffix":"snap","max":5,"interval":"30s"} {"level":"info","ts":"2026-04-18T17:54:07.159894Z","caller":"fileutil/purge.go:50","msg":"started to purge file","dir":"/var/lib/etcd/member/wal","suffix":"wal","max":5,"interval":"30s"} {"level":"info","ts":"2026-04-18T17:54:07.160600Z","caller":"embed/etcd.go:633","msg":"serving peer traffic","address":"199.19.213.57:2380"} {"level":"info","ts":"2026-04-18T17:54:07.160643Z","caller":"embed/etcd.go:603","msg":"cmux::serve","address":"199.19.213.57:2380"} {"level":"info","ts":"2026-04-18T17:54:07.160907Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"d41438a8a7449f6c [term: 0] received a MsgHeartbeat message with higher term from a847c2e9c7010db6 [term: 2]"} {"level":"info","ts":"2026-04-18T17:54:07.160927Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"d41438a8a7449f6c became follower at term 2"} {"level":"info","ts":"2026-04-18T17:54:07.160937Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"raft.node: d41438a8a7449f6c elected leader a847c2e9c7010db6 at term 2"} {"level":"info","ts":"2026-04-18T17:54:07.162603Z","caller":"rafthttp/stream.go:249","msg":"set message encoder","from":"d41438a8a7449f6c","to":"a847c2e9c7010db6","stream-type":"stream MsgApp v2"} {"level":"info","ts":"2026-04-18T17:54:07.162687Z","caller":"rafthttp/peer_status.go:53","msg":"peer became active","peer-id":"a847c2e9c7010db6"} {"level":"info","ts":"2026-04-18T17:54:07.162737Z","caller":"rafthttp/stream.go:274","msg":"established TCP streaming connection with remote peer","stream-writer-type":"stream MsgApp v2","local-member-id":"d41438a8a7449f6c","remote-peer-id":"a847c2e9c7010db6"} {"level":"info","ts":"2026-04-18T17:54:07.163411Z","caller":"rafthttp/stream.go:249","msg":"set message encoder","from":"d41438a8a7449f6c","to":"a847c2e9c7010db6","stream-type":"stream Message"} {"level":"info","ts":"2026-04-18T17:54:07.163451Z","caller":"rafthttp/stream.go:274","msg":"established TCP streaming connection with remote peer","stream-writer-type":"stream Message","local-member-id":"d41438a8a7449f6c","remote-peer-id":"a847c2e9c7010db6"} {"level":"info","ts":"2026-04-18T17:54:07.171855Z","caller":"rafthttp/stream.go:412","msg":"established TCP streaming connection with remote peer","stream-reader-type":"stream MsgApp v2","local-member-id":"d41438a8a7449f6c","remote-peer-id":"a847c2e9c7010db6"} {"level":"info","ts":"2026-04-18T17:54:07.179381Z","caller":"rafthttp/stream.go:412","msg":"established TCP streaming connection with remote peer","stream-reader-type":"stream Message","local-member-id":"d41438a8a7449f6c","remote-peer-id":"a847c2e9c7010db6"} {"level":"info","ts":"2026-04-18T17:54:07.422693Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"d41438a8a7449f6c switched to configuration voters=(12125874831040253366)"} {"level":"info","ts":"2026-04-18T17:54:07.423261Z","caller":"membership/cluster.go:421","msg":"added member","cluster-id":"2b11a68e27507b05","local-member-id":"d41438a8a7449f6c","added-peer-id":"a847c2e9c7010db6","added-peer-peer-urls":["https://199.204.45.19:2380"],"added-peer-is-learner":false} {"level":"info","ts":"2026-04-18T17:54:07.423655Z","caller":"membership/cluster.go:587","msg":"set initial cluster version","cluster-id":"2b11a68e27507b05","local-member-id":"d41438a8a7449f6c","cluster-version":"3.5"} {"level":"info","ts":"2026-04-18T17:54:07.423774Z","caller":"api/capability.go:75","msg":"enabled capabilities for version","cluster-version":"3.5"} {"level":"info","ts":"2026-04-18T17:54:07.471863Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"d41438a8a7449f6c switched to configuration voters=(12125874831040253366) learners=(15281901732586889068)"} {"level":"info","ts":"2026-04-18T17:54:07.472054Z","caller":"membership/cluster.go:421","msg":"added member","cluster-id":"2b11a68e27507b05","local-member-id":"d41438a8a7449f6c","added-peer-id":"d41438a8a7449f6c","added-peer-peer-urls":["https://199.19.213.57:2380"],"added-peer-is-learner":true} {"level":"info","ts":"2026-04-18T17:54:07.472706Z","caller":"etcdserver/server.go:2144","msg":"published local member to cluster through raft","local-member-id":"d41438a8a7449f6c","local-member-attributes":"{Name:controller-2 ClientURLs:[https://199.19.213.57:2379]}","request-path":"/0/members/d41438a8a7449f6c/attributes","cluster-id":"2b11a68e27507b05","publish-timeout":"7s"} {"level":"info","ts":"2026-04-18T17:54:07.474379Z","caller":"embed/serve.go:124","msg":"ready to serve client requests"} {"level":"info","ts":"2026-04-18T17:54:07.474553Z","caller":"etcdmain/main.go:44","msg":"notifying init daemon"} {"level":"info","ts":"2026-04-18T17:54:07.474621Z","caller":"etcdmain/main.go:50","msg":"successfully notified init daemon"} {"level":"info","ts":"2026-04-18T17:54:07.476048Z","caller":"v3rpc/health.go:61","msg":"grpc service status changed","service":"","status":"SERVING"} {"level":"info","ts":"2026-04-18T17:54:07.477086Z","caller":"embed/serve.go:275","msg":"serving client traffic securely","traffic":"grpc+http","address":"199.19.213.57:2379"} {"level":"info","ts":"2026-04-18T17:54:07.474248Z","caller":"embed/serve.go:124","msg":"ready to serve client requests"} {"level":"info","ts":"2026-04-18T17:54:07.481581Z","caller":"v3rpc/health.go:61","msg":"grpc service status changed","service":"","status":"SERVING"} {"level":"info","ts":"2026-04-18T17:54:07.482426Z","caller":"embed/serve.go:275","msg":"serving client traffic securely","traffic":"grpc+http","address":"127.0.0.1:2379"} {"level":"warn","ts":"2026-04-18T17:54:07.485221Z","caller":"embed/config_logging.go:170","msg":"rejected connection on client endpoint","remote-addr":"199.19.213.57:37938","server-name":"","error":"EOF"} {"level":"warn","ts":"2026-04-18T17:54:07.485442Z","caller":"embed/config_logging.go:170","msg":"rejected connection on client endpoint","remote-addr":"199.19.213.57:37950","server-name":"","error":"EOF"} {"level":"info","ts":"2026-04-18T17:54:07.898169Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"d41438a8a7449f6c switched to configuration voters=(12125874831040253366 15281901732586889068)"} {"level":"info","ts":"2026-04-18T17:54:07.898376Z","caller":"membership/cluster.go:537","msg":"promote member","cluster-id":"2b11a68e27507b05","local-member-id":"d41438a8a7449f6c","promoted-member-id":"d41438a8a7449f6c"} {"level":"warn","ts":"2026-04-18T17:54:10.209190Z","caller":"wal/wal.go:805","msg":"slow fdatasync","took":"1.12063603s","expected-duration":"1s"} {"level":"warn","ts":"2026-04-18T17:54:10.344940Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"133.649361ms","expected-duration":"100ms","prefix":"","request":"header: txn: success:> failure:<>>","response":"size:16"} {"level":"warn","ts":"2026-04-18T17:54:14.856303Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"280.795735ms","expected-duration":"100ms","prefix":"","request":"header: lease_grant:","response":"size:40"} {"level":"warn","ts":"2026-04-18T17:54:14.856423Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-04-18T17:54:14.319618Z","time spent":"536.802119ms","remote":"127.0.0.1:37984","response type":"/etcdserverpb.Lease/LeaseGrant","request count":-1,"request size":-1,"response count":-1,"response size":-1,"request content":""} {"level":"info","ts":"2026-04-18T17:54:15.068262Z","caller":"traceutil/trace.go:171","msg":"trace[594082175] transaction","detail":"{read_only:false; response_revision:561; number_of_response:1; }","duration":"210.854766ms","start":"2026-04-18T17:54:14.857387Z","end":"2026-04-18T17:54:15.068242Z","steps":["trace[594082175] 'process raft request' (duration: 210.723535ms)"],"step_count":1} {"level":"info","ts":"2026-04-18T17:54:18.971775Z","caller":"traceutil/trace.go:171","msg":"trace[2012026640] transaction","detail":"{read_only:false; response_revision:573; number_of_response:1; }","duration":"107.058715ms","start":"2026-04-18T17:54:18.864685Z","end":"2026-04-18T17:54:18.971744Z","steps":["trace[2012026640] 'process raft request' (duration: 106.787082ms)"],"step_count":1} {"level":"warn","ts":"2026-04-18T17:54:20.669180Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"122.575291ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/csinodes/controller-2\" limit:1 ","response":"range_response_count:0 size:5"} {"level":"info","ts":"2026-04-18T17:54:20.669298Z","caller":"traceutil/trace.go:171","msg":"trace[947737798] range","detail":"{range_begin:/registry/csinodes/controller-2; range_end:; response_count:0; response_revision:579; }","duration":"122.825643ms","start":"2026-04-18T17:54:20.546449Z","end":"2026-04-18T17:54:20.669275Z","steps":["trace[947737798] 'range keys from in-memory index tree' (duration: 120.773926ms)"],"step_count":1} {"level":"info","ts":"2026-04-18T17:54:21.958029Z","caller":"traceutil/trace.go:171","msg":"trace[1558727854] linearizableReadLoop","detail":"{readStateIndex:618; appliedIndex:618; }","duration":"433.564849ms","start":"2026-04-18T17:54:21.524439Z","end":"2026-04-18T17:54:21.958004Z","steps":["trace[1558727854] 'read index received' (duration: 433.556739ms)","trace[1558727854] 'applied index is now lower than readState.Index' (duration: 6.63µs)"],"step_count":2} {"level":"warn","ts":"2026-04-18T17:54:21.958294Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"433.796912ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/csinodes/controller-2\" limit:1 ","response":"range_response_count:0 size:5"} {"level":"info","ts":"2026-04-18T17:54:21.958432Z","caller":"traceutil/trace.go:171","msg":"trace[2087319508] range","detail":"{range_begin:/registry/csinodes/controller-2; range_end:; response_count:0; response_revision:581; }","duration":"434.026835ms","start":"2026-04-18T17:54:21.524382Z","end":"2026-04-18T17:54:21.958409Z","steps":["trace[2087319508] 'agreement among raft nodes before linearized reading' (duration: 433.738391ms)"],"step_count":1} {"level":"warn","ts":"2026-04-18T17:54:21.958511Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-04-18T17:54:21.524358Z","time spent":"434.142066ms","remote":"127.0.0.1:38328","response type":"/etcdserverpb.KV/Range","request count":0,"request size":35,"response count":0,"response size":28,"request content":"key:\"/registry/csinodes/controller-2\" limit:1 "} {"level":"warn","ts":"2026-04-18T17:54:21.996058Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"198.653242ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/minions/controller-2\" limit:1 ","response":"range_response_count:0 size:5"} {"level":"warn","ts":"2026-04-18T17:54:21.996107Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"149.58616ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/leases/kube-system/kube-controller-manager\" limit:1 ","response":"range_response_count:1 size:509"} {"level":"info","ts":"2026-04-18T17:54:21.996193Z","caller":"traceutil/trace.go:171","msg":"trace[2116228921] range","detail":"{range_begin:/registry/minions/controller-2; range_end:; response_count:0; response_revision:582; }","duration":"198.807594ms","start":"2026-04-18T17:54:21.797355Z","end":"2026-04-18T17:54:21.996163Z","steps":["trace[2116228921] 'agreement among raft nodes before linearized reading' (duration: 198.604511ms)"],"step_count":1} {"level":"info","ts":"2026-04-18T17:54:21.996219Z","caller":"traceutil/trace.go:171","msg":"trace[892961815] range","detail":"{range_begin:/registry/leases/kube-system/kube-controller-manager; range_end:; response_count:1; response_revision:582; }","duration":"149.722921ms","start":"2026-04-18T17:54:21.846466Z","end":"2026-04-18T17:54:21.996189Z","steps":["trace[892961815] 'agreement among raft nodes before linearized reading' (duration: 149.466638ms)"],"step_count":1} {"level":"info","ts":"2026-04-18T17:54:24.783355Z","caller":"traceutil/trace.go:171","msg":"trace[1631137900] transaction","detail":"{read_only:false; response_revision:600; number_of_response:1; }","duration":"443.046726ms","start":"2026-04-18T17:54:24.340274Z","end":"2026-04-18T17:54:24.783321Z","steps":["trace[1631137900] 'process raft request' (duration: 442.788793ms)"],"step_count":1} {"level":"warn","ts":"2026-04-18T17:54:24.783562Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-04-18T17:54:24.340256Z","time spent":"443.215618ms","remote":"127.0.0.1:38146","response type":"/etcdserverpb.KV/Txn","request count":1,"request size":3118,"response count":0,"response size":39,"request content":"compare: success:> failure:<>"} {"level":"info","ts":"2026-04-18T17:54:24.791458Z","caller":"traceutil/trace.go:171","msg":"trace[2026903385] linearizableReadLoop","detail":"{readStateIndex:640; appliedIndex:642; }","duration":"349.211697ms","start":"2026-04-18T17:54:24.442214Z","end":"2026-04-18T17:54:24.791425Z","steps":["trace[2026903385] 'read index received' (duration: 349.204517ms)","trace[2026903385] 'applied index is now lower than readState.Index' (duration: 5.7µs)"],"step_count":2} {"level":"warn","ts":"2026-04-18T17:54:24.791727Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"349.492841ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/serviceaccounts/kube-system/kube-proxy\" limit:1 ","response":"range_response_count:1 size:185"} {"level":"info","ts":"2026-04-18T17:54:24.792485Z","caller":"traceutil/trace.go:171","msg":"trace[771461761] transaction","detail":"{read_only:false; response_revision:603; number_of_response:1; }","duration":"418.738ms","start":"2026-04-18T17:54:24.373672Z","end":"2026-04-18T17:54:24.792410Z","steps":["trace[771461761] 'process raft request' (duration: 418.096902ms)"],"step_count":1} {"level":"info","ts":"2026-04-18T17:54:24.793162Z","caller":"traceutil/trace.go:171","msg":"trace[1590229673] range","detail":"{range_begin:/registry/serviceaccounts/kube-system/kube-proxy; range_end:; response_count:1; response_revision:602; }","duration":"350.99659ms","start":"2026-04-18T17:54:24.442143Z","end":"2026-04-18T17:54:24.793139Z","steps":["trace[1590229673] 'agreement among raft nodes before linearized reading' (duration: 349.473951ms)"],"step_count":1} {"level":"warn","ts":"2026-04-18T17:54:24.793341Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-04-18T17:54:24.442114Z","time spent":"351.208012ms","remote":"127.0.0.1:38158","response type":"/etcdserverpb.KV/Range","request count":0,"request size":52,"response count":1,"response size":208,"request content":"key:\"/registry/serviceaccounts/kube-system/kube-proxy\" limit:1 "} {"level":"info","ts":"2026-04-18T17:54:24.793469Z","caller":"traceutil/trace.go:171","msg":"trace[1175936604] transaction","detail":"{read_only:false; response_revision:604; number_of_response:1; }","duration":"208.496248ms","start":"2026-04-18T17:54:24.584917Z","end":"2026-04-18T17:54:24.793413Z","steps":["trace[1175936604] 'process raft request' (duration: 208.177994ms)"],"step_count":1} {"level":"warn","ts":"2026-04-18T17:54:24.794115Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-04-18T17:54:24.373632Z","time spent":"419.465098ms","remote":"127.0.0.1:37984","response type":"/etcdserverpb.KV/Txn","request count":1,"request size":118,"response count":0,"response size":39,"request content":"compare: success:> failure: >"} {"level":"warn","ts":"2026-04-18T17:54:24.794524Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"326.069456ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/pods/kube-system/kube-controller-manager-controller-2\" limit:1 ","response":"range_response_count:1 size:5509"} {"level":"info","ts":"2026-04-18T17:54:24.794602Z","caller":"traceutil/trace.go:171","msg":"trace[240336554] range","detail":"{range_begin:/registry/pods/kube-system/kube-controller-manager-controller-2; range_end:; response_count:1; response_revision:604; }","duration":"326.153208ms","start":"2026-04-18T17:54:24.468399Z","end":"2026-04-18T17:54:24.794553Z","steps":["trace[240336554] 'agreement among raft nodes before linearized reading' (duration: 326.037496ms)"],"step_count":1} {"level":"warn","ts":"2026-04-18T17:54:24.794631Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-04-18T17:54:24.468366Z","time spent":"326.257899ms","remote":"127.0.0.1:38146","response type":"/etcdserverpb.KV/Range","request count":0,"request size":67,"response count":1,"response size":5532,"request content":"key:\"/registry/pods/kube-system/kube-controller-manager-controller-2\" limit:1 "} {"level":"info","ts":"2026-04-18T17:54:28.268036Z","caller":"traceutil/trace.go:171","msg":"trace[1431914988] linearizableReadLoop","detail":"{readStateIndex:677; appliedIndex:677; }","duration":"399.566942ms","start":"2026-04-18T17:54:27.868447Z","end":"2026-04-18T17:54:28.268014Z","steps":["trace[1431914988] 'read index received' (duration: 399.562542ms)","trace[1431914988] 'applied index is now lower than readState.Index' (duration: 3.52µs)"],"step_count":2} {"level":"warn","ts":"2026-04-18T17:54:28.268387Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"399.870065ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/leases/kube-system/kube-controller-manager\" limit:1 ","response":"range_response_count:1 size:509"} {"level":"info","ts":"2026-04-18T17:54:28.268529Z","caller":"traceutil/trace.go:171","msg":"trace[1038836456] range","detail":"{range_begin:/registry/leases/kube-system/kube-controller-manager; range_end:; response_count:1; response_revision:633; }","duration":"400.187179ms","start":"2026-04-18T17:54:27.868316Z","end":"2026-04-18T17:54:28.268503Z","steps":["trace[1038836456] 'agreement among raft nodes before linearized reading' (duration: 399.819284ms)"],"step_count":1} {"level":"warn","ts":"2026-04-18T17:54:28.268593Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-04-18T17:54:27.868233Z","time spent":"400.345921ms","remote":"127.0.0.1:38214","response type":"/etcdserverpb.KV/Range","request count":0,"request size":56,"response count":1,"response size":532,"request content":"key:\"/registry/leases/kube-system/kube-controller-manager\" limit:1 "} {"level":"warn","ts":"2026-04-18T17:54:28.270637Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"380.029008ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/leases/kube-system/plndr-svcs-lock\" limit:1 ","response":"range_response_count:1 size:441"} {"level":"info","ts":"2026-04-18T17:54:28.275014Z","caller":"traceutil/trace.go:171","msg":"trace[1248927380] range","detail":"{range_begin:/registry/leases/kube-system/plndr-svcs-lock; range_end:; response_count:1; response_revision:633; }","duration":"385.288526ms","start":"2026-04-18T17:54:27.889700Z","end":"2026-04-18T17:54:28.274988Z","steps":["trace[1248927380] 'agreement among raft nodes before linearized reading' (duration: 379.981738ms)"],"step_count":1} {"level":"warn","ts":"2026-04-18T17:54:28.275109Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-04-18T17:54:27.889669Z","time spent":"385.416518ms","remote":"127.0.0.1:38214","response type":"/etcdserverpb.KV/Range","request count":0,"request size":48,"response count":1,"response size":464,"request content":"key:\"/registry/leases/kube-system/plndr-svcs-lock\" limit:1 "} {"level":"warn","ts":"2026-04-18T17:54:29.573460Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"123.445703ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/leases/kube-system/plndr-cp-lock\" limit:1 ","response":"range_response_count:1 size:436"} {"level":"info","ts":"2026-04-18T17:54:29.573613Z","caller":"traceutil/trace.go:171","msg":"trace[1230604460] range","detail":"{range_begin:/registry/leases/kube-system/plndr-cp-lock; range_end:; response_count:1; response_revision:636; }","duration":"123.673465ms","start":"2026-04-18T17:54:29.449905Z","end":"2026-04-18T17:54:29.573579Z","steps":["trace[1230604460] 'range keys from in-memory index tree' (duration: 121.559829ms)"],"step_count":1} {"level":"info","ts":"2026-04-18T17:54:34.662388Z","caller":"traceutil/trace.go:171","msg":"trace[1936216026] transaction","detail":"{read_only:false; response_revision:651; number_of_response:1; }","duration":"183.818068ms","start":"2026-04-18T17:54:34.478543Z","end":"2026-04-18T17:54:34.662361Z","steps":["trace[1936216026] 'process raft request' (duration: 183.645956ms)"],"step_count":1} {"level":"info","ts":"2026-04-18T17:54:43.736008Z","caller":"traceutil/trace.go:171","msg":"trace[633650467] transaction","detail":"{read_only:false; response_revision:673; number_of_response:1; }","duration":"373.590927ms","start":"2026-04-18T17:54:43.362397Z","end":"2026-04-18T17:54:43.735988Z","steps":["trace[633650467] 'process raft request' (duration: 373.544126ms)"],"step_count":1} {"level":"warn","ts":"2026-04-18T17:54:43.736621Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-04-18T17:54:43.362358Z","time spent":"373.749188ms","remote":"127.0.0.1:38214","response type":"/etcdserverpb.KV/Txn","request count":1,"request size":677,"response count":0,"response size":39,"request content":"compare: success:> failure: >"} {"level":"info","ts":"2026-04-18T17:54:43.775866Z","caller":"traceutil/trace.go:171","msg":"trace[951907427] linearizableReadLoop","detail":"{readStateIndex:722; appliedIndex:723; }","duration":"431.558907ms","start":"2026-04-18T17:54:43.344269Z","end":"2026-04-18T17:54:43.775828Z","steps":["trace[951907427] 'read index received' (duration: 431.550537ms)","trace[951907427] 'applied index is now lower than readState.Index' (duration: 6.54µs)"],"step_count":2} {"level":"warn","ts":"2026-04-18T17:54:43.776070Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"431.787021ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/leases/kube-system/kube-scheduler\" limit:1 ","response":"range_response_count:1 size:482"} {"level":"info","ts":"2026-04-18T17:54:43.776140Z","caller":"traceutil/trace.go:171","msg":"trace[670823758] range","detail":"{range_begin:/registry/leases/kube-system/kube-scheduler; range_end:; response_count:1; response_revision:673; }","duration":"431.910582ms","start":"2026-04-18T17:54:43.344210Z","end":"2026-04-18T17:54:43.776120Z","steps":["trace[670823758] 'agreement among raft nodes before linearized reading' (duration: 431.75215ms)"],"step_count":1} {"level":"warn","ts":"2026-04-18T17:54:43.776207Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-04-18T17:54:43.344182Z","time spent":"432.005763ms","remote":"127.0.0.1:38214","response type":"/etcdserverpb.KV/Range","request count":0,"request size":47,"response count":1,"response size":505,"request content":"key:\"/registry/leases/kube-system/kube-scheduler\" limit:1 "} {"level":"info","ts":"2026-04-18T17:54:46.702563Z","caller":"traceutil/trace.go:171","msg":"trace[1977788109] transaction","detail":"{read_only:false; response_revision:681; number_of_response:1; }","duration":"144.425671ms","start":"2026-04-18T17:54:46.558114Z","end":"2026-04-18T17:54:46.702540Z","steps":["trace[1977788109] 'process raft request' (duration: 144.281169ms)"],"step_count":1} {"level":"info","ts":"2026-04-18T17:54:47.921444Z","caller":"traceutil/trace.go:171","msg":"trace[1459484545] linearizableReadLoop","detail":"{readStateIndex:736; appliedIndex:736; }","duration":"111.858527ms","start":"2026-04-18T17:54:47.809558Z","end":"2026-04-18T17:54:47.921417Z","steps":["trace[1459484545] 'read index received' (duration: 111.850297ms)","trace[1459484545] 'applied index is now lower than readState.Index' (duration: 6.82µs)"],"step_count":2} {"level":"warn","ts":"2026-04-18T17:54:47.921585Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"112.007789ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/health\" ","response":"range_response_count:0 size:5"} {"level":"info","ts":"2026-04-18T17:54:47.921678Z","caller":"traceutil/trace.go:171","msg":"trace[1408650340] range","detail":"{range_begin:/registry/health; range_end:; response_count:0; response_revision:684; }","duration":"112.155382ms","start":"2026-04-18T17:54:47.809501Z","end":"2026-04-18T17:54:47.921656Z","steps":["trace[1408650340] 'agreement among raft nodes before linearized reading' (duration: 112.020219ms)"],"step_count":1} {"level":"warn","ts":"2026-04-18T17:54:48.248463Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"238.667012ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/health\" ","response":"range_response_count:0 size:5"} {"level":"info","ts":"2026-04-18T17:54:48.248543Z","caller":"traceutil/trace.go:171","msg":"trace[1229587651] range","detail":"{range_begin:/registry/health; range_end:; response_count:0; response_revision:685; }","duration":"238.754093ms","start":"2026-04-18T17:54:48.009769Z","end":"2026-04-18T17:54:48.248523Z","steps":["trace[1229587651] 'range keys from in-memory index tree' (duration: 236.88362ms)"],"step_count":1} {"level":"warn","ts":"2026-04-18T17:54:48.248870Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"190.926946ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/leases/kube-system/plndr-cp-lock\" limit:1 ","response":"range_response_count:1 size:435"} {"level":"info","ts":"2026-04-18T17:54:48.248945Z","caller":"traceutil/trace.go:171","msg":"trace[1848420675] range","detail":"{range_begin:/registry/leases/kube-system/plndr-cp-lock; range_end:; response_count:1; response_revision:685; }","duration":"191.045787ms","start":"2026-04-18T17:54:48.057881Z","end":"2026-04-18T17:54:48.248927Z","steps":["trace[1848420675] 'range keys from in-memory index tree' (duration: 188.86991ms)"],"step_count":1} {"level":"warn","ts":"2026-04-18T17:54:50.098736Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"119.818157ms","expected-duration":"100ms","prefix":"","request":"header: txn: success:> failure:<>>","response":"size:16"} {"level":"warn","ts":"2026-04-18T17:54:50.395291Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"174.443605ms","expected-duration":"100ms","prefix":"read-only range ","request":"limit:1 keys_only:true ","response":"range_response_count:0 size:5"} {"level":"info","ts":"2026-04-18T17:54:50.395404Z","caller":"traceutil/trace.go:171","msg":"trace[346082166] range","detail":"{range_begin:; range_end:; response_count:0; response_revision:689; }","duration":"174.579057ms","start":"2026-04-18T17:54:50.220797Z","end":"2026-04-18T17:54:50.395376Z","steps":["trace[346082166] 'range keys from in-memory index tree' (duration: 173.089998ms)"],"step_count":1} {"level":"info","ts":"2026-04-18T17:54:51.202670Z","caller":"traceutil/trace.go:171","msg":"trace[368637802] linearizableReadLoop","detail":"{readStateIndex:744; appliedIndex:744; }","duration":"134.032548ms","start":"2026-04-18T17:54:51.068570Z","end":"2026-04-18T17:54:51.202602Z","steps":["trace[368637802] 'read index received' (duration: 134.027468ms)","trace[368637802] 'applied index is now lower than readState.Index' (duration: 4.05µs)"],"step_count":2} {"level":"warn","ts":"2026-04-18T17:54:51.202803Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"134.21992ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/leases/kube-system/plndr-cp-lock\" limit:1 ","response":"range_response_count:1 size:436"} {"level":"info","ts":"2026-04-18T17:54:51.202861Z","caller":"traceutil/trace.go:171","msg":"trace[1425990345] range","detail":"{range_begin:/registry/leases/kube-system/plndr-cp-lock; range_end:; response_count:1; response_revision:691; }","duration":"134.318651ms","start":"2026-04-18T17:54:51.068527Z","end":"2026-04-18T17:54:51.202846Z","steps":["trace[1425990345] 'agreement among raft nodes before linearized reading' (duration: 134.2076ms)"],"step_count":1} {"level":"warn","ts":"2026-04-18T17:54:52.709383Z","caller":"etcdserver/v3_server.go:920","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":11487730067459448279,"retry-timeout":"500ms"} {"level":"warn","ts":"2026-04-18T17:54:53.209902Z","caller":"etcdserver/v3_server.go:920","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":11487730067459448279,"retry-timeout":"500ms"} {"level":"info","ts":"2026-04-18T17:54:53.231823Z","caller":"traceutil/trace.go:171","msg":"trace[306160045] linearizableReadLoop","detail":"{readStateIndex:746; appliedIndex:747; }","duration":"1.02307822s","start":"2026-04-18T17:54:52.208698Z","end":"2026-04-18T17:54:53.231777Z","steps":["trace[306160045] 'read index received' (duration: 1.02306791s)","trace[306160045] 'applied index is now lower than readState.Index' (duration: 8.5µs)"],"step_count":2} {"level":"warn","ts":"2026-04-18T17:54:53.321078Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"1.112345717s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/leases/kube-system/plndr-svcs-lock\" limit:1 ","response":"range_response_count:1 size:441"} {"level":"info","ts":"2026-04-18T17:54:53.321211Z","caller":"traceutil/trace.go:171","msg":"trace[1211895059] range","detail":"{range_begin:/registry/leases/kube-system/plndr-svcs-lock; range_end:; response_count:1; response_revision:694; }","duration":"1.112488238s","start":"2026-04-18T17:54:52.208663Z","end":"2026-04-18T17:54:53.321151Z","steps":["trace[1211895059] 'agreement among raft nodes before linearized reading' (duration: 1.023296872s)","trace[1211895059] 'range keys from in-memory index tree' (duration: 89.012624ms)"],"step_count":2} {"level":"warn","ts":"2026-04-18T17:54:53.321274Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-04-18T17:54:52.208603Z","time spent":"1.11265998s","remote":"127.0.0.1:38214","response type":"/etcdserverpb.KV/Range","request count":0,"request size":48,"response count":1,"response size":464,"request content":"key:\"/registry/leases/kube-system/plndr-svcs-lock\" limit:1 "} {"level":"info","ts":"2026-04-18T17:54:53.334588Z","caller":"traceutil/trace.go:171","msg":"trace[1512015823] linearizableReadLoop","detail":"{readStateIndex:749; appliedIndex:747; }","duration":"102.645119ms","start":"2026-04-18T17:54:53.231921Z","end":"2026-04-18T17:54:53.334566Z","steps":["trace[1512015823] 'read index received' (duration: 1.900903ms)","trace[1512015823] 'applied index is now lower than readState.Index' (duration: 100.743056ms)"],"step_count":2} {"level":"warn","ts":"2026-04-18T17:54:53.334682Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"1.114630674s","expected-duration":"100ms","prefix":"read-only range ","request":"limit:1 keys_only:true ","response":"range_response_count:0 size:5"} {"level":"info","ts":"2026-04-18T17:54:53.334714Z","caller":"traceutil/trace.go:171","msg":"trace[1373333360] range","detail":"{range_begin:; range_end:; response_count:0; response_revision:695; }","duration":"1.114667534s","start":"2026-04-18T17:54:52.220037Z","end":"2026-04-18T17:54:53.334704Z","steps":["trace[1373333360] 'agreement among raft nodes before linearized reading' (duration: 1.114611043s)"],"step_count":1} {"level":"warn","ts":"2026-04-18T17:54:53.334740Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"324.430639ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/health\" ","response":"range_response_count:0 size:5"} {"level":"info","ts":"2026-04-18T17:54:53.334780Z","caller":"traceutil/trace.go:171","msg":"trace[321444235] range","detail":"{range_begin:/registry/health; range_end:; response_count:0; response_revision:695; }","duration":"324.5287ms","start":"2026-04-18T17:54:53.010241Z","end":"2026-04-18T17:54:53.334770Z","steps":["trace[321444235] 'agreement among raft nodes before linearized reading' (duration: 324.439749ms)"],"step_count":1} {"level":"warn","ts":"2026-04-18T17:54:53.334894Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-04-18T17:54:53.010217Z","time spent":"324.669751ms","remote":"127.0.0.1:37964","response type":"/etcdserverpb.KV/Range","request count":0,"request size":18,"response count":0,"response size":28,"request content":"key:\"/registry/health\" "} {"level":"warn","ts":"2026-04-18T17:54:58.330217Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"110.125769ms","expected-duration":"100ms","prefix":"read-only range ","request":"limit:1 keys_only:true ","response":"range_response_count:0 size:5"} {"level":"info","ts":"2026-04-18T17:54:58.330321Z","caller":"traceutil/trace.go:171","msg":"trace[834252275] range","detail":"{range_begin:; range_end:; response_count:0; response_revision:710; }","duration":"110.23937ms","start":"2026-04-18T17:54:58.220053Z","end":"2026-04-18T17:54:58.330292Z","steps":["trace[834252275] 'range keys from in-memory index tree' (duration: 108.194395ms)"],"step_count":1} {"level":"warn","ts":"2026-04-18T17:55:01.565901Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"307.057386ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/leases/kube-system/plndr-cp-lock\" limit:1 ","response":"range_response_count:1 size:436"} {"level":"info","ts":"2026-04-18T17:55:01.566004Z","caller":"traceutil/trace.go:171","msg":"trace[800519726] range","detail":"{range_begin:/registry/leases/kube-system/plndr-cp-lock; range_end:; response_count:1; response_revision:715; }","duration":"307.196408ms","start":"2026-04-18T17:55:01.258779Z","end":"2026-04-18T17:55:01.565975Z","steps":["trace[800519726] 'range keys from in-memory index tree' (duration: 305.155033ms)"],"step_count":1} {"level":"warn","ts":"2026-04-18T17:55:01.566093Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-04-18T17:55:01.258757Z","time spent":"307.298699ms","remote":"127.0.0.1:38214","response type":"/etcdserverpb.KV/Range","request count":0,"request size":46,"response count":1,"response size":459,"request content":"key:\"/registry/leases/kube-system/plndr-cp-lock\" limit:1 "} {"level":"info","ts":"2026-04-18T17:55:03.519208Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"d41438a8a7449f6c switched to configuration voters=(12125874831040253366 15281901732586889068) learners=(4121331078346651250)"} {"level":"info","ts":"2026-04-18T17:55:03.519516Z","caller":"membership/cluster.go:421","msg":"added member","cluster-id":"2b11a68e27507b05","local-member-id":"d41438a8a7449f6c","added-peer-id":"3931e8c7aea13672","added-peer-peer-urls":["https://199.204.45.248:2380"],"added-peer-is-learner":true} {"level":"info","ts":"2026-04-18T17:55:03.519562Z","caller":"rafthttp/peer.go:133","msg":"starting remote peer","remote-peer-id":"3931e8c7aea13672"} {"level":"info","ts":"2026-04-18T17:55:03.519711Z","caller":"rafthttp/pipeline.go:72","msg":"started HTTP pipelining with remote peer","local-member-id":"d41438a8a7449f6c","remote-peer-id":"3931e8c7aea13672"} {"level":"info","ts":"2026-04-18T17:55:03.519976Z","caller":"rafthttp/stream.go:169","msg":"started stream writer with remote peer","local-member-id":"d41438a8a7449f6c","remote-peer-id":"3931e8c7aea13672"} {"level":"info","ts":"2026-04-18T17:55:03.520557Z","caller":"rafthttp/stream.go:169","msg":"started stream writer with remote peer","local-member-id":"d41438a8a7449f6c","remote-peer-id":"3931e8c7aea13672"} {"level":"info","ts":"2026-04-18T17:55:03.524198Z","caller":"rafthttp/peer.go:137","msg":"started remote peer","remote-peer-id":"3931e8c7aea13672"} {"level":"info","ts":"2026-04-18T17:55:03.524285Z","caller":"rafthttp/stream.go:395","msg":"started stream reader with remote peer","stream-reader-type":"stream MsgApp v2","local-member-id":"d41438a8a7449f6c","remote-peer-id":"3931e8c7aea13672"} {"level":"info","ts":"2026-04-18T17:55:03.524310Z","caller":"rafthttp/stream.go:395","msg":"started stream reader with remote peer","stream-reader-type":"stream Message","local-member-id":"d41438a8a7449f6c","remote-peer-id":"3931e8c7aea13672"} {"level":"info","ts":"2026-04-18T17:55:03.525049Z","caller":"rafthttp/transport.go:317","msg":"added remote peer","local-member-id":"d41438a8a7449f6c","remote-peer-id":"3931e8c7aea13672","remote-peer-urls":["https://199.204.45.248:2380"]} {"level":"info","ts":"2026-04-18T17:55:03.525206Z","caller":"etcdserver/server.go:2021","msg":"applied a configuration change through raft","local-member-id":"d41438a8a7449f6c","raft-conf-change":"ConfChangeAddLearnerNode","raft-conf-change-node-id":"3931e8c7aea13672"} {"level":"warn","ts":"2026-04-18T17:55:03.567996Z","caller":"embed/config_logging.go:170","msg":"rejected connection on client endpoint","remote-addr":"199.204.45.248:48814","server-name":"","error":"EOF"} {"level":"info","ts":"2026-04-18T17:55:05.237518Z","caller":"rafthttp/stream.go:249","msg":"set message encoder","from":"d41438a8a7449f6c","to":"3931e8c7aea13672","stream-type":"stream MsgApp v2"} {"level":"info","ts":"2026-04-18T17:55:05.237548Z","caller":"rafthttp/peer_status.go:53","msg":"peer became active","peer-id":"3931e8c7aea13672"} {"level":"info","ts":"2026-04-18T17:55:05.237565Z","caller":"rafthttp/stream.go:274","msg":"established TCP streaming connection with remote peer","stream-writer-type":"stream MsgApp v2","local-member-id":"d41438a8a7449f6c","remote-peer-id":"3931e8c7aea13672"} {"level":"info","ts":"2026-04-18T17:55:05.241756Z","caller":"rafthttp/stream.go:249","msg":"set message encoder","from":"d41438a8a7449f6c","to":"3931e8c7aea13672","stream-type":"stream Message"} {"level":"info","ts":"2026-04-18T17:55:05.241807Z","caller":"rafthttp/stream.go:274","msg":"established TCP streaming connection with remote peer","stream-writer-type":"stream Message","local-member-id":"d41438a8a7449f6c","remote-peer-id":"3931e8c7aea13672"} {"level":"info","ts":"2026-04-18T17:55:05.242787Z","caller":"rafthttp/stream.go:412","msg":"established TCP streaming connection with remote peer","stream-reader-type":"stream Message","local-member-id":"d41438a8a7449f6c","remote-peer-id":"3931e8c7aea13672"} {"level":"info","ts":"2026-04-18T17:55:05.242787Z","caller":"rafthttp/stream.go:412","msg":"established TCP streaming connection with remote peer","stream-reader-type":"stream MsgApp v2","local-member-id":"d41438a8a7449f6c","remote-peer-id":"3931e8c7aea13672"} {"level":"info","ts":"2026-04-18T17:55:05.621706Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"d41438a8a7449f6c switched to configuration voters=(4121331078346651250 12125874831040253366 15281901732586889068)"} {"level":"info","ts":"2026-04-18T17:55:05.621863Z","caller":"membership/cluster.go:537","msg":"promote member","cluster-id":"2b11a68e27507b05","local-member-id":"d41438a8a7449f6c","promoted-member-id":"3931e8c7aea13672"} {"level":"info","ts":"2026-04-18T17:55:07.301564Z","caller":"traceutil/trace.go:171","msg":"trace[1722059883] transaction","detail":"{read_only:false; response_revision:732; number_of_response:1; }","duration":"102.147645ms","start":"2026-04-18T17:55:07.199384Z","end":"2026-04-18T17:55:07.301532Z","steps":["trace[1722059883] 'process raft request' (duration: 101.980204ms)"],"step_count":1} {"level":"info","ts":"2026-04-18T17:55:07.354141Z","caller":"traceutil/trace.go:171","msg":"trace[1547962501] linearizableReadLoop","detail":"{readStateIndex:795; appliedIndex:795; }","duration":"133.254363ms","start":"2026-04-18T17:55:07.220840Z","end":"2026-04-18T17:55:07.354095Z","steps":["trace[1547962501] 'read index received' (duration: 133.245343ms)","trace[1547962501] 'applied index is now lower than readState.Index' (duration: 6.56µs)"],"step_count":2} {"level":"warn","ts":"2026-04-18T17:55:07.362579Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"141.710104ms","expected-duration":"100ms","prefix":"read-only range ","request":"limit:1 keys_only:true ","response":"range_response_count:0 size:5"} {"level":"info","ts":"2026-04-18T17:55:07.362651Z","caller":"traceutil/trace.go:171","msg":"trace[1066818330] range","detail":"{range_begin:; range_end:; response_count:0; response_revision:732; }","duration":"141.800285ms","start":"2026-04-18T17:55:07.220833Z","end":"2026-04-18T17:55:07.362633Z","steps":["trace[1066818330] 'agreement among raft nodes before linearized reading' (duration: 133.396155ms)"],"step_count":1} {"level":"info","ts":"2026-04-18T17:55:24.858755Z","caller":"traceutil/trace.go:171","msg":"trace[1061437626] transaction","detail":"{read_only:false; response_revision:787; number_of_response:1; }","duration":"158.015566ms","start":"2026-04-18T17:55:24.700717Z","end":"2026-04-18T17:55:24.858732Z","steps":["trace[1061437626] 'process raft request' (duration: 89.739082ms)","trace[1061437626] 'compare' (duration: 68.120272ms)"],"step_count":2} {"level":"info","ts":"2026-04-18T17:55:27.207378Z","caller":"traceutil/trace.go:171","msg":"trace[567460846] linearizableReadLoop","detail":"{readStateIndex:878; appliedIndex:876; }","duration":"197.169804ms","start":"2026-04-18T17:55:27.010166Z","end":"2026-04-18T17:55:27.207336Z","steps":["trace[567460846] 'read index received' (duration: 196.752269ms)","trace[567460846] 'applied index is now lower than readState.Index' (duration: 416.525µs)"],"step_count":2} {"level":"warn","ts":"2026-04-18T17:55:27.207626Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"197.400826ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/health\" ","response":"range_response_count:0 size:5"} {"level":"info","ts":"2026-04-18T17:55:27.207701Z","caller":"traceutil/trace.go:171","msg":"trace[1583958433] range","detail":"{range_begin:/registry/health; range_end:; response_count:0; response_revision:804; }","duration":"197.57013ms","start":"2026-04-18T17:55:27.010109Z","end":"2026-04-18T17:55:27.207679Z","steps":["trace[1583958433] 'agreement among raft nodes before linearized reading' (duration: 197.381866ms)"],"step_count":1} {"level":"warn","ts":"2026-04-18T17:55:27.684211Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"236.439429ms","expected-duration":"100ms","prefix":"","request":"header: txn: success:> failure:<>>","response":"size:16"} {"level":"info","ts":"2026-04-18T17:55:27.684548Z","caller":"traceutil/trace.go:171","msg":"trace[1135123944] linearizableReadLoop","detail":"{readStateIndex:880; appliedIndex:879; }","duration":"464.619131ms","start":"2026-04-18T17:55:27.219841Z","end":"2026-04-18T17:55:27.684461Z","steps":["trace[1135123944] 'read index received' (duration: 228.370524ms)","trace[1135123944] 'applied index is now lower than readState.Index' (duration: 236.245317ms)"],"step_count":2} {"level":"warn","ts":"2026-04-18T17:55:27.684608Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"464.794143ms","expected-duration":"100ms","prefix":"read-only range ","request":"limit:1 keys_only:true ","response":"range_response_count:0 size:5"} {"level":"info","ts":"2026-04-18T17:55:27.684693Z","caller":"traceutil/trace.go:171","msg":"trace[1475424570] range","detail":"{range_begin:; range_end:; response_count:0; response_revision:806; }","duration":"464.874194ms","start":"2026-04-18T17:55:27.219789Z","end":"2026-04-18T17:55:27.684663Z","steps":["trace[1475424570] 'agreement among raft nodes before linearized reading' (duration: 464.773323ms)"],"step_count":1} {"level":"warn","ts":"2026-04-18T17:55:27.686664Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"461.613265ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/leases/kube-system/kube-controller-manager\" limit:1 ","response":"range_response_count:1 size:509"} {"level":"info","ts":"2026-04-18T17:55:27.686701Z","caller":"traceutil/trace.go:171","msg":"trace[293358065] range","detail":"{range_begin:/registry/leases/kube-system/kube-controller-manager; range_end:; response_count:1; response_revision:806; }","duration":"461.711337ms","start":"2026-04-18T17:55:27.224981Z","end":"2026-04-18T17:55:27.686693Z","steps":["trace[293358065] 'agreement among raft nodes before linearized reading' (duration: 461.647656ms)"],"step_count":1} {"level":"warn","ts":"2026-04-18T17:55:27.686727Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-04-18T17:55:27.224956Z","time spent":"461.765178ms","remote":"127.0.0.1:38214","response type":"/etcdserverpb.KV/Range","request count":0,"request size":56,"response count":1,"response size":532,"request content":"key:\"/registry/leases/kube-system/kube-controller-manager\" limit:1 "} {"level":"warn","ts":"2026-04-18T17:55:27.686966Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"418.660249ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/daemonsets/\" range_end:\"/registry/daemonsets0\" count_only:true ","response":"range_response_count:0 size:7"} {"level":"info","ts":"2026-04-18T17:55:27.687229Z","caller":"traceutil/trace.go:171","msg":"trace[632838207] range","detail":"{range_begin:/registry/daemonsets/; range_end:/registry/daemonsets0; response_count:0; response_revision:806; }","duration":"419.009403ms","start":"2026-04-18T17:55:27.268199Z","end":"2026-04-18T17:55:27.687209Z","steps":["trace[632838207] 'agreement among raft nodes before linearized reading' (duration: 418.638778ms)"],"step_count":1} {"level":"warn","ts":"2026-04-18T17:55:27.687707Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-04-18T17:55:27.268171Z","time spent":"419.513069ms","remote":"127.0.0.1:38390","response type":"/etcdserverpb.KV/Range","request count":0,"request size":48,"response count":1,"response size":30,"request content":"key:\"/registry/daemonsets/\" range_end:\"/registry/daemonsets0\" count_only:true "} {"level":"info","ts":"2026-04-18T17:55:28.199756Z","caller":"traceutil/trace.go:171","msg":"trace[1055269514] linearizableReadLoop","detail":"{readStateIndex:882; appliedIndex:883; }","duration":"153.360784ms","start":"2026-04-18T17:55:28.046367Z","end":"2026-04-18T17:55:28.199728Z","steps":["trace[1055269514] 'read index received' (duration: 153.355624ms)","trace[1055269514] 'applied index is now lower than readState.Index' (duration: 3.94µs)"],"step_count":2} {"level":"warn","ts":"2026-04-18T17:55:28.199922Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"153.533366ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/leases/kube-system/plndr-cp-lock\" limit:1 ","response":"range_response_count:1 size:436"} {"level":"info","ts":"2026-04-18T17:55:28.199957Z","caller":"traceutil/trace.go:171","msg":"trace[662512558] range","detail":"{range_begin:/registry/leases/kube-system/plndr-cp-lock; range_end:; response_count:1; response_revision:808; }","duration":"153.622657ms","start":"2026-04-18T17:55:28.046325Z","end":"2026-04-18T17:55:28.199948Z","steps":["trace[662512558] 'agreement among raft nodes before linearized reading' (duration: 153.509785ms)"],"step_count":1} {"level":"info","ts":"2026-04-18T17:55:28.200112Z","caller":"traceutil/trace.go:171","msg":"trace[724511790] transaction","detail":"{read_only:false; response_revision:809; number_of_response:1; }","duration":"256.193774ms","start":"2026-04-18T17:55:27.943888Z","end":"2026-04-18T17:55:28.200082Z","steps":["trace[724511790] 'process raft request' (duration: 256.090783ms)"],"step_count":1} {"level":"info","ts":"2026-04-18T17:55:55.222827Z","caller":"traceutil/trace.go:171","msg":"trace[737838777] linearizableReadLoop","detail":"{readStateIndex:1076; appliedIndex:1075; }","duration":"212.84483ms","start":"2026-04-18T17:55:55.009955Z","end":"2026-04-18T17:55:55.222800Z","steps":["trace[737838777] 'read index received' (duration: 140.922082ms)","trace[737838777] 'applied index is now lower than readState.Index' (duration: 71.921798ms)"],"step_count":2} {"level":"warn","ts":"2026-04-18T17:55:55.223174Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"213.143474ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/health\" ","response":"range_response_count:0 size:5"} {"level":"info","ts":"2026-04-18T17:55:55.223252Z","caller":"traceutil/trace.go:171","msg":"trace[117920584] range","detail":"{range_begin:/registry/health; range_end:; response_count:0; response_revision:981; }","duration":"213.343652ms","start":"2026-04-18T17:55:55.009891Z","end":"2026-04-18T17:55:55.223235Z","steps":["trace[117920584] 'agreement among raft nodes before linearized reading' (duration: 213.157934ms)"],"step_count":1} {"level":"info","ts":"2026-04-18T17:55:57.115446Z","caller":"traceutil/trace.go:171","msg":"trace[1478168223] linearizableReadLoop","detail":"{readStateIndex:1082; appliedIndex:1082; }","duration":"105.998957ms","start":"2026-04-18T17:55:57.009421Z","end":"2026-04-18T17:55:57.115420Z","steps":["trace[1478168223] 'read index received' (duration: 105.992827ms)","trace[1478168223] 'applied index is now lower than readState.Index' (duration: 5.02µs)"],"step_count":2} {"level":"warn","ts":"2026-04-18T17:55:57.115614Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"106.142673ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/health\" ","response":"range_response_count:0 size:5"} {"level":"info","ts":"2026-04-18T17:55:57.115672Z","caller":"traceutil/trace.go:171","msg":"trace[285660205] range","detail":"{range_begin:/registry/health; range_end:; response_count:0; response_revision:986; }","duration":"106.273719ms","start":"2026-04-18T17:55:57.009381Z","end":"2026-04-18T17:55:57.115655Z","steps":["trace[285660205] 'agreement among raft nodes before linearized reading' (duration: 106.144144ms)"],"step_count":1} {"level":"warn","ts":"2026-04-18T17:55:57.233801Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"116.965831ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/health\" ","response":"range_response_count:0 size:5"} {"level":"info","ts":"2026-04-18T17:55:57.233946Z","caller":"traceutil/trace.go:171","msg":"trace[1788890320] range","detail":"{range_begin:/registry/health; range_end:; response_count:0; response_revision:987; }","duration":"117.151669ms","start":"2026-04-18T17:55:57.116756Z","end":"2026-04-18T17:55:57.233908Z","steps":["trace[1788890320] 'agreement among raft nodes before linearized reading' (duration: 28.607322ms)","trace[1788890320] 'range keys from in-memory index tree' (duration: 88.352839ms)"],"step_count":2} {"level":"info","ts":"2026-04-18T17:56:05.911167Z","caller":"traceutil/trace.go:171","msg":"trace[439695180] transaction","detail":"{read_only:false; response_revision:1011; number_of_response:1; }","duration":"157.792109ms","start":"2026-04-18T17:56:05.753352Z","end":"2026-04-18T17:56:05.911144Z","steps":["trace[439695180] 'process raft request' (duration: 157.639373ms)"],"step_count":1} {"level":"warn","ts":"2026-04-18T17:56:07.668028Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"448.212871ms","expected-duration":"100ms","prefix":"read-only range ","request":"limit:1 serializable:true keys_only:true ","response":"range_response_count:0 size:5"} {"level":"warn","ts":"2026-04-18T17:56:07.668151Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"479.741162ms","expected-duration":"100ms","prefix":"","request":"header: txn: success:> failure:<>>","response":"size:16"} {"level":"info","ts":"2026-04-18T17:56:07.668153Z","caller":"traceutil/trace.go:171","msg":"trace[1218575891] range","detail":"{range_begin:; range_end:; response_count:0; response_revision:1016; }","duration":"448.349707ms","start":"2026-04-18T17:56:07.219784Z","end":"2026-04-18T17:56:07.668133Z","steps":["trace[1218575891] 'range keys from in-memory index tree' (duration: 448.169938ms)"],"step_count":1} {"level":"info","ts":"2026-04-18T17:56:07.668380Z","caller":"traceutil/trace.go:171","msg":"trace[1969713578] linearizableReadLoop","detail":"{readStateIndex:1118; appliedIndex:1117; }","duration":"496.963803ms","start":"2026-04-18T17:56:07.171405Z","end":"2026-04-18T17:56:07.668369Z","steps":["trace[1969713578] 'read index received' (duration: 488.427706ms)","trace[1969713578] 'applied index is now lower than readState.Index' (duration: 8.534977ms)"],"step_count":2} {"level":"warn","ts":"2026-04-18T17:56:07.668478Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"497.074368ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/leases/kube-system/plndr-cp-lock\" limit:1 ","response":"range_response_count:1 size:436"} {"level":"info","ts":"2026-04-18T17:56:07.668503Z","caller":"traceutil/trace.go:171","msg":"trace[1179039793] range","detail":"{range_begin:/registry/leases/kube-system/plndr-cp-lock; range_end:; response_count:1; response_revision:1018; }","duration":"497.128131ms","start":"2026-04-18T17:56:07.171368Z","end":"2026-04-18T17:56:07.668497Z","steps":["trace[1179039793] 'agreement among raft nodes before linearized reading' (duration: 497.081749ms)"],"step_count":1} {"level":"warn","ts":"2026-04-18T17:56:07.668527Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-04-18T17:56:07.171353Z","time spent":"497.167992ms","remote":"127.0.0.1:38214","response type":"/etcdserverpb.KV/Range","request count":0,"request size":46,"response count":1,"response size":459,"request content":"key:\"/registry/leases/kube-system/plndr-cp-lock\" limit:1 "} {"level":"warn","ts":"2026-04-18T17:56:07.670437Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"222.319045ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/leases/kube-system/plndr-svcs-lock\" limit:1 ","response":"range_response_count:1 size:441"} {"level":"info","ts":"2026-04-18T17:56:07.670486Z","caller":"traceutil/trace.go:171","msg":"trace[1050842138] range","detail":"{range_begin:/registry/leases/kube-system/plndr-svcs-lock; range_end:; response_count:1; response_revision:1019; }","duration":"222.42611ms","start":"2026-04-18T17:56:07.448047Z","end":"2026-04-18T17:56:07.670473Z","steps":["trace[1050842138] 'agreement among raft nodes before linearized reading' (duration: 222.350386ms)"],"step_count":1} {"level":"warn","ts":"2026-04-18T17:56:07.670566Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"201.920531ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/pods/\" range_end:\"/registry/pods0\" count_only:true ","response":"range_response_count:0 size:7"} {"level":"info","ts":"2026-04-18T17:56:07.670644Z","caller":"traceutil/trace.go:171","msg":"trace[1122150831] range","detail":"{range_begin:/registry/pods/; range_end:/registry/pods0; response_count:0; response_revision:1019; }","duration":"202.025605ms","start":"2026-04-18T17:56:07.468604Z","end":"2026-04-18T17:56:07.670629Z","steps":["trace[1122150831] 'agreement among raft nodes before linearized reading' (duration: 201.882209ms)"],"step_count":1} {"level":"warn","ts":"2026-04-18T17:56:10.513173Z","caller":"etcdserver/v3_server.go:920","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":11487730067459448677,"retry-timeout":"500ms"} {"level":"warn","ts":"2026-04-18T17:56:11.013619Z","caller":"etcdserver/v3_server.go:920","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":11487730067459448677,"retry-timeout":"500ms"} {"level":"warn","ts":"2026-04-18T17:56:11.514582Z","caller":"etcdserver/v3_server.go:920","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":11487730067459448677,"retry-timeout":"500ms"} {"level":"warn","ts":"2026-04-18T17:56:12.010229Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"1.998159304s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/health\" ","response":"","error":"context canceled"} {"level":"info","ts":"2026-04-18T17:56:12.010297Z","caller":"traceutil/trace.go:171","msg":"trace[272223105] range","detail":"{range_begin:/registry/health; range_end:; }","duration":"1.99830648s","start":"2026-04-18T17:56:10.011973Z","end":"2026-04-18T17:56:12.010280Z","steps":["trace[272223105] 'agreement among raft nodes before linearized reading' (duration: 1.998223185s)"],"step_count":1} {"level":"warn","ts":"2026-04-18T17:56:12.010359Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-04-18T17:56:10.011949Z","time spent":"1.998386603s","remote":"127.0.0.1:37964","response type":"/etcdserverpb.KV/Range","request count":0,"request size":18,"response count":0,"response size":0,"request content":"key:\"/registry/health\" "} 2026/04/18 17:56:12 WARNING: [core] [Server #8] grpc: Server.processUnaryRPC failed to write status: connection error: desc = "transport is closing" {"level":"warn","ts":"2026-04-18T17:56:12.015746Z","caller":"etcdserver/v3_server.go:920","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":11487730067459448677,"retry-timeout":"500ms"} {"level":"warn","ts":"2026-04-18T17:56:12.515938Z","caller":"etcdserver/v3_server.go:920","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":11487730067459448677,"retry-timeout":"500ms"} {"level":"warn","ts":"2026-04-18T17:56:12.801606Z","caller":"wal/wal.go:805","msg":"slow fdatasync","took":"1.993348597s","expected-duration":"1s"} {"level":"info","ts":"2026-04-18T17:56:12.802485Z","caller":"traceutil/trace.go:171","msg":"trace[1920039445] linearizableReadLoop","detail":"{readStateIndex:1171; appliedIndex:1171; }","duration":"2.79039692s","start":"2026-04-18T17:56:10.012046Z","end":"2026-04-18T17:56:12.802443Z","steps":["trace[1920039445] 'read index received' (duration: 2.790389859s)","trace[1920039445] 'applied index is now lower than readState.Index' (duration: 5.181µs)"],"step_count":2} {"level":"warn","ts":"2026-04-18T17:56:12.803516Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"1.858444089s","expected-duration":"100ms","prefix":"read-only range ","request":"limit:1 serializable:true keys_only:true ","response":"range_response_count:0 size:5"} {"level":"info","ts":"2026-04-18T17:56:12.803922Z","caller":"traceutil/trace.go:171","msg":"trace[405269241] range","detail":"{range_begin:; range_end:; response_count:0; response_revision:1066; }","duration":"1.858882847s","start":"2026-04-18T17:56:10.945016Z","end":"2026-04-18T17:56:12.803899Z","steps":["trace[405269241] 'range keys from in-memory index tree' (duration: 1.858374846s)"],"step_count":1} {"level":"warn","ts":"2026-04-18T17:56:12.804633Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"1.363320545s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/controllerrevisions/\" range_end:\"/registry/controllerrevisions0\" count_only:true ","response":"range_response_count:0 size:7"} {"level":"warn","ts":"2026-04-18T17:56:12.804639Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"2.625808026s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/leases/kube-system/plndr-svcs-lock\" limit:1 ","response":"range_response_count:1 size:441"} {"level":"info","ts":"2026-04-18T17:56:12.804704Z","caller":"traceutil/trace.go:171","msg":"trace[1689446875] range","detail":"{range_begin:/registry/controllerrevisions/; range_end:/registry/controllerrevisions0; response_count:0; response_revision:1068; }","duration":"1.363404139s","start":"2026-04-18T17:56:11.441282Z","end":"2026-04-18T17:56:12.804686Z","steps":["trace[1689446875] 'agreement among raft nodes before linearized reading' (duration: 1.363275843s)"],"step_count":1} {"level":"info","ts":"2026-04-18T17:56:12.804736Z","caller":"traceutil/trace.go:171","msg":"trace[699327204] range","detail":"{range_begin:/registry/leases/kube-system/plndr-svcs-lock; range_end:; response_count:1; response_revision:1068; }","duration":"2.625961783s","start":"2026-04-18T17:56:10.178752Z","end":"2026-04-18T17:56:12.804714Z","steps":["trace[699327204] 'agreement among raft nodes before linearized reading' (duration: 2.625761415s)"],"step_count":1} {"level":"warn","ts":"2026-04-18T17:56:12.804760Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-04-18T17:56:11.441228Z","time spent":"1.363520213s","remote":"127.0.0.1:38408","response type":"/etcdserverpb.KV/Range","request count":0,"request size":66,"response count":2,"response size":30,"request content":"key:\"/registry/controllerrevisions/\" range_end:\"/registry/controllerrevisions0\" count_only:true "} {"level":"warn","ts":"2026-04-18T17:56:12.804793Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-04-18T17:56:10.178728Z","time spent":"2.626055276s","remote":"127.0.0.1:38214","response type":"/etcdserverpb.KV/Range","request count":0,"request size":48,"response count":1,"response size":464,"request content":"key:\"/registry/leases/kube-system/plndr-svcs-lock\" limit:1 "} {"level":"warn","ts":"2026-04-18T17:56:12.804960Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"794.406915ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/health\" ","response":"range_response_count:0 size:5"} {"level":"warn","ts":"2026-04-18T17:56:12.805035Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"2.022933867s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/leases/kube-system/plndr-cp-lock\" limit:1 ","response":"range_response_count:1 size:436"} {"level":"warn","ts":"2026-04-18T17:56:12.805043Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"1.31695689s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/serviceaccounts/\" range_end:\"/registry/serviceaccounts0\" count_only:true ","response":"range_response_count:0 size:7"} {"level":"warn","ts":"2026-04-18T17:56:12.805060Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"272.008412ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/leases/kube-system/kube-scheduler\" limit:1 ","response":"range_response_count:1 size:482"} {"level":"info","ts":"2026-04-18T17:56:12.805091Z","caller":"traceutil/trace.go:171","msg":"trace[1896426890] range","detail":"{range_begin:/registry/leases/kube-system/plndr-cp-lock; range_end:; response_count:1; response_revision:1068; }","duration":"2.023040861s","start":"2026-04-18T17:56:10.782035Z","end":"2026-04-18T17:56:12.805076Z","steps":["trace[1896426890] 'agreement among raft nodes before linearized reading' (duration: 2.022943407s)"],"step_count":1} {"level":"info","ts":"2026-04-18T17:56:12.805086Z","caller":"traceutil/trace.go:171","msg":"trace[150324739] range","detail":"{range_begin:/registry/health; range_end:; response_count:0; response_revision:1068; }","duration":"794.609703ms","start":"2026-04-18T17:56:12.010442Z","end":"2026-04-18T17:56:12.805051Z","steps":["trace[150324739] 'agreement among raft nodes before linearized reading' (duration: 794.406245ms)"],"step_count":1} {"level":"info","ts":"2026-04-18T17:56:12.805111Z","caller":"traceutil/trace.go:171","msg":"trace[352277826] range","detail":"{range_begin:/registry/serviceaccounts/; range_end:/registry/serviceaccounts0; response_count:0; response_revision:1068; }","duration":"1.317099596s","start":"2026-04-18T17:56:11.487994Z","end":"2026-04-18T17:56:12.805094Z","steps":["trace[352277826] 'agreement among raft nodes before linearized reading' (duration: 1.316933819s)"],"step_count":1} {"level":"warn","ts":"2026-04-18T17:56:12.805132Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-04-18T17:56:10.782010Z","time spent":"2.023113894s","remote":"127.0.0.1:38214","response type":"/etcdserverpb.KV/Range","request count":0,"request size":46,"response count":1,"response size":459,"request content":"key:\"/registry/leases/kube-system/plndr-cp-lock\" limit:1 "} {"level":"warn","ts":"2026-04-18T17:56:12.805154Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-04-18T17:56:11.487975Z","time spent":"1.317169089s","remote":"127.0.0.1:38158","response type":"/etcdserverpb.KV/Range","request count":0,"request size":58,"response count":42,"response size":30,"request content":"key:\"/registry/serviceaccounts/\" range_end:\"/registry/serviceaccounts0\" count_only:true "} {"level":"info","ts":"2026-04-18T17:56:12.805152Z","caller":"traceutil/trace.go:171","msg":"trace[2018756773] range","detail":"{range_begin:/registry/leases/kube-system/kube-scheduler; range_end:; response_count:1; response_revision:1068; }","duration":"272.153959ms","start":"2026-04-18T17:56:12.532944Z","end":"2026-04-18T17:56:12.805098Z","steps":["trace[2018756773] 'agreement among raft nodes before linearized reading' (duration: 271.967712ms)"],"step_count":1} {"level":"warn","ts":"2026-04-18T17:56:12.805151Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-04-18T17:56:12.010408Z","time spent":"794.728768ms","remote":"127.0.0.1:37954","response type":"/etcdserverpb.KV/Range","request count":0,"request size":18,"response count":0,"response size":28,"request content":"key:\"/registry/health\" "} {"level":"warn","ts":"2026-04-18T17:56:12.805180Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"2.584917538s","expected-duration":"100ms","prefix":"read-only range ","request":"limit:1 keys_only:true ","response":"range_response_count:0 size:5"} {"level":"warn","ts":"2026-04-18T17:56:12.805192Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"1.802451687s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/leases/kube-system/kube-controller-manager\" limit:1 ","response":"range_response_count:1 size:509"} {"level":"info","ts":"2026-04-18T17:56:12.805234Z","caller":"traceutil/trace.go:171","msg":"trace[2042805769] range","detail":"{range_begin:; range_end:; response_count:0; response_revision:1068; }","duration":"2.58497465s","start":"2026-04-18T17:56:10.220245Z","end":"2026-04-18T17:56:12.805220Z","steps":["trace[2042805769] 'agreement among raft nodes before linearized reading' (duration: 2.584889847s)"],"step_count":1} {"level":"info","ts":"2026-04-18T17:56:12.805261Z","caller":"traceutil/trace.go:171","msg":"trace[1776493563] range","detail":"{range_begin:/registry/leases/kube-system/kube-controller-manager; range_end:; response_count:1; response_revision:1068; }","duration":"1.802580982s","start":"2026-04-18T17:56:11.002670Z","end":"2026-04-18T17:56:12.805251Z","steps":["trace[1776493563] 'agreement among raft nodes before linearized reading' (duration: 1.802478358s)"],"step_count":1} {"level":"warn","ts":"2026-04-18T17:56:12.805313Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-04-18T17:56:11.002639Z","time spent":"1.802665496s","remote":"127.0.0.1:38214","response type":"/etcdserverpb.KV/Range","request count":0,"request size":56,"response count":1,"response size":532,"request content":"key:\"/registry/leases/kube-system/kube-controller-manager\" limit:1 "} {"level":"info","ts":"2026-04-18T17:56:17.278326Z","caller":"traceutil/trace.go:171","msg":"trace[906518950] linearizableReadLoop","detail":"{readStateIndex:1352; appliedIndex:1352; }","duration":"405.781426ms","start":"2026-04-18T17:56:16.872517Z","end":"2026-04-18T17:56:17.278299Z","steps":["trace[906518950] 'read index received' (duration: 405.772446ms)","trace[906518950] 'applied index is now lower than readState.Index' (duration: 7.9µs)"],"step_count":2} {"level":"warn","ts":"2026-04-18T17:56:17.779119Z","caller":"etcdserver/v3_server.go:920","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":11487730067459448755,"retry-timeout":"500ms"} {"level":"warn","ts":"2026-04-18T17:56:18.279639Z","caller":"etcdserver/v3_server.go:920","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":11487730067459448755,"retry-timeout":"500ms"} {"level":"warn","ts":"2026-04-18T17:56:18.733664Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"1.861227194s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/limitranges/\" range_end:\"/registry/limitranges0\" count_only:true ","response":"range_response_count:0 size:5"} {"level":"info","ts":"2026-04-18T17:56:18.733751Z","caller":"traceutil/trace.go:171","msg":"trace[1625743026] range","detail":"{range_begin:/registry/limitranges/; range_end:/registry/limitranges0; response_count:0; response_revision:1163; }","duration":"1.86135204s","start":"2026-04-18T17:56:16.872380Z","end":"2026-04-18T17:56:18.733732Z","steps":["trace[1625743026] 'agreement among raft nodes before linearized reading' (duration: 406.080679ms)","trace[1625743026] 'count revisions from in-memory index tree' (duration: 1.455148196s)"],"step_count":2} {"level":"warn","ts":"2026-04-18T17:56:18.734200Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-04-18T17:56:16.872366Z","time spent":"1.861413362s","remote":"127.0.0.1:38092","response type":"/etcdserverpb.KV/Range","request count":0,"request size":50,"response count":0,"response size":28,"request content":"key:\"/registry/limitranges/\" range_end:\"/registry/limitranges0\" count_only:true "} {"level":"warn","ts":"2026-04-18T17:56:18.734949Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"1.456242079s","expected-duration":"100ms","prefix":"","request":"header: txn: success:> failure:<>>","response":"size:16"} {"level":"warn","ts":"2026-04-18T17:56:18.780084Z","caller":"etcdserver/v3_server.go:920","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":11487730067459448755,"retry-timeout":"500ms"} {"level":"info","ts":"2026-04-18T17:56:18.873948Z","caller":"traceutil/trace.go:171","msg":"trace[930061341] linearizableReadLoop","detail":"{readStateIndex:1354; appliedIndex:1354; }","duration":"1.595495911s","start":"2026-04-18T17:56:17.278401Z","end":"2026-04-18T17:56:18.873897Z","steps":["trace[930061341] 'read index received' (duration: 1.59548399s)","trace[930061341] 'applied index is now lower than readState.Index' (duration: 9.471µs)"],"step_count":2} {"level":"warn","ts":"2026-04-18T17:56:19.004012Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"1.994548447s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/health\" ","response":"range_response_count:0 size:5"} {"level":"warn","ts":"2026-04-18T17:56:19.004090Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"1.783877923s","expected-duration":"100ms","prefix":"read-only range ","request":"limit:1 keys_only:true ","response":"range_response_count:0 size:5"} {"level":"info","ts":"2026-04-18T17:56:19.004164Z","caller":"traceutil/trace.go:171","msg":"trace[1986239428] range","detail":"{range_begin:/registry/health; range_end:; response_count:0; response_revision:1165; }","duration":"1.994762275s","start":"2026-04-18T17:56:17.009345Z","end":"2026-04-18T17:56:19.004108Z","steps":["trace[1986239428] 'agreement among raft nodes before linearized reading' (duration: 1.864701439s)","trace[1986239428] 'range keys from in-memory index tree' (duration: 129.851468ms)"],"step_count":2} {"level":"warn","ts":"2026-04-18T17:56:19.004228Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-04-18T17:56:17.009315Z","time spent":"1.994903212s","remote":"127.0.0.1:37964","response type":"/etcdserverpb.KV/Range","request count":0,"request size":18,"response count":0,"response size":28,"request content":"key:\"/registry/health\" "} {"level":"info","ts":"2026-04-18T17:56:19.004268Z","caller":"traceutil/trace.go:171","msg":"trace[986596561] range","detail":"{range_begin:; range_end:; response_count:0; response_revision:1165; }","duration":"1.784019278s","start":"2026-04-18T17:56:17.220154Z","end":"2026-04-18T17:56:19.004173Z","steps":["trace[986596561] 'agreement among raft nodes before linearized reading' (duration: 1.653832686s)","trace[986596561] 'range keys from in-memory index tree' (duration: 129.993144ms)"],"step_count":2} {"level":"warn","ts":"2026-04-18T17:56:19.158459Z","caller":"etcdserver/v3_server.go:897","msg":"ignored out-of-date read index response; local node read indexes queueing up and waiting to be in sync with leader","sent-request-id":11487730067459448756,"received-request-id":11487730067459448755} {"level":"warn","ts":"2026-04-18T17:56:19.212565Z","caller":"etcdserver/v3_server.go:897","msg":"ignored out-of-date read index response; local node read indexes queueing up and waiting to be in sync with leader","sent-request-id":11487730067459448756,"received-request-id":11487730067459448755} {"level":"info","ts":"2026-04-18T17:56:19.219309Z","caller":"traceutil/trace.go:171","msg":"trace[833366486] linearizableReadLoop","detail":"{readStateIndex:1359; appliedIndex:1357; }","duration":"345.189034ms","start":"2026-04-18T17:56:18.874051Z","end":"2026-04-18T17:56:19.219240Z","steps":["trace[833366486] 'read index received' (duration: 344.205215ms)","trace[833366486] 'applied index is now lower than readState.Index' (duration: 981.199µs)"],"step_count":2} {"level":"warn","ts":"2026-04-18T17:56:19.219666Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"1.096289086s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/poddisruptionbudgets/\" range_end:\"/registry/poddisruptionbudgets0\" count_only:true ","response":"range_response_count:0 size:5"} {"level":"info","ts":"2026-04-18T17:56:19.219756Z","caller":"traceutil/trace.go:171","msg":"trace[523326828] range","detail":"{range_begin:/registry/poddisruptionbudgets/; range_end:/registry/poddisruptionbudgets0; response_count:0; response_revision:1169; }","duration":"1.096439921s","start":"2026-04-18T17:56:18.123302Z","end":"2026-04-18T17:56:19.219742Z","steps":["trace[523326828] 'agreement among raft nodes before linearized reading' (duration: 1.096210412s)"],"step_count":1} {"level":"warn","ts":"2026-04-18T17:56:19.219821Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-04-18T17:56:18.123280Z","time spent":"1.096529315s","remote":"127.0.0.1:38260","response type":"/etcdserverpb.KV/Range","request count":0,"request size":68,"response count":0,"response size":28,"request content":"key:\"/registry/poddisruptionbudgets/\" range_end:\"/registry/poddisruptionbudgets0\" count_only:true "} {"level":"warn","ts":"2026-04-18T17:56:19.220207Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"886.56427ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/leases/kube-system/kube-controller-manager\" limit:1 ","response":"range_response_count:1 size:509"} {"level":"info","ts":"2026-04-18T17:56:19.220318Z","caller":"traceutil/trace.go:171","msg":"trace[340753415] range","detail":"{range_begin:/registry/leases/kube-system/kube-controller-manager; range_end:; response_count:1; response_revision:1168; }","duration":"887.07429ms","start":"2026-04-18T17:56:18.333220Z","end":"2026-04-18T17:56:19.220294Z","steps":["trace[340753415] 'agreement among raft nodes before linearized reading' (duration: 886.085551ms)"],"step_count":1} {"level":"warn","ts":"2026-04-18T17:56:19.220372Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-04-18T17:56:18.333200Z","time spent":"887.157762ms","remote":"127.0.0.1:38214","response type":"/etcdserverpb.KV/Range","request count":0,"request size":56,"response count":1,"response size":532,"request content":"key:\"/registry/leases/kube-system/kube-controller-manager\" limit:1 "} {"level":"info","ts":"2026-04-18T17:56:19.221195Z","caller":"traceutil/trace.go:171","msg":"trace[462494276] transaction","detail":"{read_only:false; response_revision:1171; number_of_response:1; }","duration":"176.195442ms","start":"2026-04-18T17:56:19.044982Z","end":"2026-04-18T17:56:19.221178Z","steps":["trace[462494276] 'process raft request' (duration: 174.955633ms)"],"step_count":1} {"level":"warn","ts":"2026-04-18T17:56:19.223293Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"217.580074ms","expected-duration":"100ms","prefix":"read-only range ","request":"limit:1 keys_only:true ","response":"range_response_count:0 size:5"} {"level":"info","ts":"2026-04-18T17:56:19.223396Z","caller":"traceutil/trace.go:171","msg":"trace[305005873] range","detail":"{range_begin:; range_end:; response_count:0; response_revision:1171; }","duration":"217.691848ms","start":"2026-04-18T17:56:19.005677Z","end":"2026-04-18T17:56:19.223369Z","steps":["trace[305005873] 'agreement among raft nodes before linearized reading' (duration: 217.551162ms)"],"step_count":1} {"level":"warn","ts":"2026-04-18T17:56:19.224074Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"217.641378ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/health\" ","response":"range_response_count:0 size:5"} {"level":"info","ts":"2026-04-18T17:56:19.224139Z","caller":"traceutil/trace.go:171","msg":"trace[1864085685] range","detail":"{range_begin:/registry/health; range_end:; response_count:0; response_revision:1171; }","duration":"217.839476ms","start":"2026-04-18T17:56:19.006290Z","end":"2026-04-18T17:56:19.224130Z","steps":["trace[1864085685] 'agreement among raft nodes before linearized reading' (duration: 216.95273ms)"],"step_count":1} {"level":"warn","ts":"2026-04-18T17:56:20.089678Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"416.872211ms","expected-duration":"100ms","prefix":"","request":"header: lease_revoke:","response":"size:28"} {"level":"info","ts":"2026-04-18T17:56:20.425011Z","caller":"traceutil/trace.go:171","msg":"trace[652156669] linearizableReadLoop","detail":"{readStateIndex:1364; appliedIndex:1364; }","duration":"414.993574ms","start":"2026-04-18T17:56:20.009975Z","end":"2026-04-18T17:56:20.424969Z","steps":["trace[652156669] 'read index received' (duration: 414.981353ms)","trace[652156669] 'applied index is now lower than readState.Index' (duration: 8.991µs)"],"step_count":2} {"level":"warn","ts":"2026-04-18T17:56:20.425442Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"415.38342ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/health\" ","response":"range_response_count:0 size:5"} {"level":"info","ts":"2026-04-18T17:56:20.425927Z","caller":"traceutil/trace.go:171","msg":"trace[1988177583] range","detail":"{range_begin:/registry/health; range_end:; response_count:0; response_revision:1173; }","duration":"415.690091ms","start":"2026-04-18T17:56:20.009924Z","end":"2026-04-18T17:56:20.425614Z","steps":["trace[1988177583] 'agreement among raft nodes before linearized reading' (duration: 415.190572ms)"],"step_count":1} {"level":"warn","ts":"2026-04-18T17:56:20.426087Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-04-18T17:56:20.009903Z","time spent":"416.131179ms","remote":"127.0.0.1:37954","response type":"/etcdserverpb.KV/Range","request count":0,"request size":18,"response count":0,"response size":28,"request content":"key:\"/registry/health\" "} {"level":"warn","ts":"2026-04-18T17:56:20.432256Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"265.3548ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/leases/kube-system/kube-scheduler\" limit:1 ","response":"range_response_count:1 size:482"} {"level":"info","ts":"2026-04-18T17:56:20.432354Z","caller":"traceutil/trace.go:171","msg":"trace[1124271145] range","detail":"{range_begin:/registry/leases/kube-system/kube-scheduler; range_end:; response_count:1; response_revision:1175; }","duration":"265.509595ms","start":"2026-04-18T17:56:20.166821Z","end":"2026-04-18T17:56:20.432331Z","steps":["trace[1124271145] 'agreement among raft nodes before linearized reading' (duration: 265.223834ms)"],"step_count":1} {"level":"warn","ts":"2026-04-18T17:56:20.432955Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"119.254804ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/leases/kube-system/plndr-cp-lock\" limit:1 ","response":"range_response_count:1 size:436"} {"level":"warn","ts":"2026-04-18T17:56:20.432987Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"216.274732ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/controllers/\" range_end:\"/registry/controllers0\" count_only:true ","response":"range_response_count:0 size:5"} {"level":"info","ts":"2026-04-18T17:56:20.433053Z","caller":"traceutil/trace.go:171","msg":"trace[923138513] range","detail":"{range_begin:/registry/controllers/; range_end:/registry/controllers0; response_count:0; response_revision:1175; }","duration":"216.400596ms","start":"2026-04-18T17:56:20.216627Z","end":"2026-04-18T17:56:20.433027Z","steps":["trace[923138513] 'agreement among raft nodes before linearized reading' (duration: 216.250981ms)"],"step_count":1} {"level":"warn","ts":"2026-04-18T17:56:20.433072Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"212.562297ms","expected-duration":"100ms","prefix":"read-only range ","request":"limit:1 keys_only:true ","response":"range_response_count:0 size:5"} {"level":"warn","ts":"2026-04-18T17:56:20.433113Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"218.932416ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/leases/kube-system/plndr-svcs-lock\" limit:1 ","response":"range_response_count:1 size:441"} {"level":"info","ts":"2026-04-18T17:56:20.433198Z","caller":"traceutil/trace.go:171","msg":"trace[1203409700] range","detail":"{range_begin:; range_end:; response_count:0; response_revision:1175; }","duration":"212.682401ms","start":"2026-04-18T17:56:20.220473Z","end":"2026-04-18T17:56:20.433156Z","steps":["trace[1203409700] 'agreement among raft nodes before linearized reading' (duration: 212.509355ms)"],"step_count":1} {"level":"info","ts":"2026-04-18T17:56:20.433231Z","caller":"traceutil/trace.go:171","msg":"trace[2014948667] range","detail":"{range_begin:/registry/leases/kube-system/plndr-svcs-lock; range_end:; response_count:1; response_revision:1175; }","duration":"219.093052ms","start":"2026-04-18T17:56:20.214106Z","end":"2026-04-18T17:56:20.433199Z","steps":["trace[2014948667] 'agreement among raft nodes before linearized reading' (duration: 218.867683ms)"],"step_count":1} {"level":"info","ts":"2026-04-18T17:56:20.433968Z","caller":"traceutil/trace.go:171","msg":"trace[338724497] range","detail":"{range_begin:/registry/leases/kube-system/plndr-cp-lock; range_end:; response_count:1; response_revision:1175; }","duration":"119.381739ms","start":"2026-04-18T17:56:20.313623Z","end":"2026-04-18T17:56:20.433004Z","steps":["trace[338724497] 'agreement among raft nodes before linearized reading' (duration: 119.261254ms)"],"step_count":1} {"level":"warn","ts":"2026-04-18T17:56:21.227290Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"282.708626ms","expected-duration":"100ms","prefix":"read-only range ","request":"limit:1 serializable:true keys_only:true ","response":"range_response_count:0 size:5"} {"level":"warn","ts":"2026-04-18T17:56:21.227427Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"219.573718ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/health\" ","response":"range_response_count:0 size:5"} {"level":"info","ts":"2026-04-18T17:56:21.227490Z","caller":"traceutil/trace.go:171","msg":"trace[1853264684] range","detail":"{range_begin:/registry/health; range_end:; response_count:0; response_revision:1176; }","duration":"219.673482ms","start":"2026-04-18T17:56:21.007800Z","end":"2026-04-18T17:56:21.227474Z","steps":["trace[1853264684] 'range keys from in-memory index tree' (duration: 217.884223ms)"],"step_count":1} {"level":"info","ts":"2026-04-18T17:56:21.227403Z","caller":"traceutil/trace.go:171","msg":"trace[692859999] range","detail":"{range_begin:; range_end:; response_count:0; response_revision:1176; }","duration":"282.835401ms","start":"2026-04-18T17:56:20.944541Z","end":"2026-04-18T17:56:21.227376Z","steps":["trace[692859999] 'range keys from in-memory index tree' (duration: 282.642714ms)"],"step_count":1} {"level":"info","ts":"2026-04-18T17:56:21.464233Z","caller":"traceutil/trace.go:171","msg":"trace[1226220635] linearizableReadLoop","detail":"{readStateIndex:1369; appliedIndex:1368; }","duration":"243.617029ms","start":"2026-04-18T17:56:21.220586Z","end":"2026-04-18T17:56:21.464203Z","steps":["trace[1226220635] 'read index received' (duration: 242.500006ms)","trace[1226220635] 'applied index is now lower than readState.Index' (duration: 1.115353ms)"],"step_count":2} {"level":"warn","ts":"2026-04-18T17:56:21.464612Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"244.028575ms","expected-duration":"100ms","prefix":"read-only range ","request":"limit:1 keys_only:true ","response":"range_response_count:0 size:5"} {"level":"info","ts":"2026-04-18T17:56:21.464650Z","caller":"traceutil/trace.go:171","msg":"trace[1923299338] range","detail":"{range_begin:; range_end:; response_count:0; response_revision:1178; }","duration":"244.093767ms","start":"2026-04-18T17:56:21.220547Z","end":"2026-04-18T17:56:21.464641Z","steps":["trace[1923299338] 'agreement among raft nodes before linearized reading' (duration: 243.795195ms)"],"step_count":1} {"level":"warn","ts":"2026-04-18T17:56:21.965038Z","caller":"etcdserver/v3_server.go:920","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":11487730067459448765,"retry-timeout":"500ms"} {"level":"info","ts":"2026-04-18T17:56:22.337423Z","caller":"traceutil/trace.go:171","msg":"trace[801629120] linearizableReadLoop","detail":"{readStateIndex:1370; appliedIndex:1370; }","duration":"873.061187ms","start":"2026-04-18T17:56:21.464318Z","end":"2026-04-18T17:56:22.337379Z","steps":["trace[801629120] 'read index received' (duration: 873.050177ms)","trace[801629120] 'applied index is now lower than readState.Index' (duration: 9.42µs)"],"step_count":2} {"level":"warn","ts":"2026-04-18T17:56:22.538818Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"1.309302914s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/health\" ","response":"range_response_count:0 size:5"} {"level":"info","ts":"2026-04-18T17:56:22.538887Z","caller":"traceutil/trace.go:171","msg":"trace[611639506] range","detail":"{range_begin:/registry/health; range_end:; response_count:0; response_revision:1178; }","duration":"1.309397358s","start":"2026-04-18T17:56:21.229470Z","end":"2026-04-18T17:56:22.538868Z","steps":["trace[611639506] 'agreement among raft nodes before linearized reading' (duration: 1.108018448s)","trace[611639506] 'range keys from in-memory index tree' (duration: 201.270126ms)"],"step_count":2} {"level":"warn","ts":"2026-04-18T17:56:22.538915Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-04-18T17:56:21.229425Z","time spent":"1.309484652s","remote":"127.0.0.1:37954","response type":"/etcdserverpb.KV/Range","request count":0,"request size":18,"response count":0,"response size":28,"request content":"key:\"/registry/health\" "} {"level":"warn","ts":"2026-04-18T17:56:22.838698Z","caller":"etcdserver/v3_server.go:920","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":11487730067459448766,"retry-timeout":"500ms"} {"level":"info","ts":"2026-04-18T17:56:23.149802Z","caller":"traceutil/trace.go:171","msg":"trace[930946751] linearizableReadLoop","detail":"{readStateIndex:1372; appliedIndex:1374; }","duration":"812.228631ms","start":"2026-04-18T17:56:22.337533Z","end":"2026-04-18T17:56:23.149762Z","steps":["trace[930946751] 'read index received' (duration: 812.21807ms)","trace[930946751] 'applied index is now lower than readState.Index' (duration: 8.781µs)"],"step_count":2} {"level":"warn","ts":"2026-04-18T17:56:23.153951Z","caller":"etcdserver/v3_server.go:897","msg":"ignored out-of-date read index response; local node read indexes queueing up and waiting to be in sync with leader","sent-request-id":11487730067459448767,"received-request-id":11487730067459448766} {"level":"warn","ts":"2026-04-18T17:56:23.302937Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"1.188081705s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/leases/kube-system/kube-controller-manager\" limit:1 ","response":"range_response_count:1 size:509"} {"level":"info","ts":"2026-04-18T17:56:23.303065Z","caller":"traceutil/trace.go:171","msg":"trace[1771846213] range","detail":"{range_begin:/registry/leases/kube-system/kube-controller-manager; range_end:; response_count:1; response_revision:1182; }","duration":"1.188307554s","start":"2026-04-18T17:56:22.114725Z","end":"2026-04-18T17:56:23.303032Z","steps":["trace[1771846213] 'agreement among raft nodes before linearized reading' (duration: 1.035296454s)","trace[1771846213] 'range keys from in-memory index tree' (duration: 152.796672ms)"],"step_count":2} {"level":"warn","ts":"2026-04-18T17:56:23.303049Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"1.083079343s","expected-duration":"100ms","prefix":"read-only range ","request":"limit:1 keys_only:true ","response":"range_response_count:0 size:5"} {"level":"warn","ts":"2026-04-18T17:56:23.303130Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-04-18T17:56:22.114697Z","time spent":"1.188420619s","remote":"127.0.0.1:38214","response type":"/etcdserverpb.KV/Range","request count":0,"request size":56,"response count":1,"response size":532,"request content":"key:\"/registry/leases/kube-system/kube-controller-manager\" limit:1 "} {"level":"info","ts":"2026-04-18T17:56:23.303151Z","caller":"traceutil/trace.go:171","msg":"trace[158784769] range","detail":"{range_begin:; range_end:; response_count:0; response_revision:1182; }","duration":"1.083178856s","start":"2026-04-18T17:56:22.219934Z","end":"2026-04-18T17:56:23.303113Z","steps":["trace[158784769] 'agreement among raft nodes before linearized reading' (duration: 930.000829ms)","trace[158784769] 'range keys from in-memory index tree' (duration: 153.061452ms)"],"step_count":2} {"level":"warn","ts":"2026-04-18T17:56:23.553305Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"399.236957ms","expected-duration":"100ms","prefix":"","request":"header: lease_revoke:","response":"size:28"} {"level":"info","ts":"2026-04-18T17:56:23.553421Z","caller":"traceutil/trace.go:171","msg":"trace[980461495] linearizableReadLoop","detail":"{readStateIndex:1375; appliedIndex:1374; }","duration":"403.499172ms","start":"2026-04-18T17:56:23.149904Z","end":"2026-04-18T17:56:23.553403Z","steps":["trace[980461495] 'read index received' (duration: 5.000894ms)","trace[980461495] 'applied index is now lower than readState.Index' (duration: 398.496518ms)"],"step_count":2} {"level":"warn","ts":"2026-04-18T17:56:23.553805Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"507.753874ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/clusterroles/\" range_end:\"/registry/clusterroles0\" count_only:true ","response":"range_response_count:0 size:7"} {"level":"info","ts":"2026-04-18T17:56:23.553850Z","caller":"traceutil/trace.go:171","msg":"trace[51190640] range","detail":"{range_begin:/registry/clusterroles/; range_end:/registry/clusterroles0; response_count:0; response_revision:1182; }","duration":"507.879929ms","start":"2026-04-18T17:56:23.045960Z","end":"2026-04-18T17:56:23.553840Z","steps":["trace[51190640] 'agreement among raft nodes before linearized reading' (duration: 507.757045ms)"],"step_count":1} {"level":"warn","ts":"2026-04-18T17:56:23.553888Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-04-18T17:56:23.045931Z","time spent":"507.944842ms","remote":"127.0.0.1:38280","response type":"/etcdserverpb.KV/Range","request count":0,"request size":52,"response count":70,"response size":30,"request content":"key:\"/registry/clusterroles/\" range_end:\"/registry/clusterroles0\" count_only:true "} {"level":"warn","ts":"2026-04-18T17:56:23.553909Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"1.004213248s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/health\" ","response":"range_response_count:0 size:5"} {"level":"info","ts":"2026-04-18T17:56:23.553998Z","caller":"traceutil/trace.go:171","msg":"trace[1051555052] range","detail":"{range_begin:/registry/health; range_end:; response_count:0; response_revision:1182; }","duration":"1.004378985s","start":"2026-04-18T17:56:22.549598Z","end":"2026-04-18T17:56:23.553976Z","steps":["trace[1051555052] 'agreement among raft nodes before linearized reading' (duration: 1.004207618s)"],"step_count":1} {"level":"warn","ts":"2026-04-18T17:56:23.553998Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"573.254583ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/leases/kube-system/plndr-svcs-lock\" limit:1 ","response":"range_response_count:1 size:440"} {"level":"info","ts":"2026-04-18T17:56:23.554157Z","caller":"traceutil/trace.go:171","msg":"trace[462267866] range","detail":"{range_begin:/registry/leases/kube-system/plndr-svcs-lock; range_end:; response_count:1; response_revision:1182; }","duration":"573.485532ms","start":"2026-04-18T17:56:22.980635Z","end":"2026-04-18T17:56:23.554120Z","steps":["trace[462267866] 'agreement among raft nodes before linearized reading' (duration: 573.17605ms)"],"step_count":1} {"level":"warn","ts":"2026-04-18T17:56:23.554235Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-04-18T17:56:22.980611Z","time spent":"573.613087ms","remote":"127.0.0.1:38214","response type":"/etcdserverpb.KV/Range","request count":0,"request size":48,"response count":1,"response size":463,"request content":"key:\"/registry/leases/kube-system/plndr-svcs-lock\" limit:1 "} {"level":"warn","ts":"2026-04-18T17:56:23.554065Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-04-18T17:56:22.549578Z","time spent":"1.004473719s","remote":"127.0.0.1:37964","response type":"/etcdserverpb.KV/Range","request count":0,"request size":18,"response count":0,"response size":28,"request content":"key:\"/registry/health\" "} {"level":"warn","ts":"2026-04-18T17:56:24.053578Z","caller":"etcdserver/v3_server.go:920","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":11487730067459448768,"retry-timeout":"500ms"} {"level":"warn","ts":"2026-04-18T17:56:24.554523Z","caller":"etcdserver/v3_server.go:920","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":11487730067459448768,"retry-timeout":"500ms"} {"level":"warn","ts":"2026-04-18T17:56:25.054978Z","caller":"etcdserver/v3_server.go:920","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":11487730067459448768,"retry-timeout":"500ms"} {"level":"warn","ts":"2026-04-18T17:56:25.555376Z","caller":"etcdserver/v3_server.go:920","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":11487730067459448768,"retry-timeout":"500ms"} {"level":"warn","ts":"2026-04-18T17:56:25.556623Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"2.000050428s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/health\" ","response":"","error":"context deadline exceeded"} {"level":"info","ts":"2026-04-18T17:56:25.556735Z","caller":"traceutil/trace.go:171","msg":"trace[1659305392] range","detail":"{range_begin:/registry/health; range_end:; }","duration":"2.000224525s","start":"2026-04-18T17:56:23.556488Z","end":"2026-04-18T17:56:25.556712Z","steps":["trace[1659305392] 'agreement among raft nodes before linearized reading' (duration: 2.00010006s)"],"step_count":1} {"level":"warn","ts":"2026-04-18T17:56:25.556788Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-04-18T17:56:23.556438Z","time spent":"2.000340539s","remote":"127.0.0.1:37954","response type":"/etcdserverpb.KV/Range","request count":0,"request size":18,"response count":0,"response size":0,"request content":"key:\"/registry/health\" "} {"level":"warn","ts":"2026-04-18T17:56:25.608800Z","caller":"wal/wal.go:805","msg":"slow fdatasync","took":"1.556751587s","expected-duration":"1s"} {"level":"warn","ts":"2026-04-18T17:56:26.056308Z","caller":"etcdserver/v3_server.go:920","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":11487730067459448768,"retry-timeout":"500ms"} {"level":"warn","ts":"2026-04-18T17:56:26.557097Z","caller":"etcdserver/v3_server.go:920","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":11487730067459448768,"retry-timeout":"500ms"} {"level":"info","ts":"2026-04-18T17:56:26.829609Z","caller":"traceutil/trace.go:171","msg":"trace[1263242716] linearizableReadLoop","detail":"{readStateIndex:1377; appliedIndex:1377; }","duration":"3.276137461s","start":"2026-04-18T17:56:23.553449Z","end":"2026-04-18T17:56:26.829586Z","steps":["trace[1263242716] 'read index received' (duration: 3.276131651s)","trace[1263242716] 'applied index is now lower than readState.Index' (duration: 4.86µs)"],"step_count":2} {"level":"warn","ts":"2026-04-18T17:56:26.829720Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"3.496011387s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/leases/kube-system/kube-scheduler\" limit:1 ","response":"range_response_count:1 size:482"} {"level":"warn","ts":"2026-04-18T17:56:26.829768Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"3.524954207s","expected-duration":"100ms","prefix":"read-only range ","request":"limit:1 keys_only:true ","response":"range_response_count:0 size:5"} {"level":"info","ts":"2026-04-18T17:56:26.829794Z","caller":"traceutil/trace.go:171","msg":"trace[1422098187] range","detail":"{range_begin:; range_end:; response_count:0; response_revision:1184; }","duration":"3.525001881s","start":"2026-04-18T17:56:23.304785Z","end":"2026-04-18T17:56:26.829786Z","steps":["trace[1422098187] 'agreement among raft nodes before linearized reading' (duration: 3.524936607s)"],"step_count":1} {"level":"info","ts":"2026-04-18T17:56:26.829786Z","caller":"traceutil/trace.go:171","msg":"trace[1670417168] range","detail":"{range_begin:/registry/leases/kube-system/kube-scheduler; range_end:; response_count:1; response_revision:1184; }","duration":"3.496121051s","start":"2026-04-18T17:56:23.333647Z","end":"2026-04-18T17:56:26.829768Z","steps":["trace[1670417168] 'agreement among raft nodes before linearized reading' (duration: 3.495981136s)"],"step_count":1} {"level":"warn","ts":"2026-04-18T17:56:26.829827Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-04-18T17:56:23.333625Z","time spent":"3.496192875s","remote":"127.0.0.1:38214","response type":"/etcdserverpb.KV/Range","request count":0,"request size":47,"response count":1,"response size":505,"request content":"key:\"/registry/leases/kube-system/kube-scheduler\" limit:1 "} {"level":"warn","ts":"2026-04-18T17:56:26.937913Z","caller":"etcdserver/v3_server.go:897","msg":"ignored out-of-date read index response; local node read indexes queueing up and waiting to be in sync with leader","sent-request-id":11487730067459448770,"received-request-id":11487730067459448768} {"level":"info","ts":"2026-04-18T17:56:26.939170Z","caller":"traceutil/trace.go:171","msg":"trace[1176455259] transaction","detail":"{read_only:false; response_revision:1189; number_of_response:1; }","duration":"679.192849ms","start":"2026-04-18T17:56:26.259952Z","end":"2026-04-18T17:56:26.939144Z","steps":["trace[1176455259] 'process raft request' (duration: 678.815204ms)"],"step_count":1} {"level":"warn","ts":"2026-04-18T17:56:26.939475Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-04-18T17:56:26.259916Z","time spent":"679.306393ms","remote":"127.0.0.1:38214","response type":"/etcdserverpb.KV/Txn","request count":1,"request size":676,"response count":0,"response size":39,"request content":"compare: success:> failure: >"} {"level":"info","ts":"2026-04-18T17:56:27.285838Z","caller":"traceutil/trace.go:171","msg":"trace[937959288] linearizableReadLoop","detail":"{readStateIndex:1382; appliedIndex:1382; }","duration":"456.135493ms","start":"2026-04-18T17:56:26.829672Z","end":"2026-04-18T17:56:27.285807Z","steps":["trace[937959288] 'read index received' (duration: 456.121942ms)","trace[937959288] 'applied index is now lower than readState.Index' (duration: 12.031µs)"],"step_count":2} {"level":"warn","ts":"2026-04-18T17:56:27.296156Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"925.945076ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/servicecidrs/\" range_end:\"/registry/servicecidrs0\" count_only:true ","response":"range_response_count:0 size:7"} {"level":"warn","ts":"2026-04-18T17:56:27.296200Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"1.73060506s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/events/kube-system/kube-apiserver-controller-2.18a785253148a1d5\" limit:1 ","response":"range_response_count:1 size:794"} {"level":"info","ts":"2026-04-18T17:56:27.296243Z","caller":"traceutil/trace.go:171","msg":"trace[2013061883] range","detail":"{range_begin:/registry/servicecidrs/; range_end:/registry/servicecidrs0; response_count:0; response_revision:1189; }","duration":"926.118922ms","start":"2026-04-18T17:56:26.370102Z","end":"2026-04-18T17:56:27.296221Z","steps":["trace[2013061883] 'agreement among raft nodes before linearized reading' (duration: 915.826921ms)"],"step_count":1} {"level":"info","ts":"2026-04-18T17:56:27.296259Z","caller":"traceutil/trace.go:171","msg":"trace[1060786673] range","detail":"{range_begin:/registry/events/kube-system/kube-apiserver-controller-2.18a785253148a1d5; range_end:; response_count:1; response_revision:1189; }","duration":"1.730677102s","start":"2026-04-18T17:56:25.565555Z","end":"2026-04-18T17:56:27.296233Z","steps":["trace[1060786673] 'agreement among raft nodes before linearized reading' (duration: 1.720413122s)"],"step_count":1} {"level":"warn","ts":"2026-04-18T17:56:27.296229Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"3.059280843s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/leases/kube-system/plndr-cp-lock\" limit:1 ","response":"range_response_count:1 size:436"} {"level":"warn","ts":"2026-04-18T17:56:27.296254Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"2.971493273s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/masterleases/199.19.213.57\" limit:1 ","response":"range_response_count:1 size:133"} {"level":"warn","ts":"2026-04-18T17:56:27.296298Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-04-18T17:56:26.370060Z","time spent":"926.227307ms","remote":"127.0.0.1:38256","response type":"/etcdserverpb.KV/Range","request count":0,"request size":52,"response count":1,"response size":30,"request content":"key:\"/registry/servicecidrs/\" range_end:\"/registry/servicecidrs0\" count_only:true "} {"level":"warn","ts":"2026-04-18T17:56:27.296342Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"1.634094741s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/leases/kube-system/kube-controller-manager\" limit:1 ","response":"range_response_count:1 size:508"} {"level":"info","ts":"2026-04-18T17:56:27.296331Z","caller":"traceutil/trace.go:171","msg":"trace[909134561] range","detail":"{range_begin:/registry/leases/kube-system/plndr-cp-lock; range_end:; response_count:1; response_revision:1189; }","duration":"3.059447529s","start":"2026-04-18T17:56:24.236858Z","end":"2026-04-18T17:56:27.296306Z","steps":["trace[909134561] 'agreement among raft nodes before linearized reading' (duration: 3.049151347s)"],"step_count":1} {"level":"info","ts":"2026-04-18T17:56:27.296343Z","caller":"traceutil/trace.go:171","msg":"trace[698794346] range","detail":"{range_begin:/registry/masterleases/199.19.213.57; range_end:; response_count:1; response_revision:1189; }","duration":"2.971651178s","start":"2026-04-18T17:56:24.324673Z","end":"2026-04-18T17:56:27.296324Z","steps":["trace[698794346] 'agreement among raft nodes before linearized reading' (duration: 2.961324046s)"],"step_count":1} {"level":"info","ts":"2026-04-18T17:56:27.296365Z","caller":"traceutil/trace.go:171","msg":"trace[2044589161] range","detail":"{range_begin:/registry/leases/kube-system/kube-controller-manager; range_end:; response_count:1; response_revision:1189; }","duration":"1.634187215s","start":"2026-04-18T17:56:25.662170Z","end":"2026-04-18T17:56:27.296358Z","steps":["trace[2044589161] 'agreement among raft nodes before linearized reading' (duration: 1.623769529s)"],"step_count":1} {"level":"warn","ts":"2026-04-18T17:56:27.296394Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-04-18T17:56:25.662130Z","time spent":"1.634258837s","remote":"127.0.0.1:38214","response type":"/etcdserverpb.KV/Range","request count":0,"request size":56,"response count":1,"response size":531,"request content":"key:\"/registry/leases/kube-system/kube-controller-manager\" limit:1 "} {"level":"warn","ts":"2026-04-18T17:56:27.296390Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-04-18T17:56:24.324649Z","time spent":"2.971734061s","remote":"127.0.0.1:37984","response type":"/etcdserverpb.KV/Range","request count":0,"request size":40,"response count":1,"response size":156,"request content":"key:\"/registry/masterleases/199.19.213.57\" limit:1 "} {"level":"warn","ts":"2026-04-18T17:56:27.296394Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-04-18T17:56:24.236840Z","time spent":"3.059543373s","remote":"127.0.0.1:38214","response type":"/etcdserverpb.KV/Range","request count":0,"request size":46,"response count":1,"response size":459,"request content":"key:\"/registry/leases/kube-system/plndr-cp-lock\" limit:1 "} {"level":"warn","ts":"2026-04-18T17:56:27.296296Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-04-18T17:56:25.565543Z","time spent":"1.730743595s","remote":"127.0.0.1:38044","response type":"/etcdserverpb.KV/Range","request count":0,"request size":77,"response count":1,"response size":817,"request content":"key:\"/registry/events/kube-system/kube-apiserver-controller-2.18a785253148a1d5\" limit:1 "} {"level":"warn","ts":"2026-04-18T17:56:27.296602Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"2.462674932s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/prioritylevelconfigurations/\" range_end:\"/registry/prioritylevelconfigurations0\" count_only:true ","response":"range_response_count:0 size:7"} {"level":"info","ts":"2026-04-18T17:56:27.296634Z","caller":"traceutil/trace.go:171","msg":"trace[143384798] range","detail":"{range_begin:/registry/prioritylevelconfigurations/; range_end:/registry/prioritylevelconfigurations0; response_count:0; response_revision:1189; }","duration":"2.462763377s","start":"2026-04-18T17:56:24.833860Z","end":"2026-04-18T17:56:27.296623Z","steps":["trace[143384798] 'agreement among raft nodes before linearized reading' (duration: 2.452090021s)"],"step_count":1} {"level":"warn","ts":"2026-04-18T17:56:27.296664Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-04-18T17:56:24.833840Z","time spent":"2.462816608s","remote":"127.0.0.1:38348","response type":"/etcdserverpb.KV/Range","request count":0,"request size":82,"response count":8,"response size":30,"request content":"key:\"/registry/prioritylevelconfigurations/\" range_end:\"/registry/prioritylevelconfigurations0\" count_only:true "} {"level":"warn","ts":"2026-04-18T17:56:27.296779Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"1.730705103s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/health\" ","response":"range_response_count:0 size:5"} {"level":"info","ts":"2026-04-18T17:56:27.296818Z","caller":"traceutil/trace.go:171","msg":"trace[1389007365] range","detail":"{range_begin:/registry/health; range_end:; response_count:0; response_revision:1189; }","duration":"1.730752284s","start":"2026-04-18T17:56:25.566053Z","end":"2026-04-18T17:56:27.296806Z","steps":["trace[1389007365] 'agreement among raft nodes before linearized reading' (duration: 1.719808969s)"],"step_count":1} {"level":"warn","ts":"2026-04-18T17:56:27.296830Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"814.068049ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/leases/kube-system/plndr-svcs-lock\" limit:1 ","response":"range_response_count:1 size:440"} {"level":"info","ts":"2026-04-18T17:56:27.296856Z","caller":"traceutil/trace.go:171","msg":"trace[852363110] range","detail":"{range_begin:/registry/leases/kube-system/plndr-svcs-lock; range_end:; response_count:1; response_revision:1189; }","duration":"814.136682ms","start":"2026-04-18T17:56:26.482711Z","end":"2026-04-18T17:56:27.296847Z","steps":["trace[852363110] 'agreement among raft nodes before linearized reading' (duration: 803.207657ms)"],"step_count":1} {"level":"warn","ts":"2026-04-18T17:56:27.296854Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-04-18T17:56:25.566046Z","time spent":"1.730801907s","remote":"127.0.0.1:37964","response type":"/etcdserverpb.KV/Range","request count":0,"request size":18,"response count":0,"response size":28,"request content":"key:\"/registry/health\" "} {"level":"warn","ts":"2026-04-18T17:56:27.296885Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-04-18T17:56:26.482684Z","time spent":"814.187534ms","remote":"127.0.0.1:38214","response type":"/etcdserverpb.KV/Range","request count":0,"request size":48,"response count":1,"response size":463,"request content":"key:\"/registry/leases/kube-system/plndr-svcs-lock\" limit:1 "} {"level":"warn","ts":"2026-04-18T17:56:27.297237Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"466.451444ms","expected-duration":"100ms","prefix":"read-only range ","request":"limit:1 keys_only:true ","response":"range_response_count:0 size:5"} {"level":"info","ts":"2026-04-18T17:56:27.297279Z","caller":"traceutil/trace.go:171","msg":"trace[2123880362] range","detail":"{range_begin:; range_end:; response_count:0; response_revision:1192; }","duration":"466.493996ms","start":"2026-04-18T17:56:26.830777Z","end":"2026-04-18T17:56:27.297271Z","steps":["trace[2123880362] 'agreement among raft nodes before linearized reading' (duration: 466.411423ms)"],"step_count":1} {"level":"warn","ts":"2026-04-18T17:56:28.413024Z","caller":"etcdserver/v3_server.go:920","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":11487730067459448787,"retry-timeout":"500ms"} {"level":"warn","ts":"2026-04-18T17:56:28.914006Z","caller":"etcdserver/v3_server.go:920","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":11487730067459448787,"retry-timeout":"500ms"} {"level":"warn","ts":"2026-04-18T17:56:29.415144Z","caller":"etcdserver/v3_server.go:920","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":11487730067459448787,"retry-timeout":"500ms"} {"level":"warn","ts":"2026-04-18T17:56:29.916154Z","caller":"etcdserver/v3_server.go:920","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":11487730067459448787,"retry-timeout":"500ms"} {"level":"warn","ts":"2026-04-18T17:56:30.417504Z","caller":"etcdserver/v3_server.go:920","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":11487730067459448787,"retry-timeout":"500ms"} {"level":"warn","ts":"2026-04-18T17:56:30.918581Z","caller":"etcdserver/v3_server.go:920","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":11487730067459448787,"retry-timeout":"500ms"} {"level":"warn","ts":"2026-04-18T17:56:31.008729Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"2.000685817s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/health\" ","response":"","error":"context canceled"} {"level":"info","ts":"2026-04-18T17:56:31.008806Z","caller":"traceutil/trace.go:171","msg":"trace[249437425] range","detail":"{range_begin:/registry/health; range_end:; }","duration":"2.000802423s","start":"2026-04-18T17:56:29.007985Z","end":"2026-04-18T17:56:31.008787Z","steps":["trace[249437425] 'agreement among raft nodes before linearized reading' (duration: 2.000710619s)"],"step_count":1} {"level":"warn","ts":"2026-04-18T17:56:31.008845Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-04-18T17:56:29.007970Z","time spent":"2.000868375s","remote":"127.0.0.1:37964","response type":"/etcdserverpb.KV/Range","request count":0,"request size":18,"response count":0,"response size":0,"request content":"key:\"/registry/health\" "} 2026/04/18 17:56:31 WARNING: [core] [Server #8] grpc: Server.processUnaryRPC failed to write status: connection error: desc = "transport is closing" {"level":"info","ts":"2026-04-18T17:56:31.033256Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"d41438a8a7449f6c is starting a new election at term 2"} {"level":"info","ts":"2026-04-18T17:56:31.033442Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"d41438a8a7449f6c became pre-candidate at term 2"} {"level":"info","ts":"2026-04-18T17:56:31.033505Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"d41438a8a7449f6c received MsgPreVoteResp from d41438a8a7449f6c at term 2"} {"level":"info","ts":"2026-04-18T17:56:31.033540Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"d41438a8a7449f6c [logterm: 2, index: 1408] sent MsgPreVote request to 3931e8c7aea13672 at term 2"} {"level":"info","ts":"2026-04-18T17:56:31.033591Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"d41438a8a7449f6c [logterm: 2, index: 1408] sent MsgPreVote request to a847c2e9c7010db6 at term 2"} {"level":"info","ts":"2026-04-18T17:56:31.033615Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"raft.node: d41438a8a7449f6c lost leader a847c2e9c7010db6 at term 2"} {"level":"info","ts":"2026-04-18T17:56:31.303745Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"d41438a8a7449f6c became follower at term 2"} {"level":"info","ts":"2026-04-18T17:56:31.303794Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"raft.node: d41438a8a7449f6c elected leader a847c2e9c7010db6 at term 2"} {"level":"warn","ts":"2026-04-18T17:56:31.304123Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"3.391738437s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/pods/kube-system/cilium-rlg8f\" limit:1 ","response":"","error":"etcdserver: leader changed"} {"level":"info","ts":"2026-04-18T17:56:31.304170Z","caller":"traceutil/trace.go:171","msg":"trace[2044617448] range","detail":"{range_begin:/registry/pods/kube-system/cilium-rlg8f; range_end:; }","duration":"3.391854432s","start":"2026-04-18T17:56:27.912301Z","end":"2026-04-18T17:56:31.304155Z","steps":["trace[2044617448] 'agreement among raft nodes before linearized reading' (duration: 3.391788159s)"],"step_count":1} {"level":"warn","ts":"2026-04-18T17:56:31.304204Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-04-18T17:56:27.912270Z","time spent":"3.391925244s","remote":"127.0.0.1:38146","response type":"/etcdserverpb.KV/Range","request count":0,"request size":43,"response count":0,"response size":0,"request content":"key:\"/registry/pods/kube-system/cilium-rlg8f\" limit:1 "} {"level":"warn","ts":"2026-04-18T17:56:31.804425Z","caller":"etcdserver/v3_server.go:920","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":11487730067459448789,"retry-timeout":"500ms"} {"level":"warn","ts":"2026-04-18T17:56:32.304663Z","caller":"etcdserver/v3_server.go:920","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":11487730067459448789,"retry-timeout":"500ms"} {"level":"warn","ts":"2026-04-18T17:56:32.805825Z","caller":"etcdserver/v3_server.go:920","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":11487730067459448789,"retry-timeout":"500ms"} {"level":"warn","ts":"2026-04-18T17:56:33.009588Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"2.000592712s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/health\" ","response":"","error":"context canceled"} {"level":"info","ts":"2026-04-18T17:56:33.009718Z","caller":"traceutil/trace.go:171","msg":"trace[1518838941] range","detail":"{range_begin:/registry/health; range_end:; }","duration":"2.000795529s","start":"2026-04-18T17:56:31.008895Z","end":"2026-04-18T17:56:33.009691Z","steps":["trace[1518838941] 'agreement among raft nodes before linearized reading' (duration: 2.000625352s)"],"step_count":1} {"level":"warn","ts":"2026-04-18T17:56:33.009793Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-04-18T17:56:31.008875Z","time spent":"2.000903114s","remote":"127.0.0.1:37954","response type":"/etcdserverpb.KV/Range","request count":0,"request size":18,"response count":0,"response size":0,"request content":"key:\"/registry/health\" "} 2026/04/18 17:56:33 WARNING: [core] [Server #8] grpc: Server.processUnaryRPC failed to write status: connection error: desc = "transport is closing" {"level":"warn","ts":"2026-04-18T17:56:33.306598Z","caller":"etcdserver/v3_server.go:920","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":11487730067459448789,"retry-timeout":"500ms"} {"level":"warn","ts":"2026-04-18T17:56:33.729390Z","caller":"wal/wal.go:805","msg":"slow fdatasync","took":"2.425415603s","expected-duration":"1s"} {"level":"warn","ts":"2026-04-18T17:56:33.729653Z","caller":"etcdserver/v3_server.go:897","msg":"ignored out-of-date read index response; local node read indexes queueing up and waiting to be in sync with leader","sent-request-id":11487730067459448789,"received-request-id":11487730067459448787} {"level":"warn","ts":"2026-04-18T17:56:33.807529Z","caller":"etcdserver/v3_server.go:920","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":11487730067459448789,"retry-timeout":"500ms"} {"level":"warn","ts":"2026-04-18T17:56:33.856428Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"2.91156297s","expected-duration":"100ms","prefix":"read-only range ","request":"limit:1 serializable:true keys_only:true ","response":"range_response_count:0 size:5"} {"level":"info","ts":"2026-04-18T17:56:33.856523Z","caller":"traceutil/trace.go:171","msg":"trace[633268888] range","detail":"{range_begin:; range_end:; response_count:0; response_revision:1208; }","duration":"2.911672884s","start":"2026-04-18T17:56:30.944825Z","end":"2026-04-18T17:56:33.856498Z","steps":["trace[633268888] 'range keys from in-memory index tree' (duration: 2.911516398s)"],"step_count":1} {"level":"warn","ts":"2026-04-18T17:56:33.857028Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"2.552855314s","expected-duration":"100ms","prefix":"","request":"header: txn: success:> failure:<>>","response":"size:16"} {"level":"info","ts":"2026-04-18T17:56:33.858342Z","caller":"traceutil/trace.go:171","msg":"trace[803877415] transaction","detail":"{read_only:false; response_revision:1211; number_of_response:1; }","duration":"4.427142545s","start":"2026-04-18T17:56:29.431133Z","end":"2026-04-18T17:56:33.858275Z","steps":["trace[803877415] 'process raft request' (duration: 4.427085343s)"],"step_count":1} {"level":"warn","ts":"2026-04-18T17:56:33.858555Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-04-18T17:56:29.431094Z","time spent":"4.427401225s","remote":"127.0.0.1:38214","response type":"/etcdserverpb.KV/Txn","request count":1,"request size":537,"response count":0,"response size":39,"request content":"compare: success:> failure: >"} {"level":"warn","ts":"2026-04-18T17:56:34.308755Z","caller":"etcdserver/v3_server.go:920","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":11487730067459448789,"retry-timeout":"500ms"} {"level":"warn","ts":"2026-04-18T17:56:34.411838Z","caller":"etcdserver/v3_server.go:897","msg":"ignored out-of-date read index response; local node read indexes queueing up and waiting to be in sync with leader","sent-request-id":11487730067459448789,"received-request-id":11487730067459448787} {"level":"warn","ts":"2026-04-18T17:56:34.809588Z","caller":"etcdserver/v3_server.go:920","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":11487730067459448789,"retry-timeout":"500ms"} {"level":"warn","ts":"2026-04-18T17:56:35.018525Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"2.000472844s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/health\" ","response":"","error":"context deadline exceeded"} {"level":"info","ts":"2026-04-18T17:56:35.018615Z","caller":"traceutil/trace.go:171","msg":"trace[533586108] range","detail":"{range_begin:/registry/health; range_end:; }","duration":"2.0006198s","start":"2026-04-18T17:56:33.017972Z","end":"2026-04-18T17:56:35.018592Z","steps":["trace[533586108] 'agreement among raft nodes before linearized reading' (duration: 2.000509496s)"],"step_count":1} {"level":"warn","ts":"2026-04-18T17:56:35.018669Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-04-18T17:56:33.017947Z","time spent":"2.000711803s","remote":"127.0.0.1:37964","response type":"/etcdserverpb.KV/Range","request count":0,"request size":18,"response count":0,"response size":0,"request content":"key:\"/registry/health\" "} {"level":"warn","ts":"2026-04-18T17:56:35.196289Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"784.327164ms","expected-duration":"100ms","prefix":"","request":"header: txn: success:> failure:<>>","response":"size:16"} {"level":"warn","ts":"2026-04-18T17:56:35.309811Z","caller":"etcdserver/v3_server.go:920","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":11487730067459448789,"retry-timeout":"500ms"} {"level":"warn","ts":"2026-04-18T17:56:35.640103Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"4.999307926s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/leases/kube-system/kube-controller-manager\" limit:1 ","response":"","error":"context deadline exceeded"} {"level":"info","ts":"2026-04-18T17:56:35.640183Z","caller":"traceutil/trace.go:171","msg":"trace[1016124400] range","detail":"{range_begin:/registry/leases/kube-system/kube-controller-manager; range_end:; }","duration":"4.999437261s","start":"2026-04-18T17:56:30.640726Z","end":"2026-04-18T17:56:35.640163Z","steps":["trace[1016124400] 'agreement among raft nodes before linearized reading' (duration: 4.999262355s)"],"step_count":1} {"level":"warn","ts":"2026-04-18T17:56:35.640258Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-04-18T17:56:30.640707Z","time spent":"4.999522445s","remote":"127.0.0.1:38214","response type":"/etcdserverpb.KV/Range","request count":0,"request size":56,"response count":0,"response size":0,"request content":"key:\"/registry/leases/kube-system/kube-controller-manager\" limit:1 "} 2026/04/18 17:56:35 WARNING: [core] [Server #8] grpc: Server.processUnaryRPC failed to write status: connection error: desc = "transport is closing" {"level":"warn","ts":"2026-04-18T17:56:35.695853Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"4.999135272s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/leases/kube-system/kube-scheduler\" limit:1 ","response":"","error":"context deadline exceeded"} {"level":"info","ts":"2026-04-18T17:56:35.696390Z","caller":"traceutil/trace.go:171","msg":"trace[1769982424] range","detail":"{range_begin:/registry/leases/kube-system/kube-scheduler; range_end:; }","duration":"4.999758275s","start":"2026-04-18T17:56:30.696607Z","end":"2026-04-18T17:56:35.696365Z","steps":["trace[1769982424] 'agreement among raft nodes before linearized reading' (duration: 4.999191724s)"],"step_count":1} {"level":"warn","ts":"2026-04-18T17:56:35.696465Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-04-18T17:56:30.696577Z","time spent":"4.999869239s","remote":"127.0.0.1:38214","response type":"/etcdserverpb.KV/Range","request count":0,"request size":47,"response count":0,"response size":0,"request content":"key:\"/registry/leases/kube-system/kube-scheduler\" limit:1 "} 2026/04/18 17:56:35 WARNING: [core] [Server #8] grpc: Server.processUnaryRPC failed to write status: connection error: desc = "transport is closing" {"level":"warn","ts":"2026-04-18T17:56:35.810047Z","caller":"etcdserver/v3_server.go:920","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":11487730067459448789,"retry-timeout":"500ms"} {"level":"warn","ts":"2026-04-18T17:56:36.311343Z","caller":"etcdserver/v3_server.go:920","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":11487730067459448789,"retry-timeout":"500ms"} {"level":"warn","ts":"2026-04-18T17:56:36.812395Z","caller":"etcdserver/v3_server.go:920","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":11487730067459448789,"retry-timeout":"500ms"} {"level":"warn","ts":"2026-04-18T17:56:37.019165Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"1.999829322s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/health\" ","response":"","error":"context canceled"} {"level":"info","ts":"2026-04-18T17:56:37.019241Z","caller":"traceutil/trace.go:171","msg":"trace[255635688] range","detail":"{range_begin:/registry/health; range_end:; }","duration":"1.999941296s","start":"2026-04-18T17:56:35.019280Z","end":"2026-04-18T17:56:37.019221Z","steps":["trace[255635688] 'agreement among raft nodes before linearized reading' (duration: 1.999853093s)"],"step_count":1} {"level":"warn","ts":"2026-04-18T17:56:37.019348Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-04-18T17:56:35.019267Z","time spent":"2.00005487s","remote":"127.0.0.1:37954","response type":"/etcdserverpb.KV/Range","request count":0,"request size":18,"response count":0,"response size":0,"request content":"key:\"/registry/health\" "} 2026/04/18 17:56:37 WARNING: [core] [Server #8] grpc: Server.processUnaryRPC failed to write status: connection error: desc = "transport is closing" {"level":"warn","ts":"2026-04-18T17:56:37.285078Z","caller":"wal/wal.go:805","msg":"slow fdatasync","took":"2.872997262s","expected-duration":"1s"} {"level":"info","ts":"2026-04-18T17:56:37.285259Z","caller":"traceutil/trace.go:171","msg":"trace[1979701692] linearizableReadLoop","detail":"{readStateIndex:1409; appliedIndex:1410; }","duration":"5.981374381s","start":"2026-04-18T17:56:31.303869Z","end":"2026-04-18T17:56:37.285244Z","steps":["trace[1979701692] 'read index received' (duration: 5.981369981s)","trace[1979701692] 'applied index is now lower than readState.Index' (duration: 3.57µs)"],"step_count":2} {"level":"info","ts":"2026-04-18T17:56:37.599736Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"d41438a8a7449f6c [logterm: 2, index: 1417, vote: 0] ignored MsgPreVote from 3931e8c7aea13672 [logterm: 2, index: 1417] at term 2: lease is not expired (remaining ticks: 9)"} {"level":"warn","ts":"2026-04-18T17:56:37.785584Z","caller":"etcdserver/v3_server.go:920","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":11487730067459448790,"retry-timeout":"500ms"} {"level":"warn","ts":"2026-04-18T17:56:38.286669Z","caller":"etcdserver/v3_server.go:920","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":11487730067459448790,"retry-timeout":"500ms"} {"level":"warn","ts":"2026-04-18T17:56:38.755282Z","caller":"wal/wal.go:805","msg":"slow fdatasync","took":"1.470076289s","expected-duration":"1s"} {"level":"warn","ts":"2026-04-18T17:56:38.787302Z","caller":"etcdserver/v3_server.go:920","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":11487730067459448790,"retry-timeout":"500ms"} {"level":"warn","ts":"2026-04-18T17:56:38.961549Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"10.740867639s","expected-duration":"100ms","prefix":"read-only range ","request":"limit:1 keys_only:true ","response":"range_response_count:0 size:5"} {"level":"warn","ts":"2026-04-18T17:56:38.961721Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"8.922044693s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/leases/kube-system/plndr-svcs-lock\" limit:1 ","response":"range_response_count:1 size:440"} {"level":"info","ts":"2026-04-18T17:56:38.961806Z","caller":"traceutil/trace.go:171","msg":"trace[5967711] range","detail":"{range_begin:/registry/leases/kube-system/plndr-svcs-lock; range_end:; response_count:1; response_revision:1213; }","duration":"8.922160997s","start":"2026-04-18T17:56:30.039618Z","end":"2026-04-18T17:56:38.961779Z","steps":["trace[5967711] 'agreement among raft nodes before linearized reading' (duration: 7.245657262s)","trace[5967711] 'range keys from in-memory index tree' (duration: 1.676335289s)"],"step_count":2} {"level":"warn","ts":"2026-04-18T17:56:38.962037Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-04-18T17:56:30.039603Z","time spent":"8.922420656s","remote":"127.0.0.1:38214","response type":"/etcdserverpb.KV/Range","request count":0,"request size":48,"response count":1,"response size":463,"request content":"key:\"/registry/leases/kube-system/plndr-svcs-lock\" limit:1 "} {"level":"warn","ts":"2026-04-18T17:56:38.962610Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"10.171670571s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/statefulsets/\" range_end:\"/registry/statefulsets0\" count_only:true ","response":"range_response_count:0 size:5"} {"level":"info","ts":"2026-04-18T17:56:38.962683Z","caller":"traceutil/trace.go:171","msg":"trace[1530976291] range","detail":"{range_begin:/registry/statefulsets/; range_end:/registry/statefulsets0; response_count:0; response_revision:1213; }","duration":"10.171780965s","start":"2026-04-18T17:56:28.790881Z","end":"2026-04-18T17:56:38.962662Z","steps":["trace[1530976291] 'agreement among raft nodes before linearized reading' (duration: 8.494412079s)","trace[1530976291] 'count revisions from in-memory index tree' (duration: 1.677266452s)"],"step_count":2} {"level":"warn","ts":"2026-04-18T17:56:38.962738Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-04-18T17:56:28.790866Z","time spent":"10.17186092s","remote":"127.0.0.1:38374","response type":"/etcdserverpb.KV/Range","request count":0,"request size":52,"response count":0,"response size":28,"request content":"key:\"/registry/statefulsets/\" range_end:\"/registry/statefulsets0\" count_only:true "} {"level":"warn","ts":"2026-04-18T17:56:38.962898Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"1.677502491s","expected-duration":"100ms","prefix":"","request":"header: txn: success:> failure:<>>","response":"size:16"} {"level":"info","ts":"2026-04-18T17:56:38.963636Z","caller":"traceutil/trace.go:171","msg":"trace[412072451] range","detail":"{range_begin:; range_end:; response_count:0; response_revision:1213; }","duration":"10.740979193s","start":"2026-04-18T17:56:28.220648Z","end":"2026-04-18T17:56:38.961627Z","steps":["trace[412072451] 'agreement among raft nodes before linearized reading' (duration: 9.064656825s)","trace[412072451] 'range keys from in-memory index tree' (duration: 1.676195384s)"],"step_count":2} {"level":"warn","ts":"2026-04-18T17:56:39.028018Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"2.000677053s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/health\" ","response":"","error":"context canceled"} {"level":"info","ts":"2026-04-18T17:56:39.028097Z","caller":"traceutil/trace.go:171","msg":"trace[91534822] range","detail":"{range_begin:/registry/health; range_end:; }","duration":"2.000799147s","start":"2026-04-18T17:56:37.027280Z","end":"2026-04-18T17:56:39.028079Z","steps":["trace[91534822] 'agreement among raft nodes before linearized reading' (duration: 2.000711204s)"],"step_count":1} {"level":"warn","ts":"2026-04-18T17:56:39.028134Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-04-18T17:56:37.027259Z","time spent":"2.00087001s","remote":"127.0.0.1:37964","response type":"/etcdserverpb.KV/Range","request count":0,"request size":18,"response count":0,"response size":0,"request content":"key:\"/registry/health\" "} 2026/04/18 17:56:39 WARNING: [core] [Server #8] grpc: Server.processUnaryRPC failed to write status: connection error: desc = "transport is closing" {"level":"info","ts":"2026-04-18T17:56:39.034795Z","caller":"traceutil/trace.go:171","msg":"trace[2107419579] linearizableReadLoop","detail":"{readStateIndex:1417; appliedIndex:1417; }","duration":"1.749494149s","start":"2026-04-18T17:56:37.285280Z","end":"2026-04-18T17:56:39.034775Z","steps":["trace[2107419579] 'read index received' (duration: 1.749487729s)","trace[2107419579] 'applied index is now lower than readState.Index' (duration: 5.55µs)"],"step_count":2} {"level":"warn","ts":"2026-04-18T17:56:39.034960Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"4.709449264s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/masterleases/199.19.213.57\" limit:1 ","response":"range_response_count:1 size:133"} {"level":"info","ts":"2026-04-18T17:56:39.035011Z","caller":"traceutil/trace.go:171","msg":"trace[850273950] range","detail":"{range_begin:/registry/masterleases/199.19.213.57; range_end:; response_count:1; response_revision:1216; }","duration":"4.709541267s","start":"2026-04-18T17:56:34.325455Z","end":"2026-04-18T17:56:39.034996Z","steps":["trace[850273950] 'agreement among raft nodes before linearized reading' (duration: 4.709445853s)"],"step_count":1} {"level":"warn","ts":"2026-04-18T17:56:39.034985Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"4.565594902s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/pods/kube-system/cilium-rlg8f\" limit:1 ","response":"range_response_count:1 size:18158"} {"level":"info","ts":"2026-04-18T17:56:39.035092Z","caller":"traceutil/trace.go:171","msg":"trace[1053105320] range","detail":"{range_begin:/registry/pods/kube-system/cilium-rlg8f; range_end:; response_count:1; response_revision:1216; }","duration":"4.565763348s","start":"2026-04-18T17:56:34.469309Z","end":"2026-04-18T17:56:39.035072Z","steps":["trace[1053105320] 'agreement among raft nodes before linearized reading' (duration: 4.565552671s)"],"step_count":1} {"level":"warn","ts":"2026-04-18T17:56:39.035103Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-04-18T17:56:34.325439Z","time spent":"4.70960823s","remote":"127.0.0.1:37984","response type":"/etcdserverpb.KV/Range","request count":0,"request size":40,"response count":1,"response size":156,"request content":"key:\"/registry/masterleases/199.19.213.57\" limit:1 "} {"level":"warn","ts":"2026-04-18T17:56:39.035097Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"2.714909477s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/configmaps/\" range_end:\"/registry/configmaps0\" count_only:true ","response":"range_response_count:0 size:7"} {"level":"info","ts":"2026-04-18T17:56:39.035160Z","caller":"traceutil/trace.go:171","msg":"trace[1007418123] range","detail":"{range_begin:/registry/configmaps/; range_end:/registry/configmaps0; response_count:0; response_revision:1216; }","duration":"2.71500673s","start":"2026-04-18T17:56:36.320134Z","end":"2026-04-18T17:56:39.035141Z","steps":["trace[1007418123] 'agreement among raft nodes before linearized reading' (duration: 2.714905586s)"],"step_count":1} {"level":"warn","ts":"2026-04-18T17:56:39.035173Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-04-18T17:56:34.469263Z","time spent":"4.565866573s","remote":"127.0.0.1:38146","response type":"/etcdserverpb.KV/Range","request count":0,"request size":43,"response count":1,"response size":18181,"request content":"key:\"/registry/pods/kube-system/cilium-rlg8f\" limit:1 "} {"level":"warn","ts":"2026-04-18T17:56:39.035203Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-04-18T17:56:36.320110Z","time spent":"2.715079573s","remote":"127.0.0.1:38064","response type":"/etcdserverpb.KV/Range","request count":0,"request size":48,"response count":13,"response size":30,"request content":"key:\"/registry/configmaps/\" range_end:\"/registry/configmaps0\" count_only:true "} {"level":"warn","ts":"2026-04-18T17:56:39.035321Z","caller":"etcdserver/util.go:123","msg":"failed to apply request","took":"159.156µs","request":"header: lease_revoke:","response":"size:28","error":"lease not found"} {"level":"warn","ts":"2026-04-18T17:56:39.035391Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"6.021690988s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/events/kube-system/kube-apiserver-controller-2.18a785253148a1d5\" limit:1 ","response":"range_response_count:1 size:794"} {"level":"info","ts":"2026-04-18T17:56:39.035442Z","caller":"traceutil/trace.go:171","msg":"trace[93459188] range","detail":"{range_begin:/registry/events/kube-system/kube-apiserver-controller-2.18a785253148a1d5; range_end:; response_count:1; response_revision:1217; }","duration":"6.021794992s","start":"2026-04-18T17:56:33.013628Z","end":"2026-04-18T17:56:39.035423Z","steps":["trace[93459188] 'agreement among raft nodes before linearized reading' (duration: 6.021712149s)"],"step_count":1} {"level":"warn","ts":"2026-04-18T17:56:39.035488Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-04-18T17:56:33.013604Z","time spent":"6.021871035s","remote":"127.0.0.1:38044","response type":"/etcdserverpb.KV/Range","request count":0,"request size":77,"response count":1,"response size":817,"request content":"key:\"/registry/events/kube-system/kube-apiserver-controller-2.18a785253148a1d5\" limit:1 "} {"level":"warn","ts":"2026-04-18T17:56:39.035522Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"2.846506682s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/networkpolicies/\" range_end:\"/registry/networkpolicies0\" count_only:true ","response":"range_response_count:0 size:5"} {"level":"info","ts":"2026-04-18T17:56:39.035627Z","caller":"traceutil/trace.go:171","msg":"trace[1858994045] range","detail":"{range_begin:/registry/networkpolicies/; range_end:/registry/networkpolicies0; response_count:0; response_revision:1217; }","duration":"2.846593006s","start":"2026-04-18T17:56:36.188968Z","end":"2026-04-18T17:56:39.035561Z","steps":["trace[1858994045] 'agreement among raft nodes before linearized reading' (duration: 2.846507012s)"],"step_count":1} {"level":"warn","ts":"2026-04-18T17:56:39.035681Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-04-18T17:56:36.188954Z","time spent":"2.84670942s","remote":"127.0.0.1:38226","response type":"/etcdserverpb.KV/Range","request count":0,"request size":58,"response count":0,"response size":28,"request content":"key:\"/registry/networkpolicies/\" range_end:\"/registry/networkpolicies0\" count_only:true "} {"level":"warn","ts":"2026-04-18T17:56:39.035758Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"7.719905152s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/leases/kube-system/plndr-cp-lock\" limit:1 ","response":"range_response_count:1 size:436"} {"level":"info","ts":"2026-04-18T17:56:39.035807Z","caller":"traceutil/trace.go:171","msg":"trace[172587729] range","detail":"{range_begin:/registry/leases/kube-system/plndr-cp-lock; range_end:; response_count:1; response_revision:1218; }","duration":"7.719981805s","start":"2026-04-18T17:56:31.315811Z","end":"2026-04-18T17:56:39.035793Z","steps":["trace[172587729] 'agreement among raft nodes before linearized reading' (duration: 7.719887872s)"],"step_count":1} {"level":"warn","ts":"2026-04-18T17:56:39.035848Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-04-18T17:56:31.315796Z","time spent":"7.720039628s","remote":"127.0.0.1:38214","response type":"/etcdserverpb.KV/Range","request count":0,"request size":46,"response count":1,"response size":459,"request content":"key:\"/registry/leases/kube-system/plndr-cp-lock\" limit:1 "} {"level":"info","ts":"2026-04-18T17:56:39.041938Z","caller":"traceutil/trace.go:171","msg":"trace[1871339666] transaction","detail":"{read_only:false; response_revision:1224; number_of_response:1; }","duration":"1.729467912s","start":"2026-04-18T17:56:37.312452Z","end":"2026-04-18T17:56:39.041920Z","steps":["trace[1871339666] 'process raft request' (duration: 1.728496777s)"],"step_count":1} {"level":"warn","ts":"2026-04-18T17:56:39.042047Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-04-18T17:56:37.312429Z","time spent":"1.729560926s","remote":"127.0.0.1:38214","response type":"/etcdserverpb.KV/Txn","request count":1,"request size":677,"response count":0,"response size":39,"request content":"compare: success:> failure: >"} {"level":"info","ts":"2026-04-18T17:56:39.060888Z","caller":"traceutil/trace.go:171","msg":"trace[948206500] transaction","detail":"{read_only:false; response_revision:1225; number_of_response:1; }","duration":"1.67682442s","start":"2026-04-18T17:56:37.384043Z","end":"2026-04-18T17:56:39.060867Z","steps":["trace[948206500] 'process raft request' (duration: 1.676336261s)"],"step_count":1} {"level":"warn","ts":"2026-04-18T17:56:39.060994Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-04-18T17:56:37.384020Z","time spent":"1.676922184s","remote":"127.0.0.1:38136","response type":"/etcdserverpb.KV/Txn","request count":1,"request size":4185,"response count":0,"response size":39,"request content":"compare: success:> failure: >"} {"level":"warn","ts":"2026-04-18T17:56:39.098876Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"868.100707ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/leases/kube-system/kube-controller-manager\" limit:1 ","response":"range_response_count:1 size:509"} {"level":"warn","ts":"2026-04-18T17:56:39.098880Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"380.731809ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/leases/kube-system/kube-scheduler\" limit:1 ","response":"range_response_count:1 size:482"} {"level":"info","ts":"2026-04-18T17:56:39.098967Z","caller":"traceutil/trace.go:171","msg":"trace[794020200] range","detail":"{range_begin:/registry/leases/kube-system/kube-controller-manager; range_end:; response_count:1; response_revision:1228; }","duration":"868.242112ms","start":"2026-04-18T17:56:38.230698Z","end":"2026-04-18T17:56:39.098940Z","steps":["trace[794020200] 'agreement among raft nodes before linearized reading' (duration: 855.116991ms)"],"step_count":1} {"level":"warn","ts":"2026-04-18T17:56:39.099017Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-04-18T17:56:38.230676Z","time spent":"868.327395ms","remote":"127.0.0.1:38214","response type":"/etcdserverpb.KV/Range","request count":0,"request size":56,"response count":1,"response size":532,"request content":"key:\"/registry/leases/kube-system/kube-controller-manager\" limit:1 "} {"level":"info","ts":"2026-04-18T17:56:39.099020Z","caller":"traceutil/trace.go:171","msg":"trace[977804159] range","detail":"{range_begin:/registry/leases/kube-system/kube-scheduler; range_end:; response_count:1; response_revision:1228; }","duration":"380.926196ms","start":"2026-04-18T17:56:38.718062Z","end":"2026-04-18T17:56:39.098988Z","steps":["trace[977804159] 'agreement among raft nodes before linearized reading' (duration: 367.801605ms)"],"step_count":1} {"level":"warn","ts":"2026-04-18T17:56:39.099096Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-04-18T17:56:38.718048Z","time spent":"381.026229ms","remote":"127.0.0.1:38214","response type":"/etcdserverpb.KV/Range","request count":0,"request size":47,"response count":1,"response size":505,"request content":"key:\"/registry/leases/kube-system/kube-scheduler\" limit:1 "} {"level":"warn","ts":"2026-04-18T17:56:39.099920Z","caller":"etcdserver/util.go:123","msg":"failed to apply request","took":"58.152µs","request":"header: lease_revoke:","response":"size:28","error":"lease not found"} {"level":"warn","ts":"2026-04-18T17:56:41.122552Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"170.001267ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/pods/kube-system/cilium-rlg8f\" limit:1 ","response":"range_response_count:1 size:18428"} {"level":"info","ts":"2026-04-18T17:56:41.122651Z","caller":"traceutil/trace.go:171","msg":"trace[129181370] range","detail":"{range_begin:/registry/pods/kube-system/cilium-rlg8f; range_end:; response_count:1; response_revision:1271; }","duration":"170.147693ms","start":"2026-04-18T17:56:40.952470Z","end":"2026-04-18T17:56:41.122618Z","steps":["trace[129181370] 'range keys from in-memory index tree' (duration: 168.020608ms)"],"step_count":1} {"level":"warn","ts":"2026-04-18T17:56:41.122827Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"178.029856ms","expected-duration":"100ms","prefix":"read-only range ","request":"limit:1 serializable:true keys_only:true ","response":"range_response_count:0 size:5"} {"level":"info","ts":"2026-04-18T17:56:41.122930Z","caller":"traceutil/trace.go:171","msg":"trace[229879774] range","detail":"{range_begin:; range_end:; response_count:0; response_revision:1271; }","duration":"178.134489ms","start":"2026-04-18T17:56:40.944769Z","end":"2026-04-18T17:56:41.122904Z","steps":["trace[229879774] 'range keys from in-memory index tree' (duration: 177.976043ms)"],"step_count":1} {"level":"info","ts":"2026-04-18T17:56:41.184192Z","caller":"traceutil/trace.go:171","msg":"trace[1671123762] transaction","detail":"{read_only:false; response_revision:1272; number_of_response:1; }","duration":"230.792717ms","start":"2026-04-18T17:56:40.953377Z","end":"2026-04-18T17:56:41.184170Z","steps":["trace[1671123762] 'process raft request' (duration: 230.674503ms)"],"step_count":1} {"level":"info","ts":"2026-04-18T17:56:41.464036Z","caller":"traceutil/trace.go:171","msg":"trace[1237949652] transaction","detail":"{read_only:false; response_revision:1273; number_of_response:1; }","duration":"321.679148ms","start":"2026-04-18T17:56:41.142326Z","end":"2026-04-18T17:56:41.464005Z","steps":["trace[1237949652] 'process raft request' (duration: 321.341716ms)"],"step_count":1} {"level":"warn","ts":"2026-04-18T17:56:41.464226Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-04-18T17:56:41.142299Z","time spent":"321.824963ms","remote":"127.0.0.1:38146","response type":"/etcdserverpb.KV/Txn","request count":1,"request size":18679,"response count":0,"response size":39,"request content":"compare: success:> failure: >"} {"level":"info","ts":"2026-04-18T17:56:41.472290Z","caller":"traceutil/trace.go:171","msg":"trace[950089189] linearizableReadLoop","detail":"{readStateIndex:1481; appliedIndex:1481; }","duration":"251.626139ms","start":"2026-04-18T17:56:41.220610Z","end":"2026-04-18T17:56:41.472236Z","steps":["trace[950089189] 'read index received' (duration: 251.618849ms)","trace[950089189] 'applied index is now lower than readState.Index' (duration: 6.35µs)"],"step_count":2} {"level":"warn","ts":"2026-04-18T17:56:41.472485Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"251.935091ms","expected-duration":"100ms","prefix":"read-only range ","request":"limit:1 keys_only:true ","response":"range_response_count:0 size:5"} {"level":"info","ts":"2026-04-18T17:56:41.472556Z","caller":"traceutil/trace.go:171","msg":"trace[1388672094] range","detail":"{range_begin:; range_end:; response_count:0; response_revision:1275; }","duration":"252.034744ms","start":"2026-04-18T17:56:41.220510Z","end":"2026-04-18T17:56:41.472545Z","steps":["trace[1388672094] 'agreement among raft nodes before linearized reading' (duration: 251.878269ms)"],"step_count":1} {"level":"info","ts":"2026-04-18T17:56:44.322370Z","caller":"traceutil/trace.go:171","msg":"trace[2099409940] linearizableReadLoop","detail":"{readStateIndex:1534; appliedIndex:1534; }","duration":"102.15109ms","start":"2026-04-18T17:56:44.220179Z","end":"2026-04-18T17:56:44.322330Z","steps":["trace[2099409940] 'read index received' (duration: 102.139169ms)","trace[2099409940] 'applied index is now lower than readState.Index' (duration: 8.651µs)"],"step_count":2} {"level":"warn","ts":"2026-04-18T17:56:44.322546Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"102.370618ms","expected-duration":"100ms","prefix":"read-only range ","request":"limit:1 keys_only:true ","response":"range_response_count:0 size:5"} {"level":"info","ts":"2026-04-18T17:56:44.322657Z","caller":"traceutil/trace.go:171","msg":"trace[1064845778] range","detail":"{range_begin:; range_end:; response_count:0; response_revision:1325; }","duration":"102.505932ms","start":"2026-04-18T17:56:44.220127Z","end":"2026-04-18T17:56:44.322633Z","steps":["trace[1064845778] 'agreement among raft nodes before linearized reading' (duration: 102.302625ms)"],"step_count":1} {"level":"info","ts":"2026-04-18T17:56:45.635677Z","caller":"traceutil/trace.go:171","msg":"trace[1319536579] linearizableReadLoop","detail":"{readStateIndex:1553; appliedIndex:1551; }","duration":"308.267374ms","start":"2026-04-18T17:56:45.327390Z","end":"2026-04-18T17:56:45.635658Z","steps":["trace[1319536579] 'read index received' (duration: 307.997904ms)","trace[1319536579] 'applied index is now lower than readState.Index' (duration: 269.06µs)"],"step_count":2} {"level":"warn","ts":"2026-04-18T17:56:45.635879Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"308.47257ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/leases/kube-system/kube-controller-manager\" limit:1 ","response":"range_response_count:1 size:509"} {"level":"info","ts":"2026-04-18T17:56:45.635911Z","caller":"traceutil/trace.go:171","msg":"trace[1433727793] range","detail":"{range_begin:/registry/leases/kube-system/kube-controller-manager; range_end:; response_count:1; response_revision:1343; }","duration":"308.572224ms","start":"2026-04-18T17:56:45.327332Z","end":"2026-04-18T17:56:45.635904Z","steps":["trace[1433727793] 'agreement among raft nodes before linearized reading' (duration: 308.483681ms)"],"step_count":1} {"level":"warn","ts":"2026-04-18T17:56:45.635937Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-04-18T17:56:45.327309Z","time spent":"308.622085ms","remote":"127.0.0.1:38214","response type":"/etcdserverpb.KV/Range","request count":0,"request size":56,"response count":1,"response size":532,"request content":"key:\"/registry/leases/kube-system/kube-controller-manager\" limit:1 "} {"level":"warn","ts":"2026-04-18T17:56:45.637445Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"163.557854ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/leases/kube-system/kube-scheduler\" limit:1 ","response":"range_response_count:1 size:482"} {"level":"info","ts":"2026-04-18T17:56:45.637480Z","caller":"traceutil/trace.go:171","msg":"trace[1061736950] range","detail":"{range_begin:/registry/leases/kube-system/kube-scheduler; range_end:; response_count:1; response_revision:1343; }","duration":"163.662908ms","start":"2026-04-18T17:56:45.473809Z","end":"2026-04-18T17:56:45.637472Z","steps":["trace[1061736950] 'agreement among raft nodes before linearized reading' (duration: 163.400899ms)"],"step_count":1} {"level":"info","ts":"2026-04-18T17:56:50.516698Z","caller":"traceutil/trace.go:171","msg":"trace[1750479989] linearizableReadLoop","detail":"{readStateIndex:1676; appliedIndex:1676; }","duration":"181.48411ms","start":"2026-04-18T17:56:50.335188Z","end":"2026-04-18T17:56:50.516672Z","steps":["trace[1750479989] 'read index received' (duration: 181.475939ms)","trace[1750479989] 'applied index is now lower than readState.Index' (duration: 6.031µs)"],"step_count":2} {"level":"warn","ts":"2026-04-18T17:56:50.516949Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"181.731158ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/apiextensions.k8s.io/customresourcedefinitions/ciliumnodes.cilium.io\" limit:1 ","response":"range_response_count:1 size:24244"} {"level":"info","ts":"2026-04-18T17:56:50.517002Z","caller":"traceutil/trace.go:171","msg":"trace[665312031] range","detail":"{range_begin:/registry/apiextensions.k8s.io/customresourcedefinitions/ciliumnodes.cilium.io; range_end:; response_count:1; response_revision:1420; }","duration":"181.814341ms","start":"2026-04-18T17:56:50.335171Z","end":"2026-04-18T17:56:50.516985Z","steps":["trace[665312031] 'agreement among raft nodes before linearized reading' (duration: 181.636225ms)"],"step_count":1} {"level":"info","ts":"2026-04-18T17:56:50.517046Z","caller":"traceutil/trace.go:171","msg":"trace[1836086704] transaction","detail":"{read_only:false; number_of_response:1; response_revision:1420; }","duration":"164.963237ms","start":"2026-04-18T17:56:50.352065Z","end":"2026-04-18T17:56:50.517028Z","steps":["trace[1836086704] 'process raft request' (duration: 164.720919ms)"],"step_count":1} {"level":"info","ts":"2026-04-18T17:56:53.541254Z","caller":"traceutil/trace.go:171","msg":"trace[1499864526] linearizableReadLoop","detail":"{readStateIndex:1703; appliedIndex:1702; }","duration":"106.94812ms","start":"2026-04-18T17:56:53.434276Z","end":"2026-04-18T17:56:53.541224Z","steps":["trace[1499864526] 'read index received' (duration: 94.901224ms)","trace[1499864526] 'applied index is now lower than readState.Index' (duration: 12.046146ms)"],"step_count":2} {"level":"warn","ts":"2026-04-18T17:56:53.541413Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"107.104625ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/roles/\" range_end:\"/registry/roles0\" count_only:true ","response":"range_response_count:0 size:7"} {"level":"info","ts":"2026-04-18T17:56:53.541469Z","caller":"traceutil/trace.go:171","msg":"trace[1632633756] range","detail":"{range_begin:/registry/roles/; range_end:/registry/roles0; response_count:0; response_revision:1442; }","duration":"107.24812ms","start":"2026-04-18T17:56:53.434212Z","end":"2026-04-18T17:56:53.541460Z","steps":["trace[1632633756] 'agreement among raft nodes before linearized reading' (duration: 107.130866ms)"],"step_count":1} {"level":"info","ts":"2026-04-18T17:56:53.541596Z","caller":"traceutil/trace.go:171","msg":"trace[1176709565] transaction","detail":"{read_only:false; response_revision:1442; number_of_response:1; }","duration":"116.032846ms","start":"2026-04-18T17:56:53.425531Z","end":"2026-04-18T17:56:53.541564Z","steps":["trace[1176709565] 'process raft request' (duration: 101.458294ms)","trace[1176709565] 'compare' (duration: 14.111235ms)"],"step_count":2} {"level":"info","ts":"2026-04-18T17:56:53.690511Z","caller":"traceutil/trace.go:171","msg":"trace[419142096] transaction","detail":"{read_only:false; response_revision:1443; number_of_response:1; }","duration":"142.287868ms","start":"2026-04-18T17:56:53.548197Z","end":"2026-04-18T17:56:53.690485Z","steps":["trace[419142096] 'process raft request' (duration: 142.085811ms)"],"step_count":1} {"level":"info","ts":"2026-04-18T17:56:53.690930Z","caller":"traceutil/trace.go:171","msg":"trace[1510005575] linearizableReadLoop","detail":"{readStateIndex:1704; appliedIndex:1704; }","duration":"107.686775ms","start":"2026-04-18T17:56:53.583210Z","end":"2026-04-18T17:56:53.690896Z","steps":["trace[1510005575] 'read index received' (duration: 107.682215ms)","trace[1510005575] 'applied index is now lower than readState.Index' (duration: 3.63µs)"],"step_count":2} {"level":"warn","ts":"2026-04-18T17:56:53.691063Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"107.832119ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/leases/kube-system/plndr-svcs-lock\" limit:1 ","response":"range_response_count:1 size:441"} {"level":"info","ts":"2026-04-18T17:56:53.691150Z","caller":"traceutil/trace.go:171","msg":"trace[1212014949] range","detail":"{range_begin:/registry/leases/kube-system/plndr-svcs-lock; range_end:; response_count:1; response_revision:1443; }","duration":"107.970043ms","start":"2026-04-18T17:56:53.583155Z","end":"2026-04-18T17:56:53.691125Z","steps":["trace[1212014949] 'agreement among raft nodes before linearized reading' (duration: 107.850449ms)"],"step_count":1} {"level":"info","ts":"2026-04-18T17:56:54.050101Z","caller":"traceutil/trace.go:171","msg":"trace[1000433300] transaction","detail":"{read_only:false; response_revision:1444; number_of_response:1; }","duration":"334.250261ms","start":"2026-04-18T17:56:53.715814Z","end":"2026-04-18T17:56:54.050064Z","steps":["trace[1000433300] 'process raft request' (duration: 297.106307ms)","trace[1000433300] 'compare' (duration: 37.0058ms)"],"step_count":2} {"level":"warn","ts":"2026-04-18T17:56:54.050312Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-04-18T17:56:53.715713Z","time spent":"334.475979ms","remote":"127.0.0.1:44732","response type":"/etcdserverpb.KV/Txn","request count":1,"request size":2164,"response count":0,"response size":39,"request content":"compare: success:> failure: >"} {"level":"info","ts":"2026-04-18T17:56:54.051398Z","caller":"traceutil/trace.go:171","msg":"trace[614318174] linearizableReadLoop","detail":"{readStateIndex:1704; appliedIndex:1705; }","duration":"335.004458ms","start":"2026-04-18T17:56:53.716369Z","end":"2026-04-18T17:56:54.051373Z","steps":["trace[614318174] 'read index received' (duration: 334.998998ms)","trace[614318174] 'applied index is now lower than readState.Index' (duration: 4.61µs)"],"step_count":2} {"level":"warn","ts":"2026-04-18T17:56:54.051550Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"335.151112ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/cilium.io/ciliumcidrgroups/\" range_end:\"/registry/cilium.io/ciliumcidrgroups0\" count_only:true ","response":"range_response_count:0 size:5"} {"level":"info","ts":"2026-04-18T17:56:54.051810Z","caller":"traceutil/trace.go:171","msg":"trace[442858944] range","detail":"{range_begin:/registry/cilium.io/ciliumcidrgroups/; range_end:/registry/cilium.io/ciliumcidrgroups0; response_count:0; response_revision:1444; }","duration":"335.443432ms","start":"2026-04-18T17:56:53.716342Z","end":"2026-04-18T17:56:54.051786Z","steps":["trace[442858944] 'agreement among raft nodes before linearized reading' (duration: 335.149363ms)"],"step_count":1} {"level":"warn","ts":"2026-04-18T17:56:54.051881Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-04-18T17:56:53.716336Z","time spent":"335.535105ms","remote":"127.0.0.1:44788","response type":"/etcdserverpb.KV/Range","request count":0,"request size":80,"response count":0,"response size":28,"request content":"key:\"/registry/cilium.io/ciliumcidrgroups/\" range_end:\"/registry/cilium.io/ciliumcidrgroups0\" count_only:true "} {"level":"warn","ts":"2026-04-18T17:56:54.054875Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"338.441223ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/cilium.io/ciliumcidrgroups/\" range_end:\"/registry/cilium.io/ciliumcidrgroups0\" limit:10000 ","response":"range_response_count:0 size:5"} {"level":"warn","ts":"2026-04-18T17:56:54.054906Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"294.073869ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/leases/kube-system/kube-scheduler\" limit:1 ","response":"range_response_count:1 size:482"} {"level":"info","ts":"2026-04-18T17:56:54.054952Z","caller":"traceutil/trace.go:171","msg":"trace[1776617205] range","detail":"{range_begin:/registry/leases/kube-system/kube-scheduler; range_end:; response_count:1; response_revision:1446; }","duration":"294.169322ms","start":"2026-04-18T17:56:53.760773Z","end":"2026-04-18T17:56:54.054943Z","steps":["trace[1776617205] 'agreement among raft nodes before linearized reading' (duration: 294.078739ms)"],"step_count":1} {"level":"info","ts":"2026-04-18T17:56:54.054956Z","caller":"traceutil/trace.go:171","msg":"trace[416197788] range","detail":"{range_begin:/registry/cilium.io/ciliumcidrgroups/; range_end:/registry/cilium.io/ciliumcidrgroups0; response_count:0; response_revision:1446; }","duration":"338.570257ms","start":"2026-04-18T17:56:53.716364Z","end":"2026-04-18T17:56:54.054934Z","steps":["trace[416197788] 'agreement among raft nodes before linearized reading' (duration: 338.412111ms)"],"step_count":1} {"level":"warn","ts":"2026-04-18T17:56:54.055004Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-04-18T17:56:53.716357Z","time spent":"338.633679ms","remote":"127.0.0.1:44788","response type":"/etcdserverpb.KV/Range","request count":0,"request size":81,"response count":0,"response size":28,"request content":"key:\"/registry/cilium.io/ciliumcidrgroups/\" range_end:\"/registry/cilium.io/ciliumcidrgroups0\" limit:10000 "} {"level":"warn","ts":"2026-04-18T17:56:54.055145Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"338.271626ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/cilium.io/ciliumcidrgroups/\" range_end:\"/registry/cilium.io/ciliumcidrgroups0\" limit:500 ","response":"range_response_count:0 size:5"} {"level":"info","ts":"2026-04-18T17:56:54.055317Z","caller":"traceutil/trace.go:171","msg":"trace[1496199060] range","detail":"{range_begin:/registry/cilium.io/ciliumcidrgroups/; range_end:/registry/cilium.io/ciliumcidrgroups0; response_count:0; response_revision:1446; }","duration":"338.495684ms","start":"2026-04-18T17:56:53.716803Z","end":"2026-04-18T17:56:54.055299Z","steps":["trace[1496199060] 'agreement among raft nodes before linearized reading' (duration: 338.188024ms)"],"step_count":1} {"level":"warn","ts":"2026-04-18T17:56:54.055455Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-04-18T17:56:53.716766Z","time spent":"338.622539ms","remote":"127.0.0.1:44788","response type":"/etcdserverpb.KV/Range","request count":0,"request size":81,"response count":0,"response size":28,"request content":"key:\"/registry/cilium.io/ciliumcidrgroups/\" range_end:\"/registry/cilium.io/ciliumcidrgroups0\" limit:500 "} {"level":"info","ts":"2026-04-18T17:56:54.218119Z","caller":"traceutil/trace.go:171","msg":"trace[911141925] transaction","detail":"{read_only:false; response_revision:1449; number_of_response:1; }","duration":"137.039652ms","start":"2026-04-18T17:56:54.081048Z","end":"2026-04-18T17:56:54.218088Z","steps":["trace[911141925] 'process raft request' (duration: 137.006411ms)"],"step_count":1}