planner,executor: support `admin show slow` command #7785

tiancaiamao · 2018-09-26T08:24:13Z

What problem does this PR solve?

After this PR, together with #7688 and #7692, we can use admin show slow now.

What is changed and how it works?

Build ShowSlow plan and ShowSlowExec executor.

It works like this:

mysql> admin show slow top 3;
+--------------------------------+----------------------------+----------+------------------------------------------------------------------------------------------------------+------+---------+--------------------+----------------+------+-----------+-----------+----------+
| SQL                            | START                      | DURATION | DETAILS                                                                                              | SUCC | CONN_ID | TRANSACTION_TS     | USER           | DB   | TABLE_IDS | INDEX_IDS | INTERNAL |
+--------------------------------+----------------------------+----------+------------------------------------------------------------------------------------------------------+------+---------+--------------------+----------------+------+-----------+-----------+----------+
| select count(*) from t limit 5 | 2018-09-26 16:09:21.101256 | 00:00:09 | process_time:1m8.032s wait_time:31.62s request_count:14 total_keys:20000014 processed_keys:20000000  |    1 |       2 | 403164197311217665 | [email protected] | test | [32]      |           |        1 |
| select count(*) from t         | 2018-09-26 16:09:11.269202 | 00:00:08 | process_time:1m2.451s wait_time:29.444s request_count:14 total_keys:20000014 processed_keys:20000000 |    1 |       1 | 403164194729099265 | [email protected] | test | [32]      |           |        1 |
+--------------------------------+----------------------------+----------+------------------------------------------------------------------------------------------------------+------+---------+--------------------+----------------+------+-----------+-----------+----------+
2 rows in set (0.01 sec)

Check List

Tests

Unit test to cover the basic statement.

As the result fields always change, it's hard to put it into unit test.
I manually check the result to assure that works.

Related changes

Need to update the documentation
Need to be included in the release note

tiancaiamao · 2018-09-26T08:26:11Z

PTAL @coocood @zz-jason

winkyao · 2018-09-26T08:38:50Z

Please fix ci.

zz-jason · 2018-09-26T08:53:12Z

executor/executor.go

+
+	dom := domain.GetDomain(e.ctx)
+	slowQueries := dom.ShowSlowQuery(e.ShowSlow)
+	for _, slow := range slowQueries {


the number of rows appended to chk should be smaller than max_chunk_size

So if the result is larger than max_chunk_size, it has to be split into multiple batches?

we have to use a cursor to record how many slow queries have been returned to the client.

coocood · 2018-09-26T08:49:40Z

planner/core/planbuilder.go

@@ -746,6 +750,23 @@ func buildShowDDLJobQueriesFields() *expression.Schema {
 	return schema
 }

+func buildShowSlowSchema() *expression.Schema {
+	schema := expression.NewSchema(make([]*expression.Column, 0, 11)...)
+	schema.Append(buildColumn("", "SQL", mysql.TypeVarchar, 256))


length is too small.

How about 1024?

1024 still too small.

coocood · 2018-09-26T08:49:59Z

planner/core/planbuilder.go

+	schema.Append(buildColumn("", "TRANSACTION_TS", mysql.TypeLonglong, 4))
+	schema.Append(buildColumn("", "USER", mysql.TypeVarchar, 32))
+	schema.Append(buildColumn("", "DB", mysql.TypeVarchar, 64))
+	schema.Append(buildColumn("", "TABLE_IDS", mysql.TypeVarchar, 64))


length is too small.

coocood · 2018-09-26T08:50:12Z

planner/core/planbuilder.go

+	schema.Append(buildColumn("", "USER", mysql.TypeVarchar, 32))
+	schema.Append(buildColumn("", "DB", mysql.TypeVarchar, 64))
+	schema.Append(buildColumn("", "TABLE_IDS", mysql.TypeVarchar, 64))
+	schema.Append(buildColumn("", "INDEX_IDS", mysql.TypeVarchar, 64))


length is too small.

coocood · 2018-09-26T08:51:02Z

planner/core/planbuilder.go

+	schema.Append(buildColumn("", "DETAILS", mysql.TypeVarchar, 256))
+	schema.Append(buildColumn("", "SUCC", mysql.TypeTiny, 2))
+	schema.Append(buildColumn("", "CONN_ID", mysql.TypeLonglong, 4))
+	schema.Append(buildColumn("", "TRANSACTION_TS", mysql.TypeLonglong, 4))


length is too small

coocood · 2018-09-26T08:51:24Z

planner/core/planbuilder.go

+	schema.Append(buildColumn("", "DURATION", mysql.TypeDuration, 64))
+	schema.Append(buildColumn("", "DETAILS", mysql.TypeVarchar, 256))
+	schema.Append(buildColumn("", "SUCC", mysql.TypeTiny, 2))
+	schema.Append(buildColumn("", "CONN_ID", mysql.TypeLonglong, 4))


length is too small.

coocood · 2018-09-26T08:52:19Z

planner/core/planbuilder.go

+func buildShowSlowSchema() *expression.Schema {
+	schema := expression.NewSchema(make([]*expression.Column, 0, 11)...)
+	schema.Append(buildColumn("", "SQL", mysql.TypeVarchar, 256))
+	schema.Append(buildColumn("", "START", mysql.TypeTimestamp, 64))


length is too big

coocood · 2018-09-26T08:52:35Z

planner/core/planbuilder.go

+	schema := expression.NewSchema(make([]*expression.Column, 0, 11)...)
+	schema.Append(buildColumn("", "SQL", mysql.TypeVarchar, 256))
+	schema.Append(buildColumn("", "START", mysql.TypeTimestamp, 64))
+	schema.Append(buildColumn("", "DURATION", mysql.TypeDuration, 64))


length is too big

winkyao · 2018-09-26T08:55:07Z

executor/adapter.go

@@ -381,6 +381,12 @@ func (a *ExecStmt) logSlowQuery(txnTS uint64, succ bool) {
 		if user != nil {
 			userString = user.String()
 		}
+		if len(tableIDs) > 10 {


what about if len(tableIDs) > len("table_ids:") ?

There is a comment for it already.

winkyao · 2018-09-26T09:04:52Z

executor/show_test.go

+	tk.MustQuery(`select sleep(1)`)
+
+	// Collecting slow queries is asynchronous, wait a while to ensure it's done.
+	time.Sleep(5 * time.Millisecond)


Is 5ms enough?

Maybe add a retry to make the test stable?

winkyao · 2018-09-26T09:08:53Z

executor/show_test.go

+	tk.MustExec("use test")
+	tk.MustExec(`drop table if exists t`)
+	tk.MustExec(`create table t(a bigint)`)
+	tk.MustQuery(`select sleep(1)`)


We can't assume sleep 1s is a slow query, we need to use cfg.Log.SlowThreshold?

zz-jason

LGTM

coocood

LGTM

coocood · 2018-09-26T10:54:31Z

/run-all-tests

morgo · 2018-10-05T15:21:52Z

I just started playing with this today :-)

@tiancaiamao Is it possible to change the duration to be in ms (unformatted)? 1 second is quite a long time for OLTP, and a query could still be considered slow but show a 00:00:00 duration.

tiancaiamao added 3 commits September 13, 2018 16:57

save

b77189c

Merge branch 'master' into show-log

5d9a8fb

address comment

ed271b9

tiancaiamao added sig/execution SIG execution sig/planner SIG: Planner labels Sep 26, 2018

reset unrelated changes

133cdc1

tiancaiamao changed the title ~~support admin show slow command~~ planner,executor: support admin show slow command Sep 26, 2018

fix ci

d449de7

zz-jason reviewed Sep 26, 2018

View reviewed changes

coocood reviewed Sep 26, 2018

View reviewed changes

winkyao reviewed Sep 26, 2018

View reviewed changes

address comment

93a8e75

zz-jason reviewed Sep 26, 2018

View reviewed changes

coocood reviewed Sep 26, 2018

View reviewed changes

Merge branch 'master' into show-log

858a106

coocood approved these changes Sep 26, 2018

View reviewed changes

Merge branch 'master' into show-log

3e65995

coocood added the status/all tests passed label Sep 26, 2018

tiancaiamao merged commit 081920d into pingcap:master Sep 26, 2018

tiancaiamao deleted the show-log branch September 26, 2018 11:28

morgo mentioned this pull request Oct 5, 2018

Document 'admin show slow' command pingcap/docs#647

Closed

morgo mentioned this pull request Nov 24, 2018

record transaction in history #2518

Closed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

planner,executor: support `admin show slow` command #7785

planner,executor: support `admin show slow` command #7785

tiancaiamao commented Sep 26, 2018

tiancaiamao commented Sep 26, 2018

winkyao commented Sep 26, 2018

zz-jason Sep 26, 2018

tiancaiamao Sep 26, 2018

zz-jason Sep 26, 2018

zz-jason Sep 26, 2018

coocood Sep 26, 2018

tiancaiamao Sep 26, 2018

winkyao Sep 26, 2018

coocood Sep 26, 2018

coocood Sep 26, 2018

coocood Sep 26, 2018

coocood Sep 26, 2018

coocood Sep 26, 2018

tiancaiamao Sep 26, 2018

coocood Sep 26, 2018

winkyao Sep 26, 2018

tiancaiamao Sep 26, 2018

winkyao Sep 26, 2018

coocood Sep 26, 2018

winkyao Sep 26, 2018

zz-jason left a comment

coocood left a comment

coocood commented Sep 26, 2018

morgo commented Oct 5, 2018

planner,executor: support admin show slow command #7785

planner,executor: support admin show slow command #7785

Conversation

tiancaiamao commented Sep 26, 2018

What problem does this PR solve?

What is changed and how it works?

Check List

tiancaiamao commented Sep 26, 2018

winkyao commented Sep 26, 2018

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

zz-jason left a comment

Choose a reason for hiding this comment

coocood left a comment

Choose a reason for hiding this comment

coocood commented Sep 26, 2018

morgo commented Oct 5, 2018

planner,executor: support `admin show slow` command #7785

planner,executor: support `admin show slow` command #7785