K8S Deployment Fails in IPv4 Environment: PD Container Keeps Losing Address and Continuously Restarting

Note:
This topic has been translated from a Chinese forum by GPT and might contain errors.

Original topic: K8S在IPv4环境下部署失败,pd容器一直丢失地址,并不断重启

| username: TiDBer_G64jJ9u8

[TiDB Usage Environment] Test/PoC
[TiDB Version] tidb v6.5.8, ti-operator v1.5.2
[Reproduction Path] Installation and Deployment
[Encountered Issue: Problem Phenomenon and Impact] PD keeps restarting after installation in K8S environment
[Resource Configuration]
[Attachments: Screenshots/Logs/Monitoring]

docker Version: 20.10.2
k8s Version: v1.23.17

Using the default yaml configuration file for K8S deployment.

PD shows the phenomenon of IP address loss during the running process:

node1:/# kubectl -n name-space exec -ti basic-pd-1 – sh
/ # ifconfig
lo Link encap:Local Loopback
inet addr:127.0.0.1 Mask:255.0.0.0
UP LOOPBACK RUNNING MTU:65536 Metric:1
RX packets:10 errors:0 dropped:0 overruns:0 frame:0
TX packets:10 errors:0 dropped:0 overruns:0 carrier:0
collisions:0 txqueuelen:1000
RX bytes:500 (500.0 B) TX bytes:500 (500.0 B)

/ # command terminated with exit code 137

PD logs are as follows:

Server: 10.96.0.10
Address 1: 10.96.0.10 kube-dns.kube-system.svc.cluster.local

Name: basic-pd-1.basic-pd-peer.name-space.svc
Address 1: 100.74.135.23
nslookup domain basic-pd-1.basic-pd-peer.name-space.svc.svc success
starting pd-server …
/pd-server --data-dir=/var/lib/pd --name=basic-pd-1 --peer-urls=http://0.0.0.0:2380 --advertise-peer-urls=http://basic-pd-1.basic-pd-peer.name-space.svc:2380 --client-urls=http://0.0.0.0:2379 --advertise-client-urls=http://basic-pd-1.basic-pd-peer.name-space.svc:2379 --config=/etc/pd/pd.toml
[2024/06/19 07:39:57.435 +00:00] [INFO] [util.go:43] [“Welcome to Placement Driver (PD)”]
[2024/06/19 07:39:57.435 +00:00] [INFO] [util.go:44] [PD] [release-version=v6.5.8]
[2024/06/19 07:39:57.435 +00:00] [INFO] [util.go:45] [PD] [edition=Community]
[2024/06/19 07:39:57.435 +00:00] [INFO] [util.go:46] [PD] [git-hash=4506d63ba4fba7123ecc8277da7ef5f635efee90]
[2024/06/19 07:39:57.435 +00:00] [INFO] [util.go:47] [PD] [git-branch=heads/refs/tags/v6.5.8]
[2024/06/19 07:39:57.435 +00:00] [INFO] [util.go:48] [PD] [utc-build-time=“2024-01-25 10:03:20”]
[2024/06/19 07:39:57.435 +00:00] [INFO] [metricutil.go:83] [“disable Prometheus push client”]
[2024/06/19 07:39:57.435 +00:00] [INFO] [server.go:253] [“PD Config”] [config=“{"client-urls":"http://0.0.0.0:2379","peer-urls":"http://0.0.0.0:2380","advertise-client-urls":"http://basic-pd-1.basic-pd-peer.name-space.svc:2379","advertise-peer-urls":"http://basic-pd-1.basic-pd-peer.name-space.svc:2380","name":"basic-pd-1","data-dir":"/var/lib/pd","force-new-cluster":false,"enable-grpc-gateway":true,"initial-cluster":"basic-pd-1=http://basic-pd-1.basic-pd-peer.name-space.svc:2380","initial-cluster-state":"new","initial-cluster-token":"pd-cluster","join":"","lease":3,"log":{"level":"info","format":"text","disable-timestamp":false,"file":{"filename":"","max-size":0,"max-days":0,"max-backups":0},"development":false,"disable-caller":false,"disable-stacktrace":false,"disable-error-verbose":true,"sampling":null,"error-output-path":""},"tso-save-interval":"3s","tso-update-physical-interval":"50ms","enable-local-tso":false,"metric":{"job":"basic-pd-1","address":"","interval":"15s"},"schedule":{"max-snapshot-count":64,"max-pending-peer-count":64,"max-merge-region-size":20,"max-merge-region-keys":0,"split-merge-interval":"1h0m0s","swtich-witness-interval":"1h0m0s","enable-one-way-merge":"false","enable-cross-table-merge":"true","patrol-region-interval":"10ms","max-store-down-time":"30m0s","max-store-preparing-time":"48h0m0s","leader-schedule-limit":4,"leader-schedule-policy":"count","region-schedule-limit":2048,"replica-schedule-limit":64,"merge-schedule-limit":8,"hot-region-schedule-limit":4,"hot-region-cache-hits-threshold":3,"store-limit":{},"tolerant-size-ratio":0,"low-space-ratio":0.8,"high-space-ratio":0.7,"region-score-formula-version":"v2","scheduler-max-waiting-operator":5,"enable-remove-down-replica":"true","enable-replace-offline-replica":"true","enable-make-up-replica":"true","enable-remove-extra-replica":"true","enable-location-replacement":"true","enable-debug-metrics":"false","enable-joint-consensus":"true","enable-tikv-split-region":"true","schedulers-v2":[{"type":"balance-region","args":null,"disable":false,"args-payload":""},{"type":"balance-leader","args":null,"disable":false,"args-payload":""},{"type":"hot-region","args":null,"disable":false,"args-payload":""},{"type":"split-bucket","args":null,"disable":false,"args-payload":""}],"schedulers-payload":null,"store-limit-mode":"manual","hot-regions-write-interval":"10m0s","hot-regions-reserved-days":7,"enable-diagnostic":"false","enable-witness":"false"},"replication":{"max-replicas":3,"location-labels":"","strictly-match-label":"false","enable-placement-rules":"true","enable-placement-rules-cache":"false","isolation-level":""},"pd-server":{"use-region-storage":"true","max-gap-reset-ts":"24h0m0s","key-type":"table","runtime-services":"","metric-storage":"","dashboard-address":"auto","trace-region-flow":"true","flow-round-by-digit":3,"min-resolved-ts-persistence-interval":"1s"},"cluster-version":"0.0.0","labels":{},"quota-backend-bytes":"8GiB","auto-compaction-mode":"periodic","auto-compaction-retention-v2":"1h","TickInterval":"500ms","ElectionInterval":"3s","PreVote":true,"max-request-bytes":157286400,"security":{"cacert-path":"","cert-path":"","key-path":"","cert-allowed-cn":null,"SSLCABytes":null,"SSLCertBytes":null,"SSLKEYBytes":null,"redact-info-log":false,"encryption":{"data-encryption-method":"plaintext","data-key-rotation-period":"168h0m0s","master-key":{"type":"plaintext","key-id":"","region":"","endpoint":"","path":""}}},"label-property":null,"WarningMsgs":null,"DisableStrictReconfigCheck":false,"HeartbeatStreamBindInterval":"1m0s","LeaderPriorityCheckInterval":"1m0s","dashboard":{"tidb-cacert-path":"","tidb-cert-path":"","tidb-key-path":"","public-path-prefix":"","internal-proxy":false,"enable-telemetry":false,"enable-experimental":false},"replication-mode":{"replication-mode":"majority","dr-auto-sync":{"label-key":"","primary":"","dr":"","primary-replicas":0,"dr-replicas":0,"wait-store-timeout":"1m0s","pause-region-split":"false"}}}”]
[2024/06/19 07:39:57.443 +00:00] [INFO] [server.go:228] [“register REST path”] [path=/pd/api/v1]
[2024/06/19 07:39:57.443 +00:00] [INFO] [server.go:228] [“register REST path”] [path=/pd/api/v2/]
[2024/06/19 07:39:57.443 +00:00] [INFO] [server.go:228] [“register REST path”] [path=/autoscaling]
[2024/06/19 07:39:57.443 +00:00] [INFO] [distro.go:51] [“Using distribution strings”] [strings={}]
[2024/06/19 07:39:57.445 +00:00] [INFO] [server.go:228] [“register REST path”] [path=/dashboard/api/]
[2024/06/19 07:39:57.445 +00:00] [INFO] [server.go:228] [“register REST path”] [path=/dashboard/]
[2024/06/19 07:39:57.445 +00:00] [INFO] [etcd.go:117] [“configuring peer listeners”] [listen-peer-urls=“[http://0.0.0.0:2380]”]
[2024/06/19 07:39:57.445 +00:00] [INFO] [etcd.go:127] [“configuring client listeners”] [listen-client-urls=“[http://0.0.0.0:2379]”]
[2024/06/19 07:39:57.446 +00:00] [INFO] [etcd.go:611] [“pprof is enabled”] [path=/debug/pprof]
[2024/06/19 07:39:57.446 +00:00] [INFO] [systimemon.go:30] [“start system time monitor”]
[2024/06/19 07:39:57.446 +00:00] [INFO] [etcd.go:305] [“starting an etcd server”] [etcd-version=3.4.21] [git-sha=“Not provided (use ./build instead of go build)”] [go-version=go1.19.13] [go-os=linux] [go-arch=amd64] [max-cpu-set=16] [max-cpu-available=16] [member-initialized=true] [name=basic-pd-1] [data-dir=/var/lib/pd] [wal-dir=] [wal-dir-dedicated=] [member-dir=/var/lib/pd/member] [force-new-cluster=false] [heartbeat-interval=500ms] [election-timeout=3s] [initial-election-tick-advance=true] [snapshot-count=100000] [snapshot-catchup-entries=5000] [initial-advertise-peer-urls=“[http://basic-pd-1.basic-pd-peer.name-space.svc:2380]”] [listen-peer-urls=“[http://0.0.0.0:2380]”] [advertise-client-urls=“[http://basic-pd-1.basic-pd-peer.name-space.svc:2379]”] [listen-client-urls=“[http://0.0.0.0:2379]”] [listen-metrics-urls=“”] [cors=“[]“] [host-whitelist=”[]”] [initial-cluster=] [initial-cluster-state=new] [initial-cluster-token=] [quota-backend-bytes=8589934592] [max-request-bytes=157286400] [max-concurrent-streams=4294967295] [pre-vote=true] [initial-corrupt-check=false] [corrupt-check-time-interval=0s] [auto-compaction-mode=periodic] [auto-compaction-retention=1h0m0s] [auto-compaction-interval=1h0m0s] [discovery-url=] [discovery-proxy=]
[2024/06/19 07:39:57.446 +00:00] [WARN] [server.go:297] [“exceeded recommended request limit”] [max-request-bytes=157286400] [max-request-size=“157 MB”] [recommended-request-bytes=10485760] [recommended-request-size=“10 MB”]
2024-06-19 07:39:57.446236 W | pkg/fileutil: check file permission: directory “/var/lib/pd” exist, but the permission is “drwxr-xr-x”. The recommended permission is “-rwx------” to prevent possible unprivileged access to the data.
[2024/06/19 07:39:57.453 +00:00] [INFO] [backend.go:80] [“opened backend db”] [path=/var/lib/pd/member/snap/db] [took=7.123285ms]
[2024/06/19 07:39:57.478 +00:00] [INFO] [raft.go:586] [“restarting local member”] [cluster-id=dd0f8a758c7a4da3] [local-member-id=1ceea2c50a83b82a] [commit-index=5715]
[2024/06/19 07:39:57.479 +00:00] [INFO] [raft.go:1523] [“1ceea2c50a83b82a switched to configuration voters=()”]
[2024/06/19 07:39:57.479 +00:00] [INFO] [raft.go:706] [“1ceea2c50a83b82a became follower at term 29”]
[2024/06/19 07:39:57.479 +00:00] [INFO] [raft.go:389] [“newRaft 1ceea2c50a83b82a [peers: , term: 29, commit: 5715, applied: 0, lastindex: 5715, lastterm: 29]”]
[2024/06/19 07:39:57.479 +00:00] [WARN] [store.go:1379] [“simple token is not cryptographically signed”]
[2024/06/19 07:39:57.490 +00:00] [INFO] [quota.go:126] [“enabled backend quota”] [quota-name=v3-applier] [quota-size-bytes=8589934592] [quota-size=“8.6 GB”]
[2024/06/19 07:39:57.491 +00:00] [INFO] [server.go:816] [“starting etcd server”] [local-member-id=1ceea2c50a83b82a] [local-server-version=3.4.21] [cluster-version=to_be_decided]
[2024/06/19 07:39:57.491 +00:00] [INFO] [server.go:704] [“starting initial election tick advance”] [election-ticks=6]
[2024/06/19 07:39:57.491 +00:00] [INFO] [raft.go:1523] [“1ceea2c50a83b82a switched to configuration voters=(2084782644687779882)”]
[2024/06/19 07:39:57.491 +00:00] [INFO] [cluster.go:392] [“added member”] [cluster-id=dd0f8a758c7a4da3] [local-member-id=1ceea2c50a83b82a] [added-peer-id=1ceea2c50a83b82a] [added-peer-peer-urls=“[http://basic-pd-1.basic-pd-peer.name-space.svc:2380]”]
[2024/06/19 07:39:57.492 +00:00] [INFO] [cluster.go:558] [“set initial cluster version”] [cluster-id=dd0f8a758c7a4da3] [local-member-id=1ceea2c50a83b82a] [cluster-version=3.4]
[2024/06/19 07:39:57.492 +00:00] [INFO] [capability.go:76] [“enabled capabilities for version”] [cluster-version=3.4]
[2024/06/19 07:39:57.492 +00:00] [INFO] [raft.go:1523] [“1ceea2c50a83b82a switched to configuration voters=(2084782644687779882 11509752368320045231)”]
[2024/06/19 07:39:57.492 +00:00] [INFO] [cluster.go:392] [“added member”] [cluster-id=dd0f8a758c7a4da3] [local-member-id=1ceea2c50a83b82a] [added-peer-id=9fbadacc366d60af] [added-peer-peer-urls=“[http://basic-pd-2.basic-pd-peer.name-space.svc:2380]”]
[2024/06/19 07:39:57.492 +00:00] [INFO] [peer.go:128] [“starting remote peer”] [remote-peer-id=9fbadacc366d60af]
[2024/06/19 07:39:57.492 +00:00] [INFO] [pipeline.go:71] [“started HTTP pipelining with remote peer”] [local-member-id=1ceea2c50a83b82a] [remote-peer-id=9fbadacc366d60af]

| username: yiduoyunQ | Original post link

What is the issue with the IP address being lost?

| username: TiDBer_G64jJ9u8 | Original post link

When PD starts up, the IP address disappears after a while. Looking at the ifconfig results above, there is only the 127.0.0.1 address left. The final result is that PD cannot establish the cluster properly.

| username: 小龙虾爱大龙虾 | Original post link

This log indicates that PD received a signal to exit voluntarily. Check if there are any operations in k8s.

| username: 小于同学 | Original post link

Is there any issue with the network?

| username: yiduoyunQ | Original post link

Got signal to exit. Check the environment for issues such as OOM or k8s scheduling.

| username: TiDBer_G64jJ9u8 | Original post link

It’s been a long time, and today I revisited this issue.
TiOperator is 1.5.2, TiDB version is 6.5.8, and k8s version is 1.23.17.
PD keeps restarting repeatedly, going through the states: running → ContainerCreating → Pending → running.
After a while, it starts normally, but it takes 10 minutes if lucky, and several hours if not.
Moreover, the debug mode is not effective; even with debug mode enabled, it still restarts automatically.

Compared to the previous versions used:
TiOperator was v1.4.3, TiDB version was 6.5.0, and k8s version was v1.20.7.

Startup failure logs:

[2024/07/11 12:38:48.620 +00:00] [WARN] [v3_server.go:814] [“waiting for ReadIndex response took too long, retrying”] [sent-request-id=1124651556563639575] [retry-timeout=500ms]
[2024/07/11 12:38:48.620 +00:00] [INFO] [raft.go:1358] [“43c224d21a700f9b no leader at term 1584; dropping index reading msg”]
[2024/07/11 12:38:48.893 +00:00] [INFO] [raft.go:929] [“43c224d21a700f9b is starting a new election at term 1584”]
[2024/07/11 12:38:48.893 +00:00] [INFO] [raft.go:735] [“43c224d21a700f9b became pre-candidate at term 1584”]
[2024/07/11 12:38:48.893 +00:00] [INFO] [raft.go:830] [“43c224d21a700f9b received MsgPreVoteResp from 43c224d21a700f9b at term 1584”]
[2024/07/11 12:38:48.893 +00:00] [INFO] [raft.go:817] [“43c224d21a700f9b [logterm: 1584, index: 113074] sent MsgPreVote request to 51c5dd9dd1f119ae at term 1584”]
[2024/07/11 12:38:48.893 +00:00] [INFO] [raft.go:817] [“43c224d21a700f9b [logterm: 1584, index: 113074] sent MsgPreVote request to 738369e98f51ba86 at term 1584”]
[2024/07/11 12:38:49.120 +00:00] [WARN] [v3_server.go:814] [“waiting for ReadIndex response took too long, retrying”] [sent-request-id=1124651556563639575] [retry-timeout=500ms]
[2024/07/11 12:38:49.664 +00:00] [WARN] [v3_server.go:814] [“waiting for ReadIndex response took too long, retrying”] [sent-request-id=1124651556563639575] [retry-timeout=500ms]
[2024/07/11 12:38:49.665 +00:00] [WARN] [probing_status.go:70] [“prober detected unhealthy status”] [round-tripper-name=ROUND_TRIPPER_RAFT_MESSAGE] [remote-peer-id=738369e98f51ba86] [rtt=0s] [error=“dial tcp: lookup basic-pd-2.basic-pd-peer.ns.svc on 10.96.0.10:53: dial udp 10.96.0.10:53: connect: network is unreachable”]
[2024/07/11 12:38:49.665 +00:00] [WARN] [probing_status.go:70] [“prober detected unhealthy status”] [round-tripper-name=ROUND_TRIPPER_SNAPSHOT] [remote-peer-id=738369e98f51ba86] [rtt=0s] [error=“dial tcp 100.108.11.194:2380: connect: connection refused”]
[2024/07/11 12:38:50.165 +00:00] [WARN] [v3_server.go:814] [“waiting for ReadIndex response took too long, retrying”] [sent-request-id=1124651556563639575] [retry-timeout=500ms]
[2024/07/11 12:38:50.665 +00:00] [WARN] [v3_server.go:814] [“waiting for ReadIndex response took too long, retrying”] [sent-request-id=1124651556563639575] [retry-timeout=500ms]
[2024/07/11 12:38:51.188 +00:00] [WARN] [v3_server.go:814] [“waiting for ReadIndex response took too long, retrying”] [sent-request-id=1124651556563639575] [retry-timeout=500ms]
[2024/07/11 12:38:51.303 +00:00] [WARN] [util.go:163] [“apply request took too long”] [took=10.00007245s] [expected-duration=100ms] [prefix=“read-only range “] [request=“key:"/pd/7389506872184522927" range_end:"/pd/7389506872184522928" “] [response=] [error=“context deadline exceeded”]
[2024/07/11 12:38:51.303 +00:00] [INFO] [trace.go:152] [“trace[107107765] range”] [detail=”{range_begin:/pd/7389506872184522927; range_end:/pd/7389506872184522928; }”] [duration=10.000303807s] [start=2024/07/11 12:38:41.303 +00:00] [end=2024/07/11 12:38:51.303 +00:00] [steps=”["trace[107107765] ‘agreement among raft nodes before linearized reading’ (duration: 10.000092564s)"]”]
[2024/07/11 12:38:51.303 +00:00] [WARN] [retry_interceptor.go:62] [“retrying of unary invoker failed”] [target=endpoint://client-9be0eacd-99c7-4f44-9693-baf0775a244d/basic-pd-0.basic-pd-peer.ns.svc:2379] [attempt=0] [error=“rpc error: code = DeadlineExceeded desc = context deadline exceeded”]
[2024/07/11 12:38:51.303 +00:00] [WARN] [etcdutil.go:121] [“kv gets too slow”] [request-key=/pd/7389506872184522927] [cost=10.000653535s] [error=“context deadline exceeded”]
[2024/07/11 12:38:51.303 +00:00] [ERROR] [etcdutil.go:126] [“load from etcd meet error”] [key=/pd/7389506872184522927] [error=“[PD:etcd:ErrEtcdKVGet]context deadline exceeded: context deadline exceeded”]
[2024/07/11 12:38:51.303 +00:00] [ERROR] [server.go:1524] [“failed to initialize the global TSO allocator”] [error=“[PD:etcd:ErrEtcdKVGet]context deadline exceeded: context deadline exceeded”]
[2024/07/11 12:38:51.689 +00:00] [WARN] [v3_server.go:814] [“waiting for ReadIndex response took too long, retrying”] [sent-request-id=1124651556563639575] [retry-timeout=500ms]
[2024/07/11 12:38:52.190 +00:00] [WARN] [v3_server.go:814] [“waiting for ReadIndex response took too long, retrying”] [sent-request-id=1124651556563639575] [retry-timeout=500ms]
[2024/07/11 12:38:52.338 +00:00] [WARN] [retry_interceptor.go:62] [“retrying of unary invoker failed”] [target=endpoint://client-9be0eacd-99c7-4f44-9693-baf0775a244d/basic-pd-0.basic-pd-peer.ns.svc:2379] [attempt=0] [error=“rpc error: code = DeadlineExceeded desc = context deadline exceeded”]
[2024/07/11 12:38:52.338 +00:00] [WARN] [v3_server.go:830] [“timed out waiting for read index response (local node might have slow network)”] [timeout=11s]
[2024/07/11 12:38:52.338 +00:00] [INFO] [server.go:1420] [“server is closed, return pd leader loop”]
[2024/07/11 12:38:52.338 +00:00] [INFO] [etcd.go:369] [“closing etcd server”] [name=basic-pd-0] [data-dir=/var/lib/pd] [advertise-peer-urls=“[http://basic-pd-0.basic-pd-peer.ns.svc:2380]”] [advertise-client-urls=“[http://basic-pd-0.basic-pd-peer.ns.svc:2379]”]
[2024/07/11 12:38:52.339 +00:00] [WARN] [grpclog.go:60] [“transport: http2Server.HandleStreams failed to read frame: read tcp 100.74.135.16:2379->100.74.135.16:35694: use of closed network connection”]
[2024/07/11 12:38:52.339 +00:00] [WARN] [grpclog.go:60] [“transport: http2Server.HandleStreams failed to read frame: read tcp 100.74.135.16:2379->100.66.209.200:59794: use of closed network connection”]
[2024/07/11 12:38:52.339 +00:00] [INFO] [server.go:1494] [“skipped leadership transfer; local server is not leader”] [local-member-id=43c224d21a700f9b] [current-leader-member-id=0]
[2024/07/11 12:38:52.339 +00:00] [WARN] [grpclog.go:60] [“transport: http2Server.HandleStreams failed to read frame: read tcp 127.0.0.1:2379->127.0.0.1:46178: use of closed network connection”]
[2024/07/11 12:38:52.339 +00:00] [WARN] [grpclog.go:60] [“transport: http2Server.HandleStreams failed to read frame: read tcp 100.74.135.16:2379->100.74.135.32:42798: use of closed network connection”]
[2024/07/11 12:38:52.339 +00:00] [WARN] [grpclog.go:60] [“transport: http2Server.HandleStreams failed to read frame: read tcp 100.74.135.16:2379->100.108.11.230:53432: use of closed network connection”]
[2024/07/11 12:38:52.339 +00:00] [INFO] [peer.go:333] [“stopping remote peer”] [remote-peer-id=51c5dd9dd1f119ae]
[2024/07/11 12:38:52.339 +00:00] [WARN] [grpclog.go:60] [“transport: http2Server.HandleStreams failed to read frame: read tcp 100.74.135.16:2379->100.66.209.204:58928: use of closed network connection”]
[2024/07/11 12:38:52.339 +00:00] [WARN] [grpclog.go:60] [“transport: http2Server.HandleStreams failed to read frame: read tcp 100.74.135.16:2379->100.108.11.230:53380: use of closed network connection”]
[2024/07/11 12:38:52.339 +00:00] [WARN] [grpclog.go:60] [“transport: http2Server.HandleStreams failed to read frame: read tcp 100.74.135.16:2379->100.66.209.200:59310: use of closed network connection”]
[2024/07/11 12:38:52.339 +00:00] [WARN] [grpclog.go:60] [“transport: http2Server.HandleStreams failed to read frame: read tcp 100.74.135.16:2379->100.108.11.230:53412: use of closed network connection”]
[2024/07/11 12:38:52.339 +00:00] [WARN] [grpclog.go:60] [“transport: http2Server.HandleStreams failed to read frame: read tcp 100.74.135.16:2379->100.108.11.247:39956: use of closed network connection”]
[2024/07/11 12:38:52.339 +00:00] [WARN] [grpclog.go:60] [“transport: http2Server.HandleStreams failed to read frame: read tcp 100.74.135.16:2379->100.74.135.16:35692: use of closed network connection”]
[2024/07/11 12:38:52.339 +00:00] [WARN] [grpclog.go:60] [“transport: http2Server.HandleStreams failed to read frame: read tcp 100.74.135.16:2379->100.66.209.204:58930: use of closed network connection”]
[2024/07/11 12:38:52.339 +00:00] [WARN] [grpclog.go:60] [“transport: http2Server.HandleStreams failed to read frame: read tcp 100.74.135.16:2379->100.74.135.33:58116: use of closed network connection”]
[2024/07/11 12:38:52.339 +00:00] [WARN] [grpclog.go:60] [“transport: http2Server.HandleStreams failed to read frame: read tcp 100.74.135.16:2379->100.74.135.33:57852: use of closed network connection”]
[2024/07/11 12:38:52.339 +00:00] [WARN] [stream.go:291] [“closed TCP streaming connection with remote peer”] [stream-writer-type=“stream MsgApp v2”] [remote-peer-id=51c5dd9dd1f119ae]
[2024/07/11 12:38:52.339 +00:00] [WARN] [stream.go:301] [“stopped TCP streaming connection with remote peer”] [stream-writer-type=“stream MsgApp v2”] [remote-peer-id=51c5dd9dd1f119ae]
[2024/07/11 12:38:52.339 +00:00] [WARN] [grpclog.go:60] [“transport: http2Server.HandleStreams failed to read frame: read tcp 100.74.135.16:2379->100.74.135.32:42756: use of closed network connection”]
[2024/07/11 12:38:52.339 +00:00] [WARN] [stream.go:291] [“closed TCP streaming connection with remote peer”] [stream-writer-type=“stream Message”] [remote-peer-id=51c5dd9dd1f119ae]
[2024/07/11 12:38:52.339 +00:00] [WARN] [stream.go:301] [“stopped TCP streaming connection with remote peer”] [stream-writer-type=“stream Message”] [remote-peer-id=51c5dd9dd1f119ae]
[2024/07/11 12:38:52.339 +00:00] [INFO] [pipeline.go:86] [“stopped HTTP pipelining with remote peer”] [local-member-id=43c224d21a700f9b] [remote-peer-id=51c5dd9dd1f119ae]
[2024/07/11 12:38:52.340 +00:00] [INFO] [stream.go:459] [“stopped stream reader with remote peer”] [stream-reader-type=“stream MsgApp v2”] [local-member-id=43c224d21a700f9b] [remote-peer-id=51c5dd9dd1f119ae]
[2024/07/11 12:38:52.340 +00:00] [INFO] [stream.go:459] [“stopped stream reader with remote peer”] [stream-reader-type=“stream Message”] [local-member-id=43c224d21a700f9b] [remote-peer-id=51c5dd9dd1f119ae]
[2024/07/11 12:38:52.340 +00:00] [INFO] [peer.go:340] [“stopped remote peer”] [remote-peer-id=51c5dd9dd1f119ae]
[2024/07/11 12:38:52.340 +00:00] [INFO] [peer.go:333] [“stopping remote peer”] [remote-peer-id=738369e98f51ba86]
[2024/07/11 12:38:52.340 +00:00] [WARN] [stream.go:291] [“closed TCP streaming connection with remote peer”] [stream-writer-type=“stream MsgApp v2”] [remote-peer-id=738369e98f51ba86]
[2024/07/11 12:38:52.340 +00:00] [WARN] [stream.go:301] [“stopped TCP streaming connection with remote peer”] [stream-writer-type=“stream MsgApp v2”] [remote-peer-id=

| username: YuchongXU | Original post link

Expand the CPU and memory resource limits.

| username: TiDBer_G64jJ9u8 | Original post link

I didn’t see any logs indicating issues with the CPU or memory. On the same resources, the deployment of version 6.5.0 and operator 1.4 was normal.

| username: TiDBer_G64jJ9u8 | Original post link

This is in a high-performance environment, where starting a single-node PD sometimes fails:

ci:~ # kubectl logs -n ns basic-pd-0 pd -f
Server:    10.96.0.10
Address 1: 10.96.0.10 kube-dns.kube-system.svc.cluster.local

Name:      basic-pd-0.basic-pd-peer.ns.svc
Address 1: 100.91.136.6
nslookup domain basic-pd-0.basic-pd-peer.ns.svc.svc success
starting pd-server ...
/pd-server --data-dir=/var/lib/pd --name=basic-pd-0 --peer-urls=http://0.0.0.0:2380 --advertise-peer-urls=http://basic-pd-0.basic-pd-peer.ns.svc:2380 --client-urls=http://0.0.0.0:2379 --advertise-client-urls=http://basic-pd-0.basic-pd-peer.ns.svc:2379 --config=/etc/pd/pd.toml
[2024/07/12 02:54:48.942 +00:00] [INFO] [util.go:43] ["Welcome to Placement Driver (PD)"]
[2024/07/12 02:54:48.942 +00:00] [INFO] [util.go:44] [PD] [release-version=v6.5.8]
[2024/07/12 02:54:48.942 +00:00] [INFO] [util.go:45] [PD] [edition=Community]
[2024/07/12 02:54:48.942 +00:00] [INFO] [util.go:46] [PD] [git-hash=4506d63ba4fba7123ecc8277da7ef5f635efee90]
[2024/07/12 02:54:48.942 +00:00] [INFO] [util.go:47] [PD] [git-branch=heads/refs/tags/v6.5.8]
[2024/07/12 02:54:48.942 +00:00] [INFO] [util.go:48] [PD] [utc-build-time="2024-01-25 10:03:20"]
[2024/07/12 02:54:48.942 +00:00] [INFO] [metricutil.go:83] ["disable Prometheus push client"]
[2024/07/12 02:54:48.942 +00:00] [INFO] [server.go:253] ["PD Config"] [config="{\"client-urls\":\"http://0.0.0.0:2379\",\"peer-urls\":\"http://0.0.0.0:2380\",\"advertise-client-urls\":\"http://basic-pd-0.basic-pd-peer.ns.svc:2379\",\"advertise-peer-urls\":\"http://basic-pd-0.basic-pd-peer.ns.svc:2380\",\"name\":\"basic-pd-0\",\"data-dir\":\"/var/lib/pd\",\"force-new-cluster\":false,\"enable-grpc-gateway\":true,\"initial-cluster\":\"basic-pd-0=http://basic-pd-0.basic-pd-peer.ns.svc:2380\",\"initial-cluster-state\":\"new\",\"initial-cluster-token\":\"pd-cluster\",\"join\":\"\",\"lease\":3,\"log\":{\"level\":\"info\",\"format\":\"text\",\"disable-timestamp\":false,\"file\":{\"filename\":\"\",\"max-size\":0,\"max-days\":0,\"max-backups\":0},\"development\":false,\"disable-caller\":false,\"disable-stacktrace\":false,\"disable-error-verbose\":true,\"sampling\":null,\"error-output-path\":\"\"},\"tso-save-interval\":\"3s\",\"tso-update-physical-interval\":\"50ms\",\"enable-local-tso\":false,\"metric\":{\"job\":\"basic-pd-0\",\"address\":\"\",\"interval\":\"15s\"},\"schedule\":{\"max-snapshot-count\":64,\"max-pending-peer-count\":64,\"max-merge-region-size\":20,\"max-merge-region-keys\":0,\"split-merge-interval\":\"1h0m0s\",\"swtich-witness-interval\":\"1h0m0s\",\"enable-one-way-merge\":\"false\",\"enable-cross-table-merge\":\"true\",\"patrol-region-interval\":\"10ms\",\"max-store-down-time\":\"30m0s\",\"max-store-preparing-time\":\"48h0m0s\",\"leader-schedule-limit\":4,\"leader-schedule-policy\":\"count\",\"region-schedule-limit\":2048,\"replica-schedule-limit\":64,\"merge-schedule-limit\":8,\"hot-region-schedule-limit\":4,\"hot-region-cache-hits-threshold\":3,\"store-limit\":{},\"tolerant-size-ratio\":0,\"low-space-ratio\":0.8,\"high-space-ratio\":0.7,\"region-score-formula-version\":\"v2\",\"scheduler-max-waiting-operator\":5,\"enable-remove-down-replica\":\"true\",\"enable-replace-offline-replica\":\"true\",\"enable-make-up-replica\":\"true\",\"enable-remove-extra-replica\":\"true\",\"enable-location-replacement\":\"true\",\"enable-debug-metrics\":\"false\",\"enable-joint-consensus\":\"true\",\"enable-tikv-split-region\":\"true\",\"schedulers-v2\":[{\"type\":\"balance-region\",\"args\":null,\"disable\":false,\"args-payload\":\"\"},{\"type\":\"balance-leader\",\"args\":null,\"disable\":false,\"args-payload\":\"\"},{\"type\":\"hot-region\",\"args\":null,\"disable\":false,\"args-payload\":\"\"},{\"type\":\"split-bucket\",\"args\":null,\"disable\":false,\"args-payload\":\"\"}],\"schedulers-payload\":null,\"store-limit-mode\":\"manual\",\"hot-regions-write-interval\":\"10m0s\",\"hot-regions-reserved-days\":7,\"enable-diagnostic\":\"false\",\"enable-witness\":\"false\"},\"replication\":{\"max-replicas\":3,\"location-labels\":\"\",\"strictly-match-label\":\"false\",\"enable-placement-rules\":\"true\",\"enable-placement-rules-cache\":\"false\",\"isolation-level\":\"\"},\"pd-server\":{\"use-region-storage\":\"true\",\"max-gap-reset-ts\":\"24h0m0s\",\"key-type\":\"table\",\"runtime-services\":\"\",\"metric-storage\":\"\",\"dashboard-address\":\"auto\",\"trace-region-flow\":\"true\",\"flow-round-by-digit\":3,\"min-resolved-ts-persistence-interval\":\"1s\"},\"cluster-version\":\"0.0.0\",\"labels\":{},\"quota-backend-bytes\":\"8GiB\",\"auto-compaction-mode\":\"periodic\",\"auto-compaction-retention-v2\":\"1h\",\"TickInterval\":\"500ms\",\"ElectionInterval\":\"3s\",\"PreVote\":true,\"max-request-bytes\":157286400,\"security\":{\"cacert-path\":\"\",\"cert-path\":\"\",\"key-path\":\"\",\"cert-allowed-cn\":null,\"SSLCABytes\":null,\"SSLCertBytes\":null,\"SSLKEYBytes\":null,\"redact-info-log\":false,\"encryption\":{\"data-encryption-method\":\"plaintext\",\"data-key-rotation-period\":\"168h0m0s\",\"master-key\":{\"type\":\"plaintext\",\"key-id\":\"\",\"region\":\"\",\"endpoint\":\"\",\"path\":\"\"}}},\"label-property\":null,\"WarningMsgs\":null,\"DisableStrictReconfigCheck\":false,\"HeartbeatStreamBindInterval\":\"1m0s\",\"LeaderPriorityCheckInterval\":\"1m0s\",\"dashboard\":{\"tidb-cacert-path\":\"\",\"tidb-cert-path\":\"\",\"tidb-key-path\":\"\",\"public-path-prefix\":\"\",\"internal-proxy\":false,\"enable-telemetry\":false,\"enable-experimental\":false},\"replication-mode\":{\"replication-mode\":\"majority\",\"dr-auto-sync\":{\"label-key\":\"\",\"primary\":\"\",\"dr\":\"\",\"primary-replicas\":0,\"dr-replicas\":0,\"wait-store-timeout\":\"1m0s\",\"pause-region-split\":\"false\"}}}"]
[2024/07/12 02:54:48.946 +00:00] [INFO] [server.go:228] ["register REST path"] [path=/pd/api/v1]
[2024/07/12 02:54:48.947 +00:00] [INFO] [server.go:228] ["register REST path"] [path=/pd/api/v2/]
[2024/07/12 02:54:48.947 +00:00] [INFO] [server.go:228] ["register REST path"] [path=/autoscaling]
[2024/07/12 02:54:48.947 +00:00] [INFO] [distro.go:51] ["Using distribution strings"] [strings={}]
[2024/07/12 02:54:48.948 +00:00] [INFO] [server.go:228] ["register REST path"] [path=/dashboard/api/]
[2024/07/12 02:54:48.948 +00:00] [INFO] [server.go:228] ["register REST path"] [path=/dashboard/]
[2024/07/12 02:54:48.948 +00:00] [INFO] [etcd.go:117] ["configuring peer listeners"] [listen-peer-urls="[http://0.0.0.0:2380]"]
[2024/07/12 02:54:48.949 +00:00] [INFO] [etcd.go:127] ["configuring client listeners"] [listen-client-urls="[http://0.0.0.0:2379]"]
[2024/07/12 02:54:48.949 +00:00] [INFO] [systimemon.go:30] ["start system time monitor"]
[2024/07/12 02:54:48.949 +00:00] [INFO] [etcd.go:611] ["pprof is enabled"] [path=/debug/pprof]
[2024/07/12 02:54:48.949 +00:00] [INFO] [etcd.go:305] ["starting an etcd server"] [etcd-version=3.4.21] [git-sha="Not provided (use ./build instead of go build)"] [go-version=go1.19.13] [go-os=linux] [go-arch=amd64] [max-cpu-set=16] [max-cpu-available=16] [member-initialized=true] [name=basic-pd-0] [data-dir=/var/lib/pd] [wal-dir=] [wal-dir-dedicated=] [member-dir=/var/lib/pd/member] [force-new-cluster=false] [heartbeat-interval=500ms] [election-timeout=3s] [initial-election-tick-advance=true] [snapshot-count=100000] [snapshot-catchup-entries=5000] [initial-advertise-peer-urls="[http://basic-pd-0.basic-pd-peer.ns.svc:2380]"] [listen-peer-urls="[http://0.0.0.0:2380]"] [advertise-client-urls="[http://basic-pd-0.basic-pd-peer.ns.svc:2379]"] [listen-client-urls="[http://0.0.0.0:2379]"] [listen-metrics-urls="[]"] [cors="[*]"] [host-whitelist="[*]"] [initial-cluster=] [initial-cluster-state=new] [initial-cluster-token=] [quota-backend-bytes=8589934592] [max-request-bytes=157286400] [max-concurrent-streams=4294967295] [pre-vote=true] [initial-corrupt-check=false] [corrupt-check-time-interval=0s] [auto-compaction-mode=periodic] [auto-compaction-retention=1h0m0s] [auto-compaction-interval=1h0m0s] [discovery-url=] [discovery-proxy=]
[2024/07/12 02:54:48.949 +00:00] [WARN] [server.go:297] ["exceeded recommended request limit"] [max-request-bytes=157286400] [max-request-size="157 MB"] [recommended-request-bytes=10485760] [recommended-request-size="10 MB"]
2024-07-12 02:54:48.949450 W | pkg/fileutil: check file permission: directory "/var/lib/pd" exist, but the permission is "drwxr-xr-x". The recommended permission is "-rwx------" to prevent possible unprivileged access to the data.
[2024/07/12 02:54:48.952 +00:00] [INFO] [backend.go:80] ["opened backend db"] [path=/var/lib/pd/member/snap/db] [took=2.525235ms]
[2024/07/12 02:54:49.570 +00:00] [INFO] [server.go:462] ["recovered v2 store from snapshot"] [snapshot-index=600006] [snapshot-size="18 kB"]
[2024/07/12 02:54:49.571 +00:00] [INFO] [kvstore.go:388] ["restored last compact revision"] [meta-bucket-name=meta] [meta-bucket-name-key=finishedCompactRev] [restored-compact-revision=597525]
[2024/07/12 02:54:49.573 +00:00] [INFO] [server.go:480] ["recovered v3 backend from snapshot"] [backend-size-bytes=2547712] [backend-size="2.5 MB"] [backend-size-in-use-bytes=417792] [backend-size-in-use="418 kB"]
[2024/07/12 02:54:49.784 +00:00] [INFO] [raft.go:586] ["restarting local member"] [cluster-id=a57d21dfafd146d9] [local-member-id=43c224d21a700f9b] [commit-index=606478]
[2024/07/12 02:54:49.784 +00:00] [INFO] [raft.go:1523] ["43c224d21a700f9b switched to configuration voters=(4882505430828322715)"]
[2024/07/12 02:54:49.784 +00:00] [INFO] [raft.go:706] ["43c224d21a700f9b became follower at term 29"]
[2024/07/12 02:54:49.784 +00:00] [INFO] [raft.go:389] ["newRaft 43c224d21a700f9b [peers: [43c224d21a700f9b], term: 29, commit: 606478, applied: 600006, lastindex: 606478, lastterm: 29]"]
[2024/07/12 02:54:49.784 +00:00] [INFO] [capability.go:76] ["enabled capabilities for version"] [cluster-version=3.4]
[2024/07/12 02:54:49.784 +00:00] [INFO] [cluster.go:256] ["recovered/added member from store"] [cluster-id=a57d21dfafd146d9] [local-member-id=43c224d21a700f9b] [recovered-remote-peer-id=43c224d21a700f9b] [recovered-remote-peer-urls="[http://basic-pd-0.basic-pd-peer.ns.svc:2380]"]
[2024/07/12 02:54:49.784 +00:00] [INFO] [cluster.go:269] ["set cluster version from store"] [cluster-version=3.4]
[2024/07/12 02:54:49.785 +00:00] [WARN] [store.go:1379] ["simple token is not cryptographically signed"]
[2024/07/12 02:54:49.785 +00:00] [INFO] [kvstore.go:388] ["restored last compact revision"] [meta-bucket-name=meta] [meta-bucket-name-key=finishedCompactRev] [restored-compact-revision=597525]
[2024/07/12 02:54:49.787 +00:00] [INFO] [quota.go:126] ["enabled backend quota"] [quota-name=v3-applier] [quota-size-bytes=8589934592] [quota-size="8.6 GB"]
[2024/07/12 02:54:49.787 +00:00] [INFO] [server.go:803] ["starting etcd server"] [local-member-id=43c224d21a700f9b] [local-server-version=3.4.21] [cluster-id=a57d21dfafd146d9] [cluster-version=3.4]
[2024/07/12 02:54:49.787 +00:00] [INFO] [server.go:682] ["started as single-node; fast-forwarding election ticks"] [local-member-id=43c224d21a700f9b] [forward-ticks=5] [forward-duration=2.5s] [election-ticks=6] [election-timeout=3s]
[2024/07/12 02:54:49.789 +00:00] [INFO] [etcd.go:247] ["now serving peer/client/metrics"] [local-member-id=43c224d21a700f9b] [initial-advertise-peer-urls="[http://basic-pd-0.basic-pd-peer.ns.svc:2380]"] [listen-peer-urls="[http://0.0.0.0:2380]"] [advertise-client-urls="[http://basic-pd-0.basic-pd-peer.ns.svc:2379]"] [listen-client-urls="[http://0.0.0.0:2379]"] [listen-metrics-urls="[]"]
[2024/07/12 02:54:49.789 +00:00] [INFO] [etcd.go:585] ["serving peer traffic"] [address="[::]:2380"]
[2024/07/12 02:54:51.785 +00:00] [INFO] [raft.go:929] ["43c224d21a700f9b is starting a new election at term 29"]
[2024/07/12 02:54:51.786 +00:00] [INFO] [raft.go:735] ["43c224d21a700f9b became pre-candidate at term 29"]
[
| username: TiDBer_G64jJ9u8 | Original post link

Multiple startups, when successful, the corresponding logs are as follows, although ErrEtcdGetCluster is reported, it still started successfully:
[2024/07/12 03:06:08.105 +00:00] [INFO] [serve.go:145] [“serving client traffic insecurely; this is strongly discouraged!”] [address=“[::]:2379”]
2024-07-12 03:06:15.109376 W | etcdserver: could not get cluster response from http://basic-pd-0.basic-pd-peer.ns.svc:2380: Get “http://basic-pd-0.basic-pd-peer.ns.svc:2380/members”: context deadline exceeded (Client.Timeout exceeded while awaiting headers)
[2024/07/12 03:06:15.109 +00:00] [ERROR] [etcdutil.go:71] [“failed to get cluster from remote”] [error=“[PD:etcd:ErrEtcdGetCluster]could not retrieve cluster information from the given URLs: could not retrieve cluster information from the given URLs”]
[2024/07/12 03:06:15.109 +00:00] [INFO] [server.go:335] [“create etcd v3 client”] [endpoints=“[http://basic-pd-0.basic-pd-peer.ns.svc:2379]”] [cert=“{"cacert-path":"","cert-path":"","key-path":"","cert-allowed-cn":null,"SSLCABytes":null,"SSLCertBytes":null,"SSLKEYBytes":null,"redact-info-log":false,"encryption":{"data-encryption-method":"plaintext","data-key-rotation-period":"168h0m0s","master-key":{"type":"plaintext","key-id":"","region":"","endpoint":"","path":""}}}”]
[2024/07/12 03:06:15.112 +00:00] [INFO] [server.go:400] [“init cluster id”] [cluster-id=7385453281335235694]
[2024/07/12 03:06:15.126 +00:00] [INFO] [allocator_manager.go:262] [“delete the dc-location key previously written in etcd”] [server-id=4882505430828322715]
[2024/07/12 03:06:15.157 +00:00] [INFO] [history_buffer.go:147] [“start from history index”] [start-index=728800]
[2024/07/12 03:06:15.166 +00:00] [INFO] [server.go:1489] [“start to campaign pd leader”] [campaign-pd-leader-name=basic-pd-0]

| username: WalterWj | Original post link

Check the logs of the tidb Operator manager.

kubectl get all -n tidb-admin
NAME                                          READY   STATUS    RESTARTS      AGE
pod/tidb-controller-manager-f49f57768-6jgvl   1/1     Running   7 (31d ago)   88d

Then check the logs of this pod.
| username: TiDBer_7S8XqKfl-1158 | Original post link

Resource limits: Kubernetes may have set resource limits on the PD container, causing the process to be killed.
Configuration file issues: The PD configuration may be incorrect, such as errors in advertise-peer-urls and advertise-client-urls configurations.

| username: TiDBer_G64jJ9u8 | Original post link

Didn’t see any useful information.

| username: TiDBer_G64jJ9u8 | Original post link

  1. No special YAML modifications have been made, and the current PD YAML configuration has no resource limits.
  2. Both advertise-peer-urls and advertise-client-urls configurations are part of the TiOperator YAML file, with no special configurations.
  3. We are attempting deployment in an IPv4 environment. The dual-stack deployment of IPv6 and IPv4 currently has issues with IPv4 deployment.
| username: WalterWj | Original post link

You have an E, which stands for ERROR. It seems like it’s trying to get the health status of PD but can’t retrieve it?

| username: TiDBer_G64jJ9u8 | Original post link

Absolutely, PD keeps restarting; does this mean that the tidb-controller-manager is constantly triggering the restart? Can we make the tidb-controller-manager wait a bit longer?

| username: 小龙虾爱大龙虾 | Original post link

Try renaming the cluster and starting a new one.

| username: WalterWj | Original post link

It might be a network issue. Try going into the manager’s pod and curling this API.

| username: WalterWj | Original post link

Try this link to see if it helps: Kubernetes 上的 TiDB 集群管理常用使用技巧 | PingCAP 文档中心