【 TiDB 使用环境】测试
【 TiDB 版本】6.1.0
【复现路径】
环境:
VMware7u3平台虚拟机
Rocky Linux release 9.5 (Blue Onyx)
操作系统已关闭防火墙和selinux;
操作:
通过tiup在线部署tidb cluster,首次安全启动/非安全启动数据库均提示warn;
tiup 用root或tidb用户安装均报此类错误。
【遇到的问题:问题现象及影响】
初始数据库不能正常结束,不能显示临时密码。但tidb cluster查看状态正常,数据库可登录/查询/插入等操作。
在后续通过tiup修改cluster tikv log level等参数报类似错,且参数不能在各节点生效。
【资源配置】进入到 TiDB Dashboard -集群信息 (Cluster Info) -主机(Hosts) 截图此页面
【复制黏贴 ERROR 报错的日志】
报错信息如下:
[root@tidb30 ~]# tiup cluster start tidb-test –init
…………………………
- [ Serial ] - UpdateTopology: cluster=tidb-test
{“level”:“warn”,“ts”:“2025-02-21T16:20:27.656+0800”,“logger”:“etcd-client”,“caller”:“v3@v3.5.7/retry_interceptor.go:62”,“msg”:“retrying of unary invoker failed”,“target”:“etcd-endpoints://0xc0002d3880/192.168.169.31:2379”,“attempt”:0,“error”:“rpc error: code = DeadlineExceeded desc = latest balancer error: last connection error: connection error: desc = "error reading server preface: http2: frame too large"”}
Error: context deadline exceeded
Verbose debug logs has been written to /root/.tiup/logs/tiup-cluster-debug-2025-02-21-16-20-27.log.
tiup cluster start tidb-test
……………………………………
- [ Serial ] - UpdateTopology: cluster=tidb-test
{“level”:“warn”,“ts”:“2025-02-21T17:29:05.003+0800”,“logger”:“etcd-client”,“caller”:“v3@v3.5.7/retry_interceptor.go:62”,“msg”:“retrying of unary invoker failed”,“target”:“etcd-endpoints://0xc0001dc000/192.168.169.31:2379”,“attempt”:0,“error”:“rpc error: code = DeadlineExceeded desc = latest balancer error: last connection error: connection error: desc = "error reading server preface: http2: frame too large"”}
Error: context deadline exceeded
Verbose debug logs has been written to /root/.tiup/logs/tiup-cluster-debug-2025-02-21-17-29-05.log.
两个log如下:
tiup-cluster-debug-2025-02-21-17-29-05.log
tiup-cluster-debug-2025-02-21-16-20-27.log
tiup-cluster-debug-2025-02-21-16-20-27.log (138.2 KB)
tiup-cluster-debug-2025-02-21-17-29-05.log (90.5 KB)
查看日志/root/.tiup/logs/tiup-cluster-debug-2025-02-21-16-20-27.log 有PD 节点报错,但查看对应节点服务已启动;:
2025-02-21T16:20:17.271+0800 INFO SSHCommand {“host”: “192.168.169.31”, “port”: “22”, “cmd”: “export LANG=C; PATH=$PATH:/bin:/sbin:/usr/bin:/usr/sbin; /usr/bin/sudo -H bash -c "systemctl daemon-reload && systemctl start blackbox_exporter-9115.service"”, “stdout”: “”, “stderr”: “”}
2025-02-21T16:20:17.271+0800 INFO CheckPoint {“host”: “192.168.169.31”, “port”: 22, “user”: “tidb”, “sudo”: true, “cmd”: “systemctl daemon-reload && systemctl start blackbox_exporter-9115.service”, “stdout”: “”, “stderr”: “”, “hash”: “775384c48a95f7047c016cbf2905eec1e267f629”, “func”: “github.com/pingcap/tiup/pkg/cluster/executor.(*CheckPointExecutor).Execute”, “hit”: false}
查看服务已启动
[root@tidb31 ~]# systemctl status blackbox_exporter-9115.service
● blackbox_exporter-9115.service - blackbox_exporter service
Loaded: loaded (/etc/systemd/system/blackbox_exporter-9115.service; enabled; preset: disabled)
Active: active (running) since Fri 2025-02-21 16:20:17 CST; 19min ago
Main PID: 19439 (blackbox_export)
Tasks: 16 (limit: 203157)
Memory: 12.3M
CPU: 6.819s
CGroup: /system.slice/blackbox_exporter-9115.service
├─19439 bin/blackbox_exporter/blackbox_exporter --web.listen-address=:9115 --log.level=info --config.file=conf/blackbox.yml
├─19440 /bin/bash /tidb-deploy/monitor-9100/scripts/run_blackbox_exporter.sh
└─19441 tee -i -a /tidb-deploy/monitor-9100/log/blackbox_exporter.logFeb 21 16:20:17 tidb31 systemd[1]: Started blackbox_exporter service.
Feb 21 16:20:17 tidb31 bash[19441]: ts=2025-02-21T08:20:17.285Z caller=main.go:78 level=info msg=“Starting blackbox_exporter” version=“(version=0.23.0, branch=HEAD, revisio>
Feb 21 16:20:17 tidb31 bash[19441]: ts=2025-02-21T08:20:17.285Z caller=main.go:79 level=info build_context=”(go=go1.19.3, user=root@f360719453e3, date=20221202-12:26:32)"
Feb 21 16:20:17 tidb31 bash[19441]: ts=2025-02-21T08:20:17.286Z caller=main.go:91 level=info msg=“Loaded config file”
Feb 21 16:20:17 tidb31 bash[19441]: ts=2025-02-21T08:20:17.287Z caller=tls_config.go:232 level=info msg=“Listening on” address=[::]:9115
Feb 21 16:20:17 tidb31 bash[19441]: ts=2025-02-21T08:20:17.287Z caller=tls_config.go:235 level=info msg=“TLS is disabled.” http2=false address=[::]:9115
【其他附件:截图/日志/监控】
tiup 修改集群参数失败,提示超时;报错类似
$ tiup cluster reload tidb-test
………………………………
- [ Serial ] - UpdateTopology: cluster=tidb-test
{“level”:“warn”,“ts”:“2025-02-18T16:00:55.818+0800”,“logger”:“etcd-client”,“caller”:“v3@v3.5.7/retry_interceptor.go:62”,“msg”:“retrying of unary invoker failed”,“target”:“etcd-endpoints://0xc000410540/192.168.169.31:2379”,“attempt”:0,“error”:“rpc error: code = DeadlineExceeded desc = latest balancer error: last connection error: connection error: desc = "error reading server preface: http2: frame too large"”}
Error: context deadline exceeded
Verbose debug logs has been written to /home/tidb/.tiup/logs/tiup-cluster-debug-2025-02-18-16-00-55.log.
dumpling 导出报错
[tidb@tidb30 tidb-community-toolkit-v6.1.5-linux-amd64]$ dumpling -h192.168.169.31 -P4000 -uroot -ptidb --filetype sql -t 8 -o /tmp/dept -r 2000 -F 256MiB -T emp.dep
Release version: v6.1.5
Git commit hash: 73d82e330b02a39f74073d98daefbadd7deab9b9
Git branch: heads/refs/tags/v6.1.5
Build timestamp: 2023-02-22 06:14:32Z
Go version: go version go1.19.5 linux/amd64
[2025/02/21 10:52:39.032 +08:00] [INFO] [versions.go:55] [“Welcome to dumpling”] [“Release Version”=v6.1.5] [“Git Commit Hash”=73d82e330b02a39f74073d98daefbadd7deab9b9] [“Git Branch”=heads/refs/tags/v6.1.5] [“Build timestamp”=“2023-02-22 06:14:32”] [“Go Version”=“go version go1.19.5 linux/amd64”]
[2025/02/21 10:52:39.037 +08:00] [INFO] [version.go:362] [“detect server version”] [type=TiDB] [version=6.1.5]
{“level”:“warn”,“ts”:“2025-02-21T10:52:49.053+0800”,“logger”:“etcd-client”,“caller”:“v3@v3.5.2/retry_interceptor.go:62”,“msg”:“retrying of unary invoker failed”,“target”:“etcd-endpoints://0xc0009661c0/192.168.169.33:2379”,“attempt”:0,“error”:“rpc error: code = DeadlineExceeded desc = latest balancer error: last connection error: connection closed before server preface received”}
[2025/02/21 10:52:49.053 +08:00] [INFO] [dump.go:1370] [“meet error while check whether fetched pd addr and TiDB belong to one cluster. This won’t affect dump process”] [error=“context deadline exceeded”] [pdAddrs=“[192.168.169.33:2379,192.168.169.32:2379,192.168.169.31:2379]”]
[2025/02/21 10:52:49.055 +08:00] [WARN] [dump.go:1424] [“If the amount of data to dump is large, criteria: (data more than 60GB or dumped time more than 10 minutes)\nyou’d better adjust the tikv_gc_life_time to avoid export failure due to TiDB GC during the dump process.\nBefore dumping: run sql
update mysql.tidb set VARIABLE_VALUE = '720h' where VARIABLE_NAME = 'tikv_gc_life_time';
in tidb.\nAfter dumping: run sqlupdate mysql.tidb set VARIABLE_VALUE = '10m' where VARIABLE_NAME = 'tikv_gc_life_time';
in tidb.\n”][2025/02/21 10:52:49.073 +08:00] [INFO] [dump.go:117] [“begin to run Dump”] [conf=“{"s3":{"endpoint":"","region":"","storage-class":"","sse":"","sse-kms-key-id":"","acl":"","access-key":"","secret-access-key":"","provider":"","force-path-style":true,"use-accelerate-endpoint":false},"gcs":{"endpoint":"","storage-class":"","predefined-acl":"","credentials-file":""},"azblob":{"endpoint":"","account-name":"","account-key":"","access-tier":""},"AllowCleartextPasswords":false,"SortByPk":true,"NoViews":true,"NoSequences":true,"NoHeader":false,"NoSchemas":false,"NoData":false,"CompleteInsert":false,"TransactionalConsistency":true,"EscapeBackslash":true,"DumpEmptyDatabase":true,"PosAfterConnect":false,"CompressType":0,"Host":"192.168.169.31","Port":4000,"Threads":8,"User":"root","Security":{"CAPath":"","CertPath":"","KeyPath":""},"LogLevel":"info","LogFile":"","LogFormat":"text","OutputDirPath":"/tmp/dept","StatusAddr":":8281","Snapshot":"456158444007718913","Consistency":"snapshot","CsvNullValue":"\\N","SQL":"","CsvSeparator":",","CsvDelimiter":"\"","Databases":,"Where":"","FileType":"sql","ServerInfo":{"ServerType":3,"ServerVersion":"6.1.5","HasTiKV":true},"Rows":2000,"ReadTimeout":900000000000,"TiDBMemQuotaQuery":0,"FileSize":268435456,"StatementSize":1000000,"SessionParams":{"tidb_snapshot":"456158444007718913"},"Tables":{"emp":[{"Name":"dep","AvgRowLength":0,"Type":0}]},"CollationCompatible":"loose"}”]
[2025/02/21 10:52:49.166 +08:00] [INFO] [writer.go:255] [“no data written in table chunk”] [database=emp] [table=dep] [chunkIdx=0]
[2025/02/21 10:52:49.167 +08:00] [INFO] [collector.go:239] [“backup success summary”] [total-ranges=4] [ranges-succeed=4] [ranges-failed=0] [total-take=22.106216ms] [total-kv-size=270B] [average-speed=12.21kB/s] [total-rows=9]
[2025/02/21 10:52:49.168 +08:00] [INFO] [main.go:80] [“dump data successfully, dumpling will exit now”]