并发增加后,联表查询性能变慢

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

  • 【TiDB 版本】:4.0.2
  • 【问题描述】:简单两个表关联,慢查询去到几百毫秒,但是查看执行时间显示过程中的时间并不多,然后最后一步执行sql却耗时几百毫秒,这是什么原因呢?
    单独执行耗时很快统计显示也只有2到3ms,但是在并发上来后降几百毫秒

在压测中执行EXPLAIN ANALYZE,发现在root的执行计划会浮动很大:

IndexMergeJoin_18 0.00 0 root time:124.825988ms, loops:1, Concurrency:OFF inner join, inner:IndexReader_16, outer key:course.homework.clazz_plan_id, inner key:course.clazz_plan.id 0 Bytes N/A
├─IndexMergeJoin_50(Build) 0.00 0 root time:63.201669ms, loops:1, Concurrency:OFF inner join, inner:Projection_48, outer key:course.student_paper.paper_id, inner key:course.homework.paper_id 0 Bytes N/A
│ ├─IndexLookUp_75(Build) 0.01 0 root time:63.217145ms, loops:1, rpc num: 1, rpc time:29.26465ms, proc keys:0 188 Bytes N/A
│ │ ├─IndexRangeScan_72(Build) 10.00 0 cop[tikv] table:sp, index:udx_student_paper_student_id_paper_id(student_id, paper_id) time:0s, loops:1 range:[150607,150607], keep order:false, stats:pseudo N/A N/A
│ │ └─Selection_74(Probe) 0.01 cop[tikv] time:0ns, loops:0 eq(course.student_paper.status, 1) N/A N/A
│ │ └─TableRowIDScan_73 10.00 0 cop[tikv] table:sp time:0s, loops:0 keep order:false, stats:pseudo N/A N/A
│ └─Projection_48(Probe) 0.00 root time:0ns, loops:0 course.homework.id, course.homework.title, course.homework.type, course.homework.clazz_id, course.homework.clazz_plan_id, course.homework.paper_id, course.homework.arrange_time, course.homework.start_time, course.homework.expired_time, course.homework.status N/A N/A
│ └─IndexLookUp_47 0.00 root time:0ns, loops:0 N/A N/A
│ ├─Selection_45(Build) 9990.00 cop[tikv] time:0ns, loops:0 not(isnull(course.homework.paper_id)) N/A N/A
│ │ └─IndexRangeScan_43 10000.00 cop[tikv] table:h, index:paper_id(paper_id) time:0ns, loops:0 range: decided by [eq(course.homework.paper_id, course.student_paper.paper_id)], keep order:true, stats:pseudo N/A N/A
│ └─Selection_46(Probe) 0.00 cop[tikv] time:0ns, loops:0 eq(course.homework.status, 1), gt(course.homework.expired_time, 2020-07-10 00:00:00.000000), in(course.homework.type, 1, 2), lt(course.homework.start_time, 2020-07-11 00:00:00.000000) N/A N/A
│ └─TableRowIDScan_44 9990.00 cop[tikv] table:h time:0ns, loops:0 keep order:false, stats:pseudo N/A N/A
└─IndexReader_16(Probe) 1.00 root time:0ns, loops:0 index:IndexRangeScan_15 N/A N/A
└─IndexRangeScan_15 1.00 cop[tikv] table:cp, index:PRIMARY(id) time:0ns, loops:0 range: decided by [eq(course.clazz_plan.id, course.homework.clazz_plan_id)], keep order:true N/A N/A

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

  1. 单独查询快,说明在系统负载不高时是执行计划是正常的.
  2. 并发后,先检查执行计划是否和之前相同,如果相同。 可以先检查系统资源是否存在瓶颈,可以按照排查流程检查 TiDB 调优辅助神器 TiDB Performance Map 即将上线!欢迎试用反馈 看看是哪个阶段消耗的时间长。

image

这里变高:


看文档get token应该是在纳秒内,但是去到了几秒。然后对比cpu占用并不高:

这是什么原因呢?

  1. Get Token Duration:建立连接后获取 Token 耗时, 如果这里时长较久,需要判断 PD 到 TDB-Server 的链路。
  2. 检查 PD 整体性能,CPU,内存 ,IO
  3. 检查 PD 到 TiDB 的网络是否正常
  4. 检查 TiDB 整体性能,CPU,内存,IO
  5. 或者检查是否有 pd,tidb,tikv 共同部署的情况,导致消耗资源过高。

之前的sql已经被业务方优化掉了(走缓存)。
刚才我拿另一条sql重现了一下。PD资源消耗很低。

下面是tidb-server的get token和cpu截图:

您好,方便看一下 TiKV Coprocessor 部分的负载情况和延迟情况嘛

是这些吗?

  1. 看您这边的并发在5K --10K,tidb-server 的 token-limit默认是 1000,所以获取token会排队,并发太多了。
  2. 可以考虑增大token-limit 参数值。 https://github.com/pingcap/tidb/blob/a99fdc098cb3bccc63ca74dad3d682b6f80a0fbd/config/config.toml.example#L32

多谢,看起 cop duration 不高,SQL 列出的那条计划中包含 pseudo 关键词,说明该表的统计信息暂时不准确。可以尝试 analyse table table_name 来对该表执行真正的统计信息收集。以便能更优计划的生成。

上图列出的那个执行计划由于 range[150607,150607] 范围是单点,并且只有0条数据,所以返回会很快,如果是 result 数据量比较大,indexMergeJoin 可能不是一个很好的执行计划,造成延迟很高,所以统计信息表关键。

增大之后是一样的表现,这个已经试过了。

已经analyse过了,但是没有作用。并发的时候还是会很差。
是啊,单独查询返回很快,但是并发就很慢。

get token除了跟token-limit参数有关,跟pd的哪方面性能有关系呢? 我们目前参考是的官方部署,但是硬盘使用的是云ssd,只有4000左右的iops,这个有关系吗?

麻烦发一下这个时间段的 over-view,tidb, detail-tikv 多谢

(1)、chrome 安装这个插件https://chrome.google.com/webstore/detail/full-page-screen-capture/fdpohaocaechififmbbbbbknoalclacl

(2)、鼠标焦点置于 Dashboard 上,按 ?可显示所有快捷键,先按 d 再按 E 可将所有 Rows 的 Panels 打开,需等待一段时间待页面加载完成。

(3)、使用这个 full-page-screen-capture 插件进行截屏保存



  1. 从监控来看,基本都在12这个节点,而且有读热点和写热点


  2. 麻烦参考热点文章,尝试打散后看看是否有效,多谢。
    如何分析和解决 TiDB 4.0 的写热点问题

  3. empty region 较多,请检查 region merge 是否正常
    [FAQ] 解决已经开启 region merge, empty-region-count 仍然很多问题

是14点30左右的,后面是压其他的sql了。小表压测成绩很好的,都能去到4w qps左右。这个联表查询单独简单分开查能去到8 9w,但是join了之后只有3 4q,这个性能跌太多了。单独执行只有60-80ms左右的sql。
empty region应该没什么影响吧,我看都是没有fullscan的,这个只会吃一部分心跳资源但是现在服务器资源还有很多冗余。

监控信息我们再分析下,另外是否有压测时的执行计划,可以清楚看到这个sql为什么慢,多谢。

ok,我重现一下。

执行sql:
SELECT
user.id AS id,
user.username AS username,
user.phone AS phone,
user.role AS role,
user.verify_code AS verify_code,
user.verify_time AS verify_time,
user.is_verified AS is_verified,
user.avatar_oss_id AS avatar_oss_id,
user.access_token AS access_token,
user.is_staff AS is_staff,
user.status AS status,
user.school_id AS school_id,
user.school_name AS school_name,
user.score AS score,
user.grade AS grade,
user.sex AS sex,
user.real_name AS real_name,
user.create_time AS create_time,
user.is_destroy AS is_destroy,
user.destroy_time AS destroy_time,
user.register_activity AS register_activity,
user.register_source AS register_source,
user.ppt_id AS ppt_id,
user.member_id AS member_id,
user.secret AS secret,
user.hash AS hash,
official_a.id AS official_a__id,
official_a.wx_open_id AS official_a__wx_open_id,
official_a.wx_username AS official_a__wx_username,
official_a.wx_avatar AS official_a__wx_avatar,
official_a.wx_phone AS official_a__wx_phone
FROM
users user
LEFT JOIN users_official_account official_a ON user.id = official_a.user_id
AND official_a.status = 1
WHERE
1 = 1
AND user.role = 3
AND user.member_id = ‘11100060923’;

执行计划:
Projection_6 root 1.212497569286898 course.users.id, course.users.username, course.users.phone, course.users.role, course.users.verify_code, course.users.verify_time, course.users.is_verified, course.users.avatar_oss_id, course.users.access_token, course.users.is_staff, course.users.status, course.users.school_id, course.users.school_name, course.users.score, course.users.grade, course.users.sex, course.users.real_name, course.users.create_time, course.users.is_destroy, course.users.destroy_time, course.users.register_activity, course.users.register_source, course.users.ppt_id, course.users.member_id, course.users.secret, course.users.hash, course.users_official_account.id, course.users_official_account.wx_open_id, course.users_official_account.wx_username, course.users_official_account.wx_avatar, course.users_official_account.wx_phone
└─IndexMergeJoin_18 root 1.212497569286898 left outer join, inner:Projection_16, outer key:course.users.id, inner key:course.users_official_account.user_id
├─Selection_24 root 1 eq(course.users.role, 3)
│ └─Point_Get_23 root 1 table:users, index:udx_memberid(member_id)
└─Projection_16 root 1.25 course.users_official_account.id, course.users_official_account.user_id, course.users_official_account.wx_username, course.users_official_account.wx_phone, course.users_official_account.wx_open_id, course.users_official_account.wx_avatar, course.users_official_account.status
└─IndexLookUp_15 root 1.25
├─IndexScan_12 cop 1250 table:official_a, index:idx_uoa_user_id(user_id), range: decided by [eq(course.users_official_account.user_id, course.users.id)], keep order:true, stats:pseudo
└─Selection_14 cop 1.25 eq(course.users_official_account.status, 1)
└─TableScan_13 cop 1250 table:official_a, keep order:false, stats:pseudo

相关监控,查看22:36分后的监控。
https://test.dianbo.zycourse.com/tidb/pdf/ov_2236.pdf
https://test.dianbo.zycourse.com/tidb/pdf/tikv_2236.pdf
https://test.dianbo.zycourse.com/tidb/pdf/ov_2236.pdf

这是我从业务方扣出来了另一个简单join表查询也存在同样问题。这条sql拆开来执行单查user可以去到10wqps,单查office可以去到6w8qps,但是联表之后只有2kqps。非常令人疑惑。

麻烦了,我们再查看一下,多谢。 另外,是说查看 26分以后的监控? 只到 35 分

22:36之后,我在这个时间点开始压测的。26-35的不用看。