5.2.2升级5.3.0 tidb启动失败

[YangZhuo970325]

tidb5.2.2升级5.3.0

重启时tidb server启动无法成功，截图如下：

[YangZhuo970325]

a645cc3ead96a44d67b1ecd5034d112cf0", “func”: “github.com/pingcap/tiup/pkg/cluster/executor.(*CheckPointExecutor).Execute”, “hit”: false}
2021-12-03T13:48:30.499+0800 DEBUG retry error: operation timed out after 2m0s
2021-12-03T13:48:30.499+0800 DEBUG TaskFinish {“task”: “StartCluster”, “error”: “failed to start tidb: failed to start: tidb01 tidb-4000.service, please check the instance’s log(/tidb/TEST/deploy/tidb01/log) for more detail.: timed out waiting for port 4000 to be started after 2m0s”, “errorVerbose”: “timed out waiting for port 4000 to be started after 2m0s\ngithub.com/pingcap/tiup/pkg/cluster/module.(*WaitFor).Execute\ \tgithub.com/pingcap/tiup/pkg/cluster/module/wait_for.go:91\ github.com/pingcap/tiup/pkg/cluster/spec.PortStarted\ \tgithub.com/pingcap/tiup/pkg/cluster/spec/instance.go:115\ github.com/pingcap/tiup/pkg/cluster/spec.(*BaseInstance).Ready\ \tgithub.com/pingcap/tiup/pkg/cluster/spec/instance.go:147\ github.com/pingcap/tiup/pkg/cluster/operation.startInstance\ \tgithub.com/pingcap/tiup/pkg/cluster/operation/action.go:359\ github.com/pingcap/tiup/pkg/cluster/operation.StartComponent.func1\ \tgithub.com/pingcap/tiup/pkg/cluster/operation/action.go:485\ golang.org/x/sync/errgroup.(*Group).Go.func1\ \tgolang.org/x/sync@v0.0.0-20210220032951-036812b2e83c/errgroup/errgroup.go:57\ runtime.goexit\ \truntime/asm_amd64.s:1581\ failed to start: tidb01 tidb-4000.service, please check the instance’s log(/tidb/TEST/deploy/tidb01/log) for more detail.\ failed to start tidb”}
2021-12-03T13:48:30.499+0800 INFO Execute command finished {“code”: 1, “error”: “failed to start tidb: failed to start: tidb01 tidb-4000.service, please check the instance’s log(/tidb/TEST/deploy/tidb01/log) for more detail.: timed out waiting for port 4000 to be started after 2m0s”, “errorVerbose”: “timed out waiting for port 4000 to be started after 2m0s\ngithub.com/pingcap/tiup/pkg/cluster/module.(*WaitFor).Execute\ \tgithub.com/pingcap/tiup/pkg/cluster/module/wait_for.go:91\ github.com/pingcap/tiup/pkg/cluster/spec.PortStarted\ \tgithub.com/pingcap/tiup/pkg/cluster/spec/instance.go:115\ github.com/pingcap/tiup/pkg/cluster/spec.(*BaseInstance).Ready\ \tgithub.com/pingcap/tiup/pkg/cluster/spec/instance.go:147\ github.com/pingcap/tiup/pkg/cluster/operation.startInstance\ \tgithub.com/pingcap/tiup/pkg/cluster/operation/action.go:359\ github.com/pingcap/tiup/pkg/cluster/operation.StartComponent.func1\ \tgithub.com/pingcap/tiup/pkg/cluster/operation/action.go:485\ golang.org/x/sync/errgroup.(*Group).Go.func1\ \tgolang.org/x/sync@v0.0.0-20210220032951-036812b2e83c/errgroup/errgroup.go:57\ runtime.goexit\ \truntime/asm_amd64.s:1581\ failed to start: tidb01 tidb-4000.service, please check the instance’s log(/tidb/TEST/deploy/tidb01/log) for more detail.\ failed to start tidb”}

[YangZhuo970325]

通过进程可以看到tidb-server是在运行的，但是一直在刷日志

[root@honetidb01 log]# ps -ef |grep tidb-server
tidb 233999 1 99 14:53 ? 07:12:05 bin/tidb-server -P 4000 --status=10080 --host=0.0.0.0 --advertise-address=tidb01 --store=tikv --path=tidb01:2379,tidb02:2379,tidb03:2379 --log-slow-query=/tidb/TEST/deploy/tidb01/log/tidb_slow_query.log --config=conf/tidb.toml --log-file=/tidb/TEST/deploy/tidb01/log/tidb.log
tidb 234032 1 1 14:53 ? 00:00:21 bin/tidb-server -P 4001 --status=10081 --host=0.0.0.0 --advertise-address=tidb01 --store=tikv --path=tidb01:2379,tidb02:2379,tidb03:2379 --log-slow-query=/tidb/TEST/deploy/tidb02/log/tidb_slow_query.log --config=conf/tidb.toml --log-file=/tidb/TEST/deploy/tidb02/log/tidb.log

tidb-server 日志如下：
[2021/12/03 15:26:53.896 +08:00] [INFO] [2pc.go:469] ["[BIG_TXN]"] [session=0] [“key sample”=7480000000000015045f69800000000000000e03800000000000000001304c000000000000f90380000000000003e8013130303230313031ff0000000000000000f70380000000000007e603800000000000000203c800000032ebbd42] [size=1157120] [keys=20480] [puts=10240] [dels=0] [locks=10240] [checks=0] [txnStartTS=429527246469595137]
[2021/12/03 15:26:54.652 +08:00] [INFO] [2pc.go:469] ["[BIG_TXN]"] [session=0] [“key sample”=7480000000000015045f69800000000000000e03800000000000000001304c000000000000f90380000000000003e8013130303230313031ff0000000000000000f70380000000000007e603800000000000000203c800000033a295a3] [size=1003553] [keys=17762] [puts=8881] [dels=0] [locks=8881] [checks=0] [txnStartTS=429527246626881540]
[2021/12/03 15:26:54.739 +08:00] [INFO] [backfilling.go:281] ["[ddl] backfill worker finish task"] [workerID=12] [task=“physicalTableID_5380_[5188146771596434004,5188146771597120594]”] [addedCount=70321] [scanCount=70321] [nextHandle=5188146771597120594.next] [takeTime=11.076917299s]
[2021/12/03 15:26:54.840 +08:00] [INFO] [2pc.go:469] ["[BIG_TXN]"] [session=0] [“key sample”=7480000000000015045f69800000000000000e03800000000000000001304c000000000000f90380000000000003e8013130303230313031ff0000000000000000f70380000000000007e603800000000000000203c80000003378e6e8] [size=1157120] [keys=20480] [puts=10240] [dels=0] [locks=10240] [checks=0] [txnStartTS=429527246626881537]
[2021/12/03 15:26:54.906 +08:00] [INFO] [2pc.go:469] ["[BIG_TXN]"] [session=0] [“key sample”=7480000000000015045f69800000000000000e03800000000000000001304c000000000000f90380000000000003e8013130303230313031ff0000000000000000f70380000000000007e603800000000000000203c800000032ebf452] [size=629975] [keys=11150] [puts=5575] [dels=0] [locks=5575] [checks=0] [txnStartTS=429527246823489539]
[2021/12/03 15:26:54.968 +08:00] [INFO] [backfilling.go:281] ["[ddl] backfill worker finish task"] [workerID=5] [task=“physicalTableID_5380_[5188146771582719134,5188146771585153316]”] [addedCount=77255] [scanCount=77255] [nextHandle=5188146771585153316.next] [takeTime=11.305237984s]

[Cong-PingCAP]

请问升级过程中，有同时执行的 DDL 操作么？

[YangZhuo970325]

是之前执行的ddl，升级的时候可能还没有执行完，后来等了一个小时左右，自动恢复了，是因为升级的时候不可以执行ddl么

[Johnny]

升级兼容性说明

在升级的过程中不要执行 DDL 请求，否则可能会出现行为未定义的问题。