{"level":"warn","ts":"2026-03-02T22:15:53.20449Z","caller":"embed/config.go:679","msg":"Running http and grpc server on single port. This is not recommended for production."} {"level":"info","ts":"2026-03-02T22:15:53.204562Z","caller":"etcdmain/etcd.go:73","msg":"Running: ","args":["etcd","--advertise-client-urls=https://199.204.45.35: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.204.45.35:2380","--initial-cluster=instance=https://199.204.45.35:2380","--key-file=/etc/kubernetes/pki/etcd/server.key","--listen-client-urls=https://127.0.0.1:2379,https://199.204.45.35:2379","--listen-metrics-urls=http://127.0.0.1:2381","--listen-peer-urls=https://199.204.45.35:2380","--name=instance","--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-03-02T22:15:53.204616Z","caller":"embed/config.go:679","msg":"Running http and grpc server on single port. This is not recommended for production."} {"level":"info","ts":"2026-03-02T22:15:53.204628Z","caller":"embed/etcd.go:127","msg":"configuring peer listeners","listen-peer-urls":["https://199.204.45.35:2380"]} {"level":"info","ts":"2026-03-02T22:15:53.204645Z","caller":"embed/etcd.go:494","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-03-02T22:15:53.205229Z","caller":"embed/etcd.go:135","msg":"configuring client listeners","listen-client-urls":["https://127.0.0.1:2379","https://199.204.45.35:2379"]} {"level":"info","ts":"2026-03-02T22:15:53.205307Z","caller":"embed/etcd.go:308","msg":"starting an etcd server","etcd-version":"3.5.12","git-sha":"e7b3bb6cc","go-version":"go1.20.13","go-os":"linux","go-arch":"amd64","max-cpu-set":8,"max-cpu-available":8,"member-initialized":false,"name":"instance","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.204.45.35:2380"],"listen-peer-urls":["https://199.204.45.35:2380"],"advertise-client-urls":["https://199.204.45.35:2379"],"listen-client-urls":["https://127.0.0.1:2379","https://199.204.45.35:2379"],"listen-metrics-urls":["http://127.0.0.1:2381"],"cors":["*"],"host-whitelist":["*"],"initial-cluster":"instance=https://199.204.45.35:2380","initial-cluster-state":"new","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-03-02T22:15:53.20934Z","caller":"etcdserver/backend.go:81","msg":"opened backend db","path":"/var/lib/etcd/member/snap/db","took":"3.779419ms"} {"level":"info","ts":"2026-03-02T22:15:53.216668Z","caller":"etcdserver/raft.go:495","msg":"starting local member","local-member-id":"fb85913747d92cac","cluster-id":"636a84d5a3ba9c31"} {"level":"info","ts":"2026-03-02T22:15:53.216748Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"fb85913747d92cac switched to configuration voters=()"} {"level":"info","ts":"2026-03-02T22:15:53.216774Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"fb85913747d92cac became follower at term 0"} {"level":"info","ts":"2026-03-02T22:15:53.216789Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"newRaft fb85913747d92cac [peers: [], term: 0, commit: 0, applied: 0, lastindex: 0, lastterm: 0]"} {"level":"info","ts":"2026-03-02T22:15:53.216806Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"fb85913747d92cac became follower at term 1"} {"level":"info","ts":"2026-03-02T22:15:53.216839Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"fb85913747d92cac switched to configuration voters=(18124051942037073068)"} {"level":"warn","ts":"2026-03-02T22:15:53.22486Z","caller":"auth/store.go:1241","msg":"simple token is not cryptographically signed"} {"level":"info","ts":"2026-03-02T22:15:53.227216Z","caller":"mvcc/kvstore.go:407","msg":"kvstore restored","current-rev":1} {"level":"info","ts":"2026-03-02T22:15:53.228522Z","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-03-02T22:15:53.231839Z","caller":"etcdserver/server.go:860","msg":"starting etcd server","local-member-id":"fb85913747d92cac","local-server-version":"3.5.12","cluster-version":"to_be_decided"} {"level":"info","ts":"2026-03-02T22:15:53.232568Z","caller":"etcdserver/server.go:744","msg":"started as single-node; fast-forwarding election ticks","local-member-id":"fb85913747d92cac","forward-ticks":9,"forward-duration":"900ms","election-ticks":10,"election-timeout":"1s"} {"level":"info","ts":"2026-03-02T22:15:53.232854Z","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-03-02T22:15:53.233005Z","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-03-02T22:15:53.233141Z","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-03-02T22:15:53.233601Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"fb85913747d92cac switched to configuration voters=(18124051942037073068)"} {"level":"info","ts":"2026-03-02T22:15:53.234832Z","caller":"membership/cluster.go:421","msg":"added member","cluster-id":"636a84d5a3ba9c31","local-member-id":"fb85913747d92cac","added-peer-id":"fb85913747d92cac","added-peer-peer-urls":["https://199.204.45.35:2380"]} {"level":"info","ts":"2026-03-02T22:15:53.237723Z","caller":"embed/etcd.go:726","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-03-02T22:15:53.237952Z","caller":"embed/etcd.go:277","msg":"now serving peer/client/metrics","local-member-id":"fb85913747d92cac","initial-advertise-peer-urls":["https://199.204.45.35:2380"],"listen-peer-urls":["https://199.204.45.35:2380"],"advertise-client-urls":["https://199.204.45.35:2379"],"listen-client-urls":["https://127.0.0.1:2379","https://199.204.45.35:2379"],"listen-metrics-urls":["http://127.0.0.1:2381"]} {"level":"info","ts":"2026-03-02T22:15:53.237985Z","caller":"embed/etcd.go:857","msg":"serving metrics","address":"http://127.0.0.1:2381"} {"level":"info","ts":"2026-03-02T22:15:53.238095Z","caller":"embed/etcd.go:597","msg":"serving peer traffic","address":"199.204.45.35:2380"} {"level":"info","ts":"2026-03-02T22:15:53.238109Z","caller":"embed/etcd.go:569","msg":"cmux::serve","address":"199.204.45.35:2380"} {"level":"info","ts":"2026-03-02T22:15:53.417204Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"fb85913747d92cac is starting a new election at term 1"} {"level":"info","ts":"2026-03-02T22:15:53.417264Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"fb85913747d92cac became pre-candidate at term 1"} {"level":"info","ts":"2026-03-02T22:15:53.417282Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"fb85913747d92cac received MsgPreVoteResp from fb85913747d92cac at term 1"} {"level":"info","ts":"2026-03-02T22:15:53.417296Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"fb85913747d92cac became candidate at term 2"} {"level":"info","ts":"2026-03-02T22:15:53.417304Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"fb85913747d92cac received MsgVoteResp from fb85913747d92cac at term 2"} {"level":"info","ts":"2026-03-02T22:15:53.417312Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"fb85913747d92cac became leader at term 2"} {"level":"info","ts":"2026-03-02T22:15:53.417322Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"raft.node: fb85913747d92cac elected leader fb85913747d92cac at term 2"} {"level":"info","ts":"2026-03-02T22:15:53.418524Z","caller":"etcdserver/server.go:2068","msg":"published local member to cluster through raft","local-member-id":"fb85913747d92cac","local-member-attributes":"{Name:instance ClientURLs:[https://199.204.45.35:2379]}","request-path":"/0/members/fb85913747d92cac/attributes","cluster-id":"636a84d5a3ba9c31","publish-timeout":"7s"} {"level":"info","ts":"2026-03-02T22:15:53.418617Z","caller":"embed/serve.go:103","msg":"ready to serve client requests"} {"level":"info","ts":"2026-03-02T22:15:53.41867Z","caller":"embed/serve.go:103","msg":"ready to serve client requests"} {"level":"info","ts":"2026-03-02T22:15:53.41884Z","caller":"etcdserver/server.go:2578","msg":"setting up initial cluster version using v2 API","cluster-version":"3.5"} {"level":"info","ts":"2026-03-02T22:15:53.419789Z","caller":"membership/cluster.go:584","msg":"set initial cluster version","cluster-id":"636a84d5a3ba9c31","local-member-id":"fb85913747d92cac","cluster-version":"3.5"} {"level":"info","ts":"2026-03-02T22:15:53.419879Z","caller":"api/capability.go:75","msg":"enabled capabilities for version","cluster-version":"3.5"} {"level":"info","ts":"2026-03-02T22:15:53.419925Z","caller":"etcdserver/server.go:2602","msg":"cluster version is updated","cluster-version":"3.5"} {"level":"info","ts":"2026-03-02T22:15:53.420145Z","caller":"embed/serve.go:250","msg":"serving client traffic securely","traffic":"grpc+http","address":"127.0.0.1:2379"} {"level":"info","ts":"2026-03-02T22:15:53.420562Z","caller":"etcdmain/main.go:44","msg":"notifying init daemon"} {"level":"info","ts":"2026-03-02T22:15:53.42058Z","caller":"etcdmain/main.go:50","msg":"successfully notified init daemon"} {"level":"info","ts":"2026-03-02T22:15:53.421319Z","caller":"embed/serve.go:250","msg":"serving client traffic securely","traffic":"grpc+http","address":"199.204.45.35:2379"} {"level":"info","ts":"2026-03-02T22:16:18.962158Z","caller":"traceutil/trace.go:171","msg":"trace[1104093967] transaction","detail":"{read_only:false; response_revision:467; number_of_response:1; }","duration":"142.337826ms","start":"2026-03-02T22:16:18.819792Z","end":"2026-03-02T22:16:18.96213Z","steps":["trace[1104093967] 'process raft request' (duration: 141.969623ms)"],"step_count":1} {"level":"warn","ts":"2026-03-02T22:16:19.310485Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"183.90389ms","expected-duration":"100ms","prefix":"","request":"header: txn: success:> failure: >>","response":"size:16"} {"level":"info","ts":"2026-03-02T22:16:19.310668Z","caller":"traceutil/trace.go:171","msg":"trace[1412380580] linearizableReadLoop","detail":"{readStateIndex:484; appliedIndex:483; }","duration":"256.706834ms","start":"2026-03-02T22:16:19.053939Z","end":"2026-03-02T22:16:19.310646Z","steps":["trace[1412380580] 'read index received' (duration: 71.898056ms)","trace[1412380580] 'applied index is now lower than readState.Index' (duration: 184.806898ms)"],"step_count":2} {"level":"warn","ts":"2026-03-02T22:16:19.310794Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"256.844939ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/health\" ","response":"range_response_count:0 size:5"} {"level":"info","ts":"2026-03-02T22:16:19.310758Z","caller":"traceutil/trace.go:171","msg":"trace[1289910051] transaction","detail":"{read_only:false; response_revision:468; number_of_response:1; }","duration":"344.695164ms","start":"2026-03-02T22:16:18.966009Z","end":"2026-03-02T22:16:19.310704Z","steps":["trace[1289910051] 'process raft request' (duration: 159.832684ms)","trace[1289910051] 'compare' (duration: 183.747396ms)"],"step_count":2} {"level":"info","ts":"2026-03-02T22:16:19.31085Z","caller":"traceutil/trace.go:171","msg":"trace[894084678] range","detail":"{range_begin:/registry/health; range_end:; response_count:0; response_revision:468; }","duration":"256.934771ms","start":"2026-03-02T22:16:19.053902Z","end":"2026-03-02T22:16:19.310836Z","steps":["trace[894084678] 'agreement among raft nodes before linearized reading' (duration: 256.851069ms)"],"step_count":1} {"level":"warn","ts":"2026-03-02T22:16:19.310929Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"221.407547ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/leases/kube-system/kube-scheduler\" ","response":"range_response_count:1 size:478"} {"level":"info","ts":"2026-03-02T22:16:19.311025Z","caller":"traceutil/trace.go:171","msg":"trace[250881957] range","detail":"{range_begin:/registry/leases/kube-system/kube-scheduler; range_end:; response_count:1; response_revision:468; }","duration":"221.568151ms","start":"2026-03-02T22:16:19.089426Z","end":"2026-03-02T22:16:19.310994Z","steps":["trace[250881957] 'agreement among raft nodes before linearized reading' (duration: 221.366525ms)"],"step_count":1} {"level":"warn","ts":"2026-03-02T22:16:19.311112Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"215.278484ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/secrets/kube-system/\" range_end:\"/registry/secrets/kube-system0\" ","response":"range_response_count:3 size:12669"} {"level":"warn","ts":"2026-03-02T22:16:19.311114Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-02T22:16:18.965988Z","time spent":"344.8761ms","remote":"127.0.0.1:36576","response type":"/etcdserverpb.KV/Txn","request count":1,"request size":491,"response count":0,"response size":39,"request content":"compare: success:> failure: >"} {"level":"info","ts":"2026-03-02T22:16:19.311195Z","caller":"traceutil/trace.go:171","msg":"trace[2015742436] range","detail":"{range_begin:/registry/secrets/kube-system/; range_end:/registry/secrets/kube-system0; response_count:3; response_revision:468; }","duration":"215.380588ms","start":"2026-03-02T22:16:19.095795Z","end":"2026-03-02T22:16:19.311176Z","steps":["trace[2015742436] 'agreement among raft nodes before linearized reading' (duration: 215.089539ms)"],"step_count":1} {"level":"info","ts":"2026-03-02T22:16:26.593267Z","caller":"traceutil/trace.go:171","msg":"trace[25721475] transaction","detail":"{read_only:false; response_revision:519; number_of_response:1; }","duration":"123.577787ms","start":"2026-03-02T22:16:26.469666Z","end":"2026-03-02T22:16:26.593244Z","steps":["trace[25721475] 'process raft request' (duration: 121.76023ms)"],"step_count":1} {"level":"info","ts":"2026-03-02T22:16:29.624693Z","caller":"traceutil/trace.go:171","msg":"trace[1425876179] linearizableReadLoop","detail":"{readStateIndex:548; appliedIndex:547; }","duration":"144.375312ms","start":"2026-03-02T22:16:29.480294Z","end":"2026-03-02T22:16:29.62467Z","steps":["trace[1425876179] 'read index received' (duration: 112.608191ms)","trace[1425876179] 'applied index is now lower than readState.Index' (duration: 31.766201ms)"],"step_count":2} {"level":"warn","ts":"2026-03-02T22:16:29.624905Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"144.594658ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/leases/kube-system/plndr-svcs-lock\" ","response":"range_response_count:1 size:438"} {"level":"info","ts":"2026-03-02T22:16:29.625599Z","caller":"traceutil/trace.go:171","msg":"trace[1993067577] range","detail":"{range_begin:/registry/leases/kube-system/plndr-svcs-lock; range_end:; response_count:1; response_revision:530; }","duration":"145.313623ms","start":"2026-03-02T22:16:29.480251Z","end":"2026-03-02T22:16:29.625565Z","steps":["trace[1993067577] 'agreement among raft nodes before linearized reading' (duration: 144.588107ms)"],"step_count":1} {"level":"info","ts":"2026-03-02T22:16:29.624949Z","caller":"traceutil/trace.go:171","msg":"trace[47556520] transaction","detail":"{read_only:false; response_revision:530; number_of_response:1; }","duration":"246.764868ms","start":"2026-03-02T22:16:29.378157Z","end":"2026-03-02T22:16:29.624922Z","steps":["trace[47556520] 'process raft request' (duration: 214.799772ms)","trace[47556520] 'compare' (duration: 31.622058ms)"],"step_count":2} {"level":"info","ts":"2026-03-02T22:16:30.477659Z","caller":"traceutil/trace.go:171","msg":"trace[2003106509] transaction","detail":"{read_only:false; response_revision:532; number_of_response:1; }","duration":"391.189641ms","start":"2026-03-02T22:16:30.086439Z","end":"2026-03-02T22:16:30.477629Z","steps":["trace[2003106509] 'process raft request' (duration: 390.965266ms)"],"step_count":1} {"level":"warn","ts":"2026-03-02T22:16:30.477866Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-02T22:16:30.086407Z","time spent":"391.335213ms","remote":"127.0.0.1:36494","response type":"/etcdserverpb.KV/Txn","request count":1,"request size":17130,"response count":0,"response size":39,"request content":"compare: success:> failure: >"} {"level":"warn","ts":"2026-03-02T22:16:32.76279Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"1.118531557s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/leases/kube-system/plndr-svcs-lock\" ","response":"range_response_count:1 size:438"} {"level":"info","ts":"2026-03-02T22:16:32.762873Z","caller":"traceutil/trace.go:171","msg":"trace[1667526377] range","detail":"{range_begin:/registry/leases/kube-system/plndr-svcs-lock; range_end:; response_count:1; response_revision:532; }","duration":"1.11865806s","start":"2026-03-02T22:16:31.644196Z","end":"2026-03-02T22:16:32.762854Z","steps":["trace[1667526377] 'range keys from in-memory index tree' (duration: 1.118443645s)"],"step_count":1} {"level":"warn","ts":"2026-03-02T22:16:32.762917Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-02T22:16:31.644183Z","time spent":"1.118722722s","remote":"127.0.0.1:36576","response type":"/etcdserverpb.KV/Range","request count":0,"request size":46,"response count":1,"response size":461,"request content":"key:\"/registry/leases/kube-system/plndr-svcs-lock\" "} {"level":"warn","ts":"2026-03-02T22:16:32.762983Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"1.687019908s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/leases/kube-system/plndr-cp-lock\" ","response":"range_response_count:1 size:433"} {"level":"info","ts":"2026-03-02T22:16:32.763031Z","caller":"traceutil/trace.go:171","msg":"trace[1790952651] range","detail":"{range_begin:/registry/leases/kube-system/plndr-cp-lock; range_end:; response_count:1; response_revision:532; }","duration":"1.68710357s","start":"2026-03-02T22:16:31.075912Z","end":"2026-03-02T22:16:32.763016Z","steps":["trace[1790952651] 'range keys from in-memory index tree' (duration: 1.686949187s)"],"step_count":1} {"level":"warn","ts":"2026-03-02T22:16:32.763064Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-02T22:16:31.075893Z","time spent":"1.687163821s","remote":"127.0.0.1:36576","response type":"/etcdserverpb.KV/Range","request count":0,"request size":44,"response count":1,"response size":456,"request content":"key:\"/registry/leases/kube-system/plndr-cp-lock\" "} {"level":"warn","ts":"2026-03-02T22:16:32.763071Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"1.384684001s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/leases/kube-system/kube-controller-manager\" ","response":"range_response_count:1 size:506"} {"level":"info","ts":"2026-03-02T22:16:32.763143Z","caller":"traceutil/trace.go:171","msg":"trace[1974765478] range","detail":"{range_begin:/registry/leases/kube-system/kube-controller-manager; range_end:; response_count:1; response_revision:532; }","duration":"1.384793674s","start":"2026-03-02T22:16:31.378331Z","end":"2026-03-02T22:16:32.763124Z","steps":["trace[1974765478] 'range keys from in-memory index tree' (duration: 1.384606239s)"],"step_count":1} {"level":"warn","ts":"2026-03-02T22:16:32.76318Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-02T22:16:31.378315Z","time spent":"1.384857845s","remote":"127.0.0.1:36576","response type":"/etcdserverpb.KV/Range","request count":0,"request size":54,"response count":1,"response size":529,"request content":"key:\"/registry/leases/kube-system/kube-controller-manager\" "} {"level":"warn","ts":"2026-03-02T22:16:32.763163Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"1.133616515s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/leases/kube-system/kube-scheduler\" ","response":"range_response_count:1 size:479"} {"level":"info","ts":"2026-03-02T22:16:32.76328Z","caller":"traceutil/trace.go:171","msg":"trace[720012701] range","detail":"{range_begin:/registry/leases/kube-system/kube-scheduler; range_end:; response_count:1; response_revision:532; }","duration":"1.13382508s","start":"2026-03-02T22:16:31.629426Z","end":"2026-03-02T22:16:32.763251Z","steps":["trace[720012701] 'range keys from in-memory index tree' (duration: 1.133506313s)"],"step_count":1} {"level":"warn","ts":"2026-03-02T22:16:32.763369Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-02T22:16:31.629406Z","time spent":"1.133915281s","remote":"127.0.0.1:36576","response type":"/etcdserverpb.KV/Range","request count":0,"request size":45,"response count":1,"response size":502,"request content":"key:\"/registry/leases/kube-system/kube-scheduler\" "} {"level":"warn","ts":"2026-03-02T22:16:32.855138Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"975.71992ms","expected-duration":"100ms","prefix":"","request":"header: lease_revoke:","response":"size:28"} {"level":"info","ts":"2026-03-02T22:16:32.855528Z","caller":"traceutil/trace.go:171","msg":"trace[1768721775] linearizableReadLoop","detail":"{readStateIndex:551; appliedIndex:550; }","duration":"801.246246ms","start":"2026-03-02T22:16:32.054226Z","end":"2026-03-02T22:16:32.855472Z","steps":["trace[1768721775] 'read index received' (duration: 34.031µs)","trace[1768721775] 'applied index is now lower than readState.Index' (duration: 801.210125ms)"],"step_count":2} {"level":"warn","ts":"2026-03-02T22:16:32.855616Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"801.374069ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/health\" ","response":"range_response_count:0 size:5"} {"level":"info","ts":"2026-03-02T22:16:32.855682Z","caller":"traceutil/trace.go:171","msg":"trace[363347464] range","detail":"{range_begin:/registry/health; range_end:; response_count:0; response_revision:532; }","duration":"801.446861ms","start":"2026-03-02T22:16:32.05422Z","end":"2026-03-02T22:16:32.855667Z","steps":["trace[363347464] 'agreement among raft nodes before linearized reading' (duration: 801.342138ms)"],"step_count":1} {"level":"warn","ts":"2026-03-02T22:16:32.855727Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-02T22:16:32.05417Z","time spent":"801.546033ms","remote":"127.0.0.1:36336","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-03-02T22:16:34.646201Z","caller":"traceutil/trace.go:171","msg":"trace[1634831671] transaction","detail":"{read_only:false; response_revision:548; number_of_response:1; }","duration":"418.870058ms","start":"2026-03-02T22:16:34.227309Z","end":"2026-03-02T22:16:34.646179Z","steps":["trace[1634831671] 'process raft request' (duration: 418.045899ms)"],"step_count":1} {"level":"warn","ts":"2026-03-02T22:16:34.646338Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-02T22:16:34.22728Z","time spent":"418.99863ms","remote":"127.0.0.1:36576","response type":"/etcdserverpb.KV/Txn","request count":1,"request size":475,"response count":0,"response size":39,"request content":"compare: success:> failure:<>"} {"level":"info","ts":"2026-03-02T22:16:50.953652Z","caller":"traceutil/trace.go:171","msg":"trace[1851866433] transaction","detail":"{read_only:false; response_revision:714; number_of_response:1; }","duration":"218.010446ms","start":"2026-03-02T22:16:50.735608Z","end":"2026-03-02T22:16:50.953618Z","steps":["trace[1851866433] 'process raft request' (duration: 217.721129ms)"],"step_count":1} {"level":"info","ts":"2026-03-02T22:16:51.163983Z","caller":"traceutil/trace.go:171","msg":"trace[77071483] transaction","detail":"{read_only:false; response_revision:715; number_of_response:1; }","duration":"206.271946ms","start":"2026-03-02T22:16:50.957678Z","end":"2026-03-02T22:16:51.163949Z","steps":["trace[77071483] 'process raft request' (duration: 171.69083ms)","trace[77071483] 'compare' (duration: 27.792669ms)"],"step_count":2} {"level":"info","ts":"2026-03-02T22:16:51.1816Z","caller":"traceutil/trace.go:171","msg":"trace[1609489811] linearizableReadLoop","detail":"{readStateIndex:739; appliedIndex:737; }","duration":"214.058725ms","start":"2026-03-02T22:16:50.967513Z","end":"2026-03-02T22:16:51.181572Z","steps":["trace[1609489811] 'read index received' (duration: 161.863704ms)","trace[1609489811] 'applied index is now lower than readState.Index' (duration: 52.194041ms)"],"step_count":2} {"level":"info","ts":"2026-03-02T22:16:51.181736Z","caller":"traceutil/trace.go:171","msg":"trace[1484502698] transaction","detail":"{read_only:false; response_revision:716; number_of_response:1; }","duration":"223.165955ms","start":"2026-03-02T22:16:50.958538Z","end":"2026-03-02T22:16:51.181704Z","steps":["trace[1484502698] 'process raft request' (duration: 222.867499ms)"],"step_count":1} {"level":"warn","ts":"2026-03-02T22:16:51.181868Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"214.336952ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/leases/kube-system/plndr-svcs-lock\" ","response":"range_response_count:1 size:438"} {"level":"warn","ts":"2026-03-02T22:16:51.181893Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"126.006839ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/health\" ","response":"range_response_count:0 size:5"} {"level":"info","ts":"2026-03-02T22:16:51.181925Z","caller":"traceutil/trace.go:171","msg":"trace[1469843095] range","detail":"{range_begin:/registry/leases/kube-system/plndr-svcs-lock; range_end:; response_count:1; response_revision:716; }","duration":"214.449465ms","start":"2026-03-02T22:16:50.96746Z","end":"2026-03-02T22:16:51.18191Z","steps":["trace[1469843095] 'agreement among raft nodes before linearized reading' (duration: 214.257711ms)"],"step_count":1} {"level":"info","ts":"2026-03-02T22:16:51.181973Z","caller":"traceutil/trace.go:171","msg":"trace[1204316851] range","detail":"{range_begin:/registry/health; range_end:; response_count:0; response_revision:716; }","duration":"126.151533ms","start":"2026-03-02T22:16:51.055802Z","end":"2026-03-02T22:16:51.181953Z","steps":["trace[1204316851] 'agreement among raft nodes before linearized reading' (duration: 126.00624ms)"],"step_count":1} {"level":"warn","ts":"2026-03-02T22:16:51.18203Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"211.872985ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/leases/kube-system/kube-scheduler\" ","response":"range_response_count:1 size:479"} {"level":"info","ts":"2026-03-02T22:16:51.182158Z","caller":"traceutil/trace.go:171","msg":"trace[1071808539] range","detail":"{range_begin:/registry/leases/kube-system/kube-scheduler; range_end:; response_count:1; response_revision:716; }","duration":"212.030649ms","start":"2026-03-02T22:16:50.970105Z","end":"2026-03-02T22:16:51.182136Z","steps":["trace[1071808539] 'agreement among raft nodes before linearized reading' (duration: 211.608439ms)"],"step_count":1} {"level":"warn","ts":"2026-03-02T22:16:51.416072Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"100.841001ms","expected-duration":"100ms","prefix":"","request":"header: txn: success:> failure: >>","response":"size:16"} {"level":"info","ts":"2026-03-02T22:16:51.416648Z","caller":"traceutil/trace.go:171","msg":"trace[1264088415] transaction","detail":"{read_only:false; response_revision:718; number_of_response:1; }","duration":"229.694695ms","start":"2026-03-02T22:16:51.186929Z","end":"2026-03-02T22:16:51.416624Z","steps":["trace[1264088415] 'process raft request' (duration: 229.618803ms)"],"step_count":1} {"level":"info","ts":"2026-03-02T22:16:51.416658Z","caller":"traceutil/trace.go:171","msg":"trace[1423954988] transaction","detail":"{read_only:false; response_revision:717; number_of_response:1; }","duration":"229.909431ms","start":"2026-03-02T22:16:51.186702Z","end":"2026-03-02T22:16:51.416611Z","steps":["trace[1423954988] 'process raft request' (duration: 128.417076ms)","trace[1423954988] 'compare' (duration: 100.699396ms)"],"step_count":2} {"level":"info","ts":"2026-03-02T22:17:17.858275Z","caller":"traceutil/trace.go:171","msg":"trace[627758867] transaction","detail":"{read_only:false; response_revision:796; number_of_response:1; }","duration":"327.932077ms","start":"2026-03-02T22:17:17.530324Z","end":"2026-03-02T22:17:17.858256Z","steps":["trace[627758867] 'process raft request' (duration: 327.837715ms)"],"step_count":1} {"level":"warn","ts":"2026-03-02T22:17:17.858424Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-02T22:17:17.530303Z","time spent":"328.038149ms","remote":"127.0.0.1:36576","response type":"/etcdserverpb.KV/Txn","request count":1,"request size":464,"response count":0,"response size":39,"request content":"compare: success:> failure: >"} {"level":"info","ts":"2026-03-02T22:17:17.8604Z","caller":"traceutil/trace.go:171","msg":"trace[458603966] linearizableReadLoop","detail":"{readStateIndex:827; appliedIndex:825; }","duration":"139.598126ms","start":"2026-03-02T22:17:17.720779Z","end":"2026-03-02T22:17:17.860377Z","steps":["trace[458603966] 'read index received' (duration: 137.420374ms)","trace[458603966] 'applied index is now lower than readState.Index' (duration: 2.176762ms)"],"step_count":2} {"level":"info","ts":"2026-03-02T22:17:17.860452Z","caller":"traceutil/trace.go:171","msg":"trace[513454000] transaction","detail":"{read_only:false; response_revision:797; number_of_response:1; }","duration":"327.844845ms","start":"2026-03-02T22:17:17.532596Z","end":"2026-03-02T22:17:17.860441Z","steps":["trace[513454000] 'process raft request' (duration: 327.66354ms)"],"step_count":1} {"level":"warn","ts":"2026-03-02T22:17:17.860526Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"139.723959ms","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":"warn","ts":"2026-03-02T22:17:17.860526Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-02T22:17:17.532578Z","time spent":"327.921767ms","remote":"127.0.0.1:36576","response type":"/etcdserverpb.KV/Txn","request count":1,"request size":423,"response count":0,"response size":39,"request content":"compare: success:> failure: >"} {"level":"info","ts":"2026-03-02T22:17:17.860576Z","caller":"traceutil/trace.go:171","msg":"trace[1259245827] range","detail":"{range_begin:/registry/prioritylevelconfigurations/; range_end:/registry/prioritylevelconfigurations0; response_count:0; response_revision:797; }","duration":"139.824041ms","start":"2026-03-02T22:17:17.720731Z","end":"2026-03-02T22:17:17.860555Z","steps":["trace[1259245827] 'agreement among raft nodes before linearized reading' (duration: 139.736099ms)"],"step_count":1} {"level":"warn","ts":"2026-03-02T22:17:20.556336Z","caller":"etcdserver/v3_server.go:897","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":3219120116063176412,"retry-timeout":"500ms"} {"level":"info","ts":"2026-03-02T22:17:20.775233Z","caller":"traceutil/trace.go:171","msg":"trace[196056106] transaction","detail":"{read_only:false; response_revision:801; number_of_response:1; }","duration":"909.064244ms","start":"2026-03-02T22:17:19.866134Z","end":"2026-03-02T22:17:20.775198Z","steps":["trace[196056106] 'process raft request' (duration: 908.755036ms)"],"step_count":1} {"level":"warn","ts":"2026-03-02T22:17:20.775386Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-02T22:17:19.866114Z","time spent":"909.198948ms","remote":"127.0.0.1:36576","response type":"/etcdserverpb.KV/Txn","request count":1,"request size":464,"response count":0,"response size":39,"request content":"compare: success:> failure: >"} {"level":"info","ts":"2026-03-02T22:17:20.848196Z","caller":"traceutil/trace.go:171","msg":"trace[972491588] linearizableReadLoop","detail":"{readStateIndex:833; appliedIndex:830; }","duration":"792.882707ms","start":"2026-03-02T22:17:20.05527Z","end":"2026-03-02T22:17:20.848153Z","steps":["trace[972491588] 'read index received' (duration: 719.680497ms)","trace[972491588] 'applied index is now lower than readState.Index' (duration: 73.20147ms)"],"step_count":2} {"level":"info","ts":"2026-03-02T22:17:20.84827Z","caller":"traceutil/trace.go:171","msg":"trace[1638582941] transaction","detail":"{read_only:false; response_revision:803; number_of_response:1; }","duration":"908.636733ms","start":"2026-03-02T22:17:19.939623Z","end":"2026-03-02T22:17:20.84826Z","steps":["trace[1638582941] 'process raft request' (duration: 908.494939ms)"],"step_count":1} {"level":"warn","ts":"2026-03-02T22:17:20.848337Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"793.050831ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/health\" ","response":"range_response_count:0 size:5"} {"level":"info","ts":"2026-03-02T22:17:20.848374Z","caller":"traceutil/trace.go:171","msg":"trace[879010613] range","detail":"{range_begin:/registry/health; range_end:; response_count:0; response_revision:803; }","duration":"793.139173ms","start":"2026-03-02T22:17:20.055224Z","end":"2026-03-02T22:17:20.848364Z","steps":["trace[879010613] 'agreement among raft nodes before linearized reading' (duration: 793.073392ms)"],"step_count":1} {"level":"warn","ts":"2026-03-02T22:17:20.848404Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-02T22:17:20.055205Z","time spent":"793.190895ms","remote":"127.0.0.1:36336","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-03-02T22:17:20.848432Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"255.265969ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/endpointslices/\" range_end:\"/registry/endpointslices0\" count_only:true ","response":"range_response_count:0 size:7"} {"level":"info","ts":"2026-03-02T22:17:20.848486Z","caller":"traceutil/trace.go:171","msg":"trace[1036537866] range","detail":"{range_begin:/registry/endpointslices/; range_end:/registry/endpointslices0; response_count:0; response_revision:803; }","duration":"255.370542ms","start":"2026-03-02T22:17:20.593102Z","end":"2026-03-02T22:17:20.848472Z","steps":["trace[1036537866] 'agreement among raft nodes before linearized reading' (duration: 255.2777ms)"],"step_count":1} {"level":"info","ts":"2026-03-02T22:17:20.84819Z","caller":"traceutil/trace.go:171","msg":"trace[1267986434] transaction","detail":"{read_only:false; response_revision:802; number_of_response:1; }","duration":"908.608643ms","start":"2026-03-02T22:17:19.939557Z","end":"2026-03-02T22:17:20.848165Z","steps":["trace[1267986434] 'process raft request' (duration: 906.280346ms)"],"step_count":1} {"level":"warn","ts":"2026-03-02T22:17:20.848783Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"252.693346ms","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":"warn","ts":"2026-03-02T22:17:20.848705Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-02T22:17:19.939595Z","time spent":"908.765046ms","remote":"127.0.0.1:36576","response type":"/etcdserverpb.KV/Txn","request count":1,"request size":423,"response count":0,"response size":39,"request content":"compare: success:> failure: >"} {"level":"info","ts":"2026-03-02T22:17:20.848825Z","caller":"traceutil/trace.go:171","msg":"trace[845106968] range","detail":"{range_begin:/registry/configmaps/; range_end:/registry/configmaps0; response_count:0; response_revision:803; }","duration":"252.759228ms","start":"2026-03-02T22:17:20.596056Z","end":"2026-03-02T22:17:20.848815Z","steps":["trace[845106968] 'agreement among raft nodes before linearized reading' (duration: 252.687376ms)"],"step_count":1} {"level":"warn","ts":"2026-03-02T22:17:20.848787Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-02T22:17:19.939543Z","time spent":"909.181226ms","remote":"127.0.0.1:36576","response type":"/etcdserverpb.KV/Txn","request count":1,"request size":521,"response count":0,"response size":39,"request content":"compare: success:> failure: >"} {"level":"info","ts":"2026-03-02T22:17:21.249089Z","caller":"traceutil/trace.go:171","msg":"trace[1095253475] transaction","detail":"{read_only:false; response_revision:804; number_of_response:1; }","duration":"157.485551ms","start":"2026-03-02T22:17:21.091584Z","end":"2026-03-02T22:17:21.249069Z","steps":["trace[1095253475] 'process raft request' (duration: 157.148983ms)"],"step_count":1} {"level":"warn","ts":"2026-03-02T22:17:21.891846Z","caller":"etcdserver/v3_server.go:897","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":3219120116063176420,"retry-timeout":"500ms"} {"level":"warn","ts":"2026-03-02T22:17:22.392634Z","caller":"etcdserver/v3_server.go:897","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":3219120116063176420,"retry-timeout":"500ms"} {"level":"warn","ts":"2026-03-02T22:17:22.603279Z","caller":"wal/wal.go:805","msg":"slow fdatasync","took":"1.250357095s","expected-duration":"1s"} {"level":"info","ts":"2026-03-02T22:17:22.603617Z","caller":"traceutil/trace.go:171","msg":"trace[901096720] transaction","detail":"{read_only:false; response_revision:805; number_of_response:1; }","duration":"1.250797977s","start":"2026-03-02T22:17:21.3528Z","end":"2026-03-02T22:17:22.603598Z","steps":["trace[901096720] 'process raft request' (duration: 1.250677693s)"],"step_count":1} {"level":"warn","ts":"2026-03-02T22:17:22.603765Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-02T22:17:21.352772Z","time spent":"1.250931519s","remote":"127.0.0.1:36576","response type":"/etcdserverpb.KV/Txn","request count":1,"request size":491,"response count":0,"response size":39,"request content":"compare: success:> failure: >"} {"level":"warn","ts":"2026-03-02T22:17:23.083792Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"412.291169ms","expected-duration":"100ms","prefix":"","request":"header: lease_revoke:","response":"size:28"} {"level":"info","ts":"2026-03-02T22:17:23.083911Z","caller":"traceutil/trace.go:171","msg":"trace[1965540234] linearizableReadLoop","detail":"{readStateIndex:836; appliedIndex:834; }","duration":"1.692351068s","start":"2026-03-02T22:17:21.391538Z","end":"2026-03-02T22:17:23.083889Z","steps":["trace[1965540234] 'read index received' (duration: 1.212025513s)","trace[1965540234] 'applied index is now lower than readState.Index' (duration: 480.323455ms)"],"step_count":2} {"level":"warn","ts":"2026-03-02T22:17:23.084184Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"1.692642965s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/leases/kube-system/plndr-cp-lock\" ","response":"range_response_count:1 size:434"} {"level":"info","ts":"2026-03-02T22:17:23.084234Z","caller":"traceutil/trace.go:171","msg":"trace[2131001406] range","detail":"{range_begin:/registry/leases/kube-system/plndr-cp-lock; range_end:; response_count:1; response_revision:805; }","duration":"1.692736537s","start":"2026-03-02T22:17:21.391483Z","end":"2026-03-02T22:17:23.084219Z","steps":["trace[2131001406] 'agreement among raft nodes before linearized reading' (duration: 1.692531672s)"],"step_count":1} {"level":"warn","ts":"2026-03-02T22:17:23.084283Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-02T22:17:21.391459Z","time spent":"1.692812648s","remote":"127.0.0.1:36576","response type":"/etcdserverpb.KV/Range","request count":0,"request size":44,"response count":1,"response size":457,"request content":"key:\"/registry/leases/kube-system/plndr-cp-lock\" "} {"level":"warn","ts":"2026-03-02T22:17:23.084407Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"303.683917ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/leases/kube-system/kube-scheduler\" ","response":"range_response_count:1 size:479"} {"level":"warn","ts":"2026-03-02T22:17:23.084385Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"1.030377745s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/health\" ","response":"range_response_count:0 size:5"} {"level":"warn","ts":"2026-03-02T22:17:23.084452Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"221.960619ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/leases/kube-system/plndr-svcs-lock\" ","response":"range_response_count:1 size:438"} {"level":"info","ts":"2026-03-02T22:17:23.084538Z","caller":"traceutil/trace.go:171","msg":"trace[1462470044] range","detail":"{range_begin:/registry/health; range_end:; response_count:0; response_revision:805; }","duration":"1.030537749s","start":"2026-03-02T22:17:22.053936Z","end":"2026-03-02T22:17:23.084474Z","steps":["trace[1462470044] 'agreement among raft nodes before linearized reading' (duration: 1.030314534s)"],"step_count":1} {"level":"info","ts":"2026-03-02T22:17:23.084551Z","caller":"traceutil/trace.go:171","msg":"trace[1972364670] range","detail":"{range_begin:/registry/leases/kube-system/plndr-svcs-lock; range_end:; response_count:1; response_revision:805; }","duration":"222.110963ms","start":"2026-03-02T22:17:22.862417Z","end":"2026-03-02T22:17:23.084528Z","steps":["trace[1972364670] 'agreement among raft nodes before linearized reading' (duration: 221.851926ms)"],"step_count":1} {"level":"info","ts":"2026-03-02T22:17:23.084484Z","caller":"traceutil/trace.go:171","msg":"trace[1337118710] range","detail":"{range_begin:/registry/leases/kube-system/kube-scheduler; range_end:; response_count:1; response_revision:805; }","duration":"303.7984ms","start":"2026-03-02T22:17:22.780665Z","end":"2026-03-02T22:17:23.084463Z","steps":["trace[1337118710] 'agreement among raft nodes before linearized reading' (duration: 303.594465ms)"],"step_count":1} {"level":"warn","ts":"2026-03-02T22:17:23.084767Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-02T22:17:22.780641Z","time spent":"304.114248ms","remote":"127.0.0.1:36576","response type":"/etcdserverpb.KV/Range","request count":0,"request size":45,"response count":1,"response size":502,"request content":"key:\"/registry/leases/kube-system/kube-scheduler\" "} {"level":"warn","ts":"2026-03-02T22:17:23.084743Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-02T22:17:22.053918Z","time spent":"1.030805105s","remote":"127.0.0.1:36336","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-03-02T22:17:23.28441Z","caller":"traceutil/trace.go:171","msg":"trace[558272196] linearizableReadLoop","detail":"{readStateIndex:839; appliedIndex:836; }","duration":"190.230318ms","start":"2026-03-02T22:17:23.09415Z","end":"2026-03-02T22:17:23.28438Z","steps":["trace[558272196] 'read index received' (duration: 53.762758ms)","trace[558272196] 'applied index is now lower than readState.Index' (duration: 136.465909ms)"],"step_count":2} {"level":"info","ts":"2026-03-02T22:17:23.284559Z","caller":"traceutil/trace.go:171","msg":"trace[271567370] transaction","detail":"{read_only:false; response_revision:808; number_of_response:1; }","duration":"194.778109ms","start":"2026-03-02T22:17:23.089769Z","end":"2026-03-02T22:17:23.284547Z","steps":["trace[271567370] 'process raft request' (duration: 194.547112ms)"],"step_count":1} {"level":"info","ts":"2026-03-02T22:17:23.284536Z","caller":"traceutil/trace.go:171","msg":"trace[1219535107] transaction","detail":"{read_only:false; response_revision:807; number_of_response:1; }","duration":"195.176218ms","start":"2026-03-02T22:17:23.089324Z","end":"2026-03-02T22:17:23.284501Z","steps":["trace[1219535107] 'process raft request' (duration: 120.579224ms)","trace[1219535107] 'compare' (duration: 74.230575ms)"],"step_count":2} {"level":"warn","ts":"2026-03-02T22:17:23.284782Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"190.613797ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/health\" ","response":"range_response_count:0 size:5"} {"level":"info","ts":"2026-03-02T22:17:23.284829Z","caller":"traceutil/trace.go:171","msg":"trace[105301065] range","detail":"{range_begin:/registry/health; range_end:; response_count:0; response_revision:808; }","duration":"190.691809ms","start":"2026-03-02T22:17:23.094124Z","end":"2026-03-02T22:17:23.284816Z","steps":["trace[105301065] 'agreement among raft nodes before linearized reading' (duration: 190.592747ms)"],"step_count":1} {"level":"warn","ts":"2026-03-02T22:17:25.553702Z","caller":"etcdserver/v3_server.go:897","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":3219120116063176435,"retry-timeout":"500ms"} {"level":"warn","ts":"2026-03-02T22:17:26.05404Z","caller":"etcdserver/v3_server.go:897","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":3219120116063176435,"retry-timeout":"500ms"} {"level":"warn","ts":"2026-03-02T22:17:26.555047Z","caller":"etcdserver/v3_server.go:897","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":3219120116063176435,"retry-timeout":"500ms"} {"level":"warn","ts":"2026-03-02T22:17:26.625105Z","caller":"wal/wal.go:805","msg":"slow fdatasync","took":"2.012099815s","expected-duration":"1s"} {"level":"info","ts":"2026-03-02T22:17:26.625621Z","caller":"traceutil/trace.go:171","msg":"trace[1086321330] transaction","detail":"{read_only:false; response_revision:810; number_of_response:1; }","duration":"2.01272801s","start":"2026-03-02T22:17:24.612868Z","end":"2026-03-02T22:17:26.625596Z","steps":["trace[1086321330] 'process raft request' (duration: 2.012549366s)"],"step_count":1} {"level":"warn","ts":"2026-03-02T22:17:26.625855Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-02T22:17:24.612849Z","time spent":"2.012926085s","remote":"127.0.0.1:36576","response type":"/etcdserverpb.KV/Txn","request count":1,"request size":491,"response count":0,"response size":39,"request content":"compare: success:> failure: >"} {"level":"info","ts":"2026-03-02T22:17:26.762553Z","caller":"traceutil/trace.go:171","msg":"trace[1799180865] linearizableReadLoop","detail":"{readStateIndex:842; appliedIndex:840; }","duration":"1.709181856s","start":"2026-03-02T22:17:25.053338Z","end":"2026-03-02T22:17:26.762519Z","steps":["trace[1799180865] 'read index received' (duration: 1.572187223s)","trace[1799180865] 'applied index is now lower than readState.Index' (duration: 136.993313ms)"],"step_count":2} {"level":"info","ts":"2026-03-02T22:17:26.762776Z","caller":"traceutil/trace.go:171","msg":"trace[201982719] transaction","detail":"{read_only:false; response_revision:811; number_of_response:1; }","duration":"394.149778ms","start":"2026-03-02T22:17:26.368592Z","end":"2026-03-02T22:17:26.762742Z","steps":["trace[201982719] 'process raft request' (duration: 300.353867ms)","trace[201982719] 'compare' (duration: 93.435832ms)"],"step_count":2} {"level":"warn","ts":"2026-03-02T22:17:26.762829Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"1.709449613s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/health\" ","response":"range_response_count:0 size:5"} {"level":"info","ts":"2026-03-02T22:17:26.762879Z","caller":"traceutil/trace.go:171","msg":"trace[2094311562] range","detail":"{range_begin:/registry/health; range_end:; response_count:0; response_revision:811; }","duration":"1.709560355s","start":"2026-03-02T22:17:25.053303Z","end":"2026-03-02T22:17:26.762863Z","steps":["trace[2094311562] 'agreement among raft nodes before linearized reading' (duration: 1.709424992s)"],"step_count":1} {"level":"warn","ts":"2026-03-02T22:17:26.762944Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-02T22:17:25.053288Z","time spent":"1.709640497s","remote":"127.0.0.1:36336","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-03-02T22:17:26.763051Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-02T22:17:26.36858Z","time spent":"394.267491ms","remote":"127.0.0.1:36576","response type":"/etcdserverpb.KV/Txn","request count":1,"request size":673,"response count":0,"response size":39,"request content":"compare: success:> failure: >"} {"level":"warn","ts":"2026-03-02T22:17:26.763189Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"1.473096334s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/leases/kube-system/plndr-svcs-lock\" ","response":"range_response_count:1 size:438"} {"level":"warn","ts":"2026-03-02T22:17:26.763197Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"1.39814932s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/leases/kube-system/cilium-operator-resource-lock\" ","response":"range_response_count:1 size:490"} {"level":"info","ts":"2026-03-02T22:17:26.763229Z","caller":"traceutil/trace.go:171","msg":"trace[894109492] range","detail":"{range_begin:/registry/leases/kube-system/plndr-svcs-lock; range_end:; response_count:1; response_revision:811; }","duration":"1.473153055s","start":"2026-03-02T22:17:25.290064Z","end":"2026-03-02T22:17:26.763217Z","steps":["trace[894109492] 'agreement among raft nodes before linearized reading' (duration: 1.473053093s)"],"step_count":1} {"level":"info","ts":"2026-03-02T22:17:26.76325Z","caller":"traceutil/trace.go:171","msg":"trace[326766254] range","detail":"{range_begin:/registry/leases/kube-system/cilium-operator-resource-lock; range_end:; response_count:1; response_revision:811; }","duration":"1.398218012s","start":"2026-03-02T22:17:25.365016Z","end":"2026-03-02T22:17:26.763234Z","steps":["trace[326766254] 'agreement among raft nodes before linearized reading' (duration: 1.397911874s)"],"step_count":1} {"level":"warn","ts":"2026-03-02T22:17:26.763262Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-02T22:17:25.290055Z","time spent":"1.473199836s","remote":"127.0.0.1:36576","response type":"/etcdserverpb.KV/Range","request count":0,"request size":46,"response count":1,"response size":461,"request content":"key:\"/registry/leases/kube-system/plndr-svcs-lock\" "} {"level":"warn","ts":"2026-03-02T22:17:26.763161Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"401.953767ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/masterleases/199.204.45.35\" ","response":"range_response_count:1 size:133"} {"level":"warn","ts":"2026-03-02T22:17:26.763289Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-02T22:17:25.364987Z","time spent":"1.398292864s","remote":"127.0.0.1:36576","response type":"/etcdserverpb.KV/Range","request count":0,"request size":60,"response count":1,"response size":513,"request content":"key:\"/registry/leases/kube-system/cilium-operator-resource-lock\" "} {"level":"warn","ts":"2026-03-02T22:17:26.763313Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"596.170732ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/persistentvolumes/\" range_end:\"/registry/persistentvolumes0\" count_only:true ","response":"range_response_count:0 size:5"} {"level":"info","ts":"2026-03-02T22:17:26.763337Z","caller":"traceutil/trace.go:171","msg":"trace[651486142] range","detail":"{range_begin:/registry/masterleases/199.204.45.35; range_end:; response_count:1; response_revision:811; }","duration":"402.176453ms","start":"2026-03-02T22:17:26.361138Z","end":"2026-03-02T22:17:26.763315Z","steps":["trace[651486142] 'agreement among raft nodes before linearized reading' (duration: 401.792744ms)"],"step_count":1} {"level":"warn","ts":"2026-03-02T22:17:26.763034Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"1.610492846s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/leases/kube-system/plndr-cp-lock\" ","response":"range_response_count:1 size:434"} {"level":"info","ts":"2026-03-02T22:17:26.763411Z","caller":"traceutil/trace.go:171","msg":"trace[1929980257] range","detail":"{range_begin:/registry/persistentvolumes/; range_end:/registry/persistentvolumes0; response_count:0; response_revision:811; }","duration":"596.324356ms","start":"2026-03-02T22:17:26.167063Z","end":"2026-03-02T22:17:26.763387Z","steps":["trace[1929980257] 'agreement among raft nodes before linearized reading' (duration: 596.156711ms)"],"step_count":1} {"level":"info","ts":"2026-03-02T22:17:26.763436Z","caller":"traceutil/trace.go:171","msg":"trace[1669299833] range","detail":"{range_begin:/registry/leases/kube-system/plndr-cp-lock; range_end:; response_count:1; response_revision:811; }","duration":"1.610927196s","start":"2026-03-02T22:17:25.152492Z","end":"2026-03-02T22:17:26.763419Z","steps":["trace[1669299833] 'agreement among raft nodes before linearized reading' (duration: 1.610281321s)"],"step_count":1} {"level":"warn","ts":"2026-03-02T22:17:26.763435Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-02T22:17:26.361121Z","time spent":"402.290585ms","remote":"127.0.0.1:36358","response type":"/etcdserverpb.KV/Range","request count":0,"request size":38,"response count":1,"response size":156,"request content":"key:\"/registry/masterleases/199.204.45.35\" "} {"level":"warn","ts":"2026-03-02T22:17:26.763461Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"1.474135799s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/leases/kube-system/kube-scheduler\" ","response":"range_response_count:1 size:479"} {"level":"warn","ts":"2026-03-02T22:17:26.763461Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-02T22:17:26.167043Z","time spent":"596.407777ms","remote":"127.0.0.1:36474","response type":"/etcdserverpb.KV/Range","request count":0,"request size":62,"response count":0,"response size":28,"request content":"key:\"/registry/persistentvolumes/\" range_end:\"/registry/persistentvolumes0\" count_only:true "} {"level":"info","ts":"2026-03-02T22:17:26.763498Z","caller":"traceutil/trace.go:171","msg":"trace[1114579408] range","detail":"{range_begin:/registry/leases/kube-system/kube-scheduler; range_end:; response_count:1; response_revision:811; }","duration":"1.474207101s","start":"2026-03-02T22:17:25.289281Z","end":"2026-03-02T22:17:26.763488Z","steps":["trace[1114579408] 'agreement among raft nodes before linearized reading' (duration: 1.474109499s)"],"step_count":1} {"level":"warn","ts":"2026-03-02T22:17:26.763494Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-02T22:17:25.152477Z","time spent":"1.611000198s","remote":"127.0.0.1:36576","response type":"/etcdserverpb.KV/Range","request count":0,"request size":44,"response count":1,"response size":457,"request content":"key:\"/registry/leases/kube-system/plndr-cp-lock\" "} {"level":"warn","ts":"2026-03-02T22:17:26.763525Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-02T22:17:25.289265Z","time spent":"1.474254872s","remote":"127.0.0.1:36576","response type":"/etcdserverpb.KV/Range","request count":0,"request size":45,"response count":1,"response size":502,"request content":"key:\"/registry/leases/kube-system/kube-scheduler\" "} {"level":"info","ts":"2026-03-02T22:17:27.052701Z","caller":"traceutil/trace.go:171","msg":"trace[288234688] transaction","detail":"{read_only:false; response_revision:815; number_of_response:1; }","duration":"283.000695ms","start":"2026-03-02T22:17:26.769677Z","end":"2026-03-02T22:17:27.052678Z","steps":["trace[288234688] 'process raft request' (duration: 282.937193ms)"],"step_count":1} {"level":"info","ts":"2026-03-02T22:17:27.052762Z","caller":"traceutil/trace.go:171","msg":"trace[1044617666] linearizableReadLoop","detail":"{readStateIndex:848; appliedIndex:843; }","duration":"277.187783ms","start":"2026-03-02T22:17:26.77555Z","end":"2026-03-02T22:17:27.052738Z","steps":["trace[1044617666] 'read index received' (duration: 1.793933ms)","trace[1044617666] 'applied index is now lower than readState.Index' (duration: 275.39294ms)"],"step_count":2} {"level":"info","ts":"2026-03-02T22:17:27.052912Z","caller":"traceutil/trace.go:171","msg":"trace[1922639056] transaction","detail":"{read_only:false; response_revision:813; number_of_response:1; }","duration":"284.637014ms","start":"2026-03-02T22:17:26.768264Z","end":"2026-03-02T22:17:27.052901Z","steps":["trace[1922639056] 'process raft request' (duration: 269.976927ms)","trace[1922639056] 'compare' (duration: 13.975151ms)"],"step_count":2} {"level":"warn","ts":"2026-03-02T22:17:27.052911Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"277.348127ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/health\" ","response":"range_response_count:0 size:5"} {"level":"info","ts":"2026-03-02T22:17:27.052947Z","caller":"traceutil/trace.go:171","msg":"trace[1676772797] range","detail":"{range_begin:/registry/health; range_end:; response_count:0; response_revision:816; }","duration":"277.411328ms","start":"2026-03-02T22:17:26.775523Z","end":"2026-03-02T22:17:27.052934Z","steps":["trace[1676772797] 'agreement among raft nodes before linearized reading' (duration: 277.324206ms)"],"step_count":1} {"level":"info","ts":"2026-03-02T22:17:27.053004Z","caller":"traceutil/trace.go:171","msg":"trace[2024475150] transaction","detail":"{read_only:false; response_revision:814; number_of_response:1; }","duration":"284.575003ms","start":"2026-03-02T22:17:26.768423Z","end":"2026-03-02T22:17:27.052998Z","steps":["trace[2024475150] 'process raft request' (duration: 284.087092ms)"],"step_count":1} {"level":"info","ts":"2026-03-02T22:17:27.053245Z","caller":"traceutil/trace.go:171","msg":"trace[1289007439] transaction","detail":"{read_only:false; response_revision:816; number_of_response:1; }","duration":"283.394354ms","start":"2026-03-02T22:17:26.76984Z","end":"2026-03-02T22:17:27.053235Z","steps":["trace[1289007439] 'process raft request' (duration: 282.80319ms)"],"step_count":1} {"level":"info","ts":"2026-03-02T22:17:37.382783Z","caller":"traceutil/trace.go:171","msg":"trace[39498949] transaction","detail":"{read_only:false; response_revision:892; number_of_response:1; }","duration":"306.337052ms","start":"2026-03-02T22:17:37.076434Z","end":"2026-03-02T22:17:37.382771Z","steps":["trace[39498949] 'process raft request' (duration: 306.098836ms)"],"step_count":1} {"level":"warn","ts":"2026-03-02T22:17:37.382959Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-02T22:17:37.076417Z","time spent":"306.449474ms","remote":"127.0.0.1:36576","response type":"/etcdserverpb.KV/Txn","request count":1,"request size":672,"response count":0,"response size":39,"request content":"compare: success:> failure: >"} {"level":"warn","ts":"2026-03-02T22:17:37.382971Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"290.834415ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/leases/kube-system/kube-scheduler\" ","response":"range_response_count:1 size:478"} {"level":"info","ts":"2026-03-02T22:17:37.38303Z","caller":"traceutil/trace.go:171","msg":"trace[2127001182] range","detail":"{range_begin:/registry/leases/kube-system/kube-scheduler; range_end:; response_count:1; response_revision:892; }","duration":"290.932648ms","start":"2026-03-02T22:17:37.092083Z","end":"2026-03-02T22:17:37.383015Z","steps":["trace[2127001182] 'agreement among raft nodes before linearized reading' (duration: 290.763624ms)"],"step_count":1} {"level":"info","ts":"2026-03-02T22:17:37.382713Z","caller":"traceutil/trace.go:171","msg":"trace[1793669193] linearizableReadLoop","detail":"{readStateIndex:928; appliedIndex:927; }","duration":"290.556828ms","start":"2026-03-02T22:17:37.092129Z","end":"2026-03-02T22:17:37.382685Z","steps":["trace[1793669193] 'read index received' (duration: 290.295281ms)","trace[1793669193] 'applied index is now lower than readState.Index' (duration: 260.217µs)"],"step_count":2} {"level":"warn","ts":"2026-03-02T22:17:37.383464Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"290.436844ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/leases/kube-system/cilium-operator-resource-lock\" ","response":"range_response_count:1 size:490"} {"level":"info","ts":"2026-03-02T22:17:37.383499Z","caller":"traceutil/trace.go:171","msg":"trace[169193968] range","detail":"{range_begin:/registry/leases/kube-system/cilium-operator-resource-lock; range_end:; response_count:1; response_revision:892; }","duration":"290.494076ms","start":"2026-03-02T22:17:37.092994Z","end":"2026-03-02T22:17:37.383488Z","steps":["trace[169193968] 'agreement among raft nodes before linearized reading' (duration: 290.342922ms)"],"step_count":1} {"level":"warn","ts":"2026-03-02T22:17:37.383582Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"288.524388ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/leases/kube-system/plndr-cp-lock\" ","response":"range_response_count:1 size:433"} {"level":"info","ts":"2026-03-02T22:17:37.383661Z","caller":"traceutil/trace.go:171","msg":"trace[1154438416] range","detail":"{range_begin:/registry/leases/kube-system/plndr-cp-lock; range_end:; response_count:1; response_revision:892; }","duration":"288.615971ms","start":"2026-03-02T22:17:37.095025Z","end":"2026-03-02T22:17:37.383641Z","steps":["trace[1154438416] 'agreement among raft nodes before linearized reading' (duration: 288.370035ms)"],"step_count":1} {"level":"info","ts":"2026-03-02T22:17:39.320318Z","caller":"traceutil/trace.go:171","msg":"trace[719420784] linearizableReadLoop","detail":"{readStateIndex:932; appliedIndex:931; }","duration":"451.135234ms","start":"2026-03-02T22:17:38.869163Z","end":"2026-03-02T22:17:39.320298Z","steps":["trace[719420784] 'read index received' (duration: 450.929999ms)","trace[719420784] 'applied index is now lower than readState.Index' (duration: 204.105µs)"],"step_count":2} {"level":"info","ts":"2026-03-02T22:17:39.320545Z","caller":"traceutil/trace.go:171","msg":"trace[1352424676] transaction","detail":"{read_only:false; response_revision:896; number_of_response:1; }","duration":"639.596429ms","start":"2026-03-02T22:17:38.680939Z","end":"2026-03-02T22:17:39.320536Z","steps":["trace[1352424676] 'process raft request' (duration: 639.203949ms)"],"step_count":1} {"level":"warn","ts":"2026-03-02T22:17:39.320635Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-02T22:17:38.680924Z","time spent":"639.647879ms","remote":"127.0.0.1:36576","response type":"/etcdserverpb.KV/Txn","request count":1,"request size":491,"response count":0,"response size":39,"request content":"compare: success:> failure: >"} {"level":"warn","ts":"2026-03-02T22:17:39.320832Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"451.666316ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/leases/kube-system/plndr-svcs-lock\" ","response":"range_response_count:1 size:438"} {"level":"info","ts":"2026-03-02T22:17:39.320859Z","caller":"traceutil/trace.go:171","msg":"trace[991033952] range","detail":"{range_begin:/registry/leases/kube-system/plndr-svcs-lock; range_end:; response_count:1; response_revision:896; }","duration":"451.732699ms","start":"2026-03-02T22:17:38.869116Z","end":"2026-03-02T22:17:39.320849Z","steps":["trace[991033952] 'agreement among raft nodes before linearized reading' (duration: 451.640717ms)"],"step_count":1} {"level":"warn","ts":"2026-03-02T22:17:39.32088Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-02T22:17:38.869092Z","time spent":"451.78252ms","remote":"127.0.0.1:36576","response type":"/etcdserverpb.KV/Range","request count":0,"request size":46,"response count":1,"response size":461,"request content":"key:\"/registry/leases/kube-system/plndr-svcs-lock\" "} {"level":"warn","ts":"2026-03-02T22:17:39.321175Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"399.906569ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/jobs/\" range_end:\"/registry/jobs0\" count_only:true ","response":"range_response_count:0 size:5"} {"level":"info","ts":"2026-03-02T22:17:39.321197Z","caller":"traceutil/trace.go:171","msg":"trace[1960680354] range","detail":"{range_begin:/registry/jobs/; range_end:/registry/jobs0; response_count:0; response_revision:896; }","duration":"399.958749ms","start":"2026-03-02T22:17:38.921232Z","end":"2026-03-02T22:17:39.321191Z","steps":["trace[1960680354] 'agreement among raft nodes before linearized reading' (duration: 399.923658ms)"],"step_count":1} {"level":"warn","ts":"2026-03-02T22:17:39.321217Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-02T22:17:38.921213Z","time spent":"399.998331ms","remote":"127.0.0.1:36550","response type":"/etcdserverpb.KV/Range","request count":0,"request size":36,"response count":0,"response size":28,"request content":"key:\"/registry/jobs/\" range_end:\"/registry/jobs0\" count_only:true "} {"level":"warn","ts":"2026-03-02T22:17:39.321372Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"265.903058ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/health\" ","response":"range_response_count:0 size:5"} {"level":"info","ts":"2026-03-02T22:17:39.321396Z","caller":"traceutil/trace.go:171","msg":"trace[1602148101] range","detail":"{range_begin:/registry/health; range_end:; response_count:0; response_revision:896; }","duration":"265.96431ms","start":"2026-03-02T22:17:39.055425Z","end":"2026-03-02T22:17:39.32139Z","steps":["trace[1602148101] 'agreement among raft nodes before linearized reading' (duration: 265.929299ms)"],"step_count":1} {"level":"warn","ts":"2026-03-02T22:17:39.857401Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"161.076978ms","expected-duration":"100ms","prefix":"","request":"header: txn: success:> failure: >>","response":"size:16"} {"level":"info","ts":"2026-03-02T22:17:39.857531Z","caller":"traceutil/trace.go:171","msg":"trace[1176778201] linearizableReadLoop","detail":"{readStateIndex:933; appliedIndex:932; }","duration":"463.499825ms","start":"2026-03-02T22:17:39.394015Z","end":"2026-03-02T22:17:39.857515Z","steps":["trace[1176778201] 'read index received' (duration: 302.250403ms)","trace[1176778201] 'applied index is now lower than readState.Index' (duration: 161.247922ms)"],"step_count":2} {"level":"warn","ts":"2026-03-02T22:17:39.857733Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"461.404624ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/leases/kube-system/plndr-cp-lock\" ","response":"range_response_count:1 size:433"} {"level":"warn","ts":"2026-03-02T22:17:39.857766Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"463.72633ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/leases/kube-system/kube-scheduler\" ","response":"range_response_count:1 size:478"} {"level":"info","ts":"2026-03-02T22:17:39.857797Z","caller":"traceutil/trace.go:171","msg":"trace[706087560] range","detail":"{range_begin:/registry/leases/kube-system/plndr-cp-lock; range_end:; response_count:1; response_revision:897; }","duration":"461.502657ms","start":"2026-03-02T22:17:39.396281Z","end":"2026-03-02T22:17:39.857784Z","steps":["trace[706087560] 'agreement among raft nodes before linearized reading' (duration: 461.350973ms)"],"step_count":1} {"level":"warn","ts":"2026-03-02T22:17:39.85783Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-02T22:17:39.396267Z","time spent":"461.556298ms","remote":"127.0.0.1:36576","response type":"/etcdserverpb.KV/Range","request count":0,"request size":44,"response count":1,"response size":456,"request content":"key:\"/registry/leases/kube-system/plndr-cp-lock\" "} {"level":"info","ts":"2026-03-02T22:17:39.857828Z","caller":"traceutil/trace.go:171","msg":"trace[175825460] range","detail":"{range_begin:/registry/leases/kube-system/kube-scheduler; range_end:; response_count:1; response_revision:897; }","duration":"463.842693ms","start":"2026-03-02T22:17:39.393974Z","end":"2026-03-02T22:17:39.857817Z","steps":["trace[175825460] 'agreement among raft nodes before linearized reading' (duration: 463.628428ms)"],"step_count":1} {"level":"warn","ts":"2026-03-02T22:17:39.857872Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-02T22:17:39.393952Z","time spent":"463.911505ms","remote":"127.0.0.1:36576","response type":"/etcdserverpb.KV/Range","request count":0,"request size":45,"response count":1,"response size":501,"request content":"key:\"/registry/leases/kube-system/kube-scheduler\" "} {"level":"info","ts":"2026-03-02T22:17:39.857994Z","caller":"traceutil/trace.go:171","msg":"trace[880174817] transaction","detail":"{read_only:false; response_revision:897; number_of_response:1; }","duration":"523.063944ms","start":"2026-03-02T22:17:39.334488Z","end":"2026-03-02T22:17:39.857552Z","steps":["trace[880174817] 'process raft request' (duration: 361.75323ms)","trace[880174817] 'compare' (duration: 155.729088ms)"],"step_count":2} {"level":"warn","ts":"2026-03-02T22:17:39.85808Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-02T22:17:39.334477Z","time spent":"523.548865ms","remote":"127.0.0.1:36576","response type":"/etcdserverpb.KV/Txn","request count":1,"request size":423,"response count":0,"response size":39,"request content":"compare: success:> failure: >"} {"level":"warn","ts":"2026-03-02T22:17:39.858178Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"464.067809ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/leases/kube-system/cilium-operator-resource-lock\" ","response":"range_response_count:1 size:490"} {"level":"info","ts":"2026-03-02T22:17:39.858212Z","caller":"traceutil/trace.go:171","msg":"trace[1388001819] range","detail":"{range_begin:/registry/leases/kube-system/cilium-operator-resource-lock; range_end:; response_count:1; response_revision:897; }","duration":"464.121391ms","start":"2026-03-02T22:17:39.394081Z","end":"2026-03-02T22:17:39.858203Z","steps":["trace[1388001819] 'agreement among raft nodes before linearized reading' (duration: 463.526666ms)"],"step_count":1} {"level":"warn","ts":"2026-03-02T22:17:39.858236Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-02T22:17:39.394071Z","time spent":"464.159381ms","remote":"127.0.0.1:36576","response type":"/etcdserverpb.KV/Range","request count":0,"request size":60,"response count":1,"response size":513,"request content":"key:\"/registry/leases/kube-system/cilium-operator-resource-lock\" "} {"level":"info","ts":"2026-03-02T22:17:53.632721Z","caller":"traceutil/trace.go:171","msg":"trace[503026757] transaction","detail":"{read_only:false; response_revision:935; number_of_response:1; }","duration":"244.597259ms","start":"2026-03-02T22:17:53.388088Z","end":"2026-03-02T22:17:53.632685Z","steps":["trace[503026757] 'process raft request' (duration: 244.299072ms)"],"step_count":1} {"level":"info","ts":"2026-03-02T22:17:55.642751Z","caller":"traceutil/trace.go:171","msg":"trace[873855526] transaction","detail":"{read_only:false; response_revision:956; number_of_response:1; }","duration":"225.993007ms","start":"2026-03-02T22:17:55.416735Z","end":"2026-03-02T22:17:55.642728Z","steps":["trace[873855526] 'process raft request' (duration: 225.737811ms)"],"step_count":1} {"level":"warn","ts":"2026-03-02T22:17:56.70573Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"354.136395ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/masterleases/199.204.45.35\" ","response":"range_response_count:1 size:133"} {"level":"info","ts":"2026-03-02T22:17:56.705822Z","caller":"traceutil/trace.go:171","msg":"trace[1615773300] range","detail":"{range_begin:/registry/masterleases/199.204.45.35; range_end:; response_count:1; response_revision:964; }","duration":"354.252888ms","start":"2026-03-02T22:17:56.351537Z","end":"2026-03-02T22:17:56.70579Z","steps":["trace[1615773300] 'range keys from in-memory index tree' (duration: 353.985442ms)"],"step_count":1} {"level":"warn","ts":"2026-03-02T22:17:56.705863Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-02T22:17:56.351519Z","time spent":"354.33502ms","remote":"127.0.0.1:36358","response type":"/etcdserverpb.KV/Range","request count":0,"request size":38,"response count":1,"response size":156,"request content":"key:\"/registry/masterleases/199.204.45.35\" "} {"level":"warn","ts":"2026-03-02T22:17:57.117547Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-02T22:17:56.706924Z","time spent":"410.617699ms","remote":"127.0.0.1:36358","response type":"/etcdserverpb.Lease/LeaseGrant","request count":-1,"request size":-1,"response count":-1,"response size":-1,"request content":""} {"level":"warn","ts":"2026-03-02T22:17:57.626907Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"213.925524ms","expected-duration":"100ms","prefix":"","request":"header: txn: success:> failure: >>","response":"size:16"} {"level":"info","ts":"2026-03-02T22:17:57.627082Z","caller":"traceutil/trace.go:171","msg":"trace[400450306] transaction","detail":"{read_only:false; response_revision:965; number_of_response:1; }","duration":"508.468789ms","start":"2026-03-02T22:17:57.118537Z","end":"2026-03-02T22:17:57.627006Z","steps":["trace[400450306] 'process raft request' (duration: 294.35205ms)","trace[400450306] 'compare' (duration: 213.250617ms)"],"step_count":2} {"level":"warn","ts":"2026-03-02T22:17:57.627312Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-02T22:17:57.118519Z","time spent":"508.665194ms","remote":"127.0.0.1:36358","response type":"/etcdserverpb.KV/Txn","request count":1,"request size":118,"response count":0,"response size":39,"request content":"compare: success:> failure: >"} {"level":"info","ts":"2026-03-02T22:17:58.058015Z","caller":"traceutil/trace.go:171","msg":"trace[1117053161] transaction","detail":"{read_only:false; response_revision:968; number_of_response:1; }","duration":"152.5007ms","start":"2026-03-02T22:17:57.904236Z","end":"2026-03-02T22:17:58.056737Z","steps":["trace[1117053161] 'process raft request' (duration: 70.811532ms)","trace[1117053161] 'compare' (duration: 81.469662ms)"],"step_count":2} {"level":"info","ts":"2026-03-02T22:17:58.619615Z","caller":"traceutil/trace.go:171","msg":"trace[155403211] linearizableReadLoop","detail":"{readStateIndex:1014; appliedIndex:1013; }","duration":"117.47285ms","start":"2026-03-02T22:17:58.502122Z","end":"2026-03-02T22:17:58.619595Z","steps":["trace[155403211] 'read index received' (duration: 117.397468ms)","trace[155403211] 'applied index is now lower than readState.Index' (duration: 74.542µs)"],"step_count":2} {"level":"info","ts":"2026-03-02T22:17:58.619682Z","caller":"traceutil/trace.go:171","msg":"trace[857468908] transaction","detail":"{read_only:false; response_revision:974; number_of_response:1; }","duration":"252.299099ms","start":"2026-03-02T22:17:58.367346Z","end":"2026-03-02T22:17:58.619645Z","steps":["trace[857468908] 'process raft request' (duration: 252.152476ms)"],"step_count":1} {"level":"warn","ts":"2026-03-02T22:17:58.619738Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"117.593722ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/priorityclasses/\" range_end:\"/registry/priorityclasses0\" count_only:true ","response":"range_response_count:0 size:7"} {"level":"info","ts":"2026-03-02T22:17:58.619764Z","caller":"traceutil/trace.go:171","msg":"trace[1274953218] range","detail":"{range_begin:/registry/priorityclasses/; range_end:/registry/priorityclasses0; response_count:0; response_revision:974; }","duration":"117.665274ms","start":"2026-03-02T22:17:58.502091Z","end":"2026-03-02T22:17:58.619757Z","steps":["trace[1274953218] 'agreement among raft nodes before linearized reading' (duration: 117.589903ms)"],"step_count":1} {"level":"warn","ts":"2026-03-02T22:17:59.257256Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"318.958217ms","expected-duration":"100ms","prefix":"","request":"header: txn: success:> failure:<>>","response":"size:16"} {"level":"info","ts":"2026-03-02T22:17:59.257484Z","caller":"traceutil/trace.go:171","msg":"trace[2014187243] transaction","detail":"{read_only:false; response_revision:976; number_of_response:1; }","duration":"632.066524ms","start":"2026-03-02T22:17:58.625402Z","end":"2026-03-02T22:17:59.257468Z","steps":["trace[2014187243] 'process raft request' (duration: 631.948542ms)"],"step_count":1} {"level":"warn","ts":"2026-03-02T22:17:59.257539Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-02T22:17:58.625376Z","time spent":"632.140466ms","remote":"127.0.0.1:36400","response type":"/etcdserverpb.KV/Txn","request count":1,"request size":769,"response count":0,"response size":39,"request content":"compare: success:> failure:<>"} {"level":"info","ts":"2026-03-02T22:17:59.257574Z","caller":"traceutil/trace.go:171","msg":"trace[11883714] transaction","detail":"{read_only:false; response_revision:975; number_of_response:1; }","duration":"719.493438ms","start":"2026-03-02T22:17:58.53805Z","end":"2026-03-02T22:17:59.257544Z","steps":["trace[11883714] 'process raft request' (duration: 400.183543ms)","trace[11883714] 'compare' (duration: 318.735222ms)"],"step_count":2} {"level":"warn","ts":"2026-03-02T22:17:59.257706Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-02T22:17:58.538029Z","time spent":"719.611411ms","remote":"127.0.0.1:36400","response type":"/etcdserverpb.KV/Txn","request count":1,"request size":787,"response count":0,"response size":39,"request content":"compare: success:> failure:<>"} {"level":"info","ts":"2026-03-02T22:17:59.25776Z","caller":"traceutil/trace.go:171","msg":"trace[742334248] linearizableReadLoop","detail":"{readStateIndex:1015; appliedIndex:1014; }","duration":"634.435638ms","start":"2026-03-02T22:17:58.623313Z","end":"2026-03-02T22:17:59.257749Z","steps":["trace[742334248] 'read index received' (duration: 315.04132ms)","trace[742334248] 'applied index is now lower than readState.Index' (duration: 319.393298ms)"],"step_count":2} {"level":"warn","ts":"2026-03-02T22:17:59.257974Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"634.655062ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/leases/kube-system/rbd-csi-ceph-com\" ","response":"range_response_count:1 size:473"} {"level":"info","ts":"2026-03-02T22:17:59.258001Z","caller":"traceutil/trace.go:171","msg":"trace[873058302] range","detail":"{range_begin:/registry/leases/kube-system/rbd-csi-ceph-com; range_end:; response_count:1; response_revision:976; }","duration":"634.711654ms","start":"2026-03-02T22:17:58.623281Z","end":"2026-03-02T22:17:59.257993Z","steps":["trace[873058302] 'agreement among raft nodes before linearized reading' (duration: 634.54724ms)"],"step_count":1} {"level":"warn","ts":"2026-03-02T22:17:59.258029Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-02T22:17:58.623269Z","time spent":"634.753695ms","remote":"127.0.0.1:36576","response type":"/etcdserverpb.KV/Range","request count":0,"request size":47,"response count":1,"response size":496,"request content":"key:\"/registry/leases/kube-system/rbd-csi-ceph-com\" "} {"level":"warn","ts":"2026-03-02T22:17:59.258177Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"202.93993ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/health\" ","response":"range_response_count:0 size:5"} {"level":"info","ts":"2026-03-02T22:17:59.258202Z","caller":"traceutil/trace.go:171","msg":"trace[496953652] range","detail":"{range_begin:/registry/health; range_end:; response_count:0; response_revision:976; }","duration":"202.999911ms","start":"2026-03-02T22:17:59.055195Z","end":"2026-03-02T22:17:59.258195Z","steps":["trace[496953652] 'agreement among raft nodes before linearized reading' (duration: 202.962761ms)"],"step_count":1} {"level":"info","ts":"2026-03-02T22:17:59.559607Z","caller":"traceutil/trace.go:171","msg":"trace[662382926] transaction","detail":"{read_only:false; response_revision:977; number_of_response:1; }","duration":"297.221661ms","start":"2026-03-02T22:17:59.262359Z","end":"2026-03-02T22:17:59.559581Z","steps":["trace[662382926] 'process raft request' (duration: 297.020027ms)"],"step_count":1} {"level":"info","ts":"2026-03-02T22:17:59.586202Z","caller":"traceutil/trace.go:171","msg":"trace[251896488] linearizableReadLoop","detail":"{readStateIndex:1018; appliedIndex:1016; }","duration":"254.369567ms","start":"2026-03-02T22:17:59.331804Z","end":"2026-03-02T22:17:59.586174Z","steps":["trace[251896488] 'read index received' (duration: 227.555075ms)","trace[251896488] 'applied index is now lower than readState.Index' (duration: 26.813422ms)"],"step_count":2} {"level":"warn","ts":"2026-03-02T22:17:59.586352Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"254.5264ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/events/\" range_end:\"/registry/events0\" count_only:true ","response":"range_response_count:0 size:7"} {"level":"info","ts":"2026-03-02T22:17:59.586381Z","caller":"traceutil/trace.go:171","msg":"trace[1286058137] range","detail":"{range_begin:/registry/events/; range_end:/registry/events0; response_count:0; response_revision:978; }","duration":"254.612132ms","start":"2026-03-02T22:17:59.331761Z","end":"2026-03-02T22:17:59.586373Z","steps":["trace[1286058137] 'agreement among raft nodes before linearized reading' (duration: 254.49525ms)"],"step_count":1} {"level":"info","ts":"2026-03-02T22:17:59.586389Z","caller":"traceutil/trace.go:171","msg":"trace[1049190289] transaction","detail":"{read_only:false; response_revision:978; number_of_response:1; }","duration":"323.991381ms","start":"2026-03-02T22:17:59.26238Z","end":"2026-03-02T22:17:59.586371Z","steps":["trace[1049190289] 'process raft request' (duration: 323.688315ms)"],"step_count":1} {"level":"warn","ts":"2026-03-02T22:17:59.586528Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-02T22:17:59.262357Z","time spent":"324.096304ms","remote":"127.0.0.1:36576","response type":"/etcdserverpb.KV/Txn","request count":1,"request size":458,"response count":0,"response size":39,"request content":"compare: success:> failure: >"} {"level":"warn","ts":"2026-03-02T22:18:00.019658Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"147.915924ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/replicasets/\" range_end:\"/registry/replicasets0\" count_only:true ","response":"range_response_count:0 size:7"} {"level":"info","ts":"2026-03-02T22:18:00.019733Z","caller":"traceutil/trace.go:171","msg":"trace[936244595] range","detail":"{range_begin:/registry/replicasets/; range_end:/registry/replicasets0; response_count:0; response_revision:979; }","duration":"148.078678ms","start":"2026-03-02T22:17:59.871638Z","end":"2026-03-02T22:18:00.019717Z","steps":["trace[936244595] 'count revisions from in-memory index tree' (duration: 147.74553ms)"],"step_count":1} {"level":"info","ts":"2026-03-02T22:18:00.417126Z","caller":"traceutil/trace.go:171","msg":"trace[1710849227] linearizableReadLoop","detail":"{readStateIndex:1020; appliedIndex:1019; }","duration":"311.524641ms","start":"2026-03-02T22:18:00.105572Z","end":"2026-03-02T22:18:00.417097Z","steps":["trace[1710849227] 'read index received' (duration: 311.324717ms)","trace[1710849227] 'applied index is now lower than readState.Index' (duration: 198.844µs)"],"step_count":2} {"level":"info","ts":"2026-03-02T22:18:00.417255Z","caller":"traceutil/trace.go:171","msg":"trace[165780115] transaction","detail":"{read_only:false; response_revision:980; number_of_response:1; }","duration":"328.720428ms","start":"2026-03-02T22:18:00.088524Z","end":"2026-03-02T22:18:00.417245Z","steps":["trace[165780115] 'process raft request' (duration: 328.37142ms)"],"step_count":1} {"level":"warn","ts":"2026-03-02T22:18:00.417411Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-02T22:18:00.088508Z","time spent":"328.791179ms","remote":"127.0.0.1:36576","response type":"/etcdserverpb.KV/Txn","request count":1,"request size":422,"response count":0,"response size":39,"request content":"compare: success:> failure: >"} {"level":"warn","ts":"2026-03-02T22:18:00.41759Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"311.983072ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/leases/kube-system/plndr-cp-lock\" ","response":"range_response_count:1 size:433"} {"level":"info","ts":"2026-03-02T22:18:00.418322Z","caller":"traceutil/trace.go:171","msg":"trace[283480548] range","detail":"{range_begin:/registry/leases/kube-system/plndr-cp-lock; range_end:; response_count:1; response_revision:980; }","duration":"312.83131ms","start":"2026-03-02T22:18:00.105433Z","end":"2026-03-02T22:18:00.418265Z","steps":["trace[283480548] 'agreement among raft nodes before linearized reading' (duration: 311.89929ms)"],"step_count":1} {"level":"warn","ts":"2026-03-02T22:18:00.418448Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-02T22:18:00.105411Z","time spent":"312.997785ms","remote":"127.0.0.1:36576","response type":"/etcdserverpb.KV/Range","request count":0,"request size":44,"response count":1,"response size":456,"request content":"key:\"/registry/leases/kube-system/plndr-cp-lock\" "} {"level":"warn","ts":"2026-03-02T22:18:00.917395Z","caller":"etcdserver/v3_server.go:897","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":3219120116063176834,"retry-timeout":"500ms"} {"level":"warn","ts":"2026-03-02T22:18:01.064292Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"583.112214ms","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-03-02T22:18:01.06447Z","caller":"traceutil/trace.go:171","msg":"trace[930486463] range","detail":"{range_begin:; range_end:; response_count:0; response_revision:980; }","duration":"583.328839ms","start":"2026-03-02T22:18:00.481118Z","end":"2026-03-02T22:18:01.064446Z","steps":["trace[930486463] 'range keys from in-memory index tree' (duration: 583.090314ms)"],"step_count":1} {"level":"info","ts":"2026-03-02T22:18:01.065307Z","caller":"traceutil/trace.go:171","msg":"trace[1497779522] transaction","detail":"{read_only:false; response_revision:982; number_of_response:1; }","duration":"642.920288ms","start":"2026-03-02T22:18:00.422368Z","end":"2026-03-02T22:18:01.065288Z","steps":["trace[1497779522] 'process raft request' (duration: 642.630461ms)"],"step_count":1} {"level":"info","ts":"2026-03-02T22:18:01.065388Z","caller":"traceutil/trace.go:171","msg":"trace[257824395] transaction","detail":"{read_only:false; response_revision:981; number_of_response:1; }","duration":"688.216436ms","start":"2026-03-02T22:18:00.377093Z","end":"2026-03-02T22:18:01.06531Z","steps":["trace[257824395] 'process raft request' (duration: 589.000057ms)","trace[257824395] 'compare' (duration: 98.758599ms)"],"step_count":2} {"level":"warn","ts":"2026-03-02T22:18:01.065581Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-02T22:18:00.377065Z","time spent":"688.412971ms","remote":"127.0.0.1:36480","response type":"/etcdserverpb.KV/Txn","request count":1,"request size":5957,"response count":0,"response size":39,"request content":"compare: success:> failure: >"} {"level":"warn","ts":"2026-03-02T22:18:01.065419Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-02T22:18:00.422352Z","time spent":"642.995259ms","remote":"127.0.0.1:36576","response type":"/etcdserverpb.KV/Txn","request count":1,"request size":418,"response count":0,"response size":39,"request content":"compare: success:> failure: >"} {"level":"warn","ts":"2026-03-02T22:18:01.065594Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"959.40117ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/leases/kube-system/kube-scheduler\" ","response":"range_response_count:1 size:478"} {"level":"info","ts":"2026-03-02T22:18:01.065675Z","caller":"traceutil/trace.go:171","msg":"trace[1368432642] range","detail":"{range_begin:/registry/leases/kube-system/kube-scheduler; range_end:; response_count:1; response_revision:982; }","duration":"959.509542ms","start":"2026-03-02T22:18:00.106144Z","end":"2026-03-02T22:18:01.065654Z","steps":["trace[1368432642] 'agreement among raft nodes before linearized reading' (duration: 959.215375ms)"],"step_count":1} {"level":"warn","ts":"2026-03-02T22:18:01.065683Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"959.87372ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/leases/kube-system/cilium-operator-resource-lock\" ","response":"range_response_count:1 size:490"} {"level":"warn","ts":"2026-03-02T22:18:01.065727Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-02T22:18:00.106137Z","time spent":"959.581454ms","remote":"127.0.0.1:36576","response type":"/etcdserverpb.KV/Range","request count":0,"request size":45,"response count":1,"response size":501,"request content":"key:\"/registry/leases/kube-system/kube-scheduler\" "} {"level":"info","ts":"2026-03-02T22:18:01.065741Z","caller":"traceutil/trace.go:171","msg":"trace[1913154868] range","detail":"{range_begin:/registry/leases/kube-system/cilium-operator-resource-lock; range_end:; response_count:1; response_revision:982; }","duration":"959.951502ms","start":"2026-03-02T22:18:00.105773Z","end":"2026-03-02T22:18:01.065725Z","steps":["trace[1913154868] 'agreement among raft nodes before linearized reading' (duration: 959.749768ms)"],"step_count":1} {"level":"warn","ts":"2026-03-02T22:18:01.065812Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-02T22:18:00.105766Z","time spent":"960.020884ms","remote":"127.0.0.1:36576","response type":"/etcdserverpb.KV/Range","request count":0,"request size":60,"response count":1,"response size":513,"request content":"key:\"/registry/leases/kube-system/cilium-operator-resource-lock\" "} {"level":"info","ts":"2026-03-02T22:18:01.065613Z","caller":"traceutil/trace.go:171","msg":"trace[1246101768] linearizableReadLoop","detail":"{readStateIndex:1022; appliedIndex:1020; }","duration":"647.884019ms","start":"2026-03-02T22:18:00.41721Z","end":"2026-03-02T22:18:01.065094Z","steps":["trace[1246101768] 'read index received' (duration: 548.895415ms)","trace[1246101768] 'applied index is now lower than readState.Index' (duration: 98.986994ms)"],"step_count":2} {"level":"warn","ts":"2026-03-02T22:18:01.356818Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"182.92059ms","expected-duration":"100ms","prefix":"","request":"header: txn: success:> failure: >>","response":"size:16"} {"level":"info","ts":"2026-03-02T22:18:01.356989Z","caller":"traceutil/trace.go:171","msg":"trace[1166002800] transaction","detail":"{read_only:false; response_revision:984; number_of_response:1; }","duration":"284.195366ms","start":"2026-03-02T22:18:01.072763Z","end":"2026-03-02T22:18:01.356959Z","steps":["trace[1166002800] 'process raft request' (duration: 101.046561ms)","trace[1166002800] 'compare' (duration: 182.762247ms)"],"step_count":2} {"level":"warn","ts":"2026-03-02T22:18:09.820612Z","caller":"etcdserver/v3_server.go:897","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":3219120116063176949,"retry-timeout":"500ms"} {"level":"info","ts":"2026-03-02T22:18:10.134632Z","caller":"traceutil/trace.go:171","msg":"trace[1260546028] linearizableReadLoop","detail":"{readStateIndex:1084; appliedIndex:1083; }","duration":"814.81338ms","start":"2026-03-02T22:18:09.3198Z","end":"2026-03-02T22:18:10.134613Z","steps":["trace[1260546028] 'read index received' (duration: 814.160905ms)","trace[1260546028] 'applied index is now lower than readState.Index' (duration: 651.625µs)"],"step_count":2} {"level":"info","ts":"2026-03-02T22:18:10.134669Z","caller":"traceutil/trace.go:171","msg":"trace[701294458] transaction","detail":"{read_only:false; response_revision:1042; number_of_response:1; }","duration":"945.666383ms","start":"2026-03-02T22:18:09.188975Z","end":"2026-03-02T22:18:10.134641Z","steps":["trace[701294458] 'process raft request' (duration: 945.504288ms)"],"step_count":1} {"level":"warn","ts":"2026-03-02T22:18:10.134794Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-02T22:18:09.188968Z","time spent":"945.760415ms","remote":"127.0.0.1:36576","response type":"/etcdserverpb.KV/Txn","request count":1,"request size":463,"response count":0,"response size":39,"request content":"compare: success:> failure: >"} {"level":"warn","ts":"2026-03-02T22:18:10.134822Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"815.009684ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/leases/kube-system/external-snapshotter-leader-rbd-csi-ceph-com\" ","response":"range_response_count:1 size:535"} {"level":"info","ts":"2026-03-02T22:18:10.134861Z","caller":"traceutil/trace.go:171","msg":"trace[40638700] range","detail":"{range_begin:/registry/leases/kube-system/external-snapshotter-leader-rbd-csi-ceph-com; range_end:; response_count:1; response_revision:1042; }","duration":"815.100146ms","start":"2026-03-02T22:18:09.319749Z","end":"2026-03-02T22:18:10.134849Z","steps":["trace[40638700] 'agreement among raft nodes before linearized reading' (duration: 814.970244ms)"],"step_count":1} {"level":"warn","ts":"2026-03-02T22:18:10.134867Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"708.671546ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/leases/kube-system/cilium-operator-resource-lock\" ","response":"range_response_count:1 size:491"} {"level":"warn","ts":"2026-03-02T22:18:10.134893Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-02T22:18:09.319727Z","time spent":"815.157637ms","remote":"127.0.0.1:36576","response type":"/etcdserverpb.KV/Range","request count":0,"request size":75,"response count":1,"response size":558,"request content":"key:\"/registry/leases/kube-system/external-snapshotter-leader-rbd-csi-ceph-com\" "} {"level":"info","ts":"2026-03-02T22:18:10.134901Z","caller":"traceutil/trace.go:171","msg":"trace[1453091508] range","detail":"{range_begin:/registry/leases/kube-system/cilium-operator-resource-lock; range_end:; response_count:1; response_revision:1042; }","duration":"708.709126ms","start":"2026-03-02T22:18:09.426184Z","end":"2026-03-02T22:18:10.134893Z","steps":["trace[1453091508] 'agreement among raft nodes before linearized reading' (duration: 708.572933ms)"],"step_count":1} {"level":"warn","ts":"2026-03-02T22:18:10.134927Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-02T22:18:09.426142Z","time spent":"708.780948ms","remote":"127.0.0.1:36576","response type":"/etcdserverpb.KV/Range","request count":0,"request size":60,"response count":1,"response size":514,"request content":"key:\"/registry/leases/kube-system/cilium-operator-resource-lock\" "} {"level":"warn","ts":"2026-03-02T22:18:10.134922Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"262.115071ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/leases/kube-system/kube-controller-manager\" ","response":"range_response_count:1 size:506"} {"level":"info","ts":"2026-03-02T22:18:10.134985Z","caller":"traceutil/trace.go:171","msg":"trace[1269762714] range","detail":"{range_begin:/registry/leases/kube-system/kube-controller-manager; range_end:; response_count:1; response_revision:1042; }","duration":"262.209412ms","start":"2026-03-02T22:18:09.872755Z","end":"2026-03-02T22:18:10.134965Z","steps":["trace[1269762714] 'agreement among raft nodes before linearized reading' (duration: 262.038168ms)"],"step_count":1} {"level":"warn","ts":"2026-03-02T22:18:10.135067Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"300.076883ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/leases/kube-system/rbd.csi.ceph.com-kube-system\" ","response":"range_response_count:1 size:532"} {"level":"info","ts":"2026-03-02T22:18:10.135087Z","caller":"traceutil/trace.go:171","msg":"trace[1496658381] range","detail":"{range_begin:/registry/leases/kube-system/rbd.csi.ceph.com-kube-system; range_end:; response_count:1; response_revision:1042; }","duration":"300.123525ms","start":"2026-03-02T22:18:09.834956Z","end":"2026-03-02T22:18:10.13508Z","steps":["trace[1496658381] 'agreement among raft nodes before linearized reading' (duration: 300.053613ms)"],"step_count":1} {"level":"warn","ts":"2026-03-02T22:18:10.135105Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-02T22:18:09.834918Z","time spent":"300.180766ms","remote":"127.0.0.1:36576","response type":"/etcdserverpb.KV/Range","request count":0,"request size":59,"response count":1,"response size":555,"request content":"key:\"/registry/leases/kube-system/rbd.csi.ceph.com-kube-system\" "} {"level":"warn","ts":"2026-03-02T22:18:10.135119Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"534.955912ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/leases/kube-system/rbd-csi-ceph-com\" ","response":"range_response_count:1 size:473"} {"level":"info","ts":"2026-03-02T22:18:10.13515Z","caller":"traceutil/trace.go:171","msg":"trace[1444232071] range","detail":"{range_begin:/registry/leases/kube-system/rbd-csi-ceph-com; range_end:; response_count:1; response_revision:1042; }","duration":"535.032524ms","start":"2026-03-02T22:18:09.600107Z","end":"2026-03-02T22:18:10.13514Z","steps":["trace[1444232071] 'agreement among raft nodes before linearized reading' (duration: 534.926242ms)"],"step_count":1} {"level":"warn","ts":"2026-03-02T22:18:10.135175Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-02T22:18:09.600085Z","time spent":"535.084045ms","remote":"127.0.0.1:36576","response type":"/etcdserverpb.KV/Range","request count":0,"request size":47,"response count":1,"response size":496,"request content":"key:\"/registry/leases/kube-system/rbd-csi-ceph-com\" "} {"level":"info","ts":"2026-03-02T22:19:24.699524Z","caller":"traceutil/trace.go:171","msg":"trace[694963104] transaction","detail":"{read_only:false; response_revision:1347; number_of_response:1; }","duration":"195.903331ms","start":"2026-03-02T22:19:24.503594Z","end":"2026-03-02T22:19:24.699498Z","steps":["trace[694963104] 'process raft request' (duration: 195.696487ms)"],"step_count":1} {"level":"info","ts":"2026-03-02T22:19:24.855049Z","caller":"traceutil/trace.go:171","msg":"trace[302382026] transaction","detail":"{read_only:false; response_revision:1349; number_of_response:1; }","duration":"348.073333ms","start":"2026-03-02T22:19:24.506958Z","end":"2026-03-02T22:19:24.855031Z","steps":["trace[302382026] 'process raft request' (duration: 347.980492ms)"],"step_count":1} {"level":"warn","ts":"2026-03-02T22:19:24.855203Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-02T22:19:24.506951Z","time spent":"348.162275ms","remote":"127.0.0.1:36576","response type":"/etcdserverpb.KV/Txn","request count":1,"request size":517,"response count":0,"response size":39,"request content":"compare: success:> failure: >"} {"level":"info","ts":"2026-03-02T22:19:24.855396Z","caller":"traceutil/trace.go:171","msg":"trace[1700262729] transaction","detail":"{read_only:false; response_revision:1350; number_of_response:1; }","duration":"348.185125ms","start":"2026-03-02T22:19:24.507189Z","end":"2026-03-02T22:19:24.855374Z","steps":["trace[1700262729] 'process raft request' (duration: 347.791958ms)"],"step_count":1} {"level":"warn","ts":"2026-03-02T22:19:24.855501Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-02T22:19:24.507147Z","time spent":"348.294718ms","remote":"127.0.0.1:36576","response type":"/etcdserverpb.KV/Txn","request count":1,"request size":476,"response count":0,"response size":39,"request content":"compare: success:> failure: >"} {"level":"info","ts":"2026-03-02T22:19:24.855466Z","caller":"traceutil/trace.go:171","msg":"trace[1359486838] transaction","detail":"{read_only:false; response_revision:1348; number_of_response:1; }","duration":"350.65509ms","start":"2026-03-02T22:19:24.504752Z","end":"2026-03-02T22:19:24.855407Z","steps":["trace[1359486838] 'process raft request' (duration: 326.966744ms)","trace[1359486838] 'compare' (duration: 23.139716ms)"],"step_count":2} {"level":"warn","ts":"2026-03-02T22:19:24.855695Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-02T22:19:24.50474Z","time spent":"350.833494ms","remote":"127.0.0.1:36576","response type":"/etcdserverpb.KV/Txn","request count":1,"request size":464,"response count":0,"response size":39,"request content":"compare: success:> failure: >"} {"level":"info","ts":"2026-03-02T22:20:41.133659Z","caller":"traceutil/trace.go:171","msg":"trace[849187241] transaction","detail":"{read_only:false; response_revision:1659; number_of_response:1; }","duration":"162.55058ms","start":"2026-03-02T22:20:40.971086Z","end":"2026-03-02T22:20:41.133636Z","steps":["trace[849187241] 'process raft request' (duration: 162.156482ms)"],"step_count":1} {"level":"info","ts":"2026-03-02T22:21:17.62956Z","caller":"traceutil/trace.go:171","msg":"trace[1635763514] transaction","detail":"{read_only:false; response_revision:1843; number_of_response:1; }","duration":"107.876093ms","start":"2026-03-02T22:21:17.521648Z","end":"2026-03-02T22:21:17.629524Z","steps":["trace[1635763514] 'process raft request' (duration: 57.933286ms)","trace[1635763514] 'compare' (duration: 49.61483ms)"],"step_count":2} {"level":"info","ts":"2026-03-02T22:21:18.273272Z","caller":"traceutil/trace.go:171","msg":"trace[1071799034] transaction","detail":"{read_only:false; response_revision:1845; number_of_response:1; }","duration":"101.607083ms","start":"2026-03-02T22:21:18.171638Z","end":"2026-03-02T22:21:18.273245Z","steps":["trace[1071799034] 'process raft request' (duration: 101.48289ms)"],"step_count":1}