重启tidb-server报错 Unknown system variable '%-.64s'"

🪐 TiDB 技术问题
1

v4.0.2 重启时时，所有 tidb-server 报错：
重启命命令：试过在tidb-server用systemctl重启，也用中控机执行，也reload过conf，都仍然报错

现在集群无法使用 请问怎么处理？
错误信息：
tidb-server日志：
[2020/09/18 10:15:05.924 +08:00] [FATAL] [terror.go:348] [“unexpected error”] [error=“[variable:1193]Unknown system variable ‘%-.64s’”] [stack=“github.com/pingcap/log.Fatal
\t/home/jenkins/agent/workspace/tidb_v4.0.2/go/pkg/mod/github.com/pingcap/log@v0.0.0-20200511115504-543df19646ad/global.go:59
github.com/pingcap/parser/terror.MustNil
\t/home/jenkins/agent/workspace/tidb_v4.0.2/go/pkg/mod/github.com/pingcap/parser@v0.0.0-20200623164729-3a18f1e5dceb/terror/terror.go:348
main.createStoreAndDomain
\t/home/jenkins/agent/workspace/tidb_v4.0.2/go/src/github.com/pingcap/tidb/tidb-server/main.go:296
main.main
\t/home/jenkins/agent/workspace/tidb_v4.0.2/go/src/github.com/pingcap/tidb/tidb-server/main.go:181
runtime.main
\t/usr/local/go/src/runtime/proc.go:203”]
[2020/09/18 10:15:21.211 +08:00] [INFO] [printer.go:42] [“Welcome to TiDB.”] [“Release Version”=v4.0.2] [Edition=Community] [“Git Commit Hash”=328b6d0a955c4668cf3188d02a6df42e16eaab4e] [“Git Branch”=heads/refs/tags/v4.0.2] [“UTC Build Time”=“2020-07-01 08:19:48”] [GoVersion=go1.13] [“Race Enabled”=false] [“Check Table Before Drop”=false] [“TiKV Min Version”=v3.0.0-60965b006877ca7234adaced7890d7b029ed1306]
[2020/09/18 10:15:21.211 +08:00] [INFO] [printer.go:56] [“loaded config”] [config=“{"host":"0.0.0.0","advertise-address":"10.10.104.116","port":4000,"cors":"","store":"tikv","path":"10.10.104.119:2379,10.10.104.120:2379,10.10.104.118:2379","socket":"","lease":"45s","run-ddl":true,"split-table":true,"token-limit":1000,"oom-use-tmp-storage":true,"tmp-storage-path":"/tmp/1001_tidb/MC4wLjAuMDo0MDAwLzAuMC4wLjA6MTAwODA=/tmp-storage","oom-action":"log","mem-quota-query":1073741824,"tmp-storage-quota":-1,"enable-streaming":false,"enable-batch-dml":false,"lower-case-table-names":2,"server-version":"","log":{"level":"info","format":"text","disable-timestamp":false,"enable-timestamp":null,"disable-error-stack":null,"enable-error-stack":null,"file":{"filename":"/data/tidb/deploy/log/tidb.log","max-size":300,"max-days":0,"max-backups":0},"enable-slow-log":true,"slow-query-file":"log/tidb_slow_query.log","slow-threshold":300,"expensive-threshold":10000,"query-log-max-len":2048,"record-plan-in-slow-log":1},"security":{"skip-grant-table":false,"ssl-ca":"","ssl-cert":"","ssl-key":"","require-secure-transport":false,"cluster-ssl-ca":"","cluster-ssl-cert":"","cluster-ssl-key":"","cluster-verify-cn":null},"status":{"status-host":"0.0.0.0","metrics-addr":"","status-port":10080,"metrics-interval":15,"report-status":true,"record-db-qps":false},"performance":{"max-procs":0,"max-memory":0,"stats-lease":"3s","stmt-count-limit":5000,"feedback-probability":0.05,"query-feedback-limit":1024,"pseudo-estimate-ratio":0.8,"force-priority":"NO_PRIORITY","bind-info-lease":"3s","txn-total-size-limit":104857600,"tcp-keep-alive":true,"cross-join":true,"run-auto-analyze":true,"agg-push-down-join":false,"committer-concurrency":16,"max-txn-ttl":600000},"prepared-plan-cache":{"enabled":false,"capacity":100,"memory-guard-ratio":0.1},"opentracing":{"enable":false,"rpc-metrics":false,"sampler":{"type":"const","param":1,"sampling-server-url":"","max-operations":0,"sampling-refresh-interval":0},"reporter":{"queue-size":0,"buffer-flush-interval":0,"log-spans":false,"local-agent-host-port":""}},"proxy-protocol":{"networks":"","header-timeout":5},"tikv-client":{"grpc-connection-count":16,"grpc-keepalive-time":10,"grpc-keepalive-timeout":3,"commit-timeout":"41s","max-batch-size":128,"overload-threshold":200,"max-batch-wait-time":0,"batch-wait-size":8,"enable-chunk-rpc":true,"region-cache-ttl":600,"store-limit":0,"store-liveness-timeout":"5s","copr-cache":{"enable":false,"capacity-mb":1000,"admission-max-result-mb":10,"admission-min-process-ms":5}},"binlog":{"enable":true,"ignore-error":true,"write-timeout":"15s","binlog-socket":"","strategy":"range"},"compatible-kill-query":false,"plugin":{"dir":"","load":""},"pessimistic-txn":{"enable":true,"max-retry-count":256},"check-mb4-value-in-utf8":true,"max-index-length":3072,"alter-primary-key":false,"treat-old-version-utf8-as-utf8mb4":true,"enable-table-lock":false,"delay-clean-table-lock":0,"split-region-max-num":1000,"stmt-summary":{"enable":true,"enable-internal-query":false,"max-stmt-count":200,"max-sql-length":4096,"refresh-interval":1800,"history-size":24},"repair-mode":false,"repair-table-list":[],"isolation-read":{"engines":["tikv","tiflash","tidb"]},"max-server-connections":0,"new_collations_enabled_on_first_bootstrap":false,"experimental":{"allow-auto-random":false,"allow-expression-index":false},"enable-collect-execution-info":false,"enable-telemetry":true}”]
[2020/09/18 10:15:21.211 +08:00] [INFO] [client.go:149] [“[pd] create pd client with endpoints”] [pd-address=“[10.10.104.119:2379,10.10.104.120:2379,10.10.104.118:2379]”]
[2020/09/18 10:15:21.215 +08:00] [INFO] [base_client.go:226] [“[pd] update member urls”] [old-urls=“[http://10.10.104.119:2379,http://10.10.104.120:2379,http://10.10.104.118:2379]”] [new-urls=“[http://10.10.104.118:2379,http://10.10.104.119:2379,http://10.10.104.120:2379]”]
[2020/09/18 10:15:21.215 +08:00] [INFO] [base_client.go:242] [“[pd] switch leader”] [new-leader=http://10.10.104.119:2379] [old-leader=]
[2020/09/18 10:15:21.215 +08:00] [INFO] [base_client.go:92] [“[pd] init cluster id”] [cluster-id=6844010657831606600]
[2020/09/18 10:15:21.218 +08:00] [INFO] [main.go:332] [tidb-server] [“create pumps client success, ignore binlog error”=true]
[2020/09/18 10:15:21.218 +08:00] [INFO] [main.go:341] [“disable Prometheus push client”]
[2020/09/18 10:15:21.218 +08:00] [INFO] [store.go:68] [“new store”] [path=tikv://10.10.104.119:2379,10.10.104.120:2379,10.10.104.118:2379]
[2020/09/18 10:15:21.218 +08:00] [INFO] [systime_mon.go:25] [“start system time monitor”]
[2020/09/18 10:15:21.218 +08:00] [INFO] [client.go:149] [“[pd] create pd client with endpoints”] [pd-address=“[10.10.104.119:2379,10.10.104.120:2379,10.10.104.118:2379]”]
[2020/09/18 10:15:21.222 +08:00] [INFO] [base_client.go:226] [“[pd] update member urls”] [old-urls=“[http://10.10.104.119:2379,http://10.10.104.120:2379,http://10.10.104.118:2379]”] [new-urls=“[http://10.10.104.118:2379,http://10.10.104.119:2379,http://10.10.104.120:2379]”]
[2020/09/18 10:15:21.222 +08:00] [INFO] [base_client.go:242] [“[pd] switch leader”] [new-leader=http://10.10.104.119:2379] [old-leader=]
[2020/09/18 10:15:21.222 +08:00] [INFO] [base_client.go:92] [“[pd] init cluster id”] [cluster-id=6844010657831606600]
[2020/09/18 10:15:21.222 +08:00] [INFO] [store.go:74] [“new store with retry success”]
[2020/09/18 10:15:21.229 +08:00] [INFO] [tidb.go:71] [“new domain”] [store=tikv-6844010657831606600] [“ddl lease”=45s] [“stats lease”=3s]
[2020/09/18 10:15:21.234 +08:00] [INFO] [ddl.go:316] [“[ddl] start DDL”] [ID=f69bb3db-7484-44c7-b641-82a581b410eb] [runWorker=true]
[2020/09/18 10:15:21.234 +08:00] [INFO] [manager.go:185] [“start campaign owner”] [ownerInfo=“[ddl] /tidb/ddl/fg/owner”]
[2020/09/18 10:15:21.237 +08:00] [INFO] [ddl.go:305] [“[ddl] start delRangeManager OK”] [“is a emulator”=false]
[2020/09/18 10:15:21.237 +08:00] [INFO] [ddl_worker.go:130] [“[ddl] start DDL worker”] [worker=“worker 1, tp general”]
[2020/09/18 10:15:21.237 +08:00] [INFO] [ddl_worker.go:130] [“[ddl] start DDL worker”] [worker=“worker 2, tp add index”]
[2020/09/18 10:15:21.429 +08:00] [INFO] [domain.go:145] [“full load InfoSchema success”] [usedSchemaVersion=0] [neededSchemaVersion=5169] [“start time”=171.800865ms]
[2020/09/18 10:15:21.432 +08:00] [INFO] [domain.go:369] [“full load and reset schema validator”]
[2020/09/18 10:15:21.439 +08:00] [FATAL] [terror.go:348] [“unexpected error”] [error=“[variable:1193]Unknown system variable ‘%-.64s’”] [stack=“github.com/pingcap/log.Fatal
\t/home/jenkins/agent/workspace/tidb_v4.0.2/go/pkg/mod/github.com/pingcap/log@v0.0.0-20200511115504-543df19646ad/global.go:59
github.com/pingcap/parser/terror.MustNil
\t/home/jenkins/agent/workspace/tidb_v4.0.2/go/pkg/mod/github.com/pingcap/parser@v0.0.0-20200623164729-3a18f1e5dceb/terror/terror.go:348
main.createStoreAndDomain
\t/home/jenkins/agent/workspace/tidb_v4.0.2/go/src/github.com/pingcap/tidb/tidb-server/main.go:296
main.main
\t/home/jenkins/agent/workspace/tidb_v4.0.2/go/src/github.com/pingcap/tidb/tidb-server/main.go:181
runtime.main
\t/usr/local/go/src/runtime/proc.go:203”]

tiup日志：
image

2

你好，请问一下重启前这边修改过什么参数配置吗？

3

没有修改参数，

我昨天的操作有
1：用 tidb-lightning v4.0.5 导入其他库的数据 10G左右 导入的时间比较长
2：在导入期间， 我用pt-show-grants 从其他tidb集群导出账号， 建在该库上 ，没管导入

今天一看 tidb-lightning 导入出错 ，错误为：
[2020/09/17 18:47:29.767 +08:00] [ERROR] [restore.go:112] [-] [table=METRICS_SCHEMA.tikv_scheduler_is_busy_total_count] [status=altered_auto_inc] [error=“ALTER TABLE METRICS_SCHEMA.tikv_scheduler_is_busy_total_count AUTO_INCREMENT=1: alter table auto_increment failed: Error 1142: ALTER command denied to user ‘root’@’%’ for table ‘tikv_scheduler_is_busy_total_count’”]
[2020/09/17 18:47:29.767 +08:00] [ERROR] [restore.go:112] [-] [table=METRICS_SCHEMA.tikv_cop_total_response_total_size] [status=altered_auto_inc] [error=“ALTER TABLE METRICS_SCHEMA.tikv_cop_total_response_total_size AUTO_INCREMENT=34: alter table auto_increment failed: Error 1142: ALTER command denied to user ‘root’@’%’ for table ‘tikv_cop_total_response_total_size’”]
[2020/09/17 18:47:29.767 +08:00] [ERROR] [restore.go:112] [-] [table=METRICS_SCHEMA.tikv_apply_log_duration] [status=altered_auto_inc] [error=“ALTER TABLE METRICS_SCHEMA.tikv_apply_log_duration AUTO_INCREMENT=34: alter table auto_increment failed: Error 1142: ALTER command denied to user ‘root’@’%’ for table ‘tikv_apply_log_duration’”]
[2020/09/17 18:47:29.767 +08:00] [ERROR] [restore.go:112] [-] [table=METRICS_SCHEMA.etcd_wal_fsync_total_time] [status=altered_auto_inc] [error=“ALTER TABLE METRICS_SCHEMA.etcd_wal_fsync_total_time AUTO_INCREMENT=67: alter table auto_increment failed: Error 1142: ALTER command denied to user ‘root’@’%’ for table ‘etcd_wal_fsync_total_time’”]
[2020/09/17 18:47:29.767 +08:00] [ERROR] [main.go:82] [“tidb lightning encountered error stack info”] [error=“restore table METRICS_SCHEMA.pd_label_distribution failed: ALTER TABLE METRICS_SCHEMA.pd_label_distribution AUTO_INCREMENT=1: alter table auto_increment failed: Error 1142: ALTER command denied to user ‘root’@’%’ for table ‘pd_label_distribution’”] [errorVerbose=“Error 1142: ALTER command denied to user ‘root’@’%’ for table ‘pd_label_distribution’\ngithub.com/pingcap/errors.AddStack\ \t/home/jenkins/agent/workspace/build_lightning_master/go/pkg/mod/github.com/pingcap/errors@v0.11.5-0.20200729012136-4e113ddee29e/errors.go:174\ github.com/pingcap/errors.Trace\ \t/home/jenkins/agent/workspace/build_lightning_master/go/pkg/mod/github.com/pingcap/errors@v0.11.5-0.20200729012136-4e113ddee29e/juju_adaptor.go:15\ github.com/pingcap/tidb-lightning/lightning/common.SQLWithRetry.Exec.func1\ \t/home/jenkins/agent/workspace/build_lightning_master/go/src/github.com/pingcap/tidb-lightning/lightning/common/util.go:182\ github.com/pingcap/tidb-lightning/lightning/common.SQLWithRetry.perform\ \t/home/jenkins/agent/workspace/build_lightning_master/go/src/github.com/pingcap/tidb-lightning/lightning/common/util.go:120\ github.com/pingcap/tidb-lightning/lightning/common.SQLWithRetry.Exec\ \t/home/jenkins/agent/workspace/build_lightning_master/go/src/github.com/pingcap/tidb-lightning/lightning/common/util.go:180\ github.com/pingcap/tidb-lightning/lightning/restore.AlterAutoIncrement\ \t/home/jenkins/agent/workspace/build_lightning_master/go/src/github.com/pingcap/tidb-lightning/lightning/restore/tidb.go:274\ github.com/pingcap/tidb-lightning/lightning/restore.(*TableRestore).postProcess\ \t/home/jenkins/agent/workspace/build_lightning_master/go/src/github.com/pingcap/tidb-lightning/lightning/restore/restore.go:1107\ngithub.com/pingcap/tidb-lightning/lightning/restore.(*TableRestore).restoreTable\ \t/home/jenkins/agent/workspace/build_lightning_master/go/src/github.com/pingcap/tidb-lightning/lightning/restore/restore.go:792\ngithub.com/pingcap/tidb-lightning/lightning/restore.(*RestoreController).restoreTables.func1\ \t/home/jenkins/agent/workspace/build_lightning_master/go/src/github.com/pingcap/tidb-lightning/lightning/restore/restore.go:618\ runtime.goexit\ \t/usr/local/go/src/runtime/asm_amd64.s:1357\ alter table auto_increment failed\ ALTER TABLE METRICS_SCHEMA.pd_label_distribution AUTO_INCREMENT=1\ restore table METRICS_SCHEMA.pd_label_distribution failed”]
[2020/09/17 18:47:29.767 +08:00] [ERROR] [main.go:83] [“tidb lightning encountered error”] [error=“restore table METRICS_SCHEMA.pd_label_distribution failed: ALTER TABLE METRICS_SCHEMA.pd_label_distribution AUTO_INCREMENT=1: alter table auto_increment failed: Error 1142: ALTER command denied to user ‘root’@’%’ for table ‘pd_label_distribution’”]

用客户端远程连接时报错 Unknown system variable ‘%-.64s’"]， 于是重启tidb-server ，也报一样的错

4

您好 请检查下 {tidb_deploy}/conf/tidb.toml 文件，如方便可上传到 asktug ，我们一块分析下。
另外 您 lightning 导入失败应是 您导入了METRICS_SCHEMA tidb 系统数据库所致，请不要还原 tidb 系统数据库

5

tidb 的配置见附件 ， 麻烦帮看看， 三个tidb节点的配置都是通过tiup reload 过来，都一样的 tidb.toml (1.7 KB)

6

您好，由于我们的失误导致，打印的 ERRORLOG 不能准确的反馈 您的异常的根本原因，如果可以我们将提供 hotfix 版本修复 LOG问题，以便查明 导致您 TIDB 不能正常启动的真实原因。

7

好的 ， 那我现在要处理 ？ hotfix 版本 怎么使用

8

工作日我们可以通过其他方式提供给你 hotfix 版本