TiDB 节点 CPU 居高不下

elvizlai · 2020 年7 月 28 日 04:59

附件为 pprofprofiling_pack_1.tar.gz (18.5 KB)

版本 v4.0.3

CPU 飙升时未执行大SQL（半测试集群，本身也没多少数据）

crazycs520-PingCAP · 2020 年7 月 28 日 05:34

@elvizlai，你好，请问是不是有工具一直在查询 INFORMATION_SCHEMA.COLUMNS 系统表？

另外麻烦查下 INFORMATION_SCHEMA.COLUMNS 表中有多少行数据？

crazycs520-PingCAP · 2020 年7 月 28 日 05:45

@elvizlai 麻烦提供下 tidb 系统版本，

select * from information_schema.cluster_info;

elvizlai · 2020 年7 月 28 日 06:23

tidb	$ADDR:4000	$ADDR:10080	5.7.25-TiDB-v4.0.3	0529b1b493e46aae71bbe34cbe24515a2eb1b47c	2020-07-28T13:01:26+08:00	1h16m56.21164225s
tidb	$ADDR:4000	$ADDR:10080	5.7.25-TiDB-v4.0.3	0529b1b493e46aae71bbe34cbe24515a2eb1b47c	2020-07-28T13:01:26+08:00	1h16m56.211646035s
pd	$ADDR:2379	$ADDR:2379	4.0.3	096ab27038530fcf674a9f9d872609ec2656ee73	2020-07-26T08:16:10+08:00	54h2m12.211648727s
pd	$ADDR:2379	$ADDR:2379	4.0.3	096ab27038530fcf674a9f9d872609ec2656ee73	2020-07-26T08:16:12+08:00	54h2m10.211650924s
tikv	$ADDR:20160	$ADDR:20180	4.0.3	57234d853fee89df0bb6474e07c078e0ab77d3a7	2020-07-27T19:29:11+08:00	18h49m11.211653042s
tikv	$ADDR:20160	$ADDR:20180	4.0.3	57234d853fee89df0bb6474e07c078e0ab77d3a7	2020-07-27T19:28:12+08:00	18h50m10.211655118s
tiflash	$ADDR:3930	$ADDR:20292	v4.0.3	bfa9128f59cf800e129152f06b12480ad78adafd	2020-07-26T08:16:05+08:00	54h2m17.211657393s

SELECT COUNT(*) FROM INFORMATION_SCHEMA.COLUMNS;

另外一个值得注意的问题，mysql.db 中 DB 列使用了前缀，比如 dev_% 对应测试环境相关数据授权，暂不确定是否跟这个有关系。（看 pprof 中有 privileges 相关）

另一个可能有用的线索：
查看 TiDB dashboard 的 dashboard/#/statement 页面，会导致 tidb cpu 上涨(且可能不会回落)
回到概况 Top SQL 部分需要很久时间才能加载出来，且加载时 cpu 飙升

crazycs520-PingCAP · 2020 年7 月 28 日 08:08

@elvizlai 麻烦确认下这个：

请问是不是有工具一直在查询 INFORMATION_SCHEMA.COLUMNS 系统表？

另外，现在 TIDB 的 CPU 还高吗？高的话，麻烦抓下这个信息：

 curl "$TIDBADDR/debug/zip?seconds=30" > debug.zip

elvizlai · 2020 年7 月 28 日 10:48

奇怪的结果

[root@tidb02 ~]# curl $TIDBADDR/debug/zip?seconds=30
5.7.25-TiDB-v4.0.3L7T)lKP}��.v+V%+c},h'mysql_native_password�tinvalid sequence 32 != 1[root@tidb02 ~]#
[root@tidb02 ~]#
[root@tidb02 ~]# curl $TIDBADDR/debug/zip?seconds=30
5.7.25-TiDB-v4.0.3O72~r^iI=,��.TOBF/v6jA.fmysql_native_password�tinvalid sequence 32 != 1[root@tidb02 ~]#
[root@tidb02 ~]#
[root@tidb02 ~]# curl $TIDBADDR/debug/zip?seconds=30
5.7.25-TiDB-v4.0.3P7J&dZlA��.qj0Lrs-dsmysql_native_password�tinvalid sequence 32 != 1[root@tidb02 ~]#
[root@tidb02 ~]#
[root@tidb02 ~]#
[root@tidb02 ~]# curl $TIDBADDR/debug/zip?seconds=30
5.7.25-TiDB-v4.0.3S7]xfJmil��..S;yx%snmysql_native_password�tinvalid sequence 32 != 1[root@tidb02 ~]#
[root@tidb02 ~]#
[root@tidb02 ~]#
[root@tidb02 ~]# curl $TIDBADDR/debug/zip?seconds=30
��..25-TiE5+Z?Ax"mysql_native_password�tinvalid sequence 32 != 1[root@tidb02 ~]#
[root@tidb02 ~]#
[root@tidb02 ~]#
[root@tidb02 ~]# curl $TIDBADDR/debug/zip?seconds=30
?]nmysql_native_password�tinvalid sequence 32 != 1[root@tidb02 ~]#
[root@tidb02 ~]#
[root@tidb02 ~]#
[root@tidb02 ~]# curl $TIDBADDR/debug/zip?seconds=30
5.7.25-TiDB-v4.0.3^7P/(A��..\9hI
-~fmysql_native_password�tinvalid sequence 32 != 1[root@tidb02 ~]#
[root@tidb02 ~]#
[root@tidb02 ~]# curl $TIDBADDR/debug/zip?seconds=30
5.7.25-TiDB-v4.0.3a7LW
EwsjKCdmysql_native_password�tinvalid sequence 32 != 1[root@tidb02 ~]#
[root@tidb02 ~]#
[root@tidb02 ~]# curl $TIDBADDR/debug/zip?seconds=30
5.7.25-TiDB-v4.0.3d7X}X=hrsC��.HKv]ULx1mysql_native_password�tinvalid sequence 32 != 1[root@tidb02 ~]#
[root@tidb02 ~]#
[root@tidb02 ~]# curl $TIDBADDR/debug/zip?seconds=30
5.7.25-TiDB-v4.0.3g7W)[6<5��.:FBn*.q_5
.Jmysql_native_password�tinvalid sequence 32 != 1[root@tidb02 ~]#
[root@tidb02 ~]#
[root@tidb02 ~]# curl $TIDBADDR/debug/zip?seconds=30
|#��.zNTiDB-v4.0.3h7n~-j

3cl.mysql_native_password�tinvalid sequence 32 != 1[root@tidb02 ~]#
[root@tidb02 ~]#
[root@tidb02 ~]#
[root@tidb02 ~]#
[root@tidb02 ~]# curl $TIDBADDR/debug/zip?seconds=30
5.7.25-TiDB-v4.0.3k7l=NJ*CW��.^D_
                                 yHg%,~Omysql_native_password�tinvalid sequence 32 != 1[root@tidb02 ~]#
[root@tidb02 ~]#
[root@tidb02 ~]#
[root@tidb02 ~]# curl $TIDBADDR/debug/zip?seconds=30
5.7.25-TiDB-v4.0.3n7+ClJF��.FLgtQ3#N?mysql_native_password�tinvalid sequence 32 != 1

crazycs520-PingCAP · 2020 年7 月 28 日 23:42

@elvizlai 输出到文件，那个 api 的输出是一个 zip 文件

elvizlai · 2020 年7 月 29 日 01:19

我知道输出到文件，我的意思是这个指令看起来不是很灵。
[root@tidb02 ~]# curl “$TIDBADDR/debug/zip?seconds=30” > debug.zip
% Total % Received % Xferd Average Speed Time Time Time Current
Dload Upload Total Spent Left Speed
100 116 0 116 0 0 233k 0 --:–:-- --:–:-- --:–:-- 113k

大小只有116，所以我没有输出文件，直接试了一下

crazycs520-PingCAP · 2020 年7 月 29 日 02:30

@elvizlai 麻烦发下抓的 debug.zip 文件吧

elvizlai · 2020 年7 月 29 日 02:38

TIDBADDR=172.19.20.139:4000
curl "$TIDBADDR/debug/zip?seconds=30" > debug.zip

debug.zip (116 字节)

我还是感觉可能跟以下部分有关

mysql.db 中 DB 列使用了前缀授权，比如 dev_% 对应测试环境相关数据授权，暂不确定是否跟这个有关系。（看 pprof 中有 privileges 相关）

crazycs520-PingCAP · 2020 年7 月 29 日 02:48

@elvizlai 抱歉， TIDBADDR 中的端口号应该是 status 端口号，默认是 10080， 4000 是默认的 mysql 请求端口号, 麻烦重新抓下后发下 debug.zip 吧

elvizlai · 2020 年7 月 29 日 03:22

profiling_pack_3.tar.gz (24.1 KB)

debug.zip (391.6 KB)

crazycs520-PingCAP · 2020 年7 月 29 日 03:41

@elvizlai 感谢，已经定位问题目前问题是：假如用户 user1 对 test.t 表没有访问权限，那么 user1 在查询 information_schema.columns 时卡住，TiDB 内部会一直 for 循环去验证 user1 的对于 test.t 表的权限。

目前的绕过方法是，建议给相关用户加上所表的访问权限来绕过这个问题。

抱歉，我们会尽快修复这个问题

elvizlai · 2020 年7 月 29 日 03:51

tidb 好像目前控制粒度没精确到表吧。

这块是要授予相关用户所有数据库的相关权限？还是给 INFORMATION_SCHEMA 这类的就可以了？

crazycs520-PingCAP · 2020 年7 月 29 日 03:54

对应的 issue: https://github.com/pingcap/tidb/issues/18845

@elvizlai 对于需要查询 columns 表的用户，需要给所有的数据库的权限来暂时绕过这个问题，给一个 select 权限就可以了, 例如

grant select on *.* to 'user1'@'%';

crazycs520-PingCAP · 2020 年7 月 29 日 04:25

TiDB 的权限控制的粒度是可以精确到表的

system · 2022 年10 月 31 日 19:15

此话题已在最后回复的 1 分钟后被自动关闭。不再允许新回复。