explain analyze support DML statement

[crazycs520]

Background

After #17573, TiDB maybe records the executor runtime information in slow log.

But currently, the executor runtime information doesn't contain the insert/update/delete executor runtime information.

Feature Request

explain analyze also need the executor runtime information to display. Currently, explain analyze DML(insert/delete/update) will return not return the runtime information, here is an example:

mysql>explain analyze insert into t values (1,1),(2,2),(3,3),(4,4);
Query OK, 4 rows affected
Time: 0.010s
mysql>explain analyze update t set a=a+10 where a>0;
Query OK, 24 rows affected
Time: 0.014s
mysql>explain analyze delete from t where a<24;
Query OK, 4 rows affected
Time: 0.010s

Describe the feature you'd like:

Add runtime information for DML in explain analyze too. Such as:

• rpc time execute: add rpc runtime stats information for insert/update/replace statement #19334
• memory
• prewrite_time,commit_time : executor: add transaction commit runtime information in slow log #19366
  . . .

Here is an example:

test> explain analyze insert into t values (1,1),(2,2),(3,3),(4,4);
+-------------------+---------+---------+-----------+---------------+--------------------------------------------------------------------+--------------------------------+-----------+------+
| id                | estRows | actRows | task      | access object | execution info                                                     | operator info                  | memory    | disk |
+-------------------+---------+---------+-----------+---------------+--------------------------------------------------------------------+--------------------------------+-----------+------+
| InsertExec _5     | 4.00    | 2       | root      | table:t       | time:535.68µs, loops:2, rpc num: 1, rpc time:498.42µs              |                                | 213 Bytes | N/A  |
+-------------------+---------+---------+-----------+---------------+--------------------------------------------------------------------+--------------------------------+-----------+------+

And then, we can record the insert/update/delete executor runtime information in slow-log.

There is some information we can add for DML and PointGet in explain analyze results (or slow logs):
For PointGet or BatchGet:

• RPC/Lock and backoff information for PointGet executor: add runtime information for point-get executor #18666
• RPC/Lock and backoff information for BatchGet executor: add runtime information for the batch-point-get executor #18828

For DML:

• memory consumed by memtable
• RPC and corresponding backoff information *: record more rpc runtime information in cop runtime stats #18916
• Lock resolving time executor: add transaction commit runtime information in slow log #19366
• Commit and Pre-Commit time executor: add transaction commit runtime information in slow log #19366
• Operation about meta data like allocating AutoIncreID/HandleID/AutoRandID

Describe alternatives you've considered:

Teachability, Documentation, Adoption, Migration Strategy:

• explain analyze

[zz-jason]

Could you describe more on the use scenarios and the motivation of this feature request?

[zz-jason]

Typically, explain analyze is used for postmortem analysis. For example, we found a statement executed too slow, wish to investigate where the time spent on.

I'm afraid it's not suitable for UPDATE statements because it changes the data state. This means the slow UPDATE query can not be reproduced repeatedly. The second EXPLAIN ANALYZE UPDATE may not able to update anything in some scenarios.

[crazycs520]

@zz-jason Sorry, Already add a background description.

My original intention is want to record insert/update/delete executor runtime information in the Plan field of slow-log.

Since explain analyze also need the runtime information, so maybe explain analyze can also display the insert/update/delete executor runtime information.

[zz-jason]

record insert/update/delete executor runtime information in the Plan field of slow-log.

Gotcha, that makes sense to me.@SunRunAway @qw4990 What's your opinion?

[SunRunAway]

Make sense to me.

[qw4990]

Make sense to me, but I think we should add extra fields in slow logs for some important behaviors(for example, time cost on commit and pre-commit), since some third-party tools like pt-query may rely on them and it's more friendly to users.

[jianyilyu]

/assign

[SunRunAway]

Added documentation for alerting users it has no explain result for DML now, pingcap/docs-cn#4059
Please update this after this issue is resolved.