TiDB v4.0.5 where 语句失效

🪐 TiDB 技术问题 部署&运维管理
1

为提高效率，提问时请提供以下信息，问题描述清晰可优先响应。

  • 【TiDB 版本】：tidb v4.0.5
  • 【问题描述】：所有字符串的 where 条件失效。如图
    image
    image1017×560 131 KB

已经确定输入无误，确定字符串两边没有空格，是 where 条件是复制粘贴过去

表结构：
CREATE TABLE org_group (
group_identityID int(11) NOT NULL AUTO_INCREMENT,
group_code varchar(500) COLLATE utf8_general_ci DEFAULT NULL,
group_createTime datetime NOT NULL,
group_creatorId varchar(50) COLLATE utf8_general_ci DEFAULT NULL,
group_id varchar(50) COLLATE utf8_general_ci NOT NULL,
group_name varchar(500) COLLATE utf8_general_ci DEFAULT NULL,
group_remark varchar(500) COLLATE utf8_general_ci DEFAULT NULL,
group_sort int(11) DEFAULT NULL,
group_thirdPartId varchar(500) COLLATE utf8_general_ci DEFAULT NULL,
group_type int(11) DEFAULT NULL,
PRIMARY KEY (group_identityID),
UNIQUE KEY group_id (group_id),
UNIQUE KEY group_code (group_code)
) ENGINE=InnoDB DEFAULT CHARSET=utf8 COLLATE=utf8_general_ci AUTO_INCREMENT=30013

若提问为性能优化、故障排查类问题，请下载脚本运行。终端输出的打印结果，请务必全选并复制粘贴上传。

2

这个问题我们做了很多次试验，重新导数据或者手动同样结构的库和表，无法复现这个问题。所以感到很奇怪。

3

image
image1086×550 129 KB

4
  1. 请问当前集群有几个 tidb-server ？ 每个 tidb 实例上都是相同问题吗？
  2. explain analyze sql 反馈下查询 security 的执行计划，是否是走的 group_code 的索引
  3. 执行查询后，麻烦查看tidb.log 日志是否有报错或者告警信息，多谢。
5

  1. 有三台 tidb-server
    其他的也是一样

    image
    image809×381 104 KB

  2. explain analyze 结果

    image
    image1430×320 110 KB

  3. tidb日志如下

[tidb@gzly1733 log]$ tail -f tidb_stderr.log



^C
[tidb@gzly1733 log]$ tail -f tidb.log
[2020/09/23 17:06:51.431 +08:00] [INFO] [client_batch.go:640] ["recycle idle connection"] [target=10.56.112.69:20161]
[2020/09/23 17:06:51.431 +08:00] [INFO] [client_batch.go:640] ["recycle idle connection"] [target=10.56.112.67:20160]
[2020/09/23 17:11:01.957 +08:00] [INFO] [server.go:391] ["connection closed"] [conn=5466]
[2020/09/23 17:11:39.490 +08:00] [INFO] [adapter.go:596] ["pessimistic write conflict, retry statement"] [txn=419653832114438149] [forUpdateTS=419653832114438149] [err="[kv:9007]Write conflict, txnStartTS=419653832114438149, conflictStartTS=419653832114438147, conflictCommitTS=419653832127545355, key={tableID=21, indexID=2, indexValues={17, }} primary={tableID=21, indexID=2, indexValues={17, }} [try again later]"]
[2020/09/23 17:13:39.490 +08:00] [INFO] [adapter.go:596] ["pessimistic write conflict, retry statement"] [txn=419653863571718149] [forUpdateTS=419653863571718149] [err="[kv:9007]Write conflict, txnStartTS=419653863571718149, conflictStartTS=419653863571718147, conflictCommitTS=419653863584825355, key={tableID=21, indexID=2, indexValues={17, }} primary={tableID=21, indexID=2, indexValues={17, }} [try again later]"]
[2020/09/23 17:14:39.489 +08:00] [INFO] [adapter.go:596] ["pessimistic write conflict, retry statement"] [txn=419653879300358149] [forUpdateTS=419653879300358149] [err="[kv:9007]Write conflict, txnStartTS=419653879300358149, conflictStartTS=419653879300358147, conflictCommitTS=419653879313465355, key={tableID=21, indexID=2, indexValues={17, }} primary={tableID=21, indexID=2, indexValues={17, }} [try again later]"]
[2020/09/23 17:16:51.431 +08:00] [INFO] [client_batch.go:640] ["recycle idle connection"] [target=10.56.112.67:20160]
[2020/09/23 17:16:51.431 +08:00] [INFO] [client_batch.go:640] ["recycle idle connection"] [target=10.56.112.69:20161]
[2020/09/23 17:17:39.488 +08:00] [INFO] [adapter.go:596] ["pessimistic write conflict, retry statement"] [txn=419653926486278150] [forUpdateTS=419653926486278150] [err="[kv:9007]Write conflict, txnStartTS=419653926486278150, conflictStartTS=419653926486278148, conflictCommitTS=419653926499385355, key={tableID=21, indexID=2, indexValues={17, }} primary={tableID=21, indexID=2, indexValues={17, }} [try again later]"]
[2020/09/23 17:18:39.492 +08:00] [INFO] [adapter.go:596] ["pessimistic write conflict, retry statement"] [txn=419653942214918150] [forUpdateTS=419653942214918150] [err="[kv:9007]Write conflict, txnStartTS=419653942214918150, conflictStartTS=419653942214918147, conflictCommitTS=419653942228025356, key={tableID=21, indexID=2, indexValues={17, }} primary={tableID=21, indexID=2, indexValues={17, }} [try again later]"]

执行 查询 sql 后的日志

MySQL [(none)]>  select * from edoc2v5.org_group where group_code = 'InbizAdmin';
Empty set (0.00 sec)

MySQL [(none)]> Bye
[root@gzly1733 edoc2v5]# tail -f /data01/tidb-deploy/tidb-4000/log/tidb.log
[2020/09/23 17:14:39.489 +08:00] [INFO] [adapter.go:596] ["pessimistic write conflict, retry statement"] [txn=419653879300358149] [forUpdateTS=419653879300358149] [err="[kv:9007]Write conflict, txnStartTS=419653879300358149, conflictStartTS=419653879300358147, conflictCommitTS=419653879313465355, key={tableID=21, indexID=2, indexValues={17, }} primary={tableID=21, indexID=2, indexValues={17, }} [try again later]"]
[2020/09/23 17:16:51.431 +08:00] [INFO] [client_batch.go:640] ["recycle idle connection"] [target=10.56.112.67:20160]
[2020/09/23 17:16:51.431 +08:00] [INFO] [client_batch.go:640] ["recycle idle connection"] [target=10.56.112.69:20161]
[2020/09/23 17:17:39.488 +08:00] [INFO] [adapter.go:596] ["pessimistic write conflict, retry statement"] [txn=419653926486278150] [forUpdateTS=419653926486278150] [err="[kv:9007]Write conflict, txnStartTS=419653926486278150, conflictStartTS=419653926486278148, conflictCommitTS=419653926499385355, key={tableID=21, indexID=2, indexValues={17, }} primary={tableID=21, indexID=2, indexValues={17, }} [try again later]"]
[2020/09/23 17:18:39.492 +08:00] [INFO] [adapter.go:596] ["pessimistic write conflict, retry statement"] [txn=419653942214918150] [forUpdateTS=419653942214918150] [err="[kv:9007]Write conflict, txnStartTS=419653942214918150, conflictStartTS=419653942214918147, conflictCommitTS=419653942228025356, key={tableID=21, indexID=2, indexValues={17, }} primary={tableID=21, indexID=2, indexValues={17, }} [try again later]"]
[2020/09/23 17:21:23.460 +08:00] [INFO] [server.go:388] ["new connection"] [conn=5467] [remoteAddr=127.0.0.1:28202]
[2020/09/23 17:22:03.464 +08:00] [INFO] [server.go:391] ["connection closed"] [conn=5467]
[2020/09/23 17:22:39.488 +08:00] [INFO] [adapter.go:596] ["pessimistic write conflict, retry statement"] [txn=419654005129478150] [forUpdateTS=419654005129478150] [err="[kv:9007]Write conflict, txnStartTS=419654005129478150, conflictStartTS=419654005129478147, conflictCommitTS=419654005142585355, key={tableID=21, indexID=2, indexValues={17, }} primary={tableID=21, indexID=2, indexValues={17, }} [try again later]"]
[2020/09/23 17:23:19.027 +08:00] [INFO] [server.go:388] ["new connection"] [conn=5468] [remoteAddr=127.0.0.1:28576]
[2020/09/23 17:23:21.588 +08:00] [INFO] [server.go:391] ["connection closed"] [conn=5468]
6
  1. 请问有升级过吗？
  2. 当前集群业务压力大吗？在业务低峰期， 可以尝试使用 admin check table <TableName> 检查下，多谢。
7

这个集群是新建的集群，数据是从 tidb v3.0.7 用 mydumper 备份， tidb-lightning 的 local 模式恢复过来，恢复过来后我们校验过表数量、表行数和表的索引 是和恢复之前的一致。

现在集群没有接入业务。admin check table 和 analyze table 之后也没有变化

image
image780×390 105 KB

8

其他的表也有类似情况，不是这一个表

image
image1031×589 209 KB

9

请问新建集群时，是否有打开 new collation？

可以通过 SELECT * FROM mysql.tidb 确认一下

10

有打开

image

image
image983×435 100 KB

select * from tidb

+--------------------------+---------------------------------------------------------------------------------------------+---------------------------------------------------------------------------------------------+
| VARIABLE_NAME            | VARIABLE_VALUE                                                                              | COMMENT                            |
+--------------------------+---------------------------------------------------------------------------------------------+---------------------------------------------------------------------------------------------+
| bootstrapped             | True                                                                                        | Bootstrap flag. Do not delete.                            |
| tidb_server_version      | 47                                                                                          | Bootstrap version. Do not delete.                            |
| system_tz                | Asia/Shanghai                                                                               | TiDB Global System Timezone.                            |
| new_collation_enabled    | True                                                                                        | If the new collations are enabled. Do not edit it.                            |
| tikv_gc_leader_uuid      | 5d26c113dd40010                                                                             | Current GC worker leader UUID. (DO NOT EDIT)                            |
| tikv_gc_leader_desc      | host:gzly1751, pid:169831, start at 2020-09-17 15:43:05.112405595 +0800 CST m=+12.761786090 | Host name and pid of current GC leader. (DO NOT EDIT)                            |
| tikv_gc_leader_lease     | 20200923-18:03:05 +0800                                                                     | Current GC worker leader lease. (DO NOT EDIT)                            |
| tikv_gc_enable           | true                                                                                        | Current GC enable status                            |
| tikv_gc_run_interval     | 10m0s                                                                                       | GC run interval, at least 10m, in Go format.                            |
| tikv_gc_life_time        | 24h                                                                                         | All versions within life time will not be collected by GC, at least 10m, in Go format.      |
| tikv_gc_last_run_time    | 20200923-17:59:05 +0800                                                                     | The time when last GC starts. (DO NOT EDIT)                            |
| tikv_gc_safe_point       | 20200922-17:59:05 +0800                                                                     | All versions after safe point can be accessed. (DO NOT EDIT)                            |
| tikv_gc_auto_concurrency | true                                                                                        | Let TiDB pick the concurrency automatically. If set false, tikv_gc_concurrency will be used |
| tikv_gc_mode             | distributed                                                                                 | Mode of GC, "central" or "distributed"                            |
+--------------------------+---------------------------------------------------------------------------------------------+---------------------------------------------------------------------------------------------+
14 rows in set (0.00 sec)\0
11

OK，那原因应该是这样的：

在打开 new collation 之后，TiDB 的索引编码产生了变化。因此无法与之前进行兼容，这也是为什么只有新集群才能打开这个开关。

然而在使用 Lightning Local 模式导入数据时，数据是直接按照旧编码写入 TiKV 的。这导致打开了 new collation 的新 TiDB 集群在对索引解码时，无法正常解出预期的结果。

很抱歉这一点造成了不便。如果确实需要 new collation，请问是否可以使用 Lightning 的 TiDB 模式重新导入数据？

12

好的。那我们今晚再恢复测试一下。对了，我们在恢复之前修改过 schema.sql 文件的 字符集和排序规则，是否和这个有关。

sed -i "s/DEFAULT CHARSET=utf8/DEFAULT CHARSET=utf8 COLLATE=utf8_general_ci/g" *schema.sql
13

嗯会有影响，打开 new collation 开关后，general_ci 的编解码方式有变化。

14

您好~
tidb-backend 恢复速度太慢了，如果用 import-backend 恢复方式是否可以避免这个问题?

15

您好，import-backend 也不行，因为原理与 local 是一样的。由于涉及编码问题，目前还只能用 local 模式。

请问您这边预估还需要导入多久？

16

我们200多G的备份sql 文件，单个sql 是 256M ， local 恢复大概1个半小时， 现在使用 tidb-backend 用了14个多小时

17

因为我们计划升级停机2 个小时。 local 恢复是 可以的。 tidb-backend 恢复时间比较久的话，就要考虑看其他方案了

18

目前我们正在着手 fix 这个问题，代码已完成，我在本地测试应该是 ok 的。如果方便的话，你可以在本地编译一个binary 替换掉 tidb-lightning 应该就可以正常导入了。具体可以执行如下操作：

git clone https://github.com/pingcap/tidb-lightning.git
cd tidb-lightning
git checkout new-collation
make lightning
cp bin/tidb-lightning your-tidb-lightning-path  // 替换当前使用的 tidb-lightning

然后重新使用 local 模式导入应该就 ok 了。
导入的时候，可以先测试一下导入一个文件，如果结果正常的话，那应该就是 ok 的了

如果在你的环境不方便编译的话，我们也可以提供一个编译好的 binary 的文件供下载替换

19

由于是在客户环境操作。麻烦提供一个编译好的 binary 文件吧。非常感谢~:heart:

20
  1. 从报错看，go 版本需要 1.13 以上
  2. 正式版本大概会在 4.0.8 测试，由于我们需要经过测试才会正式提供给客户。所以麻烦您这边可以自己编辑测试一下，最好确认没问题再使用，或者等到正式发布后再使用，带来的问题非常抱歉， 多谢。