{"level":"warn","ts":"2026-03-18T00:48:11.825459Z","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-18T00:48:11.825577Z","caller":"etcdmain/etcd.go:73","msg":"Running: ","args":["etcd","--advertise-client-urls=https://162.253.55.221: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://162.253.55.221:2380","--initial-cluster=instance=https://162.253.55.221:2380","--key-file=/etc/kubernetes/pki/etcd/server.key","--listen-client-urls=https://127.0.0.1:2379,https://162.253.55.221:2379","--listen-metrics-urls=http://127.0.0.1:2381","--listen-peer-urls=https://162.253.55.221: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-18T00:48:11.825694Z","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-18T00:48:11.825715Z","caller":"embed/etcd.go:127","msg":"configuring peer listeners","listen-peer-urls":["https://162.253.55.221:2380"]} {"level":"info","ts":"2026-03-18T00:48:11.825739Z","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-18T00:48:11.826739Z","caller":"embed/etcd.go:135","msg":"configuring client listeners","listen-client-urls":["https://127.0.0.1:2379","https://162.253.55.221:2379"]} {"level":"info","ts":"2026-03-18T00:48:11.826842Z","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://162.253.55.221:2380"],"listen-peer-urls":["https://162.253.55.221:2380"],"advertise-client-urls":["https://162.253.55.221:2379"],"listen-client-urls":["https://127.0.0.1:2379","https://162.253.55.221:2379"],"listen-metrics-urls":["http://127.0.0.1:2381"],"cors":["*"],"host-whitelist":["*"],"initial-cluster":"instance=https://162.253.55.221: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-18T00:48:11.839526Z","caller":"etcdserver/backend.go:81","msg":"opened backend db","path":"/var/lib/etcd/member/snap/db","took":"10.75388ms"} {"level":"info","ts":"2026-03-18T00:48:11.882284Z","caller":"etcdserver/raft.go:495","msg":"starting local member","local-member-id":"c187bdee547e8fd1","cluster-id":"ee7528b898b8b18e"} {"level":"info","ts":"2026-03-18T00:48:11.882444Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"c187bdee547e8fd1 switched to configuration voters=()"} {"level":"info","ts":"2026-03-18T00:48:11.882498Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"c187bdee547e8fd1 became follower at term 0"} {"level":"info","ts":"2026-03-18T00:48:11.882536Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"newRaft c187bdee547e8fd1 [peers: [], term: 0, commit: 0, applied: 0, lastindex: 0, lastterm: 0]"} {"level":"info","ts":"2026-03-18T00:48:11.882569Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"c187bdee547e8fd1 became follower at term 1"} {"level":"info","ts":"2026-03-18T00:48:11.882643Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"c187bdee547e8fd1 switched to configuration voters=(13945323602493476817)"} {"level":"warn","ts":"2026-03-18T00:48:11.919998Z","caller":"auth/store.go:1241","msg":"simple token is not cryptographically signed"} {"level":"info","ts":"2026-03-18T00:48:11.922711Z","caller":"mvcc/kvstore.go:407","msg":"kvstore restored","current-rev":1} {"level":"info","ts":"2026-03-18T00:48:11.92419Z","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-18T00:48:11.926928Z","caller":"etcdserver/server.go:860","msg":"starting etcd server","local-member-id":"c187bdee547e8fd1","local-server-version":"3.5.12","cluster-version":"to_be_decided"} {"level":"info","ts":"2026-03-18T00:48:11.927293Z","caller":"etcdserver/server.go:744","msg":"started as single-node; fast-forwarding election ticks","local-member-id":"c187bdee547e8fd1","forward-ticks":9,"forward-duration":"900ms","election-ticks":10,"election-timeout":"1s"} {"level":"info","ts":"2026-03-18T00:48:11.927615Z","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-18T00:48:11.927721Z","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-18T00:48:11.927861Z","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-18T00:48:11.934839Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"c187bdee547e8fd1 switched to configuration voters=(13945323602493476817)"} {"level":"info","ts":"2026-03-18T00:48:11.935167Z","caller":"membership/cluster.go:421","msg":"added member","cluster-id":"ee7528b898b8b18e","local-member-id":"c187bdee547e8fd1","added-peer-id":"c187bdee547e8fd1","added-peer-peer-urls":["https://162.253.55.221:2380"]} {"level":"info","ts":"2026-03-18T00:48:11.940466Z","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-18T00:48:11.94071Z","caller":"embed/etcd.go:597","msg":"serving peer traffic","address":"162.253.55.221:2380"} {"level":"info","ts":"2026-03-18T00:48:11.940745Z","caller":"embed/etcd.go:277","msg":"now serving peer/client/metrics","local-member-id":"c187bdee547e8fd1","initial-advertise-peer-urls":["https://162.253.55.221:2380"],"listen-peer-urls":["https://162.253.55.221:2380"],"advertise-client-urls":["https://162.253.55.221:2379"],"listen-client-urls":["https://127.0.0.1:2379","https://162.253.55.221:2379"],"listen-metrics-urls":["http://127.0.0.1:2381"]} {"level":"info","ts":"2026-03-18T00:48:11.940783Z","caller":"embed/etcd.go:857","msg":"serving metrics","address":"http://127.0.0.1:2381"} {"level":"info","ts":"2026-03-18T00:48:11.940769Z","caller":"embed/etcd.go:569","msg":"cmux::serve","address":"162.253.55.221:2380"} {"level":"info","ts":"2026-03-18T00:48:12.183778Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"c187bdee547e8fd1 is starting a new election at term 1"} {"level":"info","ts":"2026-03-18T00:48:12.183959Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"c187bdee547e8fd1 became pre-candidate at term 1"} {"level":"info","ts":"2026-03-18T00:48:12.184033Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"c187bdee547e8fd1 received MsgPreVoteResp from c187bdee547e8fd1 at term 1"} {"level":"info","ts":"2026-03-18T00:48:12.184127Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"c187bdee547e8fd1 became candidate at term 2"} {"level":"info","ts":"2026-03-18T00:48:12.184173Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"c187bdee547e8fd1 received MsgVoteResp from c187bdee547e8fd1 at term 2"} {"level":"info","ts":"2026-03-18T00:48:12.18425Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"c187bdee547e8fd1 became leader at term 2"} {"level":"info","ts":"2026-03-18T00:48:12.184312Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"raft.node: c187bdee547e8fd1 elected leader c187bdee547e8fd1 at term 2"} {"level":"info","ts":"2026-03-18T00:48:12.185496Z","caller":"etcdserver/server.go:2578","msg":"setting up initial cluster version using v2 API","cluster-version":"3.5"} {"level":"info","ts":"2026-03-18T00:48:12.187457Z","caller":"etcdserver/server.go:2068","msg":"published local member to cluster through raft","local-member-id":"c187bdee547e8fd1","local-member-attributes":"{Name:instance ClientURLs:[https://162.253.55.221:2379]}","request-path":"/0/members/c187bdee547e8fd1/attributes","cluster-id":"ee7528b898b8b18e","publish-timeout":"7s"} {"level":"info","ts":"2026-03-18T00:48:12.187463Z","caller":"embed/serve.go:103","msg":"ready to serve client requests"} {"level":"info","ts":"2026-03-18T00:48:12.18751Z","caller":"embed/serve.go:103","msg":"ready to serve client requests"} {"level":"info","ts":"2026-03-18T00:48:12.188628Z","caller":"etcdmain/main.go:44","msg":"notifying init daemon"} {"level":"info","ts":"2026-03-18T00:48:12.188725Z","caller":"etcdmain/main.go:50","msg":"successfully notified init daemon"} {"level":"info","ts":"2026-03-18T00:48:12.190755Z","caller":"embed/serve.go:250","msg":"serving client traffic securely","traffic":"grpc+http","address":"127.0.0.1:2379"} {"level":"info","ts":"2026-03-18T00:48:12.193093Z","caller":"embed/serve.go:250","msg":"serving client traffic securely","traffic":"grpc+http","address":"162.253.55.221:2379"} {"level":"info","ts":"2026-03-18T00:48:12.194399Z","caller":"membership/cluster.go:584","msg":"set initial cluster version","cluster-id":"ee7528b898b8b18e","local-member-id":"c187bdee547e8fd1","cluster-version":"3.5"} {"level":"info","ts":"2026-03-18T00:48:12.194554Z","caller":"api/capability.go:75","msg":"enabled capabilities for version","cluster-version":"3.5"} {"level":"info","ts":"2026-03-18T00:48:12.194626Z","caller":"etcdserver/server.go:2602","msg":"cluster version is updated","cluster-version":"3.5"} {"level":"info","ts":"2026-03-18T00:48:15.04386Z","caller":"traceutil/trace.go:171","msg":"trace[392182316] linearizableReadLoop","detail":"{readStateIndex:92; appliedIndex:91; }","duration":"404.703781ms","start":"2026-03-18T00:48:14.639113Z","end":"2026-03-18T00:48:15.043817Z","steps":["trace[392182316] 'read index received' (duration: 404.473316ms)","trace[392182316] 'applied index is now lower than readState.Index' (duration: 229.315µs)"],"step_count":2} {"level":"info","ts":"2026-03-18T00:48:15.043915Z","caller":"traceutil/trace.go:171","msg":"trace[2053801202] transaction","detail":"{read_only:false; response_revision:87; number_of_response:1; }","duration":"677.21969ms","start":"2026-03-18T00:48:14.366645Z","end":"2026-03-18T00:48:15.043865Z","steps":["trace[2053801202] 'process raft request' (duration: 676.870982ms)"],"step_count":1} {"level":"warn","ts":"2026-03-18T00:48:15.044202Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"405.0615ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/clusterroles/\" range_end:\"/registry/clusterroles0\" ","response":"range_response_count:0 size:4"} {"level":"info","ts":"2026-03-18T00:48:15.044431Z","caller":"traceutil/trace.go:171","msg":"trace[985256753] range","detail":"{range_begin:/registry/clusterroles/; range_end:/registry/clusterroles0; response_count:0; response_revision:87; }","duration":"405.374647ms","start":"2026-03-18T00:48:14.63903Z","end":"2026-03-18T00:48:15.044404Z","steps":["trace[985256753] 'agreement among raft nodes before linearized reading' (duration: 404.929147ms)"],"step_count":1} {"level":"warn","ts":"2026-03-18T00:48:15.044588Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-18T00:48:14.638997Z","time spent":"405.575942ms","remote":"127.0.0.1:45410","response type":"/etcdserverpb.KV/Range","request count":0,"request size":50,"response count":0,"response size":28,"request content":"key:\"/registry/clusterroles/\" range_end:\"/registry/clusterroles0\" "} {"level":"warn","ts":"2026-03-18T00:48:15.045333Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-18T00:48:14.366612Z","time spent":"677.60222ms","remote":"127.0.0.1:45104","response type":"/etcdserverpb.KV/Txn","request count":1,"request size":638,"response count":0,"response size":38,"request content":"compare: success:> failure: >"} {"level":"warn","ts":"2026-03-18T00:48:16.664044Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"2.000406783s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/health\" ","response":"","error":"context deadline exceeded"} {"level":"info","ts":"2026-03-18T00:48:16.664188Z","caller":"traceutil/trace.go:171","msg":"trace[771228851] range","detail":"{range_begin:/registry/health; range_end:; }","duration":"2.000585557s","start":"2026-03-18T00:48:14.663559Z","end":"2026-03-18T00:48:16.664144Z","steps":["trace[771228851] 'agreement among raft nodes before linearized reading' (duration: 2.000444794s)"],"step_count":1} {"level":"warn","ts":"2026-03-18T00:48:16.66424Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-18T00:48:14.663534Z","time spent":"2.000696589s","remote":"127.0.0.1:45038","response type":"/etcdserverpb.KV/Range","request count":0,"request size":18,"response count":0,"response size":0,"request content":"key:\"/registry/health\" "} 2026/03/18 00:48:16 WARNING: [core] [Server #6] grpc: Server.processUnaryRPC failed to write status: connection error: desc = "transport is closing" {"level":"warn","ts":"2026-03-18T00:48:16.688554Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"1.579660754s","expected-duration":"100ms","prefix":"","request":"header: txn: success:> failure:<>>","response":"size:4"} {"level":"info","ts":"2026-03-18T00:48:16.688671Z","caller":"traceutil/trace.go:171","msg":"trace[915683426] linearizableReadLoop","detail":"{readStateIndex:93; appliedIndex:92; }","duration":"1.644710809s","start":"2026-03-18T00:48:15.043943Z","end":"2026-03-18T00:48:16.688654Z","steps":["trace[915683426] 'read index received' (duration: 64.716137ms)","trace[915683426] 'applied index is now lower than readState.Index' (duration: 1.579993692s)"],"step_count":2} {"level":"info","ts":"2026-03-18T00:48:16.688716Z","caller":"traceutil/trace.go:171","msg":"trace[678117192] transaction","detail":"{read_only:false; number_of_response:0; response_revision:87; }","duration":"1.868241792s","start":"2026-03-18T00:48:14.820432Z","end":"2026-03-18T00:48:16.688673Z","steps":["trace[678117192] 'process raft request' (duration: 288.283421ms)","trace[678117192] 'compare' (duration: 1.579552932s)"],"step_count":2} {"level":"warn","ts":"2026-03-18T00:48:16.688787Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"2.047568815s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/priorityclasses/system-node-critical\" ","response":"range_response_count:0 size:4"} {"level":"warn","ts":"2026-03-18T00:48:16.688826Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-18T00:48:14.820404Z","time spent":"1.868367166s","remote":"127.0.0.1:45230","response type":"/etcdserverpb.KV/Txn","request count":0,"request size":0,"response count":0,"response size":28,"request content":"compare: success:> failure:<>"} {"level":"info","ts":"2026-03-18T00:48:16.688861Z","caller":"traceutil/trace.go:171","msg":"trace[1019102797] range","detail":"{range_begin:/registry/priorityclasses/system-node-critical; range_end:; response_count:0; response_revision:87; }","duration":"2.047702079s","start":"2026-03-18T00:48:14.641147Z","end":"2026-03-18T00:48:16.688849Z","steps":["trace[1019102797] 'agreement among raft nodes before linearized reading' (duration: 2.047601426s)"],"step_count":1} {"level":"warn","ts":"2026-03-18T00:48:16.688878Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"1.945866783s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/health\" ","response":"range_response_count:0 size:4"} {"level":"warn","ts":"2026-03-18T00:48:16.688914Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-18T00:48:14.641121Z","time spent":"2.0477837s","remote":"127.0.0.1:45438","response type":"/etcdserverpb.KV/Range","request count":0,"request size":48,"response count":0,"response size":28,"request content":"key:\"/registry/priorityclasses/system-node-critical\" "} {"level":"warn","ts":"2026-03-18T00:48:16.688921Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"1.641351568s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/clusterrolebindings/\" range_end:\"/registry/clusterrolebindings0\" ","response":"range_response_count:0 size:4"} {"level":"info","ts":"2026-03-18T00:48:16.688976Z","caller":"traceutil/trace.go:171","msg":"trace[1478952426] range","detail":"{range_begin:/registry/health; range_end:; response_count:0; response_revision:87; }","duration":"1.946032146s","start":"2026-03-18T00:48:14.742918Z","end":"2026-03-18T00:48:16.68895Z","steps":["trace[1478952426] 'agreement among raft nodes before linearized reading' (duration: 1.945834741s)"],"step_count":1} {"level":"info","ts":"2026-03-18T00:48:16.689013Z","caller":"traceutil/trace.go:171","msg":"trace[77616061] range","detail":"{range_begin:/registry/clusterrolebindings/; range_end:/registry/clusterrolebindings0; response_count:0; response_revision:87; }","duration":"1.641538112s","start":"2026-03-18T00:48:15.047456Z","end":"2026-03-18T00:48:16.688994Z","steps":["trace[77616061] 'agreement among raft nodes before linearized reading' (duration: 1.641347617s)"],"step_count":1} {"level":"warn","ts":"2026-03-18T00:48:16.689026Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-18T00:48:14.742892Z","time spent":"1.946125399s","remote":"127.0.0.1:45028","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-18T00:48:16.689069Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-18T00:48:15.04743Z","time spent":"1.641630355s","remote":"127.0.0.1:45424","response type":"/etcdserverpb.KV/Range","request count":0,"request size":64,"response count":0,"response size":28,"request content":"key:\"/registry/clusterrolebindings/\" range_end:\"/registry/clusterrolebindings0\" "} {"level":"warn","ts":"2026-03-18T00:48:16.689049Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"1.639970404s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/events/default/instance.189dc90e1b27df22\" ","response":"range_response_count:1 size:648"} {"level":"info","ts":"2026-03-18T00:48:16.689133Z","caller":"traceutil/trace.go:171","msg":"trace[1184886468] range","detail":"{range_begin:/registry/events/default/instance.189dc90e1b27df22; range_end:; response_count:1; response_revision:87; }","duration":"1.640095217s","start":"2026-03-18T00:48:15.049019Z","end":"2026-03-18T00:48:16.689115Z","steps":["trace[1184886468] 'agreement among raft nodes before linearized reading' (duration: 1.639905692s)"],"step_count":1} {"level":"warn","ts":"2026-03-18T00:48:16.689188Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-18T00:48:15.049013Z","time spent":"1.640167158s","remote":"127.0.0.1:45104","response type":"/etcdserverpb.KV/Range","request count":0,"request size":52,"response count":1,"response size":672,"request content":"key:\"/registry/events/default/instance.189dc90e1b27df22\" "} {"level":"info","ts":"2026-03-18T00:48:18.877609Z","caller":"traceutil/trace.go:171","msg":"trace[1821207794] linearizableReadLoop","detail":"{readStateIndex:258; appliedIndex:257; }","duration":"181.119575ms","start":"2026-03-18T00:48:18.696459Z","end":"2026-03-18T00:48:18.877579Z","steps":["trace[1821207794] 'read index received' (duration: 180.809928ms)","trace[1821207794] 'applied index is now lower than readState.Index' (duration: 308.307µs)"],"step_count":2} {"level":"info","ts":"2026-03-18T00:48:18.877775Z","caller":"traceutil/trace.go:171","msg":"trace[1872216706] transaction","detail":"{read_only:false; response_revision:251; number_of_response:1; }","duration":"192.44259ms","start":"2026-03-18T00:48:18.685279Z","end":"2026-03-18T00:48:18.877722Z","steps":["trace[1872216706] 'process raft request' (duration: 192.121142ms)"],"step_count":1} {"level":"warn","ts":"2026-03-18T00:48:18.877874Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"181.386352ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/serviceaccounts/kube-system/endpointslicemirroring-controller\" ","response":"range_response_count:0 size:5"} {"level":"info","ts":"2026-03-18T00:48:18.877935Z","caller":"traceutil/trace.go:171","msg":"trace[2006767524] range","detail":"{range_begin:/registry/serviceaccounts/kube-system/endpointslicemirroring-controller; range_end:; response_count:0; response_revision:251; }","duration":"181.499214ms","start":"2026-03-18T00:48:18.696414Z","end":"2026-03-18T00:48:18.877913Z","steps":["trace[2006767524] 'agreement among raft nodes before linearized reading' (duration: 181.361541ms)"],"step_count":1} {"level":"info","ts":"2026-03-18T00:48:45.826608Z","caller":"traceutil/trace.go:171","msg":"trace[2015124286] transaction","detail":"{read_only:false; response_revision:519; number_of_response:1; }","duration":"327.278386ms","start":"2026-03-18T00:48:45.499296Z","end":"2026-03-18T00:48:45.826574Z","steps":["trace[2015124286] 'process raft request' (duration: 326.923347ms)"],"step_count":1} {"level":"warn","ts":"2026-03-18T00:48:45.826767Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-18T00:48:45.499271Z","time spent":"327.41809ms","remote":"127.0.0.1:45306","response type":"/etcdserverpb.KV/Txn","request count":1,"request size":464,"response count":0,"response size":40,"request content":"compare: success:> failure: >"} {"level":"info","ts":"2026-03-18T00:48:46.22362Z","caller":"traceutil/trace.go:171","msg":"trace[1534914551] linearizableReadLoop","detail":"{readStateIndex:540; appliedIndex:539; }","duration":"187.840918ms","start":"2026-03-18T00:48:46.035751Z","end":"2026-03-18T00:48:46.223592Z","steps":["trace[1534914551] 'read index received' (duration: 187.618933ms)","trace[1534914551] 'applied index is now lower than readState.Index' (duration: 220.885µs)"],"step_count":2} {"level":"info","ts":"2026-03-18T00:48:46.223674Z","caller":"traceutil/trace.go:171","msg":"trace[626608964] transaction","detail":"{read_only:false; response_revision:521; number_of_response:1; }","duration":"247.31965ms","start":"2026-03-18T00:48:45.976321Z","end":"2026-03-18T00:48:46.22364Z","steps":["trace[626608964] 'process raft request' (duration: 247.129445ms)"],"step_count":1} {"level":"warn","ts":"2026-03-18T00:48:46.223746Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"187.982452ms","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-18T00:48:46.223782Z","caller":"traceutil/trace.go:171","msg":"trace[1469936898] range","detail":"{range_begin:/registry/leases/kube-system/plndr-cp-lock; range_end:; response_count:1; response_revision:521; }","duration":"188.079445ms","start":"2026-03-18T00:48:46.035691Z","end":"2026-03-18T00:48:46.223771Z","steps":["trace[1469936898] 'agreement among raft nodes before linearized reading' (duration: 187.997783ms)"],"step_count":1} {"level":"warn","ts":"2026-03-18T00:48:46.919826Z","caller":"etcdserver/v3_server.go:897","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":10363236834071834484,"retry-timeout":"500ms"} {"level":"info","ts":"2026-03-18T00:48:46.956268Z","caller":"traceutil/trace.go:171","msg":"trace[1271641034] linearizableReadLoop","detail":"{readStateIndex:541; appliedIndex:540; }","duration":"537.291351ms","start":"2026-03-18T00:48:46.41895Z","end":"2026-03-18T00:48:46.956242Z","steps":["trace[1271641034] 'read index received' (duration: 537.167827ms)","trace[1271641034] 'applied index is now lower than readState.Index' (duration: 122.204µs)"],"step_count":2} {"level":"info","ts":"2026-03-18T00:48:46.956365Z","caller":"traceutil/trace.go:171","msg":"trace[1259660143] transaction","detail":"{read_only:false; response_revision:522; number_of_response:1; }","duration":"729.150648ms","start":"2026-03-18T00:48:46.227191Z","end":"2026-03-18T00:48:46.956341Z","steps":["trace[1259660143] 'process raft request' (duration: 728.86652ms)"],"step_count":1} {"level":"warn","ts":"2026-03-18T00:48:46.956484Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-18T00:48:46.227171Z","time spent":"729.236419ms","remote":"127.0.0.1:45306","response type":"/etcdserverpb.KV/Txn","request count":1,"request size":418,"response count":0,"response size":40,"request content":"compare: success:> failure: >"} {"level":"warn","ts":"2026-03-18T00:48:46.956498Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"537.529537ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/minions/instance\" ","response":"range_response_count:1 size:4375"} {"level":"info","ts":"2026-03-18T00:48:46.956548Z","caller":"traceutil/trace.go:171","msg":"trace[1035343850] range","detail":"{range_begin:/registry/minions/instance; range_end:; response_count:1; response_revision:522; }","duration":"537.635789ms","start":"2026-03-18T00:48:46.418896Z","end":"2026-03-18T00:48:46.956532Z","steps":["trace[1035343850] 'agreement among raft nodes before linearized reading' (duration: 537.481786ms)"],"step_count":1} {"level":"warn","ts":"2026-03-18T00:48:46.956556Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"210.828395ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/health\" ","response":"range_response_count:0 size:5"} {"level":"warn","ts":"2026-03-18T00:48:46.956591Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-18T00:48:46.418874Z","time spent":"537.70698ms","remote":"127.0.0.1:45220","response type":"/etcdserverpb.KV/Range","request count":0,"request size":28,"response count":1,"response size":4399,"request content":"key:\"/registry/minions/instance\" "} {"level":"info","ts":"2026-03-18T00:48:46.956605Z","caller":"traceutil/trace.go:171","msg":"trace[1068946826] range","detail":"{range_begin:/registry/health; range_end:; response_count:0; response_revision:522; }","duration":"210.913708ms","start":"2026-03-18T00:48:46.745677Z","end":"2026-03-18T00:48:46.956591Z","steps":["trace[1068946826] 'agreement among raft nodes before linearized reading' (duration: 210.831976ms)"],"step_count":1} {"level":"warn","ts":"2026-03-18T00:48:55.157099Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"1.389673723s","expected-duration":"100ms","prefix":"","request":"header: lease_revoke:","response":"size:29"} {"level":"info","ts":"2026-03-18T00:48:55.157385Z","caller":"traceutil/trace.go:171","msg":"trace[203402175] transaction","detail":"{read_only:false; response_revision:541; number_of_response:1; }","duration":"748.756371ms","start":"2026-03-18T00:48:54.408605Z","end":"2026-03-18T00:48:55.157361Z","steps":["trace[203402175] 'process raft request' (duration: 748.603698ms)"],"step_count":1} {"level":"warn","ts":"2026-03-18T00:48:55.157664Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-18T00:48:54.408548Z","time spent":"749.026878ms","remote":"127.0.0.1:45306","response type":"/etcdserverpb.KV/Txn","request count":1,"request size":673,"response count":0,"response size":40,"request content":"compare: success:> failure: >"} {"level":"info","ts":"2026-03-18T00:48:55.158082Z","caller":"traceutil/trace.go:171","msg":"trace[149228247] linearizableReadLoop","detail":"{readStateIndex:561; appliedIndex:560; }","duration":"1.625165146s","start":"2026-03-18T00:48:53.532895Z","end":"2026-03-18T00:48:55.15806Z","steps":["trace[149228247] 'read index received' (duration: 234.576541ms)","trace[149228247] 'applied index is now lower than readState.Index' (duration: 1.390585895s)"],"step_count":2} {"level":"warn","ts":"2026-03-18T00:48:55.158378Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"1.625461373s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/pods/kube-system/cilium-zvzj7\" ","response":"range_response_count:1 size:16965"} {"level":"warn","ts":"2026-03-18T00:48:55.158427Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"907.6533ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/leases/kube-system/plndr-svcs-lock\" ","response":"range_response_count:1 size:437"} {"level":"warn","ts":"2026-03-18T00:48:55.158446Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"412.297454ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/health\" ","response":"range_response_count:0 size:5"} {"level":"info","ts":"2026-03-18T00:48:55.158456Z","caller":"traceutil/trace.go:171","msg":"trace[281502739] range","detail":"{range_begin:/registry/pods/kube-system/cilium-zvzj7; range_end:; response_count:1; response_revision:541; }","duration":"1.625582496s","start":"2026-03-18T00:48:53.532856Z","end":"2026-03-18T00:48:55.158438Z","steps":["trace[281502739] 'agreement among raft nodes before linearized reading' (duration: 1.625305059s)"],"step_count":1} {"level":"info","ts":"2026-03-18T00:48:55.158489Z","caller":"traceutil/trace.go:171","msg":"trace[209624644] range","detail":"{range_begin:/registry/leases/kube-system/plndr-svcs-lock; range_end:; response_count:1; response_revision:541; }","duration":"907.744622ms","start":"2026-03-18T00:48:54.250729Z","end":"2026-03-18T00:48:55.158474Z","steps":["trace[209624644] 'agreement among raft nodes before linearized reading' (duration: 907.537117ms)"],"step_count":1} {"level":"info","ts":"2026-03-18T00:48:55.158496Z","caller":"traceutil/trace.go:171","msg":"trace[285530453] range","detail":"{range_begin:/registry/health; range_end:; response_count:0; response_revision:541; }","duration":"412.388406ms","start":"2026-03-18T00:48:54.746094Z","end":"2026-03-18T00:48:55.158482Z","steps":["trace[285530453] 'agreement among raft nodes before linearized reading' (duration: 412.305924ms)"],"step_count":1} {"level":"warn","ts":"2026-03-18T00:48:55.158476Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"997.094215ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/health\" ","response":"range_response_count:0 size:5"} {"level":"warn","ts":"2026-03-18T00:48:55.15851Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-18T00:48:53.532838Z","time spent":"1.625662838s","remote":"127.0.0.1:45230","response type":"/etcdserverpb.KV/Range","request count":0,"request size":41,"response count":1,"response size":16989,"request content":"key:\"/registry/pods/kube-system/cilium-zvzj7\" "} {"level":"warn","ts":"2026-03-18T00:48:55.158525Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-18T00:48:54.250716Z","time spent":"907.800484ms","remote":"127.0.0.1:45306","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-18T00:48:55.158537Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-18T00:48:54.746065Z","time spent":"412.462038ms","remote":"127.0.0.1:45028","response type":"/etcdserverpb.KV/Range","request count":0,"request size":18,"response count":0,"response size":29,"request content":"key:\"/registry/health\" "} {"level":"warn","ts":"2026-03-18T00:48:55.158532Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"127.992459ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/leases/kube-system/plndr-cp-lock\" ","response":"range_response_count:1 size:434"} {"level":"warn","ts":"2026-03-18T00:48:55.158548Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"1.295041991s","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-18T00:48:55.15858Z","caller":"traceutil/trace.go:171","msg":"trace[1991440526] range","detail":"{range_begin:/registry/leases/kube-system/plndr-cp-lock; range_end:; response_count:1; response_revision:541; }","duration":"128.100891ms","start":"2026-03-18T00:48:55.030467Z","end":"2026-03-18T00:48:55.158568Z","steps":["trace[1991440526] 'agreement among raft nodes before linearized reading' (duration: 127.910877ms)"],"step_count":1} {"level":"warn","ts":"2026-03-18T00:48:55.158542Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"1.296106326s","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-18T00:48:55.158608Z","caller":"traceutil/trace.go:171","msg":"trace[499812140] range","detail":"{range_begin:/registry/leases/kube-system/kube-controller-manager; range_end:; response_count:1; response_revision:541; }","duration":"1.295115124s","start":"2026-03-18T00:48:53.863477Z","end":"2026-03-18T00:48:55.158592Z","steps":["trace[499812140] 'agreement among raft nodes before linearized reading' (duration: 1.294934638s)"],"step_count":1} {"level":"warn","ts":"2026-03-18T00:48:55.158651Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-18T00:48:53.863471Z","time spent":"1.295170255s","remote":"127.0.0.1:45306","response type":"/etcdserverpb.KV/Range","request count":0,"request size":54,"response count":1,"response size":530,"request content":"key:\"/registry/leases/kube-system/kube-controller-manager\" "} {"level":"info","ts":"2026-03-18T00:48:55.158553Z","caller":"traceutil/trace.go:171","msg":"trace[1991490213] range","detail":"{range_begin:/registry/health; range_end:; response_count:0; response_revision:541; }","duration":"997.198337ms","start":"2026-03-18T00:48:54.161333Z","end":"2026-03-18T00:48:55.158532Z","steps":["trace[1991490213] 'agreement among raft nodes before linearized reading' (duration: 997.049984ms)"],"step_count":1} {"level":"warn","ts":"2026-03-18T00:48:55.158722Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-18T00:48:54.161314Z","time spent":"997.392353ms","remote":"127.0.0.1:45038","response type":"/etcdserverpb.KV/Range","request count":0,"request size":18,"response count":0,"response size":29,"request content":"key:\"/registry/health\" "} {"level":"info","ts":"2026-03-18T00:48:55.158659Z","caller":"traceutil/trace.go:171","msg":"trace[1682618165] range","detail":"{range_begin:/registry/leases/kube-system/kube-scheduler; range_end:; response_count:1; response_revision:541; }","duration":"1.296274252s","start":"2026-03-18T00:48:53.862353Z","end":"2026-03-18T00:48:55.158628Z","steps":["trace[1682618165] 'agreement among raft nodes before linearized reading' (duration: 1.295883891s)"],"step_count":1} {"level":"warn","ts":"2026-03-18T00:48:55.158833Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-18T00:48:53.862335Z","time spent":"1.296484316s","remote":"127.0.0.1:45306","response type":"/etcdserverpb.KV/Range","request count":0,"request size":45,"response count":1,"response size":503,"request content":"key:\"/registry/leases/kube-system/kube-scheduler\" "} {"level":"warn","ts":"2026-03-18T00:48:55.59857Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"324.514939ms","expected-duration":"100ms","prefix":"","request":"header: txn: success:> failure: >>","response":"size:16"} {"level":"info","ts":"2026-03-18T00:48:55.598741Z","caller":"traceutil/trace.go:171","msg":"trace[1952702277] transaction","detail":"{read_only:false; response_revision:543; number_of_response:1; }","duration":"435.083917ms","start":"2026-03-18T00:48:55.163635Z","end":"2026-03-18T00:48:55.598719Z","steps":["trace[1952702277] 'process raft request' (duration: 110.328972ms)","trace[1952702277] 'compare' (duration: 324.380875ms)"],"step_count":2} {"level":"warn","ts":"2026-03-18T00:48:55.598814Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-18T00:48:55.163604Z","time spent":"435.17986ms","remote":"127.0.0.1:45306","response type":"/etcdserverpb.KV/Txn","request count":1,"request size":491,"response count":0,"response size":40,"request content":"compare: success:> failure: >"} {"level":"info","ts":"2026-03-18T00:48:55.598914Z","caller":"traceutil/trace.go:171","msg":"trace[863944850] transaction","detail":"{read_only:false; response_revision:544; number_of_response:1; }","duration":"434.940593ms","start":"2026-03-18T00:48:55.163957Z","end":"2026-03-18T00:48:55.598898Z","steps":["trace[863944850] 'process raft request' (duration: 434.715788ms)"],"step_count":1} {"level":"warn","ts":"2026-03-18T00:48:55.599017Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-18T00:48:55.163953Z","time spent":"435.010425ms","remote":"127.0.0.1:45306","response type":"/etcdserverpb.KV/Txn","request count":1,"request size":422,"response count":0,"response size":40,"request content":"compare: success:> failure: >"} {"level":"info","ts":"2026-03-18T00:48:55.599155Z","caller":"traceutil/trace.go:171","msg":"trace[1171227164] transaction","detail":"{read_only:false; response_revision:545; number_of_response:1; }","duration":"434.902592ms","start":"2026-03-18T00:48:55.164221Z","end":"2026-03-18T00:48:55.599123Z","steps":["trace[1171227164] 'process raft request' (duration: 434.616235ms)"],"step_count":1} {"level":"info","ts":"2026-03-18T00:48:55.599188Z","caller":"traceutil/trace.go:171","msg":"trace[1349137029] transaction","detail":"{read_only:false; response_revision:546; number_of_response:1; }","duration":"425.818522ms","start":"2026-03-18T00:48:55.173347Z","end":"2026-03-18T00:48:55.599165Z","steps":["trace[1349137029] 'process raft request' (duration: 425.711579ms)"],"step_count":1} {"level":"warn","ts":"2026-03-18T00:48:55.599307Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-18T00:48:55.164215Z","time spent":"435.006504ms","remote":"127.0.0.1:45306","response type":"/etcdserverpb.KV/Txn","request count":1,"request size":418,"response count":0,"response size":40,"request content":"compare: success:> failure: >"} {"level":"warn","ts":"2026-03-18T00:48:55.599314Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-18T00:48:55.173335Z","time spent":"425.912365ms","remote":"127.0.0.1:45230","response type":"/etcdserverpb.KV/Txn","request count":1,"request size":17134,"response count":0,"response size":40,"request content":"compare: success:> failure: >"} {"level":"warn","ts":"2026-03-18T00:48:57.378597Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"179.788214ms","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-18T00:48:57.378676Z","caller":"traceutil/trace.go:171","msg":"trace[1047960575] range","detail":"{range_begin:/registry/leases/kube-system/kube-scheduler; range_end:; response_count:1; response_revision:546; }","duration":"179.932508ms","start":"2026-03-18T00:48:57.198724Z","end":"2026-03-18T00:48:57.378657Z","steps":["trace[1047960575] 'range keys from in-memory index tree' (duration: 179.580189ms)"],"step_count":1} {"level":"warn","ts":"2026-03-18T00:48:57.378782Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"1.632269581s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/health\" ","response":"range_response_count:0 size:5"} {"level":"info","ts":"2026-03-18T00:48:57.378857Z","caller":"traceutil/trace.go:171","msg":"trace[1044773505] range","detail":"{range_begin:/registry/health; range_end:; response_count:0; response_revision:546; }","duration":"1.632382934s","start":"2026-03-18T00:48:55.746457Z","end":"2026-03-18T00:48:57.37884Z","steps":["trace[1044773505] 'range keys from in-memory index tree' (duration: 1.632188579s)"],"step_count":1} {"level":"warn","ts":"2026-03-18T00:48:57.378909Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-18T00:48:55.746436Z","time spent":"1.632463785s","remote":"127.0.0.1:45038","response type":"/etcdserverpb.KV/Range","request count":0,"request size":18,"response count":0,"response size":29,"request content":"key:\"/registry/health\" "} {"level":"warn","ts":"2026-03-18T00:48:59.039829Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"293.651502ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/health\" ","response":"range_response_count:0 size:5"} {"level":"info","ts":"2026-03-18T00:48:59.039923Z","caller":"traceutil/trace.go:171","msg":"trace[388834847] range","detail":"{range_begin:/registry/health; range_end:; response_count:0; response_revision:562; }","duration":"293.799755ms","start":"2026-03-18T00:48:58.7461Z","end":"2026-03-18T00:48:59.0399Z","steps":["trace[388834847] 'range keys from in-memory index tree' (duration: 293.532949ms)"],"step_count":1} {"level":"info","ts":"2026-03-18T00:49:09.428026Z","caller":"traceutil/trace.go:171","msg":"trace[1973406224] transaction","detail":"{read_only:false; response_revision:712; number_of_response:1; }","duration":"267.22269ms","start":"2026-03-18T00:49:09.160779Z","end":"2026-03-18T00:49:09.428002Z","steps":["trace[1973406224] 'process raft request' (duration: 267.099967ms)"],"step_count":1} {"level":"info","ts":"2026-03-18T00:49:15.672127Z","caller":"traceutil/trace.go:171","msg":"trace[362460233] linearizableReadLoop","detail":"{readStateIndex:757; appliedIndex:756; }","duration":"197.907985ms","start":"2026-03-18T00:49:15.474197Z","end":"2026-03-18T00:49:15.672105Z","steps":["trace[362460233] 'read index received' (duration: 197.813913ms)","trace[362460233] 'applied index is now lower than readState.Index' (duration: 93.372µs)"],"step_count":2} {"level":"warn","ts":"2026-03-18T00:49:15.672272Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"198.069849ms","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-18T00:49:15.672292Z","caller":"traceutil/trace.go:171","msg":"trace[201229459] range","detail":"{range_begin:/registry/leases/kube-system/kube-scheduler; range_end:; response_count:1; response_revision:730; }","duration":"198.149193ms","start":"2026-03-18T00:49:15.474136Z","end":"2026-03-18T00:49:15.672285Z","steps":["trace[201229459] 'agreement among raft nodes before linearized reading' (duration: 198.04474ms)"],"step_count":1} {"level":"info","ts":"2026-03-18T00:49:15.672311Z","caller":"traceutil/trace.go:171","msg":"trace[1492446592] transaction","detail":"{read_only:false; response_revision:730; number_of_response:1; }","duration":"217.636641ms","start":"2026-03-18T00:49:15.454573Z","end":"2026-03-18T00:49:15.672209Z","steps":["trace[1492446592] 'process raft request' (duration: 217.417985ms)"],"step_count":1} {"level":"info","ts":"2026-03-18T00:49:15.842191Z","caller":"traceutil/trace.go:171","msg":"trace[1647324463] linearizableReadLoop","detail":"{readStateIndex:758; appliedIndex:757; }","duration":"148.01654ms","start":"2026-03-18T00:49:15.694156Z","end":"2026-03-18T00:49:15.842172Z","steps":["trace[1647324463] 'read index received' (duration: 139.515399ms)","trace[1647324463] 'applied index is now lower than readState.Index' (duration: 8.500371ms)"],"step_count":2} {"level":"info","ts":"2026-03-18T00:49:15.8423Z","caller":"traceutil/trace.go:171","msg":"trace[329496598] transaction","detail":"{read_only:false; response_revision:731; number_of_response:1; }","duration":"166.936646ms","start":"2026-03-18T00:49:15.675347Z","end":"2026-03-18T00:49:15.842283Z","steps":["trace[329496598] 'process raft request' (duration: 158.221679ms)"],"step_count":1} {"level":"warn","ts":"2026-03-18T00:49:15.842432Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"148.271118ms","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-18T00:49:15.842463Z","caller":"traceutil/trace.go:171","msg":"trace[1594025926] range","detail":"{range_begin:/registry/leases/kube-system/plndr-svcs-lock; range_end:; response_count:1; response_revision:731; }","duration":"148.37407ms","start":"2026-03-18T00:49:15.69408Z","end":"2026-03-18T00:49:15.842454Z","steps":["trace[1594025926] 'agreement among raft nodes before linearized reading' (duration: 148.190425ms)"],"step_count":1} {"level":"warn","ts":"2026-03-18T00:49:16.343267Z","caller":"etcdserver/v3_server.go:897","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":10363236834071834901,"retry-timeout":"500ms"} {"level":"warn","ts":"2026-03-18T00:49:16.84431Z","caller":"etcdserver/v3_server.go:897","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":10363236834071834901,"retry-timeout":"500ms"} {"level":"warn","ts":"2026-03-18T00:49:17.345496Z","caller":"etcdserver/v3_server.go:897","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":10363236834071834901,"retry-timeout":"500ms"} {"level":"warn","ts":"2026-03-18T00:49:17.746535Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"1.999427068s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/health\" ","response":"","error":"context canceled"} {"level":"info","ts":"2026-03-18T00:49:17.746642Z","caller":"traceutil/trace.go:171","msg":"trace[1597500870] range","detail":"{range_begin:/registry/health; range_end:; }","duration":"1.999611403s","start":"2026-03-18T00:49:15.747012Z","end":"2026-03-18T00:49:17.746624Z","steps":["trace[1597500870] 'agreement among raft nodes before linearized reading' (duration: 1.99948499s)"],"step_count":1} {"level":"warn","ts":"2026-03-18T00:49:17.746688Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-18T00:49:15.746978Z","time spent":"1.999698966s","remote":"127.0.0.1:45038","response type":"/etcdserverpb.KV/Range","request count":0,"request size":18,"response count":0,"response size":0,"request content":"key:\"/registry/health\" "} 2026/03/18 00:49:17 WARNING: [core] [Server #6] grpc: Server.processUnaryRPC failed to write status: connection error: desc = "transport is closing" {"level":"warn","ts":"2026-03-18T00:49:17.846134Z","caller":"etcdserver/v3_server.go:897","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":10363236834071834901,"retry-timeout":"500ms"} {"level":"warn","ts":"2026-03-18T00:49:17.938066Z","caller":"wal/wal.go:805","msg":"slow fdatasync","took":"2.104364022s","expected-duration":"1s"} {"level":"info","ts":"2026-03-18T00:49:17.938579Z","caller":"traceutil/trace.go:171","msg":"trace[1062253498] transaction","detail":"{read_only:false; response_revision:732; number_of_response:1; }","duration":"2.171452507s","start":"2026-03-18T00:49:15.76706Z","end":"2026-03-18T00:49:17.938513Z","steps":["trace[1062253498] 'process raft request' (duration: 2.171235691s)"],"step_count":1} {"level":"warn","ts":"2026-03-18T00:49:17.938844Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-18T00:49:15.76703Z","time spent":"2.171618971s","remote":"127.0.0.1:45306","response type":"/etcdserverpb.KV/Txn","request count":1,"request size":673,"response count":0,"response size":40,"request content":"compare: success:> failure: >"} {"level":"info","ts":"2026-03-18T00:49:17.949049Z","caller":"traceutil/trace.go:171","msg":"trace[1835308937] linearizableReadLoop","detail":"{readStateIndex:760; appliedIndex:758; }","duration":"2.106785356s","start":"2026-03-18T00:49:15.84224Z","end":"2026-03-18T00:49:17.949025Z","steps":["trace[1835308937] 'read index received' (duration: 2.096214989s)","trace[1835308937] 'applied index is now lower than readState.Index' (duration: 10.569327ms)"],"step_count":2} {"level":"info","ts":"2026-03-18T00:49:17.949166Z","caller":"traceutil/trace.go:171","msg":"trace[420752357] transaction","detail":"{read_only:false; response_revision:733; number_of_response:1; }","duration":"2.102689769s","start":"2026-03-18T00:49:15.84646Z","end":"2026-03-18T00:49:17.949149Z","steps":["trace[420752357] 'process raft request' (duration: 2.102459064s)"],"step_count":1} {"level":"warn","ts":"2026-03-18T00:49:17.949285Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-18T00:49:15.846441Z","time spent":"2.102769081s","remote":"127.0.0.1:45306","response type":"/etcdserverpb.KV/Txn","request count":1,"request size":423,"response count":0,"response size":40,"request content":"compare: success:> failure: >"} {"level":"warn","ts":"2026-03-18T00:49:17.949337Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"2.2518514s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/leases/kube-system/plndr-cp-lock\" ","response":"range_response_count:1 size:434"} {"level":"warn","ts":"2026-03-18T00:49:17.949287Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"1.043598683s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/statefulsets/\" range_end:\"/registry/statefulsets0\" count_only:true ","response":"range_response_count:0 size:5"} {"level":"info","ts":"2026-03-18T00:49:17.949402Z","caller":"traceutil/trace.go:171","msg":"trace[1057649554] range","detail":"{range_begin:/registry/leases/kube-system/plndr-cp-lock; range_end:; response_count:1; response_revision:733; }","duration":"2.251961583s","start":"2026-03-18T00:49:15.697422Z","end":"2026-03-18T00:49:17.949384Z","steps":["trace[1057649554] 'agreement among raft nodes before linearized reading' (duration: 2.251793458s)"],"step_count":1} {"level":"warn","ts":"2026-03-18T00:49:17.949444Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-18T00:49:15.697406Z","time spent":"2.252028405s","remote":"127.0.0.1:45306","response type":"/etcdserverpb.KV/Range","request count":0,"request size":44,"response count":1,"response size":458,"request content":"key:\"/registry/leases/kube-system/plndr-cp-lock\" "} {"level":"warn","ts":"2026-03-18T00:49:17.949423Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"2.25224205s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/leases/kube-system/kube-controller-manager\" ","response":"range_response_count:1 size:506"} {"level":"warn","ts":"2026-03-18T00:49:17.949514Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"202.738822ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/health\" ","response":"range_response_count:0 size:5"} {"level":"info","ts":"2026-03-18T00:49:17.949555Z","caller":"traceutil/trace.go:171","msg":"trace[328907987] range","detail":"{range_begin:/registry/leases/kube-system/kube-controller-manager; range_end:; response_count:1; response_revision:733; }","duration":"2.252411124s","start":"2026-03-18T00:49:15.697117Z","end":"2026-03-18T00:49:17.949528Z","steps":["trace[328907987] 'agreement among raft nodes before linearized reading' (duration: 2.252080476s)"],"step_count":1} {"level":"info","ts":"2026-03-18T00:49:17.949547Z","caller":"traceutil/trace.go:171","msg":"trace[1219712711] range","detail":"{range_begin:/registry/statefulsets/; range_end:/registry/statefulsets0; response_count:0; response_revision:733; }","duration":"1.043767037s","start":"2026-03-18T00:49:16.905668Z","end":"2026-03-18T00:49:17.949435Z","steps":["trace[1219712711] 'agreement among raft nodes before linearized reading' (duration: 1.043566732s)"],"step_count":1} {"level":"info","ts":"2026-03-18T00:49:17.949574Z","caller":"traceutil/trace.go:171","msg":"trace[2048612268] range","detail":"{range_begin:/registry/health; range_end:; response_count:0; response_revision:733; }","duration":"202.879855ms","start":"2026-03-18T00:49:17.746676Z","end":"2026-03-18T00:49:17.949556Z","steps":["trace[2048612268] 'agreement among raft nodes before linearized reading' (duration: 202.738131ms)"],"step_count":1} {"level":"warn","ts":"2026-03-18T00:49:17.949605Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-18T00:49:15.697109Z","time spent":"2.252486266s","remote":"127.0.0.1:45306","response type":"/etcdserverpb.KV/Range","request count":0,"request size":54,"response count":1,"response size":530,"request content":"key:\"/registry/leases/kube-system/kube-controller-manager\" "} {"level":"warn","ts":"2026-03-18T00:49:17.949617Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"873.181726ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/services/endpoints/\" range_end:\"/registry/services/endpoints0\" count_only:true ","response":"range_response_count:0 size:7"} {"level":"info","ts":"2026-03-18T00:49:17.949638Z","caller":"traceutil/trace.go:171","msg":"trace[1859500908] range","detail":"{range_begin:/registry/services/endpoints/; range_end:/registry/services/endpoints0; response_count:0; response_revision:733; }","duration":"873.265938ms","start":"2026-03-18T00:49:17.076366Z","end":"2026-03-18T00:49:17.949632Z","steps":["trace[1859500908] 'agreement among raft nodes before linearized reading' (duration: 873.228147ms)"],"step_count":1} {"level":"warn","ts":"2026-03-18T00:49:17.949633Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"273.03052ms","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-18T00:49:17.949658Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-18T00:49:17.076333Z","time spent":"873.3197ms","remote":"127.0.0.1:45204","response type":"/etcdserverpb.KV/Range","request count":0,"request size":64,"response count":2,"response size":31,"request content":"key:\"/registry/services/endpoints/\" range_end:\"/registry/services/endpoints0\" count_only:true "} {"level":"info","ts":"2026-03-18T00:49:17.949665Z","caller":"traceutil/trace.go:171","msg":"trace[690546419] range","detail":"{range_begin:/registry/leases/kube-system/cilium-operator-resource-lock; range_end:; response_count:1; response_revision:733; }","duration":"273.103162ms","start":"2026-03-18T00:49:17.676553Z","end":"2026-03-18T00:49:17.949657Z","steps":["trace[690546419] 'agreement among raft nodes before linearized reading' (duration: 273.002179ms)"],"step_count":1} {"level":"warn","ts":"2026-03-18T00:49:17.949653Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-18T00:49:16.905593Z","time spent":"1.044032644s","remote":"127.0.0.1:45536","response type":"/etcdserverpb.KV/Range","request count":0,"request size":52,"response count":0,"response size":29,"request content":"key:\"/registry/statefulsets/\" range_end:\"/registry/statefulsets0\" count_only:true "} {"level":"warn","ts":"2026-03-18T00:49:17.949636Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"117.883613ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/apiregistration.k8s.io/apiservices/\" range_end:\"/registry/apiregistration.k8s.io/apiservices0\" count_only:true ","response":"range_response_count:0 size:7"} {"level":"info","ts":"2026-03-18T00:49:17.949743Z","caller":"traceutil/trace.go:171","msg":"trace[66194647] range","detail":"{range_begin:/registry/apiregistration.k8s.io/apiservices/; range_end:/registry/apiregistration.k8s.io/apiservices0; response_count:0; response_revision:733; }","duration":"118.036337ms","start":"2026-03-18T00:49:17.831666Z","end":"2026-03-18T00:49:17.949702Z","steps":["trace[66194647] 'agreement among raft nodes before linearized reading' (duration: 117.838972ms)"],"step_count":1} {"level":"warn","ts":"2026-03-18T00:49:17.949998Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"103.262441ms","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-18T00:49:17.950067Z","caller":"traceutil/trace.go:171","msg":"trace[350214055] range","detail":"{range_begin:/registry/leases/kube-system/kube-scheduler; range_end:; response_count:1; response_revision:733; }","duration":"103.349473ms","start":"2026-03-18T00:49:17.8467Z","end":"2026-03-18T00:49:17.95005Z","steps":["trace[350214055] 'agreement among raft nodes before linearized reading' (duration: 102.621564ms)"],"step_count":1} {"level":"info","ts":"2026-03-18T00:49:18.18683Z","caller":"traceutil/trace.go:171","msg":"trace[979449732] transaction","detail":"{read_only:false; response_revision:738; number_of_response:1; }","duration":"206.991643ms","start":"2026-03-18T00:49:17.979823Z","end":"2026-03-18T00:49:18.186814Z","steps":["trace[979449732] 'process raft request' (duration: 206.88704ms)"],"step_count":1} {"level":"warn","ts":"2026-03-18T00:49:19.34676Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-18T00:49:18.382042Z","time spent":"964.713538ms","remote":"127.0.0.1:45056","response type":"/etcdserverpb.Lease/LeaseGrant","request count":-1,"request size":-1,"response count":-1,"response size":-1,"request content":""} {"level":"info","ts":"2026-03-18T00:49:19.937392Z","caller":"traceutil/trace.go:171","msg":"trace[1083306154] linearizableReadLoop","detail":"{readStateIndex:768; appliedIndex:767; }","duration":"411.222414ms","start":"2026-03-18T00:49:19.526138Z","end":"2026-03-18T00:49:19.93736Z","steps":["trace[1083306154] 'read index received' (duration: 356.073621ms)","trace[1083306154] 'applied index is now lower than readState.Index' (duration: 55.146823ms)"],"step_count":2} {"level":"info","ts":"2026-03-18T00:49:19.937418Z","caller":"traceutil/trace.go:171","msg":"trace[1258605150] transaction","detail":"{read_only:false; response_revision:739; number_of_response:1; }","duration":"589.054455ms","start":"2026-03-18T00:49:19.348327Z","end":"2026-03-18T00:49:19.937382Z","steps":["trace[1258605150] 'process raft request' (duration: 533.833841ms)","trace[1258605150] 'compare' (duration: 54.742882ms)"],"step_count":2} {"level":"warn","ts":"2026-03-18T00:49:19.937619Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-18T00:49:19.3483Z","time spent":"589.184169ms","remote":"127.0.0.1:45056","response type":"/etcdserverpb.KV/Txn","request count":1,"request size":120,"response count":0,"response size":40,"request content":"compare: success:> failure: >"} {"level":"warn","ts":"2026-03-18T00:49:19.937751Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"411.584813ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/clusterrolebindings/\" range_end:\"/registry/clusterrolebindings0\" count_only:true ","response":"range_response_count:0 size:7"} {"level":"info","ts":"2026-03-18T00:49:19.937825Z","caller":"traceutil/trace.go:171","msg":"trace[1984130971] range","detail":"{range_begin:/registry/clusterrolebindings/; range_end:/registry/clusterrolebindings0; response_count:0; response_revision:739; }","duration":"411.707517ms","start":"2026-03-18T00:49:19.526084Z","end":"2026-03-18T00:49:19.937791Z","steps":["trace[1984130971] 'agreement among raft nodes before linearized reading' (duration: 411.42879ms)"],"step_count":1} {"level":"warn","ts":"2026-03-18T00:49:19.937878Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-18T00:49:19.526061Z","time spent":"411.805909ms","remote":"127.0.0.1:45424","response type":"/etcdserverpb.KV/Range","request count":0,"request size":66,"response count":51,"response size":31,"request content":"key:\"/registry/clusterrolebindings/\" range_end:\"/registry/clusterrolebindings0\" count_only:true "} {"level":"warn","ts":"2026-03-18T00:49:19.937907Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"194.043794ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/health\" ","response":"range_response_count:0 size:5"} {"level":"info","ts":"2026-03-18T00:49:19.937997Z","caller":"traceutil/trace.go:171","msg":"trace[915770717] range","detail":"{range_begin:/registry/health; range_end:; response_count:0; response_revision:739; }","duration":"194.175168ms","start":"2026-03-18T00:49:19.7438Z","end":"2026-03-18T00:49:19.937976Z","steps":["trace[915770717] 'agreement among raft nodes before linearized reading' (duration: 193.989093ms)"],"step_count":1} {"level":"info","ts":"2026-03-18T00:49:20.100948Z","caller":"traceutil/trace.go:171","msg":"trace[1005642149] transaction","detail":"{read_only:false; response_revision:740; number_of_response:1; }","duration":"140.32649ms","start":"2026-03-18T00:49:19.960589Z","end":"2026-03-18T00:49:20.100916Z","steps":["trace[1005642149] 'process raft request' (duration: 83.657218ms)","trace[1005642149] 'compare' (duration: 56.452466ms)"],"step_count":2} {"level":"info","ts":"2026-03-18T00:49:20.872078Z","caller":"traceutil/trace.go:171","msg":"trace[269307156] linearizableReadLoop","detail":"{readStateIndex:775; appliedIndex:774; }","duration":"123.954171ms","start":"2026-03-18T00:49:20.748102Z","end":"2026-03-18T00:49:20.872056Z","steps":["trace[269307156] 'read index received' (duration: 123.720995ms)","trace[269307156] 'applied index is now lower than readState.Index' (duration: 231.736µs)"],"step_count":2} {"level":"warn","ts":"2026-03-18T00:49:20.872198Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"124.083365ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/health\" ","response":"range_response_count:0 size:5"} {"level":"info","ts":"2026-03-18T00:49:20.872221Z","caller":"traceutil/trace.go:171","msg":"trace[1991229340] transaction","detail":"{read_only:false; response_revision:746; number_of_response:1; }","duration":"185.089701ms","start":"2026-03-18T00:49:20.687115Z","end":"2026-03-18T00:49:20.872205Z","steps":["trace[1991229340] 'process raft request' (duration: 184.794713ms)"],"step_count":1} {"level":"info","ts":"2026-03-18T00:49:20.872232Z","caller":"traceutil/trace.go:171","msg":"trace[1561185051] range","detail":"{range_begin:/registry/health; range_end:; response_count:0; response_revision:746; }","duration":"124.181877ms","start":"2026-03-18T00:49:20.748038Z","end":"2026-03-18T00:49:20.87222Z","steps":["trace[1561185051] 'agreement among raft nodes before linearized reading' (duration: 124.095285ms)"],"step_count":1} {"level":"info","ts":"2026-03-18T00:49:21.973285Z","caller":"traceutil/trace.go:171","msg":"trace[287344811] transaction","detail":"{read_only:false; response_revision:748; number_of_response:1; }","duration":"299.609724ms","start":"2026-03-18T00:49:21.67365Z","end":"2026-03-18T00:49:21.97326Z","steps":["trace[287344811] 'process raft request' (duration: 299.44953ms)"],"step_count":1} {"level":"info","ts":"2026-03-18T00:49:21.973679Z","caller":"traceutil/trace.go:171","msg":"trace[893650909] linearizableReadLoop","detail":"{readStateIndex:778; appliedIndex:776; }","duration":"229.233085ms","start":"2026-03-18T00:49:21.744426Z","end":"2026-03-18T00:49:21.973659Z","steps":["trace[893650909] 'read index received' (duration: 228.549477ms)","trace[893650909] 'applied index is now lower than readState.Index' (duration: 682.698µs)"],"step_count":2} {"level":"info","ts":"2026-03-18T00:49:21.973764Z","caller":"traceutil/trace.go:171","msg":"trace[1204214688] transaction","detail":"{read_only:false; response_revision:749; number_of_response:1; }","duration":"242.832621ms","start":"2026-03-18T00:49:21.730925Z","end":"2026-03-18T00:49:21.973758Z","steps":["trace[1204214688] 'process raft request' (duration: 242.654056ms)"],"step_count":1} {"level":"warn","ts":"2026-03-18T00:49:21.974014Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"229.565544ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/health\" ","response":"range_response_count:0 size:5"} {"level":"info","ts":"2026-03-18T00:49:21.974035Z","caller":"traceutil/trace.go:171","msg":"trace[461429767] range","detail":"{range_begin:/registry/health; range_end:; response_count:0; response_revision:749; }","duration":"229.656156ms","start":"2026-03-18T00:49:21.744373Z","end":"2026-03-18T00:49:21.974029Z","steps":["trace[461429767] 'agreement among raft nodes before linearized reading' (duration: 229.591454ms)"],"step_count":1} {"level":"info","ts":"2026-03-18T00:49:38.574629Z","caller":"traceutil/trace.go:171","msg":"trace[563331244] transaction","detail":"{read_only:false; response_revision:799; number_of_response:1; }","duration":"211.09185ms","start":"2026-03-18T00:49:38.363516Z","end":"2026-03-18T00:49:38.574608Z","steps":["trace[563331244] 'process raft request' (duration: 210.980508ms)"],"step_count":1} {"level":"info","ts":"2026-03-18T00:49:38.574805Z","caller":"traceutil/trace.go:171","msg":"trace[656673158] transaction","detail":"{read_only:false; response_revision:800; number_of_response:1; }","duration":"210.051603ms","start":"2026-03-18T00:49:38.364717Z","end":"2026-03-18T00:49:38.574769Z","steps":["trace[656673158] 'process raft request' (duration: 209.859038ms)"],"step_count":1} {"level":"info","ts":"2026-03-18T00:49:38.5753Z","caller":"traceutil/trace.go:171","msg":"trace[1468602070] transaction","detail":"{read_only:false; response_revision:798; number_of_response:1; }","duration":"211.623944ms","start":"2026-03-18T00:49:38.363019Z","end":"2026-03-18T00:49:38.574643Z","steps":["trace[1468602070] 'process raft request' (duration: 211.075079ms)"],"step_count":1} {"level":"info","ts":"2026-03-18T00:49:38.584479Z","caller":"traceutil/trace.go:171","msg":"trace[265467349] transaction","detail":"{read_only:false; response_revision:801; number_of_response:1; }","duration":"204.329534ms","start":"2026-03-18T00:49:38.380128Z","end":"2026-03-18T00:49:38.584458Z","steps":["trace[265467349] 'process raft request' (duration: 204.229591ms)"],"step_count":1} {"level":"warn","ts":"2026-03-18T00:49:41.429395Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"751.706708ms","expected-duration":"100ms","prefix":"","request":"header: txn: success:> failure: >>","response":"size:16"} {"level":"info","ts":"2026-03-18T00:49:41.429595Z","caller":"traceutil/trace.go:171","msg":"trace[1610388073] transaction","detail":"{read_only:false; response_revision:806; number_of_response:1; }","duration":"843.278612ms","start":"2026-03-18T00:49:40.586299Z","end":"2026-03-18T00:49:41.429578Z","steps":["trace[1610388073] 'process raft request' (duration: 843.19152ms)"],"step_count":1} {"level":"warn","ts":"2026-03-18T00:49:41.429658Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-18T00:49:40.586295Z","time spent":"843.332644ms","remote":"127.0.0.1:45306","response type":"/etcdserverpb.KV/Txn","request count":1,"request size":476,"response count":0,"response size":40,"request content":"compare: success:> failure: >"} {"level":"info","ts":"2026-03-18T00:49:41.429755Z","caller":"traceutil/trace.go:171","msg":"trace[1829627893] transaction","detail":"{read_only:false; response_revision:805; number_of_response:1; }","duration":"843.442057ms","start":"2026-03-18T00:49:40.586233Z","end":"2026-03-18T00:49:41.429675Z","steps":["trace[1829627893] 'process raft request' (duration: 91.362089ms)","trace[1829627893] 'compare' (duration: 751.537314ms)"],"step_count":2} {"level":"warn","ts":"2026-03-18T00:49:41.430025Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-18T00:49:40.586214Z","time spent":"843.651232ms","remote":"127.0.0.1:45306","response type":"/etcdserverpb.KV/Txn","request count":1,"request size":419,"response count":0,"response size":40,"request content":"compare: success:> failure: >"} {"level":"warn","ts":"2026-03-18T00:49:42.177984Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"431.587636ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/health\" ","response":"range_response_count:0 size:5"} {"level":"info","ts":"2026-03-18T00:49:42.178081Z","caller":"traceutil/trace.go:171","msg":"trace[199362234] range","detail":"{range_begin:/registry/health; range_end:; response_count:0; response_revision:806; }","duration":"431.72542ms","start":"2026-03-18T00:49:41.746337Z","end":"2026-03-18T00:49:42.178062Z","steps":["trace[199362234] 'range keys from in-memory index tree' (duration: 431.519145ms)"],"step_count":1} {"level":"warn","ts":"2026-03-18T00:49:42.178288Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-18T00:49:41.746296Z","time spent":"431.827743ms","remote":"127.0.0.1:45038","response type":"/etcdserverpb.KV/Range","request count":0,"request size":18,"response count":0,"response size":29,"request content":"key:\"/registry/health\" "} {"level":"info","ts":"2026-03-18T00:49:42.522837Z","caller":"traceutil/trace.go:171","msg":"trace[907449519] linearizableReadLoop","detail":"{readStateIndex:840; appliedIndex:839; }","duration":"282.247182ms","start":"2026-03-18T00:49:42.240563Z","end":"2026-03-18T00:49:42.52281Z","steps":["trace[907449519] 'read index received' (duration: 282.113348ms)","trace[907449519] 'applied index is now lower than readState.Index' (duration: 132.524µs)"],"step_count":2} {"level":"warn","ts":"2026-03-18T00:49:42.523038Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"282.451737ms","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-18T00:49:42.523044Z","caller":"traceutil/trace.go:171","msg":"trace[576071488] transaction","detail":"{read_only:false; response_revision:807; number_of_response:1; }","duration":"286.826161ms","start":"2026-03-18T00:49:42.236192Z","end":"2026-03-18T00:49:42.523018Z","steps":["trace[576071488] 'process raft request' (duration: 286.461562ms)"],"step_count":1} {"level":"info","ts":"2026-03-18T00:49:42.523074Z","caller":"traceutil/trace.go:171","msg":"trace[847904028] range","detail":"{range_begin:/registry/leases/kube-system/kube-scheduler; range_end:; response_count:1; response_revision:807; }","duration":"282.557799ms","start":"2026-03-18T00:49:42.240506Z","end":"2026-03-18T00:49:42.523064Z","steps":["trace[847904028] 'agreement among raft nodes before linearized reading' (duration: 282.399035ms)"],"step_count":1} {"level":"info","ts":"2026-03-18T00:49:42.568241Z","caller":"traceutil/trace.go:171","msg":"trace[440042724] transaction","detail":"{read_only:false; response_revision:808; number_of_response:1; }","duration":"209.953141ms","start":"2026-03-18T00:49:42.358266Z","end":"2026-03-18T00:49:42.568219Z","steps":["trace[440042724] 'process raft request' (duration: 209.823848ms)"],"step_count":1} {"level":"info","ts":"2026-03-18T00:49:42.678097Z","caller":"traceutil/trace.go:171","msg":"trace[768468048] transaction","detail":"{read_only:false; response_revision:809; number_of_response:1; }","duration":"150.749242ms","start":"2026-03-18T00:49:42.527305Z","end":"2026-03-18T00:49:42.678055Z","steps":["trace[768468048] 'process raft request' (duration: 124.694731ms)","trace[768468048] 'compare' (duration: 25.880197ms)"],"step_count":2} {"level":"info","ts":"2026-03-18T00:49:43.015195Z","caller":"traceutil/trace.go:171","msg":"trace[565206409] transaction","detail":"{read_only:false; response_revision:810; number_of_response:1; }","duration":"331.306894ms","start":"2026-03-18T00:49:42.683208Z","end":"2026-03-18T00:49:43.014515Z","steps":["trace[565206409] 'process raft request' (duration: 271.405658ms)","trace[565206409] 'compare' (duration: 59.763452ms)"],"step_count":2} {"level":"warn","ts":"2026-03-18T00:49:43.015974Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-18T00:49:42.683188Z","time spent":"332.63792ms","remote":"127.0.0.1:45306","response type":"/etcdserverpb.KV/Txn","request count":1,"request size":491,"response count":0,"response size":40,"request content":"compare: success:> failure: >"} {"level":"info","ts":"2026-03-18T00:49:43.720601Z","caller":"traceutil/trace.go:171","msg":"trace[1580444032] transaction","detail":"{read_only:false; response_revision:811; number_of_response:1; }","duration":"258.999453ms","start":"2026-03-18T00:49:43.461577Z","end":"2026-03-18T00:49:43.720576Z","steps":["trace[1580444032] 'process raft request' (duration: 258.825478ms)"],"step_count":1} {"level":"warn","ts":"2026-03-18T00:49:44.246216Z","caller":"etcdserver/v3_server.go:897","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":10363236834071835126,"retry-timeout":"500ms"} {"level":"warn","ts":"2026-03-18T00:49:44.747089Z","caller":"etcdserver/v3_server.go:897","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":10363236834071835126,"retry-timeout":"500ms"} {"level":"info","ts":"2026-03-18T00:49:45.16246Z","caller":"traceutil/trace.go:171","msg":"trace[1329635101] transaction","detail":"{read_only:false; response_revision:812; number_of_response:1; }","duration":"1.699592606s","start":"2026-03-18T00:49:43.462839Z","end":"2026-03-18T00:49:45.162432Z","steps":["trace[1329635101] 'process raft request' (duration: 1.699320949s)"],"step_count":1} {"level":"warn","ts":"2026-03-18T00:49:45.162796Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-18T00:49:43.462805Z","time spent":"1.69973027s","remote":"127.0.0.1:45306","response type":"/etcdserverpb.KV/Txn","request count":1,"request size":419,"response count":0,"response size":40,"request content":"compare: success:> failure: >"} {"level":"info","ts":"2026-03-18T00:49:45.178411Z","caller":"traceutil/trace.go:171","msg":"trace[107037592] linearizableReadLoop","detail":"{readStateIndex:846; appliedIndex:844; }","duration":"1.433275393s","start":"2026-03-18T00:49:43.745115Z","end":"2026-03-18T00:49:45.17839Z","steps":["trace[107037592] 'read index received' (duration: 1.416974427s)","trace[107037592] 'applied index is now lower than readState.Index' (duration: 16.300016ms)"],"step_count":2} {"level":"warn","ts":"2026-03-18T00:49:45.178557Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"1.433424717s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/health\" ","response":"range_response_count:0 size:5"} {"level":"info","ts":"2026-03-18T00:49:45.178586Z","caller":"traceutil/trace.go:171","msg":"trace[1277609828] range","detail":"{range_begin:/registry/health; range_end:; response_count:0; response_revision:812; }","duration":"1.433510199s","start":"2026-03-18T00:49:43.745067Z","end":"2026-03-18T00:49:45.178578Z","steps":["trace[1277609828] 'agreement among raft nodes before linearized reading' (duration: 1.433431297s)"],"step_count":1} {"level":"warn","ts":"2026-03-18T00:49:45.178595Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"261.328194ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/daemonsets/\" range_end:\"/registry/daemonsets0\" count_only:true ","response":"range_response_count:0 size:7"} {"level":"warn","ts":"2026-03-18T00:49:45.178611Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-18T00:49:43.745048Z","time spent":"1.43355805s","remote":"127.0.0.1:45038","response type":"/etcdserverpb.KV/Range","request count":0,"request size":18,"response count":0,"response size":29,"request content":"key:\"/registry/health\" "} {"level":"info","ts":"2026-03-18T00:49:45.178632Z","caller":"traceutil/trace.go:171","msg":"trace[1276033247] range","detail":"{range_begin:/registry/daemonsets/; range_end:/registry/daemonsets0; response_count:0; response_revision:812; }","duration":"261.400915ms","start":"2026-03-18T00:49:44.917221Z","end":"2026-03-18T00:49:45.178622Z","steps":["trace[1276033247] 'agreement among raft nodes before linearized reading' (duration: 261.342534ms)"],"step_count":1} {"level":"warn","ts":"2026-03-18T00:49:45.178625Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"882.684544ms","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-18T00:49:45.178679Z","caller":"traceutil/trace.go:171","msg":"trace[1561718769] range","detail":"{range_begin:/registry/events/; range_end:/registry/events0; response_count:0; response_revision:812; }","duration":"882.780626ms","start":"2026-03-18T00:49:44.295883Z","end":"2026-03-18T00:49:45.178663Z","steps":["trace[1561718769] 'agreement among raft nodes before linearized reading' (duration: 882.646053ms)"],"step_count":1} {"level":"warn","ts":"2026-03-18T00:49:45.178714Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-18T00:49:44.295861Z","time spent":"882.843977ms","remote":"127.0.0.1:45584","response type":"/etcdserverpb.KV/Range","request count":0,"request size":40,"response count":102,"response size":31,"request content":"key:\"/registry/events/\" range_end:\"/registry/events0\" count_only:true "} {"level":"warn","ts":"2026-03-18T00:49:45.178814Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"157.288203ms","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-18T00:49:45.178836Z","caller":"traceutil/trace.go:171","msg":"trace[1313438177] range","detail":"{range_begin:/registry/leases/kube-system/kube-controller-manager; range_end:; response_count:1; response_revision:812; }","duration":"157.330395ms","start":"2026-03-18T00:49:45.021499Z","end":"2026-03-18T00:49:45.17883Z","steps":["trace[1313438177] 'agreement among raft nodes before linearized reading' (duration: 157.230062ms)"],"step_count":1} {"level":"warn","ts":"2026-03-18T00:49:45.178902Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"327.766802ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/minions/\" range_end:\"/registry/minions0\" count_only:true ","response":"range_response_count:0 size:7"} {"level":"info","ts":"2026-03-18T00:49:45.178933Z","caller":"traceutil/trace.go:171","msg":"trace[1700653516] range","detail":"{range_begin:/registry/minions/; range_end:/registry/minions0; response_count:0; response_revision:812; }","duration":"327.836114ms","start":"2026-03-18T00:49:44.851088Z","end":"2026-03-18T00:49:45.178924Z","steps":["trace[1700653516] 'agreement among raft nodes before linearized reading' (duration: 327.786513ms)"],"step_count":1} {"level":"warn","ts":"2026-03-18T00:49:45.178952Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"208.231455ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/horizontalpodautoscalers/\" range_end:\"/registry/horizontalpodautoscalers0\" count_only:true ","response":"range_response_count:0 size:5"} {"level":"warn","ts":"2026-03-18T00:49:45.178964Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-18T00:49:44.851067Z","time spent":"327.889585ms","remote":"127.0.0.1:45220","response type":"/etcdserverpb.KV/Range","request count":0,"request size":42,"response count":1,"response size":31,"request content":"key:\"/registry/minions/\" range_end:\"/registry/minions0\" count_only:true "} {"level":"info","ts":"2026-03-18T00:49:45.178978Z","caller":"traceutil/trace.go:171","msg":"trace[548185896] range","detail":"{range_begin:/registry/horizontalpodautoscalers/; range_end:/registry/horizontalpodautoscalers0; response_count:0; response_revision:812; }","duration":"208.284826ms","start":"2026-03-18T00:49:44.970684Z","end":"2026-03-18T00:49:45.178969Z","steps":["trace[548185896] 'agreement among raft nodes before linearized reading' (duration: 208.244905ms)"],"step_count":1} {"level":"warn","ts":"2026-03-18T00:49:45.179144Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"652.37432ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/leases/kube-system/plndr-svcs-lock\" ","response":"range_response_count:1 size:437"} {"level":"info","ts":"2026-03-18T00:49:45.179173Z","caller":"traceutil/trace.go:171","msg":"trace[1825453280] range","detail":"{range_begin:/registry/leases/kube-system/plndr-svcs-lock; range_end:; response_count:1; response_revision:812; }","duration":"652.442092ms","start":"2026-03-18T00:49:44.526723Z","end":"2026-03-18T00:49:45.179165Z","steps":["trace[1825453280] 'agreement among raft nodes before linearized reading' (duration: 652.34999ms)"],"step_count":1} {"level":"warn","ts":"2026-03-18T00:49:45.179196Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-18T00:49:44.526701Z","time spent":"652.489794ms","remote":"127.0.0.1:45306","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-18T00:49:45.179247Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"496.321199ms","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-18T00:49:45.179275Z","caller":"traceutil/trace.go:171","msg":"trace[2009724596] range","detail":"{range_begin:/registry/leases/kube-system/kube-scheduler; range_end:; response_count:1; response_revision:812; }","duration":"496.391401ms","start":"2026-03-18T00:49:44.682877Z","end":"2026-03-18T00:49:45.179268Z","steps":["trace[2009724596] 'agreement among raft nodes before linearized reading' (duration: 496.287368ms)"],"step_count":1} {"level":"warn","ts":"2026-03-18T00:49:45.179298Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-18T00:49:44.682853Z","time spent":"496.440693ms","remote":"127.0.0.1:45306","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-18T00:49:52.987992Z","caller":"traceutil/trace.go:171","msg":"trace[1792449306] transaction","detail":"{read_only:false; response_revision:834; number_of_response:1; }","duration":"101.825674ms","start":"2026-03-18T00:49:52.886127Z","end":"2026-03-18T00:49:52.987953Z","steps":["trace[1792449306] 'process raft request' (duration: 101.565717ms)"],"step_count":1} {"level":"info","ts":"2026-03-18T00:49:53.441093Z","caller":"traceutil/trace.go:171","msg":"trace[355400697] linearizableReadLoop","detail":"{readStateIndex:871; appliedIndex:870; }","duration":"118.389736ms","start":"2026-03-18T00:49:53.32268Z","end":"2026-03-18T00:49:53.44107Z","steps":["trace[355400697] 'read index received' (duration: 118.231332ms)","trace[355400697] 'applied index is now lower than readState.Index' (duration: 157.484µs)"],"step_count":2} {"level":"info","ts":"2026-03-18T00:49:53.441181Z","caller":"traceutil/trace.go:171","msg":"trace[1370650084] transaction","detail":"{read_only:false; response_revision:836; number_of_response:1; }","duration":"145.32446ms","start":"2026-03-18T00:49:53.295835Z","end":"2026-03-18T00:49:53.441159Z","steps":["trace[1370650084] 'process raft request' (duration: 145.043683ms)"],"step_count":1} {"level":"warn","ts":"2026-03-18T00:49:53.441348Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"118.647334ms","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-18T00:49:53.441383Z","caller":"traceutil/trace.go:171","msg":"trace[1975165728] range","detail":"{range_begin:/registry/leases/kube-system/kube-scheduler; range_end:; response_count:1; response_revision:836; }","duration":"118.749236ms","start":"2026-03-18T00:49:53.322622Z","end":"2026-03-18T00:49:53.441371Z","steps":["trace[1975165728] 'agreement among raft nodes before linearized reading' (duration: 118.582781ms)"],"step_count":1} {"level":"warn","ts":"2026-03-18T00:49:53.4414Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"117.142044ms","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-18T00:49:53.441422Z","caller":"traceutil/trace.go:171","msg":"trace[931751201] range","detail":"{range_begin:/registry/leases/kube-system/kube-controller-manager; range_end:; response_count:1; response_revision:836; }","duration":"117.187465ms","start":"2026-03-18T00:49:53.324226Z","end":"2026-03-18T00:49:53.441414Z","steps":["trace[931751201] 'agreement among raft nodes before linearized reading' (duration: 117.122293ms)"],"step_count":1} {"level":"info","ts":"2026-03-18T00:49:55.398118Z","caller":"traceutil/trace.go:171","msg":"trace[1773660438] transaction","detail":"{read_only:false; response_revision:892; number_of_response:1; }","duration":"171.956886ms","start":"2026-03-18T00:49:55.22614Z","end":"2026-03-18T00:49:55.398097Z","steps":["trace[1773660438] 'process raft request' (duration: 171.835283ms)"],"step_count":1} {"level":"warn","ts":"2026-03-18T00:49:55.636414Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"191.418715ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/leases/kube-system/plndr-svcs-lock\" ","response":"range_response_count:1 size:437"} {"level":"info","ts":"2026-03-18T00:49:55.63648Z","caller":"traceutil/trace.go:171","msg":"trace[1777548986] range","detail":"{range_begin:/registry/leases/kube-system/plndr-svcs-lock; range_end:; response_count:1; response_revision:892; }","duration":"191.532739ms","start":"2026-03-18T00:49:55.444932Z","end":"2026-03-18T00:49:55.636465Z","steps":["trace[1777548986] 'range keys from in-memory index tree' (duration: 191.253461ms)"],"step_count":1} {"level":"warn","ts":"2026-03-18T00:49:55.636477Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"176.180508ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/leases/kube-system/kube-controller-manager\" ","response":"range_response_count:1 size:506"} {"level":"warn","ts":"2026-03-18T00:49:55.636549Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"177.511752ms","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-18T00:49:55.636575Z","caller":"traceutil/trace.go:171","msg":"trace[1663024931] range","detail":"{range_begin:/registry/leases/kube-system/kube-controller-manager; range_end:; response_count:1; response_revision:892; }","duration":"176.341842ms","start":"2026-03-18T00:49:55.46021Z","end":"2026-03-18T00:49:55.636552Z","steps":["trace[1663024931] 'range keys from in-memory index tree' (duration: 176.009953ms)"],"step_count":1} {"level":"info","ts":"2026-03-18T00:49:55.636622Z","caller":"traceutil/trace.go:171","msg":"trace[102805733] range","detail":"{range_begin:/registry/leases/kube-system/kube-scheduler; range_end:; response_count:1; response_revision:892; }","duration":"177.615944ms","start":"2026-03-18T00:49:55.458986Z","end":"2026-03-18T00:49:55.636602Z","steps":["trace[102805733] 'range keys from in-memory index tree' (duration: 177.353358ms)"],"step_count":1} {"level":"warn","ts":"2026-03-18T00:49:55.63711Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"201.571242ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/csistoragecapacities/\" range_end:\"/registry/csistoragecapacities0\" count_only:true ","response":"range_response_count:0 size:5"} {"level":"info","ts":"2026-03-18T00:49:55.637157Z","caller":"traceutil/trace.go:171","msg":"trace[332162626] range","detail":"{range_begin:/registry/csistoragecapacities/; range_end:/registry/csistoragecapacities0; response_count:0; response_revision:892; }","duration":"201.655093ms","start":"2026-03-18T00:49:55.435485Z","end":"2026-03-18T00:49:55.63714Z","steps":["trace[332162626] 'count revisions from in-memory index tree' (duration: 201.459748ms)"],"step_count":1} {"level":"warn","ts":"2026-03-18T00:49:58.147075Z","caller":"etcdserver/v3_server.go:897","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":10363236834071835311,"retry-timeout":"500ms"} {"level":"warn","ts":"2026-03-18T00:49:58.64781Z","caller":"etcdserver/v3_server.go:897","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":10363236834071835311,"retry-timeout":"500ms"} {"level":"warn","ts":"2026-03-18T00:49:58.901209Z","caller":"wal/wal.go:805","msg":"slow fdatasync","took":"1.495356766s","expected-duration":"1s"} {"level":"info","ts":"2026-03-18T00:49:58.901932Z","caller":"traceutil/trace.go:171","msg":"trace[2018107559] linearizableReadLoop","detail":"{readStateIndex:934; appliedIndex:933; }","duration":"1.255024701s","start":"2026-03-18T00:49:57.646876Z","end":"2026-03-18T00:49:58.901901Z","steps":["trace[2018107559] 'read index received' (duration: 1.25458271s)","trace[2018107559] 'applied index is now lower than readState.Index' (duration: 440.581µs)"],"step_count":2} {"level":"info","ts":"2026-03-18T00:49:58.90208Z","caller":"traceutil/trace.go:171","msg":"trace[1537330865] transaction","detail":"{read_only:false; response_revision:897; number_of_response:1; }","duration":"1.496330391s","start":"2026-03-18T00:49:57.405688Z","end":"2026-03-18T00:49:58.902019Z","steps":["trace[1537330865] 'process raft request' (duration: 1.495812268s)"],"step_count":1} {"level":"warn","ts":"2026-03-18T00:49:58.902354Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-18T00:49:57.40566Z","time spent":"1.496523046s","remote":"127.0.0.1:45306","response type":"/etcdserverpb.KV/Txn","request count":1,"request size":419,"response count":0,"response size":40,"request content":"compare: success:> failure: >"} {"level":"warn","ts":"2026-03-18T00:49:58.902467Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"1.255341139s","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-18T00:49:58.902562Z","caller":"traceutil/trace.go:171","msg":"trace[2085845475] range","detail":"{range_begin:/registry/leases/kube-system/kube-controller-manager; range_end:; response_count:1; response_revision:897; }","duration":"1.255728628s","start":"2026-03-18T00:49:57.646809Z","end":"2026-03-18T00:49:58.902537Z","steps":["trace[2085845475] 'agreement among raft nodes before linearized reading' (duration: 1.255209265s)"],"step_count":1} {"level":"warn","ts":"2026-03-18T00:49:58.902612Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-18T00:49:57.646782Z","time spent":"1.255818921s","remote":"127.0.0.1:45306","response type":"/etcdserverpb.KV/Range","request count":0,"request size":54,"response count":1,"response size":530,"request content":"key:\"/registry/leases/kube-system/kube-controller-manager\" "} {"level":"warn","ts":"2026-03-18T00:49:59.402236Z","caller":"etcdserver/v3_server.go:897","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":10363236834071835314,"retry-timeout":"500ms"} {"level":"warn","ts":"2026-03-18T00:49:59.744616Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"2.000361663s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/health\" ","response":"","error":"context deadline exceeded"} {"level":"info","ts":"2026-03-18T00:49:59.744709Z","caller":"traceutil/trace.go:171","msg":"trace[244852283] range","detail":"{range_begin:/registry/health; range_end:; }","duration":"2.000540428s","start":"2026-03-18T00:49:57.744146Z","end":"2026-03-18T00:49:59.744686Z","steps":["trace[244852283] 'agreement among raft nodes before linearized reading' (duration: 2.000420575s)"],"step_count":1} {"level":"warn","ts":"2026-03-18T00:49:59.744758Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-18T00:49:57.744116Z","time spent":"2.00063209s","remote":"127.0.0.1:45038","response type":"/etcdserverpb.KV/Range","request count":0,"request size":18,"response count":0,"response size":0,"request content":"key:\"/registry/health\" "} {"level":"warn","ts":"2026-03-18T00:49:59.903138Z","caller":"etcdserver/v3_server.go:897","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":10363236834071835314,"retry-timeout":"500ms"} {"level":"warn","ts":"2026-03-18T00:50:00.284725Z","caller":"wal/wal.go:805","msg":"slow fdatasync","took":"1.383295763s","expected-duration":"1s"} {"level":"warn","ts":"2026-03-18T00:50:00.398884Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"113.668493ms","expected-duration":"100ms","prefix":"","request":"header: txn: success:> failure: >>","response":"size:16"} {"level":"info","ts":"2026-03-18T00:50:00.398996Z","caller":"traceutil/trace.go:171","msg":"trace[1103589331] transaction","detail":"{read_only:false; response_revision:898; number_of_response:1; }","duration":"1.542090667s","start":"2026-03-18T00:49:58.856885Z","end":"2026-03-18T00:50:00.398976Z","steps":["trace[1103589331] 'process raft request' (duration: 1.428093925s)","trace[1103589331] 'compare' (duration: 113.221792ms)"],"step_count":2} {"level":"warn","ts":"2026-03-18T00:50:00.399057Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-18T00:49:58.856855Z","time spent":"1.542174099s","remote":"127.0.0.1:45306","response type":"/etcdserverpb.KV/Txn","request count":1,"request size":673,"response count":0,"response size":40,"request content":"compare: success:> failure: >"} {"level":"info","ts":"2026-03-18T00:50:00.427283Z","caller":"traceutil/trace.go:171","msg":"trace[1455803671] linearizableReadLoop","detail":"{readStateIndex:936; appliedIndex:934; }","duration":"1.525247396s","start":"2026-03-18T00:49:58.902017Z","end":"2026-03-18T00:50:00.427264Z","steps":["trace[1455803671] 'read index received' (duration: 1.382947295s)","trace[1455803671] 'applied index is now lower than readState.Index' (duration: 142.299401ms)"],"step_count":2} {"level":"info","ts":"2026-03-18T00:50:00.427348Z","caller":"traceutil/trace.go:171","msg":"trace[1186141012] transaction","detail":"{read_only:false; response_revision:899; number_of_response:1; }","duration":"1.51964386s","start":"2026-03-18T00:49:58.90769Z","end":"2026-03-18T00:50:00.427334Z","steps":["trace[1186141012] 'process raft request' (duration: 1.519451865s)"],"step_count":1} {"level":"warn","ts":"2026-03-18T00:50:00.427438Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"2.645997706s","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-18T00:50:00.427444Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-18T00:49:58.907662Z","time spent":"1.519717721s","remote":"127.0.0.1:45306","response type":"/etcdserverpb.KV/Txn","request count":1,"request size":491,"response count":0,"response size":40,"request content":"compare: success:> failure: >"} {"level":"info","ts":"2026-03-18T00:50:00.42746Z","caller":"traceutil/trace.go:171","msg":"trace[993613258] range","detail":"{range_begin:/registry/leases/kube-system/cilium-operator-resource-lock; range_end:; response_count:1; response_revision:899; }","duration":"2.646047887s","start":"2026-03-18T00:49:57.781406Z","end":"2026-03-18T00:50:00.427454Z","steps":["trace[993613258] 'agreement among raft nodes before linearized reading' (duration: 2.645950385s)"],"step_count":1} {"level":"warn","ts":"2026-03-18T00:50:00.427439Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"2.077875758s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/masterleases/162.253.55.221\" ","response":"range_response_count:1 size:135"} {"level":"warn","ts":"2026-03-18T00:50:00.42748Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-18T00:49:57.781395Z","time spent":"2.646081078s","remote":"127.0.0.1:45306","response type":"/etcdserverpb.KV/Range","request count":0,"request size":60,"response count":1,"response size":515,"request content":"key:\"/registry/leases/kube-system/cilium-operator-resource-lock\" "} {"level":"info","ts":"2026-03-18T00:50:00.427509Z","caller":"traceutil/trace.go:171","msg":"trace[68328108] range","detail":"{range_begin:/registry/masterleases/162.253.55.221; range_end:; response_count:1; response_revision:899; }","duration":"2.078004641s","start":"2026-03-18T00:49:58.349479Z","end":"2026-03-18T00:50:00.427483Z","steps":["trace[68328108] 'agreement among raft nodes before linearized reading' (duration: 2.077814996s)"],"step_count":1} {"level":"warn","ts":"2026-03-18T00:50:00.427542Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-18T00:49:58.349454Z","time spent":"2.078080793s","remote":"127.0.0.1:45056","response type":"/etcdserverpb.KV/Range","request count":0,"request size":39,"response count":1,"response size":159,"request content":"key:\"/registry/masterleases/162.253.55.221\" "} {"level":"warn","ts":"2026-03-18T00:50:00.427551Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"1.339236413s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/health\" ","response":"range_response_count:0 size:5"} {"level":"info","ts":"2026-03-18T00:50:00.42757Z","caller":"traceutil/trace.go:171","msg":"trace[1094139360] range","detail":"{range_begin:/registry/health; range_end:; response_count:0; response_revision:899; }","duration":"1.339255943s","start":"2026-03-18T00:49:59.088309Z","end":"2026-03-18T00:50:00.427565Z","steps":["trace[1094139360] 'agreement among raft nodes before linearized reading' (duration: 1.339228492s)"],"step_count":1} {"level":"warn","ts":"2026-03-18T00:50:00.42755Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"2.779832696s","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-18T00:50:00.427585Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-18T00:49:59.08824Z","time spent":"1.339342186s","remote":"127.0.0.1:45038","response type":"/etcdserverpb.KV/Range","request count":0,"request size":18,"response count":0,"response size":29,"request content":"key:\"/registry/health\" "} {"level":"info","ts":"2026-03-18T00:50:00.427609Z","caller":"traceutil/trace.go:171","msg":"trace[253094007] range","detail":"{range_begin:/registry/leases/kube-system/kube-scheduler; range_end:; response_count:1; response_revision:899; }","duration":"2.779934939s","start":"2026-03-18T00:49:57.647657Z","end":"2026-03-18T00:50:00.427592Z","steps":["trace[253094007] 'agreement among raft nodes before linearized reading' (duration: 2.779802415s)"],"step_count":1} {"level":"warn","ts":"2026-03-18T00:50:00.427649Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-18T00:49:57.647582Z","time spent":"2.780056452s","remote":"127.0.0.1:45306","response type":"/etcdserverpb.KV/Range","request count":0,"request size":45,"response count":1,"response size":503,"request content":"key:\"/registry/leases/kube-system/kube-scheduler\" "} {"level":"warn","ts":"2026-03-18T00:50:00.427741Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"164.717816ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/csinodes/\" range_end:\"/registry/csinodes0\" count_only:true ","response":"range_response_count:0 size:7"} {"level":"info","ts":"2026-03-18T00:50:00.427766Z","caller":"traceutil/trace.go:171","msg":"trace[2106578765] range","detail":"{range_begin:/registry/csinodes/; range_end:/registry/csinodes0; response_count:0; response_revision:899; }","duration":"164.782568ms","start":"2026-03-18T00:50:00.262976Z","end":"2026-03-18T00:50:00.427759Z","steps":["trace[2106578765] 'agreement among raft nodes before linearized reading' (duration: 164.738357ms)"],"step_count":1} {"level":"warn","ts":"2026-03-18T00:50:00.427788Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"2.778551882s","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-18T00:50:00.427822Z","caller":"traceutil/trace.go:171","msg":"trace[576745960] range","detail":"{range_begin:/registry/leases/kube-system/plndr-svcs-lock; range_end:; response_count:1; response_revision:899; }","duration":"2.778603814s","start":"2026-03-18T00:49:57.649209Z","end":"2026-03-18T00:50:00.427813Z","steps":["trace[576745960] 'agreement among raft nodes before linearized reading' (duration: 2.778518901s)"],"step_count":1} {"level":"warn","ts":"2026-03-18T00:50:00.427846Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-18T00:49:57.649194Z","time spent":"2.778645094s","remote":"127.0.0.1:45306","response type":"/etcdserverpb.KV/Range","request count":0,"request size":46,"response count":1,"response size":462,"request content":"key:\"/registry/leases/kube-system/plndr-svcs-lock\" "} {"level":"warn","ts":"2026-03-18T00:50:00.427872Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"682.514758ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/health\" ","response":"range_response_count:0 size:5"} {"level":"info","ts":"2026-03-18T00:50:00.427911Z","caller":"traceutil/trace.go:171","msg":"trace[264775882] range","detail":"{range_begin:/registry/health; range_end:; response_count:0; response_revision:899; }","duration":"682.60166ms","start":"2026-03-18T00:49:59.7453Z","end":"2026-03-18T00:50:00.427902Z","steps":["trace[264775882] 'agreement among raft nodes before linearized reading' (duration: 682.545478ms)"],"step_count":1} {"level":"warn","ts":"2026-03-18T00:50:00.427934Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-18T00:49:59.745272Z","time spent":"682.656162ms","remote":"127.0.0.1:45028","response type":"/etcdserverpb.KV/Range","request count":0,"request size":18,"response count":0,"response size":29,"request content":"key:\"/registry/health\" "} {"level":"warn","ts":"2026-03-18T00:50:00.427965Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"512.223275ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/volumeattachments/\" range_end:\"/registry/volumeattachments0\" count_only:true ","response":"range_response_count:0 size:5"} {"level":"info","ts":"2026-03-18T00:50:00.427986Z","caller":"traceutil/trace.go:171","msg":"trace[2068180685] range","detail":"{range_begin:/registry/volumeattachments/; range_end:/registry/volumeattachments0; response_count:0; response_revision:899; }","duration":"512.282357ms","start":"2026-03-18T00:49:59.915698Z","end":"2026-03-18T00:50:00.42798Z","steps":["trace[2068180685] 'agreement among raft nodes before linearized reading' (duration: 512.246965ms)"],"step_count":1} {"level":"warn","ts":"2026-03-18T00:50:00.428015Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-18T00:49:59.915675Z","time spent":"512.323257ms","remote":"127.0.0.1:45458","response type":"/etcdserverpb.KV/Range","request count":0,"request size":62,"response count":0,"response size":29,"request content":"key:\"/registry/volumeattachments/\" range_end:\"/registry/volumeattachments0\" count_only:true "} {"level":"info","ts":"2026-03-18T00:50:15.050812Z","caller":"traceutil/trace.go:171","msg":"trace[77262548] linearizableReadLoop","detail":"{readStateIndex:981; appliedIndex:980; }","duration":"471.374797ms","start":"2026-03-18T00:50:14.579413Z","end":"2026-03-18T00:50:15.050788Z","steps":["trace[77262548] 'read index received' (duration: 471.189813ms)","trace[77262548] 'applied index is now lower than readState.Index' (duration: 183.824µs)"],"step_count":2} {"level":"info","ts":"2026-03-18T00:50:15.050872Z","caller":"traceutil/trace.go:171","msg":"trace[706350391] transaction","detail":"{read_only:false; response_revision:941; number_of_response:1; }","duration":"539.089568ms","start":"2026-03-18T00:50:14.511763Z","end":"2026-03-18T00:50:15.050853Z","steps":["trace[706350391] 'process raft request' (duration: 538.862592ms)"],"step_count":1} {"level":"warn","ts":"2026-03-18T00:50:15.051021Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-18T00:50:14.511738Z","time spent":"539.19778ms","remote":"127.0.0.1:45306","response type":"/etcdserverpb.KV/Txn","request count":1,"request size":491,"response count":0,"response size":40,"request content":"compare: success:> failure: >"} {"level":"warn","ts":"2026-03-18T00:50:15.05108Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"471.651414ms","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":"info","ts":"2026-03-18T00:50:15.05113Z","caller":"traceutil/trace.go:171","msg":"trace[589716688] range","detail":"{range_begin:/registry/leases/kube-system/cilium-operator-resource-lock; range_end:; response_count:1; response_revision:941; }","duration":"471.735817ms","start":"2026-03-18T00:50:14.579382Z","end":"2026-03-18T00:50:15.051118Z","steps":["trace[589716688] 'agreement among raft nodes before linearized reading' (duration: 471.551662ms)"],"step_count":1} {"level":"warn","ts":"2026-03-18T00:50:15.051172Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-18T00:50:14.579364Z","time spent":"471.796268ms","remote":"127.0.0.1:45306","response type":"/etcdserverpb.KV/Range","request count":0,"request size":60,"response count":1,"response size":515,"request content":"key:\"/registry/leases/kube-system/cilium-operator-resource-lock\" "} {"level":"warn","ts":"2026-03-18T00:50:15.051257Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"305.90492ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/health\" ","response":"range_response_count:0 size:5"} {"level":"info","ts":"2026-03-18T00:50:15.051398Z","caller":"traceutil/trace.go:171","msg":"trace[225092189] range","detail":"{range_begin:/registry/health; range_end:; response_count:0; response_revision:941; }","duration":"306.101545ms","start":"2026-03-18T00:50:14.745267Z","end":"2026-03-18T00:50:15.051369Z","steps":["trace[225092189] 'agreement among raft nodes before linearized reading' (duration: 305.874028ms)"],"step_count":1} {"level":"warn","ts":"2026-03-18T00:50:15.05146Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-18T00:50:14.745242Z","time spent":"306.206948ms","remote":"127.0.0.1:45028","response type":"/etcdserverpb.KV/Range","request count":0,"request size":18,"response count":0,"response size":29,"request content":"key:\"/registry/health\" "} {"level":"warn","ts":"2026-03-18T00:50:15.051512Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"471.85311ms","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-18T00:50:15.051727Z","caller":"traceutil/trace.go:171","msg":"trace[501263290] range","detail":"{range_begin:/registry/leases/kube-system/plndr-svcs-lock; range_end:; response_count:1; response_revision:941; }","duration":"472.169839ms","start":"2026-03-18T00:50:14.579524Z","end":"2026-03-18T00:50:15.051694Z","steps":["trace[501263290] 'agreement among raft nodes before linearized reading' (duration: 471.699736ms)"],"step_count":1} {"level":"warn","ts":"2026-03-18T00:50:15.051886Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-18T00:50:14.579481Z","time spent":"472.370954ms","remote":"127.0.0.1:45306","response type":"/etcdserverpb.KV/Range","request count":0,"request size":46,"response count":1,"response size":462,"request content":"key:\"/registry/leases/kube-system/plndr-svcs-lock\" "} {"level":"warn","ts":"2026-03-18T00:50:15.052017Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"472.570798ms","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-18T00:50:15.052072Z","caller":"traceutil/trace.go:171","msg":"trace[1835916784] range","detail":"{range_begin:/registry/leases/kube-system/kube-scheduler; range_end:; response_count:1; response_revision:941; }","duration":"472.663601ms","start":"2026-03-18T00:50:14.579395Z","end":"2026-03-18T00:50:15.052059Z","steps":["trace[1835916784] 'agreement among raft nodes before linearized reading' (duration: 471.711095ms)"],"step_count":1} {"level":"warn","ts":"2026-03-18T00:50:15.05213Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-18T00:50:14.579379Z","time spent":"472.735273ms","remote":"127.0.0.1:45306","response type":"/etcdserverpb.KV/Range","request count":0,"request size":45,"response count":1,"response size":503,"request content":"key:\"/registry/leases/kube-system/kube-scheduler\" "} {"level":"info","ts":"2026-03-18T00:50:15.593369Z","caller":"traceutil/trace.go:171","msg":"trace[797850973] transaction","detail":"{read_only:false; response_revision:942; number_of_response:1; }","duration":"536.966753ms","start":"2026-03-18T00:50:15.056367Z","end":"2026-03-18T00:50:15.593333Z","steps":["trace[797850973] 'process raft request' (duration: 510.83654ms)","trace[797850973] 'compare' (duration: 25.775734ms)"],"step_count":2} {"level":"warn","ts":"2026-03-18T00:50:15.593537Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-18T00:50:15.056349Z","time spent":"537.098056ms","remote":"127.0.0.1:45306","response type":"/etcdserverpb.KV/Txn","request count":1,"request size":476,"response count":0,"response size":40,"request content":"compare: success:> failure: >"} {"level":"info","ts":"2026-03-18T00:50:15.617116Z","caller":"traceutil/trace.go:171","msg":"trace[1347223406] transaction","detail":"{read_only:false; response_revision:943; number_of_response:1; }","duration":"559.521632ms","start":"2026-03-18T00:50:15.057544Z","end":"2026-03-18T00:50:15.617066Z","steps":["trace[1347223406] 'process raft request' (duration: 559.184942ms)"],"step_count":1} {"level":"warn","ts":"2026-03-18T00:50:15.617327Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-18T00:50:15.057521Z","time spent":"559.702387ms","remote":"127.0.0.1:45306","response type":"/etcdserverpb.KV/Txn","request count":1,"request size":464,"response count":0,"response size":40,"request content":"compare: success:> failure: >"} {"level":"info","ts":"2026-03-18T00:50:15.617362Z","caller":"traceutil/trace.go:171","msg":"trace[210398867] transaction","detail":"{read_only:false; response_revision:944; number_of_response:1; }","duration":"559.226635ms","start":"2026-03-18T00:50:15.058107Z","end":"2026-03-18T00:50:15.617334Z","steps":["trace[210398867] 'process raft request' (duration: 558.797533ms)"],"step_count":1} {"level":"warn","ts":"2026-03-18T00:50:15.617541Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-18T00:50:15.058096Z","time spent":"559.351688ms","remote":"127.0.0.1:45306","response type":"/etcdserverpb.KV/Txn","request count":1,"request size":423,"response count":0,"response size":40,"request content":"compare: success:> failure: >"} {"level":"info","ts":"2026-03-18T00:50:15.617854Z","caller":"traceutil/trace.go:171","msg":"trace[1576769676] transaction","detail":"{read_only:false; response_revision:945; number_of_response:1; }","duration":"559.663506ms","start":"2026-03-18T00:50:15.058173Z","end":"2026-03-18T00:50:15.617836Z","steps":["trace[1576769676] 'process raft request' (duration: 559.04969ms)"],"step_count":1} {"level":"warn","ts":"2026-03-18T00:50:15.617962Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-18T00:50:15.058166Z","time spent":"559.761048ms","remote":"127.0.0.1:45306","response type":"/etcdserverpb.KV/Txn","request count":1,"request size":418,"response count":0,"response size":40,"request content":"compare: success:> failure: >"} {"level":"warn","ts":"2026-03-18T00:50:18.023332Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"401.784559ms","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-18T00:50:18.023435Z","caller":"traceutil/trace.go:171","msg":"trace[516618881] range","detail":"{range_begin:/registry/leases/kube-system/kube-scheduler; range_end:; response_count:1; response_revision:949; }","duration":"401.919712ms","start":"2026-03-18T00:50:17.621493Z","end":"2026-03-18T00:50:18.023412Z","steps":["trace[516618881] 'range keys from in-memory index tree' (duration: 401.389459ms)"],"step_count":1} {"level":"warn","ts":"2026-03-18T00:50:18.023483Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-18T00:50:17.621486Z","time spent":"401.986644ms","remote":"127.0.0.1:45306","response type":"/etcdserverpb.KV/Range","request count":0,"request size":45,"response count":1,"response size":503,"request content":"key:\"/registry/leases/kube-system/kube-scheduler\" "} {"level":"warn","ts":"2026-03-18T00:50:18.023502Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"402.377303ms","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-18T00:50:18.0235Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"117.300872ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/clusterroles/\" range_end:\"/registry/clusterroles0\" count_only:true ","response":"range_response_count:0 size:7"} {"level":"warn","ts":"2026-03-18T00:50:18.023572Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"425.550628ms","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":"info","ts":"2026-03-18T00:50:18.023578Z","caller":"traceutil/trace.go:171","msg":"trace[941398822] range","detail":"{range_begin:/registry/leases/kube-system/plndr-svcs-lock; range_end:; response_count:1; response_revision:949; }","duration":"402.540697ms","start":"2026-03-18T00:50:17.621019Z","end":"2026-03-18T00:50:18.02356Z","steps":["trace[941398822] 'range keys from in-memory index tree' (duration: 401.542133ms)"],"step_count":1} {"level":"info","ts":"2026-03-18T00:50:18.023586Z","caller":"traceutil/trace.go:171","msg":"trace[1091966890] range","detail":"{range_begin:/registry/clusterroles/; range_end:/registry/clusterroles0; response_count:0; response_revision:949; }","duration":"117.464625ms","start":"2026-03-18T00:50:17.906104Z","end":"2026-03-18T00:50:18.023569Z","steps":["trace[1091966890] 'count revisions from in-memory index tree' (duration: 117.045325ms)"],"step_count":1} {"level":"info","ts":"2026-03-18T00:50:18.023603Z","caller":"traceutil/trace.go:171","msg":"trace[1452257070] range","detail":"{range_begin:/registry/leases/kube-system/cilium-operator-resource-lock; range_end:; response_count:1; response_revision:949; }","duration":"425.61662ms","start":"2026-03-18T00:50:17.597979Z","end":"2026-03-18T00:50:18.023595Z","steps":["trace[1452257070] 'range keys from in-memory index tree' (duration: 425.373834ms)"],"step_count":1} {"level":"warn","ts":"2026-03-18T00:50:18.023615Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-18T00:50:17.620988Z","time spent":"402.620469ms","remote":"127.0.0.1:45306","response type":"/etcdserverpb.KV/Range","request count":0,"request size":46,"response count":1,"response size":462,"request content":"key:\"/registry/leases/kube-system/plndr-svcs-lock\" "} {"level":"warn","ts":"2026-03-18T00:50:18.023632Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-18T00:50:17.597955Z","time spent":"425.665542ms","remote":"127.0.0.1:45306","response type":"/etcdserverpb.KV/Range","request count":0,"request size":60,"response count":1,"response size":515,"request content":"key:\"/registry/leases/kube-system/cilium-operator-resource-lock\" "} {"level":"warn","ts":"2026-03-18T00:50:18.023632Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"402.620099ms","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-18T00:50:18.023505Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"277.668698ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/health\" ","response":"range_response_count:0 size:5"} {"level":"info","ts":"2026-03-18T00:50:18.023696Z","caller":"traceutil/trace.go:171","msg":"trace[484644398] range","detail":"{range_begin:/registry/leases/kube-system/plndr-cp-lock; range_end:; response_count:1; response_revision:949; }","duration":"402.715302ms","start":"2026-03-18T00:50:17.620951Z","end":"2026-03-18T00:50:18.023666Z","steps":["trace[484644398] 'range keys from in-memory index tree' (duration: 402.508967ms)"],"step_count":1} {"level":"info","ts":"2026-03-18T00:50:18.023723Z","caller":"traceutil/trace.go:171","msg":"trace[526289668] range","detail":"{range_begin:/registry/health; range_end:; response_count:0; response_revision:949; }","duration":"277.927194ms","start":"2026-03-18T00:50:17.745779Z","end":"2026-03-18T00:50:18.023706Z","steps":["trace[526289668] 'range keys from in-memory index tree' (duration: 277.579415ms)"],"step_count":1} {"level":"warn","ts":"2026-03-18T00:50:18.023731Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-18T00:50:17.620932Z","time spent":"402.791023ms","remote":"127.0.0.1:45306","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":"info","ts":"2026-03-18T00:50:18.130948Z","caller":"traceutil/trace.go:171","msg":"trace[722550617] transaction","detail":"{read_only:false; response_revision:950; number_of_response:1; }","duration":"102.901873ms","start":"2026-03-18T00:50:18.028023Z","end":"2026-03-18T00:50:18.130925Z","steps":["trace[722550617] 'process raft request' (duration: 102.755479ms)"],"step_count":1} {"level":"info","ts":"2026-03-18T00:50:18.205935Z","caller":"traceutil/trace.go:171","msg":"trace[1648744991] transaction","detail":"{read_only:false; response_revision:953; number_of_response:1; }","duration":"176.68675ms","start":"2026-03-18T00:50:18.029224Z","end":"2026-03-18T00:50:18.205911Z","steps":["trace[1648744991] 'process raft request' (duration: 176.649059ms)"],"step_count":1} {"level":"info","ts":"2026-03-18T00:50:18.206033Z","caller":"traceutil/trace.go:171","msg":"trace[1458706678] transaction","detail":"{read_only:false; response_revision:951; number_of_response:1; }","duration":"176.862144ms","start":"2026-03-18T00:50:18.029126Z","end":"2026-03-18T00:50:18.205988Z","steps":["trace[1458706678] 'process raft request' (duration: 176.588037ms)"],"step_count":1} {"level":"info","ts":"2026-03-18T00:50:18.206156Z","caller":"traceutil/trace.go:171","msg":"trace[1582997146] transaction","detail":"{read_only:false; response_revision:952; number_of_response:1; }","duration":"176.849733ms","start":"2026-03-18T00:50:18.029234Z","end":"2026-03-18T00:50:18.206083Z","steps":["trace[1582997146] 'process raft request' (duration: 176.603827ms)"],"step_count":1} {"level":"warn","ts":"2026-03-18T00:50:19.09176Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"644.062844ms","expected-duration":"100ms","prefix":"","request":"header: txn: success:> failure: >>","response":"size:16"} {"level":"info","ts":"2026-03-18T00:50:19.091876Z","caller":"traceutil/trace.go:171","msg":"trace[2024052957] linearizableReadLoop","detail":"{readStateIndex:998; appliedIndex:997; }","duration":"347.222255ms","start":"2026-03-18T00:50:18.744629Z","end":"2026-03-18T00:50:19.091851Z","steps":["trace[2024052957] 'read index received' (duration: 53.891µs)","trace[2024052957] 'applied index is now lower than readState.Index' (duration: 347.166494ms)"],"step_count":2} {"level":"warn","ts":"2026-03-18T00:50:19.092019Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"347.389758ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/health\" ","response":"range_response_count:0 size:5"} {"level":"info","ts":"2026-03-18T00:50:19.092072Z","caller":"traceutil/trace.go:171","msg":"trace[955233303] range","detail":"{range_begin:/registry/health; range_end:; response_count:0; response_revision:955; }","duration":"347.44377ms","start":"2026-03-18T00:50:18.744614Z","end":"2026-03-18T00:50:19.092057Z","steps":["trace[955233303] 'agreement among raft nodes before linearized reading' (duration: 347.328827ms)"],"step_count":1} {"level":"info","ts":"2026-03-18T00:50:19.092066Z","caller":"traceutil/trace.go:171","msg":"trace[1923877738] transaction","detail":"{read_only:false; response_revision:955; number_of_response:1; }","duration":"688.907699ms","start":"2026-03-18T00:50:18.403136Z","end":"2026-03-18T00:50:19.092044Z","steps":["trace[1923877738] 'process raft request' (duration: 44.481818ms)","trace[1923877738] 'compare' (duration: 643.434978ms)"],"step_count":2} {"level":"warn","ts":"2026-03-18T00:50:19.092119Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-18T00:50:18.744543Z","time spent":"347.565023ms","remote":"127.0.0.1:45038","response type":"/etcdserverpb.KV/Range","request count":0,"request size":18,"response count":0,"response size":29,"request content":"key:\"/registry/health\" "} {"level":"warn","ts":"2026-03-18T00:50:19.092158Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-18T00:50:18.403107Z","time spent":"689.007412ms","remote":"127.0.0.1:45056","response type":"/etcdserverpb.KV/Txn","request count":1,"request size":120,"response count":0,"response size":40,"request content":"compare: success:> failure: >"} {"level":"warn","ts":"2026-03-18T00:50:19.65333Z","caller":"etcdserver/v3_server.go:897","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":10363236834071835474,"retry-timeout":"500ms"} {"level":"warn","ts":"2026-03-18T00:50:20.153671Z","caller":"etcdserver/v3_server.go:897","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":10363236834071835474,"retry-timeout":"500ms"} {"level":"warn","ts":"2026-03-18T00:50:20.23349Z","caller":"wal/wal.go:805","msg":"slow fdatasync","took":"1.089421897s","expected-duration":"1s"} {"level":"info","ts":"2026-03-18T00:50:20.233872Z","caller":"traceutil/trace.go:171","msg":"trace[213378192] linearizableReadLoop","detail":"{readStateIndex:999; appliedIndex:998; }","duration":"1.080767315s","start":"2026-03-18T00:50:19.153079Z","end":"2026-03-18T00:50:20.233847Z","steps":["trace[213378192] 'read index received' (duration: 1.080536199s)","trace[213378192] 'applied index is now lower than readState.Index' (duration: 230.166µs)"],"step_count":2} {"level":"info","ts":"2026-03-18T00:50:20.233965Z","caller":"traceutil/trace.go:171","msg":"trace[1790119909] transaction","detail":"{read_only:false; response_revision:956; number_of_response:1; }","duration":"1.089975212s","start":"2026-03-18T00:50:19.143955Z","end":"2026-03-18T00:50:20.23393Z","steps":["trace[1790119909] 'process raft request' (duration: 1.089729045s)"],"step_count":1} {"level":"warn","ts":"2026-03-18T00:50:20.234067Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"1.080955109s","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-18T00:50:20.234121Z","caller":"traceutil/trace.go:171","msg":"trace[1112293794] range","detail":"{range_begin:/registry/events/; range_end:/registry/events0; response_count:0; response_revision:956; }","duration":"1.081053591s","start":"2026-03-18T00:50:19.153058Z","end":"2026-03-18T00:50:20.234111Z","steps":["trace[1112293794] 'agreement among raft nodes before linearized reading' (duration: 1.080895227s)"],"step_count":1} {"level":"warn","ts":"2026-03-18T00:50:20.234113Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-18T00:50:19.143938Z","time spent":"1.090094455s","remote":"127.0.0.1:45306","response type":"/etcdserverpb.KV/Txn","request count":1,"request size":490,"response count":0,"response size":40,"request content":"compare: success:> failure: >"} {"level":"warn","ts":"2026-03-18T00:50:20.234159Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-18T00:50:19.153048Z","time spent":"1.081101112s","remote":"127.0.0.1:45104","response type":"/etcdserverpb.KV/Range","request count":0,"request size":40,"response count":114,"response size":31,"request content":"key:\"/registry/events/\" range_end:\"/registry/events0\" count_only:true "} {"level":"warn","ts":"2026-03-18T00:50:20.234157Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"488.220115ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/health\" ","response":"range_response_count:0 size:5"} {"level":"info","ts":"2026-03-18T00:50:20.234201Z","caller":"traceutil/trace.go:171","msg":"trace[637853525] range","detail":"{range_begin:/registry/health; range_end:; response_count:0; response_revision:956; }","duration":"488.298847ms","start":"2026-03-18T00:50:19.74589Z","end":"2026-03-18T00:50:20.234189Z","steps":["trace[637853525] 'agreement among raft nodes before linearized reading' (duration: 488.229205ms)"],"step_count":1} {"level":"warn","ts":"2026-03-18T00:50:20.234229Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-18T00:50:19.745871Z","time spent":"488.351368ms","remote":"127.0.0.1:45038","response type":"/etcdserverpb.KV/Range","request count":0,"request size":18,"response count":0,"response size":29,"request content":"key:\"/registry/health\" "} {"level":"info","ts":"2026-03-18T00:50:20.357467Z","caller":"traceutil/trace.go:171","msg":"trace[1657971499] transaction","detail":"{read_only:false; response_revision:959; number_of_response:1; }","duration":"117.903486ms","start":"2026-03-18T00:50:20.239544Z","end":"2026-03-18T00:50:20.357447Z","steps":["trace[1657971499] 'process raft request' (duration: 117.845305ms)"],"step_count":1} {"level":"info","ts":"2026-03-18T00:50:20.357515Z","caller":"traceutil/trace.go:171","msg":"trace[1571443046] transaction","detail":"{read_only:false; response_revision:958; number_of_response:1; }","duration":"118.050559ms","start":"2026-03-18T00:50:20.23942Z","end":"2026-03-18T00:50:20.35747Z","steps":["trace[1571443046] 'process raft request' (duration: 108.821241ms)"],"step_count":1} {"level":"info","ts":"2026-03-18T00:50:20.35758Z","caller":"traceutil/trace.go:171","msg":"trace[324987904] transaction","detail":"{read_only:false; response_revision:960; number_of_response:1; }","duration":"117.708502ms","start":"2026-03-18T00:50:20.239858Z","end":"2026-03-18T00:50:20.357567Z","steps":["trace[324987904] 'process raft request' (duration: 117.562508ms)"],"step_count":1} {"level":"info","ts":"2026-03-18T00:50:21.063384Z","caller":"traceutil/trace.go:171","msg":"trace[556638385] transaction","detail":"{read_only:false; response_revision:961; number_of_response:1; }","duration":"181.484283ms","start":"2026-03-18T00:50:20.881884Z","end":"2026-03-18T00:50:21.063369Z","steps":["trace[556638385] 'process raft request' (duration: 181.39167ms)"],"step_count":1} {"level":"info","ts":"2026-03-18T00:50:23.575364Z","caller":"traceutil/trace.go:171","msg":"trace[1245687339] transaction","detail":"{read_only:false; response_revision:976; number_of_response:1; }","duration":"203.778776ms","start":"2026-03-18T00:50:23.371562Z","end":"2026-03-18T00:50:23.57534Z","steps":["trace[1245687339] 'process raft request' (duration: 203.625983ms)"],"step_count":1} {"level":"warn","ts":"2026-03-18T00:50:29.881749Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"1.301322498s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/cilium.io/ciliumnodes/\" range_end:\"/registry/cilium.io/ciliumnodes0\" count_only:true ","response":"range_response_count:0 size:7"} {"level":"info","ts":"2026-03-18T00:50:29.881907Z","caller":"traceutil/trace.go:171","msg":"trace[1561610730] range","detail":"{range_begin:/registry/cilium.io/ciliumnodes/; range_end:/registry/cilium.io/ciliumnodes0; response_count:0; response_revision:1020; }","duration":"1.301532273s","start":"2026-03-18T00:50:28.580351Z","end":"2026-03-18T00:50:29.881884Z","steps":["trace[1561610730] 'count revisions from in-memory index tree' (duration: 1.301232465s)"],"step_count":1} {"level":"warn","ts":"2026-03-18T00:50:29.881964Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-18T00:50:28.580311Z","time spent":"1.301639045s","remote":"127.0.0.1:45582","response type":"/etcdserverpb.KV/Range","request count":0,"request size":70,"response count":1,"response size":31,"request content":"key:\"/registry/cilium.io/ciliumnodes/\" range_end:\"/registry/cilium.io/ciliumnodes0\" count_only:true "} {"level":"warn","ts":"2026-03-18T00:50:29.882179Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"624.428892ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/leases/kube-system/rbd-csi-ceph-com\" ","response":"range_response_count:1 size:472"} {"level":"info","ts":"2026-03-18T00:50:29.88229Z","caller":"traceutil/trace.go:171","msg":"trace[1733434297] range","detail":"{range_begin:/registry/leases/kube-system/rbd-csi-ceph-com; range_end:; response_count:1; response_revision:1020; }","duration":"624.588796ms","start":"2026-03-18T00:50:29.257681Z","end":"2026-03-18T00:50:29.88227Z","steps":["trace[1733434297] 'range keys from in-memory index tree' (duration: 624.245917ms)"],"step_count":1} {"level":"warn","ts":"2026-03-18T00:50:29.882454Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"1.136225231s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/health\" ","response":"range_response_count:0 size:5"} {"level":"info","ts":"2026-03-18T00:50:29.882509Z","caller":"traceutil/trace.go:171","msg":"trace[1651904448] range","detail":"{range_begin:/registry/health; range_end:; response_count:0; response_revision:1020; }","duration":"1.136318413s","start":"2026-03-18T00:50:28.746176Z","end":"2026-03-18T00:50:29.882494Z","steps":["trace[1651904448] 'range keys from in-memory index tree' (duration: 1.136159889s)"],"step_count":1} {"level":"warn","ts":"2026-03-18T00:50:29.882622Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-18T00:50:28.746154Z","time spent":"1.136457776s","remote":"127.0.0.1:45038","response type":"/etcdserverpb.KV/Range","request count":0,"request size":18,"response count":0,"response size":29,"request content":"key:\"/registry/health\" "} {"level":"warn","ts":"2026-03-18T00:50:29.884013Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-18T00:50:29.257661Z","time spent":"624.733628ms","remote":"127.0.0.1:45306","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-18T00:50:30.392002Z","caller":"etcdserver/v3_server.go:897","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":10363236834071835594,"retry-timeout":"500ms"} {"level":"warn","ts":"2026-03-18T00:50:30.893231Z","caller":"etcdserver/v3_server.go:897","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":10363236834071835594,"retry-timeout":"500ms"} {"level":"warn","ts":"2026-03-18T00:50:31.394198Z","caller":"etcdserver/v3_server.go:897","msg":"waiting for ReadIndex response took too long, retrying","sent-request-id":10363236834071835594,"retry-timeout":"500ms"} {"level":"warn","ts":"2026-03-18T00:50:31.477972Z","caller":"wal/wal.go:805","msg":"slow fdatasync","took":"1.588434666s","expected-duration":"1s"} {"level":"info","ts":"2026-03-18T00:50:31.47827Z","caller":"traceutil/trace.go:171","msg":"trace[130728262] linearizableReadLoop","detail":"{readStateIndex:1066; appliedIndex:1065; }","duration":"1.587067494s","start":"2026-03-18T00:50:29.891182Z","end":"2026-03-18T00:50:31.478249Z","steps":["trace[130728262] 'read index received' (duration: 1.586945631s)","trace[130728262] 'applied index is now lower than readState.Index' (duration: 120.833µs)"],"step_count":2} {"level":"info","ts":"2026-03-18T00:50:31.478389Z","caller":"traceutil/trace.go:171","msg":"trace[403831364] transaction","detail":"{read_only:false; response_revision:1021; number_of_response:1; }","duration":"1.588923258s","start":"2026-03-18T00:50:29.889454Z","end":"2026-03-18T00:50:31.478377Z","steps":["trace[403831364] 'process raft request' (duration: 1.588659432s)"],"step_count":1} {"level":"warn","ts":"2026-03-18T00:50:31.478499Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-18T00:50:29.889433Z","time spent":"1.588988549s","remote":"127.0.0.1:45306","response type":"/etcdserverpb.KV/Txn","request count":1,"request size":457,"response count":0,"response size":40,"request content":"compare: success:> failure: >"} {"level":"warn","ts":"2026-03-18T00:50:31.478496Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"1.58728481s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/health\" ","response":"range_response_count:0 size:5"} {"level":"info","ts":"2026-03-18T00:50:31.478774Z","caller":"traceutil/trace.go:171","msg":"trace[382219154] range","detail":"{range_begin:/registry/health; range_end:; response_count:0; response_revision:1021; }","duration":"1.587453563s","start":"2026-03-18T00:50:29.891157Z","end":"2026-03-18T00:50:31.47861Z","steps":["trace[382219154] 'agreement among raft nodes before linearized reading' (duration: 1.587251687s)"],"step_count":1} {"level":"warn","ts":"2026-03-18T00:50:31.478825Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-18T00:50:29.891148Z","time spent":"1.587666249s","remote":"127.0.0.1:45038","response type":"/etcdserverpb.KV/Range","request count":0,"request size":18,"response count":0,"response size":29,"request content":"key:\"/registry/health\" "} {"level":"warn","ts":"2026-03-18T00:50:31.555413Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"1.104648596s","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-18T00:50:31.555471Z","caller":"traceutil/trace.go:171","msg":"trace[7888969] range","detail":"{range_begin:/registry/leases/kube-system/plndr-cp-lock; range_end:; response_count:1; response_revision:1022; }","duration":"1.104733728s","start":"2026-03-18T00:50:30.450721Z","end":"2026-03-18T00:50:31.555455Z","steps":["trace[7888969] 'agreement among raft nodes before linearized reading' (duration: 1.104603115s)"],"step_count":1} {"level":"warn","ts":"2026-03-18T00:50:31.555423Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"1.105350824s","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":"info","ts":"2026-03-18T00:50:31.555539Z","caller":"traceutil/trace.go:171","msg":"trace[1560363102] transaction","detail":"{read_only:false; response_revision:1022; number_of_response:1; }","duration":"129.99486ms","start":"2026-03-18T00:50:31.425535Z","end":"2026-03-18T00:50:31.55553Z","steps":["trace[1560363102] 'process raft request' (duration: 129.314314ms)"],"step_count":1} {"level":"info","ts":"2026-03-18T00:50:31.555659Z","caller":"traceutil/trace.go:171","msg":"trace[1760367148] range","detail":"{range_begin:/registry/leases/kube-system/cilium-operator-resource-lock; range_end:; response_count:1; response_revision:1022; }","duration":"1.105529447s","start":"2026-03-18T00:50:30.450016Z","end":"2026-03-18T00:50:31.555546Z","steps":["trace[1760367148] 'agreement among raft nodes before linearized reading' (duration: 1.105315132s)"],"step_count":1} {"level":"warn","ts":"2026-03-18T00:50:31.555731Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-18T00:50:30.449997Z","time spent":"1.105720072s","remote":"127.0.0.1:45306","response type":"/etcdserverpb.KV/Range","request count":0,"request size":60,"response count":1,"response size":515,"request content":"key:\"/registry/leases/kube-system/cilium-operator-resource-lock\" "} {"level":"warn","ts":"2026-03-18T00:50:31.55576Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"953.288173ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/leases/kube-system/external-resizer-rbd-csi-ceph-com\" ","response":"range_response_count:1 size:509"} {"level":"info","ts":"2026-03-18T00:50:31.5558Z","caller":"traceutil/trace.go:171","msg":"trace[735589923] range","detail":"{range_begin:/registry/leases/kube-system/external-resizer-rbd-csi-ceph-com; range_end:; response_count:1; response_revision:1022; }","duration":"953.363715ms","start":"2026-03-18T00:50:30.602425Z","end":"2026-03-18T00:50:31.555788Z","steps":["trace[735589923] 'agreement among raft nodes before linearized reading' (duration: 953.268042ms)"],"step_count":1} {"level":"warn","ts":"2026-03-18T00:50:31.555831Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-18T00:50:30.602402Z","time spent":"953.422597ms","remote":"127.0.0.1:45306","response type":"/etcdserverpb.KV/Range","request count":0,"request size":64,"response count":1,"response size":533,"request content":"key:\"/registry/leases/kube-system/external-resizer-rbd-csi-ceph-com\" "} {"level":"warn","ts":"2026-03-18T00:50:31.555984Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"1.155870222s","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-18T00:50:31.556042Z","caller":"traceutil/trace.go:171","msg":"trace[2022837241] range","detail":"{range_begin:/registry/leases/kube-system/kube-scheduler; range_end:; response_count:1; response_revision:1022; }","duration":"1.155964264s","start":"2026-03-18T00:50:30.400067Z","end":"2026-03-18T00:50:31.556031Z","steps":["trace[2022837241] 'agreement among raft nodes before linearized reading' (duration: 1.155837511s)"],"step_count":1} {"level":"warn","ts":"2026-03-18T00:50:31.556033Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"1.104841291s","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-18T00:50:31.556094Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-18T00:50:30.400045Z","time spent":"1.156039546s","remote":"127.0.0.1:45306","response type":"/etcdserverpb.KV/Range","request count":0,"request size":45,"response count":1,"response size":503,"request content":"key:\"/registry/leases/kube-system/kube-scheduler\" "} {"level":"info","ts":"2026-03-18T00:50:31.556122Z","caller":"traceutil/trace.go:171","msg":"trace[1097900911] range","detail":"{range_begin:/registry/leases/kube-system/plndr-svcs-lock; range_end:; response_count:1; response_revision:1022; }","duration":"1.104980304s","start":"2026-03-18T00:50:30.451126Z","end":"2026-03-18T00:50:31.556106Z","steps":["trace[1097900911] 'agreement among raft nodes before linearized reading' (duration: 1.104737688s)"],"step_count":1} {"level":"warn","ts":"2026-03-18T00:50:31.556191Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-18T00:50:30.451103Z","time spent":"1.105079356s","remote":"127.0.0.1:45306","response type":"/etcdserverpb.KV/Range","request count":0,"request size":46,"response count":1,"response size":462,"request content":"key:\"/registry/leases/kube-system/plndr-svcs-lock\" "} {"level":"warn","ts":"2026-03-18T00:50:31.556241Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"1.20547573s","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/leases/kube-system/kube-controller-manager\" ","response":"range_response_count:1 size:506"} {"level":"warn","ts":"2026-03-18T00:50:31.555504Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-18T00:50:30.450706Z","time spent":"1.104790029s","remote":"127.0.0.1:45306","response type":"/etcdserverpb.KV/Range","request count":0,"request size":44,"response count":1,"response size":458,"request content":"key:\"/registry/leases/kube-system/plndr-cp-lock\" "} {"level":"info","ts":"2026-03-18T00:50:31.556281Z","caller":"traceutil/trace.go:171","msg":"trace[755777413] range","detail":"{range_begin:/registry/leases/kube-system/kube-controller-manager; range_end:; response_count:1; response_revision:1022; }","duration":"1.205554032s","start":"2026-03-18T00:50:30.350717Z","end":"2026-03-18T00:50:31.556271Z","steps":["trace[755777413] 'agreement among raft nodes before linearized reading' (duration: 1.20546367s)"],"step_count":1} {"level":"warn","ts":"2026-03-18T00:50:31.556318Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-18T00:50:30.350696Z","time spent":"1.205614874s","remote":"127.0.0.1:45306","response type":"/etcdserverpb.KV/Range","request count":0,"request size":54,"response count":1,"response size":530,"request content":"key:\"/registry/leases/kube-system/kube-controller-manager\" "} {"level":"info","ts":"2026-03-18T00:50:32.491641Z","caller":"traceutil/trace.go:171","msg":"trace[103738437] transaction","detail":"{read_only:false; response_revision:1029; number_of_response:1; }","duration":"121.301536ms","start":"2026-03-18T00:50:32.370284Z","end":"2026-03-18T00:50:32.491585Z","steps":["trace[103738437] 'process raft request' (duration: 121.163773ms)"],"step_count":1} {"level":"info","ts":"2026-03-18T00:50:33.778767Z","caller":"traceutil/trace.go:171","msg":"trace[342150549] transaction","detail":"{read_only:false; response_revision:1035; number_of_response:1; }","duration":"105.869812ms","start":"2026-03-18T00:50:33.672875Z","end":"2026-03-18T00:50:33.778745Z","steps":["trace[342150549] 'process raft request' (duration: 105.734259ms)"],"step_count":1} {"level":"info","ts":"2026-03-18T00:50:37.639056Z","caller":"traceutil/trace.go:171","msg":"trace[2020886637] transaction","detail":"{read_only:false; response_revision:1062; number_of_response:1; }","duration":"138.095582ms","start":"2026-03-18T00:50:37.500934Z","end":"2026-03-18T00:50:37.639029Z","steps":["trace[2020886637] 'process raft request' (duration: 137.883907ms)"],"step_count":1} {"level":"warn","ts":"2026-03-18T00:50:56.782914Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"112.329775ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/leases/kube-system/external-resizer-rbd-csi-ceph-com\" ","response":"range_response_count:1 size:509"} {"level":"info","ts":"2026-03-18T00:50:56.783003Z","caller":"traceutil/trace.go:171","msg":"trace[1711571156] range","detail":"{range_begin:/registry/leases/kube-system/external-resizer-rbd-csi-ceph-com; range_end:; response_count:1; response_revision:1143; }","duration":"112.429507ms","start":"2026-03-18T00:50:56.670554Z","end":"2026-03-18T00:50:56.782984Z","steps":["trace[1711571156] 'range keys from in-memory index tree' (duration: 112.101599ms)"],"step_count":1} {"level":"warn","ts":"2026-03-18T00:51:20.200167Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"174.886178ms","expected-duration":"100ms","prefix":"","request":"header: txn: success:> failure: >>","response":"size:16"} {"level":"info","ts":"2026-03-18T00:51:20.20038Z","caller":"traceutil/trace.go:171","msg":"trace[522762493] transaction","detail":"{read_only:false; response_revision:1240; number_of_response:1; }","duration":"249.482733ms","start":"2026-03-18T00:51:19.95088Z","end":"2026-03-18T00:51:20.200363Z","steps":["trace[522762493] 'process raft request' (duration: 249.440832ms)"],"step_count":1} {"level":"info","ts":"2026-03-18T00:51:20.200511Z","caller":"traceutil/trace.go:171","msg":"trace[2066215262] transaction","detail":"{read_only:false; response_revision:1239; number_of_response:1; }","duration":"250.904768ms","start":"2026-03-18T00:51:19.949598Z","end":"2026-03-18T00:51:20.200503Z","steps":["trace[2066215262] 'process raft request' (duration: 250.673352ms)"],"step_count":1} {"level":"info","ts":"2026-03-18T00:51:20.200707Z","caller":"traceutil/trace.go:171","msg":"trace[998266892] transaction","detail":"{read_only:false; response_revision:1238; number_of_response:1; }","duration":"251.131963ms","start":"2026-03-18T00:51:19.949402Z","end":"2026-03-18T00:51:20.200534Z","steps":["trace[998266892] 'process raft request' (duration: 75.799895ms)","trace[998266892] 'compare' (duration: 174.783055ms)"],"step_count":2} {"level":"info","ts":"2026-03-18T00:52:05.206796Z","caller":"traceutil/trace.go:171","msg":"trace[1560000804] transaction","detail":"{read_only:false; response_revision:1422; number_of_response:1; }","duration":"111.773538ms","start":"2026-03-18T00:52:05.094997Z","end":"2026-03-18T00:52:05.20677Z","steps":["trace[1560000804] 'process raft request' (duration: 111.586454ms)"],"step_count":1} {"level":"info","ts":"2026-03-18T00:52:06.373106Z","caller":"traceutil/trace.go:171","msg":"trace[60925312] transaction","detail":"{read_only:false; response_revision:1424; number_of_response:1; }","duration":"134.318425ms","start":"2026-03-18T00:52:06.238761Z","end":"2026-03-18T00:52:06.37308Z","steps":["trace[60925312] 'process raft request' (duration: 134.10752ms)"],"step_count":1} {"level":"info","ts":"2026-03-18T00:52:47.054615Z","caller":"traceutil/trace.go:171","msg":"trace[1455791372] transaction","detail":"{read_only:false; response_revision:1593; number_of_response:1; }","duration":"113.149071ms","start":"2026-03-18T00:52:46.941441Z","end":"2026-03-18T00:52:47.05459Z","steps":["trace[1455791372] 'process raft request' (duration: 63.702622ms)","trace[1455791372] 'compare' (duration: 49.141402ms)"],"step_count":2} {"level":"info","ts":"2026-03-18T00:52:48.115927Z","caller":"traceutil/trace.go:171","msg":"trace[1925021176] transaction","detail":"{read_only:false; response_revision:1596; number_of_response:1; }","duration":"113.659494ms","start":"2026-03-18T00:52:48.002004Z","end":"2026-03-18T00:52:48.115664Z","steps":["trace[1925021176] 'process raft request' (duration: 113.508139ms)"],"step_count":1} {"level":"info","ts":"2026-03-18T00:52:57.022008Z","caller":"traceutil/trace.go:171","msg":"trace[1183568562] transaction","detail":"{read_only:false; response_revision:1631; number_of_response:1; }","duration":"151.180225ms","start":"2026-03-18T00:52:56.8708Z","end":"2026-03-18T00:52:57.02198Z","steps":["trace[1183568562] 'process raft request' (duration: 107.73672ms)","trace[1183568562] 'compare' (duration: 43.24818ms)"],"step_count":2} {"level":"info","ts":"2026-03-18T00:53:46.131565Z","caller":"traceutil/trace.go:171","msg":"trace[143908746] transaction","detail":"{read_only:false; response_revision:1861; number_of_response:1; }","duration":"266.985359ms","start":"2026-03-18T00:53:45.864521Z","end":"2026-03-18T00:53:46.131506Z","steps":["trace[143908746] 'process raft request' (duration: 266.725473ms)"],"step_count":1} {"level":"warn","ts":"2026-03-18T00:53:47.334167Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"356.36932ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/persistentvolumes/test-pv\" ","response":"range_response_count:0 size:5"} {"level":"info","ts":"2026-03-18T00:53:47.334254Z","caller":"traceutil/trace.go:171","msg":"trace[1361956214] range","detail":"{range_begin:/registry/persistentvolumes/test-pv; range_end:; response_count:0; response_revision:1863; }","duration":"356.508282ms","start":"2026-03-18T00:53:46.977728Z","end":"2026-03-18T00:53:47.334236Z","steps":["trace[1361956214] 'range keys from in-memory index tree' (duration: 356.235797ms)"],"step_count":1} {"level":"warn","ts":"2026-03-18T00:53:47.334292Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-18T00:53:46.977708Z","time spent":"356.575374ms","remote":"127.0.0.1:45182","response type":"/etcdserverpb.KV/Range","request count":0,"request size":37,"response count":0,"response size":29,"request content":"key:\"/registry/persistentvolumes/test-pv\" "} {"level":"warn","ts":"2026-03-18T00:53:47.334647Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"119.100775ms","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-18T00:53:47.33471Z","caller":"traceutil/trace.go:171","msg":"trace[1010738652] range","detail":"{range_begin:/registry/leases/kube-system/plndr-svcs-lock; range_end:; response_count:1; response_revision:1863; }","duration":"119.200017ms","start":"2026-03-18T00:53:47.215493Z","end":"2026-03-18T00:53:47.334693Z","steps":["trace[1010738652] 'range keys from in-memory index tree' (duration: 118.956661ms)"],"step_count":1} {"level":"warn","ts":"2026-03-18T00:53:47.334773Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"283.880466ms","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-18T00:53:47.334773Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"171.750739ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/leases/kube-system/rbd-csi-ceph-com\" ","response":"range_response_count:1 size:472"} {"level":"info","ts":"2026-03-18T00:53:47.334851Z","caller":"traceutil/trace.go:171","msg":"trace[507972842] range","detail":"{range_begin:/registry/leases/kube-system/kube-scheduler; range_end:; response_count:1; response_revision:1863; }","duration":"284.000619ms","start":"2026-03-18T00:53:47.050829Z","end":"2026-03-18T00:53:47.33483Z","steps":["trace[507972842] 'range keys from in-memory index tree' (duration: 283.698191ms)"],"step_count":1} {"level":"info","ts":"2026-03-18T00:53:47.334855Z","caller":"traceutil/trace.go:171","msg":"trace[348384683] range","detail":"{range_begin:/registry/leases/kube-system/rbd-csi-ceph-com; range_end:; response_count:1; response_revision:1863; }","duration":"171.877523ms","start":"2026-03-18T00:53:47.16296Z","end":"2026-03-18T00:53:47.334838Z","steps":["trace[348384683] 'range keys from in-memory index tree' (duration: 171.599406ms)"],"step_count":1} {"level":"info","ts":"2026-03-18T00:53:47.464331Z","caller":"traceutil/trace.go:171","msg":"trace[340845934] linearizableReadLoop","detail":"{readStateIndex:1949; appliedIndex:1948; }","duration":"125.678732ms","start":"2026-03-18T00:53:47.338629Z","end":"2026-03-18T00:53:47.464308Z","steps":["trace[340845934] 'read index received' (duration: 125.534199ms)","trace[340845934] 'applied index is now lower than readState.Index' (duration: 143.433µs)"],"step_count":2} {"level":"info","ts":"2026-03-18T00:53:47.46437Z","caller":"traceutil/trace.go:171","msg":"trace[570848329] transaction","detail":"{read_only:false; response_revision:1864; number_of_response:1; }","duration":"126.325557ms","start":"2026-03-18T00:53:47.338024Z","end":"2026-03-18T00:53:47.464349Z","steps":["trace[570848329] 'process raft request' (duration: 126.121572ms)"],"step_count":1} {"level":"warn","ts":"2026-03-18T00:53:47.464515Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"125.867057ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/persistentvolumes/test-pv\" ","response":"range_response_count:0 size:5"} {"level":"info","ts":"2026-03-18T00:53:47.464591Z","caller":"traceutil/trace.go:171","msg":"trace[1368430861] range","detail":"{range_begin:/registry/persistentvolumes/test-pv; range_end:; response_count:0; response_revision:1864; }","duration":"125.99039ms","start":"2026-03-18T00:53:47.338586Z","end":"2026-03-18T00:53:47.464577Z","steps":["trace[1368430861] 'agreement among raft nodes before linearized reading' (duration: 125.842816ms)"],"step_count":1} {"level":"info","ts":"2026-03-18T00:53:47.65873Z","caller":"traceutil/trace.go:171","msg":"trace[2056899844] transaction","detail":"{read_only:false; response_revision:1867; number_of_response:1; }","duration":"319.700767ms","start":"2026-03-18T00:53:47.339012Z","end":"2026-03-18T00:53:47.658713Z","steps":["trace[2056899844] 'process raft request' (duration: 319.654256ms)"],"step_count":1} {"level":"info","ts":"2026-03-18T00:53:47.658744Z","caller":"traceutil/trace.go:171","msg":"trace[2066122235] transaction","detail":"{read_only:false; response_revision:1865; number_of_response:1; }","duration":"320.044005ms","start":"2026-03-18T00:53:47.33867Z","end":"2026-03-18T00:53:47.658714Z","steps":["trace[2066122235] 'process raft request' (duration: 284.648424ms)","trace[2066122235] 'compare' (duration: 35.150155ms)"],"step_count":2} {"level":"warn","ts":"2026-03-18T00:53:47.658832Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-18T00:53:47.339Z","time spent":"319.778739ms","remote":"127.0.0.1:45306","response type":"/etcdserverpb.KV/Txn","request count":1,"request size":422,"response count":0,"response size":40,"request content":"compare: success:> failure: >"} {"level":"warn","ts":"2026-03-18T00:53:47.65901Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-18T00:53:47.338648Z","time spent":"320.143997ms","remote":"127.0.0.1:45306","response type":"/etcdserverpb.KV/Txn","request count":1,"request size":419,"response count":0,"response size":40,"request content":"compare: success:> failure: >"} {"level":"info","ts":"2026-03-18T00:53:47.659016Z","caller":"traceutil/trace.go:171","msg":"trace[602876389] linearizableReadLoop","detail":"{readStateIndex:1954; appliedIndex:1949; }","duration":"194.59579ms","start":"2026-03-18T00:53:47.464406Z","end":"2026-03-18T00:53:47.659001Z","steps":["trace[602876389] 'read index received' (duration: 158.85261ms)","trace[602876389] 'applied index is now lower than readState.Index' (duration: 35.7422ms)"],"step_count":2} {"level":"info","ts":"2026-03-18T00:53:47.659073Z","caller":"traceutil/trace.go:171","msg":"trace[1958169362] transaction","detail":"{read_only:false; response_revision:1869; number_of_response:1; }","duration":"319.595314ms","start":"2026-03-18T00:53:47.339469Z","end":"2026-03-18T00:53:47.659064Z","steps":["trace[1958169362] 'process raft request' (duration: 319.4233ms)"],"step_count":1} {"level":"info","ts":"2026-03-18T00:53:47.659049Z","caller":"traceutil/trace.go:171","msg":"trace[974833801] transaction","detail":"{read_only:false; response_revision:1868; number_of_response:1; }","duration":"319.687307ms","start":"2026-03-18T00:53:47.339325Z","end":"2026-03-18T00:53:47.659012Z","steps":["trace[974833801] 'process raft request' (duration: 319.364559ms)"],"step_count":1} {"level":"warn","ts":"2026-03-18T00:53:47.659125Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-18T00:53:47.339464Z","time spent":"319.638335ms","remote":"127.0.0.1:45306","response type":"/etcdserverpb.KV/Txn","request count":1,"request size":457,"response count":0,"response size":40,"request content":"compare: success:> failure: >"} {"level":"warn","ts":"2026-03-18T00:53:47.659193Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-18T00:53:47.339312Z","time spent":"319.806061ms","remote":"127.0.0.1:45306","response type":"/etcdserverpb.KV/Txn","request count":1,"request size":463,"response count":0,"response size":40,"request content":"compare: success:> failure: >"} {"level":"warn","ts":"2026-03-18T00:53:47.659234Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"320.013856ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/leases/kube-system/external-resizer-rbd-csi-ceph-com\" ","response":"range_response_count:1 size:509"} {"level":"info","ts":"2026-03-18T00:53:47.659271Z","caller":"traceutil/trace.go:171","msg":"trace[2146348082] range","detail":"{range_begin:/registry/leases/kube-system/external-resizer-rbd-csi-ceph-com; range_end:; response_count:1; response_revision:1869; }","duration":"320.092367ms","start":"2026-03-18T00:53:47.339166Z","end":"2026-03-18T00:53:47.659258Z","steps":["trace[2146348082] 'agreement among raft nodes before linearized reading' (duration: 319.912453ms)"],"step_count":1} {"level":"warn","ts":"2026-03-18T00:53:47.659309Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-18T00:53:47.339153Z","time spent":"320.148218ms","remote":"127.0.0.1:45306","response type":"/etcdserverpb.KV/Range","request count":0,"request size":64,"response count":1,"response size":533,"request content":"key:\"/registry/leases/kube-system/external-resizer-rbd-csi-ceph-com\" "} {"level":"warn","ts":"2026-03-18T00:53:47.659551Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"280.32509ms","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-18T00:53:47.65961Z","caller":"traceutil/trace.go:171","msg":"trace[1562288861] transaction","detail":"{read_only:false; response_revision:1866; number_of_response:1; }","duration":"319.780459ms","start":"2026-03-18T00:53:47.338999Z","end":"2026-03-18T00:53:47.65878Z","steps":["trace[1562288861] 'process raft request' (duration: 319.639055ms)"],"step_count":1} {"level":"warn","ts":"2026-03-18T00:53:47.659738Z","caller":"v3rpc/interceptor.go:197","msg":"request stats","start time":"2026-03-18T00:53:47.33899Z","time spent":"320.687541ms","remote":"127.0.0.1:45306","response type":"/etcdserverpb.KV/Txn","request count":1,"request size":476,"response count":0,"response size":40,"request content":"compare: success:> failure: >"} {"level":"info","ts":"2026-03-18T00:53:47.659715Z","caller":"traceutil/trace.go:171","msg":"trace[282924570] range","detail":"{range_begin:/registry/leases/kube-system/rbd.csi.ceph.com-kube-system; range_end:; response_count:1; response_revision:1869; }","duration":"280.487414ms","start":"2026-03-18T00:53:47.379172Z","end":"2026-03-18T00:53:47.659637Z","steps":["trace[282924570] 'agreement among raft nodes before linearized reading' (duration: 279.953762ms)"],"step_count":1} {"level":"info","ts":"2026-03-18T00:53:47.794684Z","caller":"traceutil/trace.go:171","msg":"trace[976160211] transaction","detail":"{read_only:false; response_revision:1871; number_of_response:1; }","duration":"130.312504ms","start":"2026-03-18T00:53:47.664327Z","end":"2026-03-18T00:53:47.79464Z","steps":["trace[976160211] 'process raft request' (duration: 129.986086ms)"],"step_count":1} {"level":"info","ts":"2026-03-18T00:53:48.487881Z","caller":"traceutil/trace.go:171","msg":"trace[1215775806] linearizableReadLoop","detail":"{readStateIndex:1958; appliedIndex:1957; }","duration":"123.687473ms","start":"2026-03-18T00:53:48.364167Z","end":"2026-03-18T00:53:48.487855Z","steps":["trace[1215775806] 'read index received' (duration: 123.517189ms)","trace[1215775806] 'applied index is now lower than readState.Index' (duration: 169.234µs)"],"step_count":2} {"level":"warn","ts":"2026-03-18T00:53:48.48808Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"123.89535ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/masterleases/162.253.55.221\" ","response":"range_response_count:1 size:135"} {"level":"info","ts":"2026-03-18T00:53:48.488122Z","caller":"traceutil/trace.go:171","msg":"trace[540262296] range","detail":"{range_begin:/registry/masterleases/162.253.55.221; range_end:; response_count:1; response_revision:1873; }","duration":"123.996332ms","start":"2026-03-18T00:53:48.364112Z","end":"2026-03-18T00:53:48.488108Z","steps":["trace[540262296] 'agreement among raft nodes before linearized reading' (duration: 123.839108ms)"],"step_count":1} {"level":"info","ts":"2026-03-18T00:53:48.488099Z","caller":"traceutil/trace.go:171","msg":"trace[271221049] transaction","detail":"{read_only:false; response_revision:1873; number_of_response:1; }","duration":"220.01363ms","start":"2026-03-18T00:53:48.26806Z","end":"2026-03-18T00:53:48.488074Z","steps":["trace[271221049] 'process raft request' (duration: 219.539127ms)"],"step_count":1} {"level":"warn","ts":"2026-03-18T00:53:53.706713Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"189.843754ms","expected-duration":"100ms","prefix":"","request":"header: lease_revoke:","response":"size:29"} {"level":"info","ts":"2026-03-18T00:53:53.707028Z","caller":"traceutil/trace.go:171","msg":"trace[1491628062] linearizableReadLoop","detail":"{readStateIndex:1982; appliedIndex:1981; }","duration":"186.360681ms","start":"2026-03-18T00:53:53.520645Z","end":"2026-03-18T00:53:53.707005Z","steps":["trace[1491628062] 'read index received' (duration: 37.401µs)","trace[1491628062] 'applied index is now lower than readState.Index' (duration: 186.29359ms)"],"step_count":2} {"level":"warn","ts":"2026-03-18T00:53:53.707213Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"186.538395ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/clusterroles/kubeadm:get-nodes\" ","response":"range_response_count:1 size:305"} {"level":"info","ts":"2026-03-18T00:53:53.707346Z","caller":"traceutil/trace.go:171","msg":"trace[960061962] range","detail":"{range_begin:/registry/clusterroles/kubeadm:get-nodes; range_end:; response_count:1; response_revision:1895; }","duration":"186.693819ms","start":"2026-03-18T00:53:53.520602Z","end":"2026-03-18T00:53:53.707296Z","steps":["trace[960061962] 'agreement among raft nodes before linearized reading' (duration: 186.466724ms)"],"step_count":1} {"level":"warn","ts":"2026-03-18T00:53:53.70737Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"144.261659ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/clusterroles/system:aggregate-to-admin\" ","response":"range_response_count:1 size:840"} {"level":"info","ts":"2026-03-18T00:53:53.707437Z","caller":"traceutil/trace.go:171","msg":"trace[20253209] range","detail":"{range_begin:/registry/clusterroles/system:aggregate-to-admin; range_end:; response_count:1; response_revision:1895; }","duration":"144.418513ms","start":"2026-03-18T00:53:53.563Z","end":"2026-03-18T00:53:53.707419Z","steps":["trace[20253209] 'agreement among raft nodes before linearized reading' (duration: 144.219758ms)"],"step_count":1} {"level":"info","ts":"2026-03-18T00:54:08.016369Z","caller":"traceutil/trace.go:171","msg":"trace[271816474] transaction","detail":"{read_only:false; response_revision:1957; number_of_response:1; }","duration":"122.458084ms","start":"2026-03-18T00:54:07.893887Z","end":"2026-03-18T00:54:08.016345Z","steps":["trace[271816474] 'process raft request' (duration: 121.136983ms)"],"step_count":1} {"level":"info","ts":"2026-03-18T00:54:08.016661Z","caller":"traceutil/trace.go:171","msg":"trace[1659449022] transaction","detail":"{read_only:false; response_revision:1958; number_of_response:1; }","duration":"122.431234ms","start":"2026-03-18T00:54:07.894206Z","end":"2026-03-18T00:54:08.016637Z","steps":["trace[1659449022] 'process raft request' (duration: 122.102135ms)"],"step_count":1} {"level":"info","ts":"2026-03-18T00:54:08.016714Z","caller":"traceutil/trace.go:171","msg":"trace[4437204] transaction","detail":"{read_only:false; response_revision:1959; number_of_response:1; }","duration":"122.213569ms","start":"2026-03-18T00:54:07.894484Z","end":"2026-03-18T00:54:08.016697Z","steps":["trace[4437204] 'process raft request' (duration: 122.042875ms)"],"step_count":1} {"level":"info","ts":"2026-03-18T00:54:08.016694Z","caller":"traceutil/trace.go:171","msg":"trace[1512576392] linearizableReadLoop","detail":"{readStateIndex:2049; appliedIndex:2044; }","duration":"118.447188ms","start":"2026-03-18T00:54:07.898224Z","end":"2026-03-18T00:54:08.016671Z","steps":["trace[1512576392] 'read index received' (duration: 54.758577ms)","trace[1512576392] 'applied index is now lower than readState.Index' (duration: 63.687401ms)"],"step_count":2} {"level":"info","ts":"2026-03-18T00:54:08.016766Z","caller":"traceutil/trace.go:171","msg":"trace[1592632030] transaction","detail":"{read_only:false; response_revision:1960; number_of_response:1; }","duration":"121.02707ms","start":"2026-03-18T00:54:07.895722Z","end":"2026-03-18T00:54:08.016749Z","steps":["trace[1592632030] 'process raft request' (duration: 120.908157ms)"],"step_count":1} {"level":"warn","ts":"2026-03-18T00:54:08.016949Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"118.698634ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/pods/kube-system/ceph-csi-rbd-provisioner-69cb97fb6-54vtp\" ","response":"range_response_count:1 size:13724"} {"level":"warn","ts":"2026-03-18T00:54:08.016976Z","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"116.371418ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:\"/registry/pods/kube-system/ceph-csi-rbd-nodeplugin-zm725\" ","response":"range_response_count:1 size:11390"} {"level":"info","ts":"2026-03-18T00:54:08.016989Z","caller":"traceutil/trace.go:171","msg":"trace[1234576566] range","detail":"{range_begin:/registry/pods/kube-system/ceph-csi-rbd-provisioner-69cb97fb6-54vtp; range_end:; response_count:1; response_revision:1960; }","duration":"118.772417ms","start":"2026-03-18T00:54:07.898201Z","end":"2026-03-18T00:54:08.016974Z","steps":["trace[1234576566] 'agreement among raft nodes before linearized reading' (duration: 118.591802ms)"],"step_count":1} {"level":"info","ts":"2026-03-18T00:54:08.017012Z","caller":"traceutil/trace.go:171","msg":"trace[574377155] range","detail":"{range_begin:/registry/pods/kube-system/ceph-csi-rbd-nodeplugin-zm725; range_end:; response_count:1; response_revision:1960; }","duration":"116.42971ms","start":"2026-03-18T00:54:07.900572Z","end":"2026-03-18T00:54:08.017002Z","steps":["trace[574377155] 'agreement among raft nodes before linearized reading' (duration: 116.300277ms)"],"step_count":1}