Skip to content

Commit 9a06750

Browse files
TomShawnyikeke
andauthored
*: add more doc for slow log (pingcap#3886)
* *: add more doc for slow log * Apply suggestions from code review Co-authored-by: Keke Yi <[email protected]> Co-authored-by: Keke Yi <[email protected]>
1 parent 0709901 commit 9a06750

File tree

2 files changed

+63
-13
lines changed

2 files changed

+63
-13
lines changed

Diff for: identify-slow-queries.md

+32
Original file line numberDiff line numberDiff line change
@@ -109,6 +109,38 @@ TiKV Coprocessor Task fields:
109109
* `Cop_backoff_{backoff-type}_avg_time`: The average time of backoff caused by an error.
110110
* `Cop_backoff_{backoff-type}_p90_time`: The P90 percentile backoff time caused by an error.
111111

112+
## Related system variables
113+
114+
* [`tidb_slow_log_threshold`](/system-variables.md#tidb_slow_log_threshold): Sets the threshold for the slow log. The SQL statement whose execution time exceeds this threshold is recorded in the slow log. The default value is 300 (ms).
115+
* [`tidb_query_log_max_len`](/system-variables.md#tidb_query_log_max_len): Sets the maximum length of the SQL statement recorded in the slow log. The default value is 4096 (byte).
116+
* [`tidb_log_desensitization`](/system-variables.md#tidb_log_desensitization): Determines whether to desensitize user data using `?` in the SQL statement recorded in the slow log. The default value is `0`, which means to disable the feature.
117+
* [`tidb_enable_collect_execution_info`](/system-variables.md#tidb_enable_collect_execution_info): Determines whether to record the execution information of each operator in the execution plan. The default value is `1`. This feature impacts the performance by approximately 3%. After enabling this feature, you can view the `Plan` information as follows:
118+
119+
```sql
120+
> select tidb_decode_plan('jAOIMAk1XzE3CTAJMQlmdW5jczpjb3VudChDb2x1bW4jNyktPkMJC/BMNQkxCXRpbWU6MTAuOTMxNTA1bXMsIGxvb3BzOjIJMzcyIEJ5dGVzCU4vQQoxCTMyXzE4CTAJMQlpbmRleDpTdHJlYW1BZ2dfOQkxCXQRSAwyNzY4LkgALCwgcnBjIG51bTogMQkMEXMQODg0MzUFK0hwcm9jIGtleXM6MjUwMDcJMjA2HXsIMgk1BWM2zwAAMRnIADcVyAAxHcEQNQlOL0EBBPBbCjMJMTNfMTYJMQkzMTI4MS44NTc4MTk5MDUyMTcJdGFibGU6dCwgaW5kZXg6aWR4KGEpLCByYW5nZTpbLWluZiw1MDAwMCksIGtlZXAgb3JkZXI6ZmFsc2UJMjUBrgnQVnsA');
121+
+------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
122+
| tidb_decode_plan('jAOIMAk1XzE3CTAJMQlmdW5jczpjb3VudChDb2x1bW4jNyktPkMJC/BMNQkxCXRpbWU6MTAuOTMxNTA1bXMsIGxvb3BzOjIJMzcyIEJ5dGVzCU4vQQoxCTMyXzE4CTAJMQlpbmRleDpTdHJlYW1BZ2dfOQkxCXQRSAwyNzY4LkgALCwgcnBjIG51bTogMQkMEXMQODg0MzUFK0hwcm9jIGtleXM6MjUwMDcJMjA2HXsIMg |
123+
+------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
124+
| id task estRows operator info actRows execution info memory disk |
125+
| StreamAgg_17 root 1 funcs:count(Column#7)->Column#5 1 time:10.931505ms, loops:2 372 Bytes N/A |
126+
| └─IndexReader_18 root 1 index:StreamAgg_9 1 time:10.927685ms, loops:2, rpc num: 1, rpc time:10.884355ms, proc keys:25007 206 Bytes N/A |
127+
| └─StreamAgg_9 cop 1 funcs:count(1)->Column#7 1 time:11ms, loops:25 N/A N/A |
128+
| └─IndexScan_16 cop 31281.857819905217 table:t, index:idx(a), range:[-inf,50000), keep order:false 25007 time:11ms, loops:25 N/A N/A |
129+
+------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
130+
```
131+
132+
If you are conducting a performance test, you can disable the feature of automatically collecting the execution information of operators:
133+
134+
{{< copyable "sql" >}}
135+
136+
```sql
137+
set @@tidb_enable_collect_execution_info=0;
138+
```
139+
140+
The returned result of the `Plan` field has roughly the same format with that of `EXPLAIN` or `EXPLAIN ANALYZE`. For more details of the execution plan, see [`EXPLAIN`](/sql-statements/sql-statement-explain.md) or [`EXPLAIN ANALYZE`](/sql-statements/sql-statement-explain-analyze.md).
141+
142+
For more information, see [TiDB specific variables and syntax](/system-variables.md).
143+
112144
## Memory mapping in slow log
113145
114146
You can query the content of the slow query log by querying the `INFORMATION_SCHEMA.SLOW_QUERY` table. Each column name in the table corresponds to one field name in the slow log. For table structure, see the introduction to the `SLOW_QUERY` table in [Information Schema](/information-schema/information-schema-slow-query.md).

Diff for: system-variables.md

+31-13
Original file line numberDiff line numberDiff line change
@@ -6,7 +6,12 @@ aliases: ['/tidb/dev/tidb-specific-system-variables','/docs/dev/system-variables
66

77
# System Variables
88

9-
TiDB system variables behave similar to MySQL, in that settings may apply on a `SESSION`, `GLOBAL` or both `SESSION` and `GLOBAL` scope. Changes to `GLOBAL` scoped variables **only apply** to new connections to TiDB. Variables can be set with the [`SET` statement](/sql-statements/sql-statement-set-variable.md) on a per-session or global basis:
9+
TiDB system variables behave similar to MySQL with some differences, in that settings might apply on a `SESSION`, `INSTANCE`, or `GLOBAL` scope, or on a scope that combines `SESSION`, `INSTANCE`, or `GLOBAL`.
10+
11+
- Changes to `GLOBAL` scoped variables **only apply to new connection sessions with TiDB**. Currently active connection sessions are not affected. These changes are persisted and valid after restarts.
12+
- Changes to `INSTANCE` scoped variables apply to all active or new connection sessions with the current TiDB instance immediately after the changes are made. Other TiDB instances are not affected. These changes are not persisted and become invalid after TiDB restarts.
13+
14+
Variables can be set with the [`SET` statement](/sql-statements/sql-statement-set-variable.md) on a per-session, instance or global basis:
1015

1116
```sql
1217
# These two identical statements change a session variable
@@ -39,7 +44,7 @@ SET GLOBAL tidb_distsql_scan_concurrency = 10;
3944

4045
### ddl_slow_threshold
4146

42-
- Scope: SESSION
47+
- Scope: INSTANCE
4348
- Default value: 300
4449
- DDL operations whose execution time exceeds the threshold value are output to the log. The unit is millisecond.
4550

@@ -171,7 +176,7 @@ SET GLOBAL tidb_distsql_scan_concurrency = 10;
171176

172177
### tidb_check_mb4_value_in_utf8
173178

174-
- Scope: SERVER
179+
- Scope: INSTANCE
175180
- Default value: 1, indicating check the validity of UTF-8 data. This default behavior is compatible with MySQL.
176181
- This variable is used to set whether to check the validity of UTF-8 data.
177182
- To upgrade an earlier version (TiDB v2.1.1 or earlier), you may need to disable this option. Otherwise, you can successfully write invalid strings in an earlier version but fail to do this in a later version, because there is no data validity check in the earlier version. For details, see [FAQs After Upgrade](/faq/upgrade-faq.md).
@@ -336,7 +341,7 @@ Constraint checking is always performed in place for pessimistic transactions (d
336341

337342
### tidb_enable_slow_log
338343

339-
- Scope: SESSION
344+
- Scope: INSTANCE
340345
- Default value: `1`
341346
- This variable is used to control whether to enable the slow log feature. It is enabled by default.
342347

@@ -410,22 +415,22 @@ Constraint checking is always performed in place for pessimistic transactions (d
410415

411416
### tidb_expensive_query_time_threshold
412417

413-
- Scope: SERVER
418+
- Scope: INSTANCE
414419
- Default value: 60
415420
- This variable is used to set the threshold value that determines whether to print expensive query logs. The unit is second. The difference between expensive query logs and slow query logs is:
416421
- Slow logs are printed after the statement is executed.
417422
- Expensive query logs print the statements that are being executed, with execution time exceeding the threshold value, and their related information.
418423

419424
### tidb_force_priority
420425

421-
- Scope: SESSION
426+
- Scope: INSTANCE
422427
- Default value: `NO_PRIORITY`
423428
- This variable is used to change the default priority for statements executed on a TiDB server. A use case is to ensure that a particular user that is performing OLAP queries receives lower priority than users performing OLTP queries.
424429
- You can set the value of this variable to `NO_PRIORITY`, `LOW_PRIORITY`, `DELAYED` or `HIGH_PRIORITY`.
425430

426431
### tidb_general_log
427432

428-
- Scope: SERVER
433+
- Scope: INSTANCE
429434
- Default value: 0
430435
- This variable is used to set whether to record all the SQL statements in the log.
431436

@@ -679,7 +684,7 @@ mysql> desc select count(distinct a) from test.t;
679684

680685
### tidb_query_log_max_len
681686

682-
- Scope: SESSION
687+
- Scope: INSTANCE
683688
- Default value: 4096 (bytes)
684689
- The maximum length of the SQL statement output. When the output length of a statement is larger than the `tidb_query-log-max-len` value, the statement is truncated to output.
685690

@@ -691,13 +696,13 @@ set tidb_query_log_max_len = 20
691696

692697
### tidb_pprof_sql_cpu <span class="version-mark">New in v4.0</span>
693698

694-
- Scope: SESSION
699+
- Scope: INSTANCE
695700
- Default value: 0
696701
- This variable is used to control whether to mark the corresponding SQL statement in the profile output to identify and troubleshoot performance issues.
697702

698703
### tidb_record_plan_in_slow_log
699704

700-
- Scope: SESSION
705+
- Scope: INSTANCE
701706
- Default value: `1`
702707
- This variable is used to control whether to include the execution plan of slow queries in the slow log.
703708

@@ -756,7 +761,7 @@ Query OK, 0 rows affected, 1 warning (0.00 sec)
756761
757762
### tidb_slow_log_threshold
758763
759-
- Scope: SESSION
764+
- Scope: INSTANCE
760765
- Default value: 300ms
761766
- This variable is used to output the threshold value of the time consumed by the slow log. When the time consumed by a query is larger than this value, this query is considered as a slow log and its log is output to the slow query log.
762767
@@ -766,6 +771,19 @@ Usage example:
766771
SET tidb_slow_log_threshold = 200;
767772
```
768773
774+
### tidb_enable_collect_execution_info
775+
776+
- Scope: INSTANCE
777+
- Default value: 1
778+
- This variable controls whether to record the execution information of each operator in the slow query log.
779+
780+
### tidb_log_desensitization
781+
782+
- Scope: GLOBAL
783+
- Default value: 0
784+
- This variable controls whether to hide user information in the SQL statement being recorded into the TiDB log and slow log.
785+
- When you set the variable to `1`, user information is hidden. For example, if the executed SQL statement is `insert into t values (1,2)`, the statement is recorded as `insert into t values (?,?)` in the log.
786+
769787
### tidb_slow_query_file
770788
771789
- Scope: SESSION
@@ -810,7 +828,7 @@ SET tidb_slow_log_threshold = 200;
810828
811829
### tidb_store_limit <span class="version-mark">New in v3.0.4 and v4.0</span>
812830
813-
- Scope: SESSION | GLOBAL
831+
- Scope: INSTANCE | GLOBAL
814832
- Default value: 0
815833
- This variable is used to limit the maximum number of requests TiDB can send to TiKV at the same time. 0 means no limit.
816834
@@ -845,7 +863,7 @@ SET tidb_slow_log_threshold = 200;
845863
846864
- Scope: SESSION | GLOBAL
847865
- Default value: 4
848-
- This variable is used to set the concurrency degree of the window operator.
866+
- This variable is used to set the concurrency degree of the window operator.
849867
850868
### time_zone
851869

0 commit comments

Comments
 (0)