support adding ExecDetailsV2 to tracing

[zyguan]

Signed-off-by: zyguan [email protected]

In order to show ExecDetailsV2 in the trace statement, we have to convert the struct to spans of opentracing. This PR add the ability to do it.

Here is an example.

/* a */ drop table if exists t;
-- a >> 0 rows affected
/* a */ create table t (a int, b int, primary key(a), key sk(b));
-- a >> 0 rows affected
/* a */ insert into t values (1, 10), (5, 50);
-- a >> 2 rows affected
/* a:query */ trace select * from t where b < 100;
-- a >> +------------------------------------------------------------+-----------------+------------+
-- a    |                         operation                          |     startTS     |  duration  |
-- a    +------------------------------------------------------------+-----------------+------------+
-- a    | trace                                                      | 17:08:50.470834 | 2.061809ms |
-- a    |   ├─session.ExecuteStmt                                    | 17:08:50.470840 | 727.421µs  |
-- a    |   │ ├─executor.Compile                                     | 17:08:50.470856 | 454.383µs  |
-- a    |   │ └─session.runStmt                                      | 17:08:50.471333 | 205.569µs  |
-- a    |   │   └─distsql.Select                                     | 17:08:50.471448 | 45.941µs   |
-- a    |   │     └─regionRequest.SendReqCtx                         | 17:08:50.471649 | 1.122398ms |
-- a    |   │       └─rpcClient.SendRequest, region ID: 2, type: Cop | 17:08:50.471674 | 1.078549ms |
-- a    |   │         └─tikv.RPC                                     | 17:08:50.471677 | 406.226µs  |
-- a    |   │           └─tikv.Wait                                  | 17:08:50.471677 | 35.375µs   |
-- a    |   │             └─tikv.GetSnapshot                         | 17:08:50.471677 | 35.375µs   |
-- a    |   ├─*executor.IndexReaderExecutor.Next                     | 17:08:50.471583 | 1.266974ms |
-- a    |   └─*executor.IndexReaderExecutor.Next                     | 17:08:50.472861 | 2.676µs    |
-- a    +------------------------------------------------------------+-----------------+------------+
/* a:query */ trace update t set a = a+10, b = b+100 where a > 0; 
-- a >> +-----------------------------------------------------------------------+-----------------+------------+
-- a    |                               operation                               |     startTS     |  duration  |
-- a    +-----------------------------------------------------------------------+-----------------+------------+
-- a    | trace                                                                 | 17:08:50.518808 | 5.875638ms |
-- a    |   └─session.ExecuteStmt                                               | 17:08:50.518814 | 5.841205ms |
-- a    |     ├─executor.Compile                                                | 17:08:50.518831 | 323.468µs  |
-- a    |     └─session.runStmt                                                 | 17:08:50.519178 | 5.461207ms |
-- a    |       ├─TableReaderExecutor.Open                                      | 17:08:50.519280 | 77.151µs   |
-- a    |       │ └─distsql.Select                                              | 17:08:50.519298 | 48.703µs   |
-- a    |       │   └─regionRequest.SendReqCtx                                  | 17:08:50.519477 | 1.039391ms |
-- a    |       │     └─rpcClient.SendRequest, region ID: 2, type: Cop          | 17:08:50.519497 | 970.776µs  |
-- a    |       │       └─tikv.RPC                                              | 17:08:50.519499 | 382.585µs  |
-- a    |       │         └─tikv.Wait                                           | 17:08:50.519499 | 32.789µs   |
-- a    |       │           └─tikv.GetSnapshot                                  | 17:08:50.519499 | 32.789µs   |
-- a    |       ├─executor.handleNoDelayExecutor                                | 17:08:50.519400 | 2.850728ms |
-- a    |       │ └─*executor.UpdateExec.Next                                   | 17:08:50.519404 | 2.82959ms  |
-- a    |       │   ├─*executor.TableReaderExecutor.Next                        | 17:08:50.519413 | 1.171011ms |
-- a    |       │   ├─executor.updateRecord                                     | 17:08:50.520616 | 827.476µs  |
-- a    |       │   │ └─table.AddRecord                                         | 17:08:50.520677 | 758.839µs  |
-- a    |       │   │   ├─tikvSnapshot.get                                      | 17:08:50.520692 | 715.601µs  |
-- a    |       │   │   └─regionRequest.SendReqCtx                              | 17:08:50.520699 | 670.142µs  |
-- a    |       │   │     └─rpcClient.SendRequest, region ID: 2, type: Get      | 17:08:50.520709 | 647.845µs  |
-- a    |       │   │       └─tikv.RPC                                          | 17:08:50.520710 | 227.137µs  |
-- a    |       │   │         └─tikv.Wait                                       | 17:08:50.520710 | 21.354µs   |
-- a    |       │   │           └─tikv.GetSnapshot                              | 17:08:50.520710 | 21.354µs   |
-- a    |       │   ├─executor.updateRecord                                     | 17:08:50.521460 | 695.629µs  |
-- a    |       │   │ └─table.AddRecord                                         | 17:08:50.521474 | 674.012µs  |
-- a    |       │   │   ├─tikvSnapshot.get                                      | 17:08:50.521484 | 637.735µs  |
-- a    |       │   │   └─regionRequest.SendReqCtx                              | 17:08:50.521494 | 616.441µs  |
-- a    |       │   │     └─rpcClient.SendRequest, region ID: 2, type: Get      | 17:08:50.521503 | 592.414µs  |
-- a    |       │   │       └─tikv.RPC                                          | 17:08:50.521504 | 158.352µs  |
-- a    |       │   │         └─tikv.Wait                                       | 17:08:50.521504 | 19.715µs   |
-- a    |       │   │           └─tikv.GetSnapshot                              | 17:08:50.521504 | 19.715µs   |
-- a    |       │   └─*executor.TableReaderExecutor.Next                        | 17:08:50.522198 | 13.537µs   |
-- a    |       └─session.CommitTxn                                             | 17:08:50.522263 | 2.35599ms  |
-- a    |         └─session.doCommitWitRetry                                    | 17:08:50.522266 | 2.344049ms |
-- a    |           └─tikvTxn.Commit                                            | 17:08:50.522278 | 2.314455ms |
-- a    |             └─twoPhaseCommitter.prewriteMutations                     | 17:08:50.522295 | 2.277919ms |
-- a    |               └─regionRequest.SendReqCtx                              | 17:08:50.522311 | 2.24855ms  |
-- a    |                 └─rpcClient.SendRequest, region ID: 2, type: Prewrite | 17:08:50.522320 | 2.226142ms |
-- a    |                   └─tikv.RPC                                          | 17:08:50.522321 | 1.560567ms |
-- a    |                     ├─tikv.Wait                                       | 17:08:50.522321 | 19.363µs   |
-- a    |                     │ └─tikv.GetSnapshot                              | 17:08:50.522321 | 19.363µs   |
-- a    |                     └─tikv.AsyncWrite                                 | 17:08:50.522340 | 987.634µs  |
-- a    |                       ├─tikv.StoreBatchWait                           | 17:08:50.522340 | 64.35µs    |
-- a    |                       ├─tikv.PersistLog                               | 17:08:50.522405 | 589.398µs  |
-- a    |                       │ ├─tikv.RaftDBWriteWait                        | 17:08:50.522405 | 205ns      |
-- a    |                       │ ├─tikv.RaftDBWriteWAL                         | 17:08:50.522405 | 539.524µs  |
-- a    |                       │ └─tikv.RaftDBWriteMemtable                    | 17:08:50.522944 | 4.425µs    |
-- a    |                       ├─tikv.CommitLog                                | 17:08:50.522405 | 623.559µs  |
-- a    |                       ├─tikv.ApplyBatchWait                           | 17:08:50.523028 | 79.677µs   |
-- a    |                       └─tikv.ApplyLog                                 | 17:08:50.523108 | 220.048µs  |
-- a    |                         ├─tikv.ApplyMutexLock                         | 17:08:50.523108 | 268ns      |
-- a    |                         ├─tikv.ApplyWriteWAL                          | 17:08:50.523108 | 79.677µs   |
-- a    |                         └─tikv.ApplyWriteMemtable                     | 17:08:50.523188 | 97.938µs   |
-- a    +-----------------------------------------------------------------------+-----------------+------------+
/* a */ begin;
-- a >> 0 rows affected
/* b */ begin;
-- b >> 0 rows affected
/* b */ select * from t where a = 2 for update;
-- b >> +---+---+
-- b    | a | b |
-- b    +---+---+
-- b    +---+---+
/* a:query */ trace insert into t values (2, 2); 
-- a >> blocked
/* b */ commit;
-- b >> 0 rows affected
-- a >> resumed
-- a >> +--------------------------------------------------------------------------+-----------------+--------------+
-- a    |                                operation                                 |     startTS     |   duration   |
-- a    +--------------------------------------------------------------------------+-----------------+--------------+
-- a    | trace                                                                    | 17:08:50.702909 | 2.004659737s |
-- a    |   └─session.ExecuteStmt                                                  | 17:08:50.702915 | 2.004644455s |
-- a    |     ├─executor.Compile                                                   | 17:08:50.702931 | 48.948µs     |
-- a    |     └─session.runStmt                                                    | 17:08:50.703000 | 2.004533913s |
-- a    |       ├─executor.handleNoDelayExecutor                                   | 17:08:50.703027 | 98.154µs     |
-- a    |       │ └─*executor.InsertExec.Next                                      | 17:08:50.703030 | 83.492µs     |
-- a    |       │   └─table.AddRecord                                              | 17:08:50.703054 | 50.416µs     |
-- a    |       ├─regionRequest.SendReqCtx                                         | 17:08:50.703161 | 1.002458857s |
-- a    |       │ ├─rpcClient.SendRequest, region ID: 2, type: PessimisticLock     | 17:08:50.703175 | 1.00241369s  |
-- a    |       │ │ └─tikv.RPC                                                     | 17:08:50.703176 | 1.001523057s |
-- a    |       │ └─regionRequest.SendReqCtx                                       | 17:08:51.705668 | 928.119µs    |
-- a    |       │   ├─rpcClient.SendRequest, region ID: 2, type: CheckTxnStatus    | 17:08:51.705700 | 880.716µs    |
-- a    |       │   │ └─tikv.RPC                                                   | 17:08:51.705703 | 353.76µs     |
-- a    |       │   └─regionRequest.SendReqCtx                                     | 17:08:51.706613 | 998.936651ms |
-- a    |       │     └─rpcClient.SendRequest, region ID: 2, type: PessimisticLock | 17:08:51.706623 | 998.88378ms  |
-- a    |       │       └─tikv.RPC                                                 | 17:08:51.706624 | 998.288998ms |
-- a    |       ├─executor.handleNoDelayExecutor                                   | 17:08:52.706078 | 200.928µs    |
-- a    |       │ └─*executor.InsertExec.Next                                      | 17:08:52.706087 | 148.948µs    |
-- a    |       │   └─table.AddRecord                                              | 17:08:52.706154 | 57.245µs     |
-- a    |       └─regionRequest.SendReqCtx                                         | 17:08:52.706323 | 786.595µs    |
-- a    |         └─rpcClient.SendRequest, region ID: 2, type: PessimisticLock     | 17:08:52.706346 | 743.883µs    |
-- a    |           └─tikv.RPC                                                     | 17:08:52.706347 | 244.309µs    |
-- a    |             └─tikv.Wait                                                  | 17:08:52.706347 | 16.798µs     |
-- a    |               └─tikv.GetSnapshot                                         | 17:08:52.706347 | 16.798µs     |
-- a    +--------------------------------------------------------------------------+-----------------+--------------+

[cfzjywxk]

Maybe the TimeDetail related information could be put together?

[cfzjywxk]

We could add a simple unit test to cover the converting process.

[sticnarf]

The rest lgtm

[disksing]

please fix the lint warning.