Shulou(Shulou.com)05/31 Report--

What this article shares with you is about the principle of slow query records in MySQL. The editor thinks it is very practical, so I share it with you to learn. I hope you can get something after reading this article.

1. Time in slow query

In fact, the time in the slow query is the clock time, which is obtained through the command of the operating system, as follows: how to get the time in Linux

While (gettimeofday (& t, NULL)! = 0) {} newtime= (ulonglong) t.tv_sec * 1000000 + t. TVICUSEC; return newtime

It is actually the time obtained through the API gettimeofday function of OS.

Second, the basis of slow query records

Long_query_time: if the execution time exceeds this parameter, set the record slow query.

Log_queries_not_using_indexes: if the statement does not use an index to record a slow query.

Log_slow_admin_statements: whether to record management statements. (e.g. ALTER TABLE,ANALYZE TABLE, CHECK TABLE, CREATE INDEX, DROP INDEX, OPTIMIZE TABLE, and REPAIR TABLE.)

This article mainly discusses the meaning of the long_query_time parameter.

III. The specific meaning of long_query_time parameters

If we define the execution time of the statement as follows:

Actual consumption time = actual execution time + lock waiting time

So long_query_time actually defines the actual execution time, so in some cases, although the statement actually takes a long time, it is caused by the long lock waiting time, so in fact, this kind of statement will not record a slow query.

Let's take a look at the code snippet of the log_slow_applicable function:

Res= cur_utime-thd- > utime_after_lock; if (res > thd- > variables.long_query_time) thd- > server_status | = SERVER_QUERY_WAS_SLOW; else thd- > server_status&= ~ SERVER_QUERY_WAS_SLOW

This actually clearly illustrates the above point of view, whether the slow query is through this function to determine, is very important. I can clearly see the following formula:

Res (actual execution time) = cur_utime (actual elapsed time)-thd- > utime_after_lock (lock waiting time)

In fact, what is recorded in the slow query is

Query_time: actual execution time

Lock_time: lock wait time

But whether it is a slow query is judged by the actual execution time and Query_time-Lock_time.

The lock wait time (Lock_time) that I already know includes:

The elapsed time for the MySQL tier MDL LOCK to wait. (Waiting for table metadata lock)

Time consumed by the MyISAM table lock in the MySQL tier. (Waiting for table level lock)

The time consumed by the InnoDB layer row lock.

4. How does MySQL record lock time

We can see that the record of utime_after_lock (lock wait time Lock_time) in the formula is the key to the whole formula, so let's try debug.

1. The recording method of utime_after_lock in MySQL layer

Both the time consumed by MDL LOCK waiting and the time consumed by MyISAM table locks are recorded at the MySQL layer. In fact, it only records the recording time of THD::set_time_after_lock that will be called at the end of the function mysql_lock_tables:

Void set_time_after_lock () {utime_after_lock= my_micro_time (); MYSQL_SET_STATEMENT_LOCK_TIME (m_statement_psi, (utime_after_lock-start_utime);}

So it can be parsed here that all the time before the code runs to the end of the mysql_lock_tables function is recorded in the utime_after_lock time, which is actually not accurate. But in fact, both MDL LOCK acquisition and MyISAM table lock acquisition are included. So even the select statement will see that Lock_time is not 0. Here are the stack frames:

# 0 THD::set_time_after_lock (this=0x7fff28012820) at / root/mysql5.7.14/percona-server-5.7.14-7/sql/sql_class.h:3414 # 1 0x0000000001760d6d in mysql_lock_tables (thd=0x7fff28012820, tables=0x7fff28c16b58, count=1, flags=0) at / root/mysql5.7.14/percona-server-5.7.14-7/sql/lock.cc:366 # 2 0x000000000151dc1a in lock_tables (thd=0x7fff28012820, tables=0x7fff28c165b0, count=1 Flags=0) at / root/mysql5.7.14/percona-server-5.7.14-7/sql/sql_base.cc:6700 # 3 0x00000000017c4234 in Sql_cmd_delete::mysql_delete (this=0x7fff28c16b50, thd=0x7fff28012820, limit=18446744073709551615) at / root/mysql5.7.14/percona-server-5.7.14-7/sql/sql_delete.cc:136 # 4 0x00000000017c84ba in Sql_cmd_delete::execute (this=0x7fff28c16b50 Thd=0x7fff28012820) at / root/mysql5.7.14/percona-server-5.7.14-7/sql/sql_delete.cc:1389 # 5 0x00000000015a7814 in mysql_execute_command (thd=0x7fff28012820, first_level=true) at / root/mysql5.7.14/percona-server-5.7.14-7/sql/sql_parse.cc:3729 # 6 0x00000000015adcd6 in mysql_parse (thd=0x7fff28012820 Parser_state=0x7ffff035b600) at / root/mysql5.7.14/percona-server-5.7.14-7/sql/sql_parse.cc:5836 # 7 0x00000000015a1b95 in dispatch_command (thd=0x7fff28012820, com_data=0x7ffff035bd70, command=COM_QUERY) at / root/mysql5.7.14/percona-server-5.7.14-7/sql/sql_parse.cc:1447 # 8 0x00000000015a09c6 in do_command (thd=0x7fff28012820) at / root/mysql5.7.14/percona-server-5.7.14-7/sql/sql_parse.cc:1010

2. Utime_after_lock recording mode of row locks in InnoDB layer

The InnoDB engine layer calls the thd_storage_lock_wait function through thd_set_lock_wait_time to complete the stack frame as follows:

# 0 thd_storage_lock_wait (thd=0x7fff2c000bc0, value=9503561) at / root/mysql5.7.14/percona-server-5.7.14-7/sql/sql_class.cc:798 # 1 0x00000000019a4b2a in thd_set_lock_wait_time (thd=0x7fff2c000bc0 Value=9503561) at / root/mysql5.7.14/percona-server-5.7.14-7/storage/innobase/handler/ha_innodb.cc:1784 # 2 0x0000000001a4b50f in lock_wait_suspend_thread (thr=0x7fff2c088200) at / root/mysql5.7.14/percona-server-5.7.14-7/storage/innobase/lock/lock0wait.cc:363 # 3 0x0000000001b0ec9b in row_mysql_handle_errors (new_err=0x7ffff0317d54, trx=0x7ffff2f2e5d0, thr=0x7fff2c088200 Savept=0x0) at / root/mysql5.7.14/percona-server-5.7.14-7/storage/innobase/row/row0mysql.cc:772 # 4 0x0000000001b4fe61 in row_search_mvcc (buf=0x7fff2c087640 "\ 377", mode=PAGE_CUR_G, prebuilt=0x7fff2c087ac0, match_mode=0, direction=0) at / root/mysql5.7.14/percona-server-5.7.14-7/storage/innobase/row/row0sel.cc:5940 # 5 0x00000000019b3051 in ha_innobase::index_read (this=0x7fff2c087100, buf=0x7fff2c087640 "\ 377", key_ptr=0x0, key_len=0 Find_flag=HA_READ_AFTER_KEY) at / root/mysql5.7.14/percona-server-5.7.14-7/storage/innobase/handler/ha_innodb.cc:9104 # 6 0x00000000019b4374 in ha_innobase::index_first (this=0x7fff2c087100, buf=0x7fff2c087640 "\ 377") at / root/mysql5.7.14/percona-server-5.7.14-7/storage/innobase/handler/ha_innodb.cc:9551 # 7 0x00000000019b462c in ha_innobase::rnd_next (this=0x7fff2c087100 Buf=0x7fff2c087640 "\ 377") at / root/mysql5.7.14/percona-server-5.7.14-7/storage/innobase/handler/ha_innodb.cc:9656 # 8 0x0000000000f66f1b in handler::ha_rnd_next (this=0x7fff2c087100 Buf=0x7fff2c087640 "\ 377") at / root/mysql5.7.14/percona-server-5.7.14-7/sql/handler.cc:3099 # 9 0x00000000014c61b6 in rr_sequential (info=0x7ffff03189e0) at / root/mysql5.7.14/percona-server-5.7.14-7/sql/records.cc:520 # 10 0x00000000017c56c3 in Sql_cmd_delete::mysql_delete (this=0x7fff2c006ae8, thd=0x7fff2c000bc0 Limit=1) at / root/mysql5.7.14/percona-server-5.7.14-7/sql/sql_delete.cc:454 # 11 0x00000000017c84ba in Sql_cmd_delete::execute (this=0x7fff2c006ae8, thd=0x7fff2c000bc0) at / root/mysql5.7.14/percona-server-5.7.14-7/sql/sql_delete.cc:1389

The function itself is still very simple and you can see for yourself that it just adds up as follows:

Void thd_storage_lock_wait (THD * thd, long long value) {thd- > utime_after_lock+= value;} V. log_slow_verbosity parameter in Percona

This is Percona's explanation:

Specifies how much information to include in your slow log. The value is a comma-delimited string, and can contain any combination of the following values:

Microtime: Log queries with microsecond precision (mandatory).

Query_plan: Log information about the query's execution plan (optional).

Innodb: Log InnoDB statistics (optional).

Minimal: Equivalent to enabling just microtime.

Standard: Equivalent to enabling microtime,innodb.

Full: Equivalent to all other values OR'ed together.

In short, you can modify this parameter in Percona to get more detailed information. The format is as follows:

# Time: 2018-05-30T09:30:12.039775Z # User@Host: root [root] @ localhost [] Id: 10 # Schema: test Last_errno: 1317 Killed: 0 # Query_time: 19.254508 Lock_time: 0.001043 Rows_sent: 0 Rows_examined: 0 Rows_affected: 0 # Bytes_sent: 44 Tmp_tables: 0 Tmp_disk_tables: 0 Tmp_table_sizes: 0 # InnoDB_trx_id: 0 # QC_Hit: No Full_scan: No Full_join: No Tmp_table: No Tmp_table_on_disk: No # Filesort: No Filesort_on_disk: No Merge_passes: 0 # InnoDB_IO_r_ops: 0 InnoDB_IO_r_bytes: 0 InnoDB_IO_r_wait: 0.000000 # InnoDB_rec_lock_wait: 0.000000 InnoDB_queue_wait: 0.000000 # InnoDB_pages_distinct: 0 SET timestamp=1527672612 Select count (*) from Z1 limit 1; VI. Detailed explanation of the output

This section will explain in detail, all the slow query output comes from the function File_query_log::write_slow, interested students can see for themselves, I will also give the location and meaning of the output, the meaning part may give the comments in the source code.

1. The first part of time

# Time: 2018-05-30T09:30:12.039775Z

Corresponding code:

My_snprintf (buff, sizeof buff, "# Time:% s\ n", my_timestamp)

Where the value of my_timestamp comes from

Thd- > current_utime ()

Actually, it is:

While (gettimeofday (& t, NULL)! = 0) {} newtime= (ulonglong) t.tv_sec * 1000000 + t. TVICUSEC; return newtime

You can see that it is actually the current time of the system obtained by calling the gettimeofday system call.

Note:

For 5.6, there is another judgment.

If (current_time! = last_time)

If the two printing times are the same in seconds, the time will not be output, only through the

SET timestamp=1527753496

To determine the time, 5.7.14 did not see such code.

2. The second part is user information

# User@Host: root [root] @ localhost [] Id: 10

Corresponding code:

Buff_len= my_snprintf (buff, 32, "% 5U", thd- > thread_id ()); if (my_b_printf (& log_file, "# User@Host:% s Id:% s\ n", user_host, buff) = (uint)-1) goto err;}

User_host is a string. Refer to the code:

Size_t user_host_len= (strxnmov (user_host_buff, MAX_USER_HOST_SIZE, sctx- > priv_user (). Str? Sctx- > priv_user (). Str: "," [", sctx_user.length? Sctx_user.str: (thd- > slave_thread? "SQL_SLAVE": "),"] @ ", sctx_host.length? Sctx_host.str: "," [", sctx_ip.length? Sctx_ip.str: "", "]", NullS)-user_host_buff)

The explanation is as follows:

Root: m_priv_user-The user privilege we are using. May be "" for anonymous user.

[root]: m_user-user of the client, set to NULL until the user has been read from the connection.

Localhost: m_host-host of the client.

[]: client IP m_ip-client IP

Id: 10 thd- > thread_id () is actually the id from show processlist.

3. The third part is schema and other information

# Schema: test Last_errno: 1317 Killed: 0

Corresponding code:

"# Schema:% s Last_errno:% u Killed:% u\ n" (thd- > db () .str? Thd- > db () .str: ""), thd- > last_errno, (uint) thd- > killed

Schema:

M_db Name of the current (default) database.If there is the current (default) database, "db" contains its name. If there is no current (default) database, "db" is NULL and "db_length" is 0. In other words, "db", "db_length" must either be NULL, or contain a valid database name.

Last_errno:

Variable last_errno contains the last error/warning acquired during query execution.

Killed: this represents the error code for termination. The source code is as follows:

Enum killed_state

{

NOT_KILLED=0

KILL_BAD_DATA=1

KILL_CONNECTION=ER_SERVER_SHUTDOWN

KILL_QUERY=ER_QUERY_INTERRUPTED

KILL_TIMEOUT=ER_QUERY_TIMEOUT

KILLED_NO_VALUE / * means neither of the states * /

}

It is represented in the error code as follows:

{"ER_SERVER_SHUTDOWN", 1053, "Server shutdown in progress"}

{"ER_QUERY_INTERRUPTED", 1317, "Query execution was interrupted"}

{"ER_QUERY_TIMEOUT", 1886, "Query execution was interrupted, max_statement_time exceeded"}

4. Part IV implementation information

This part is probably the most concerned part, and a lot of information will be output by default.

# Query_time: 19.254508 Lock_time: 0.001043 Rows_sent: 0 Rows_examined: 0 Rows_affected: 0 # Bytes_sent: 44 Tmp_tables: 0 Tmp_disk_tables: 0 Tmp_table_sizes: 0 # InnoDB_trx_id: 0

Corresponding code:

My_b_printf (& log_file, "# Schema:% s Last_errno:% u Killed:% u\ n" # Query_time:% s Lock_time:% s Rows_sent:% llu "Rows_examined:% llu Rows_affected:% llu\ n" # Bytes_sent:% lu ", (thd- > db (). Str? Thd- > db (). Str: ""), thd- > last_errno, (uint) thd- > killed, query_time_buff, lock_time_buff, (ulonglong) thd- > get_sent_row_count (), (ulonglong) thd- > get_examined_row_count () (thd- > get_row_count_func () > 0)? (ulonglong) thd- > get_row_count_func (): 0, (ulong) (thd- > status_var.bytes_sent-thd- > bytes_sent_old) my_b_printf (& log_file, "Tmp_tables:% lu Tmp_disk_tables:% lu"Tmp_table_sizes:% llu", thd- > tmp_tables_used, thd- > tmp_tables_disk_used Thd- > tmp_tables_size) snprintf (buf, 20, "% llX", thd- > innodb_trx_id) And thd- > innodb_trx_id

Query_time: the time it takes to execute the statement and the actual elapsed time.

Lock_time: contains the sum of MDL lock and InnoDB row lock and MyISAM table lock elapsed time and lock wait time. It has been described earlier (in fact, it is not all the time of the lock wait, but the lock wait is included).

Let's take a look at the source of Query_time and Lock_time, which come from the Query_logger::slow_log_write function as follows: query_utime= (current_utime > thd- > start_utime)? (current_utime-thd- > start_utime): 0; lock_utime= (thd- > utime_after_lock > thd- > start_utime)? (thd- > utime_after_lock-thd- > start_utime): 0; the following is the source of the data current_utime, current_utime= thd- > current_utime (); in fact, it is: while (gettimeofday (& t, NULL)! = 0) {} newtime= (ulonglong) t.tv_sec * 1000000 + t.t utime_after_lock; return newtime; only gets the current time. I have described the acquisition of thd- > utime_after_lock earlier and will not explain it any more.

Rows_sent: the number of lines sent to the mysql client. Here is the explanation in the source code

Number of rows we actually sent to the client

The number of lines scanned by the Rows_examined:InnoDB engine layer, the following is the explanation in the source code. (remarks stack frame 1)

Number of rows read and/or evaluated for a statement. Used for slow log reporting.

An examined row is defined as a row that is read and/or evaluated

According to a statement condition, including increate_sort_index (). Rows may be counted more than once, e.g.a statement including ORDER BY could possibly evaluate the row in filesort () before reading it for e.g. Update.

Rows_affected: when it comes to modifications (such as DML statements) this is the number of rows affected.

For DML statements: to the number of affected rows

For DDL statements: to 0.

Bytes_sent: the number of bytes of actual data sent to the client, which comes from the

(ulong) (thd- > status_var.bytes_sent-thd- > bytes_sent_old)

Tmp_tables: the number of temporary tables.

Tmp_disk_tables: the number of disk temporary tables.

Tmp_table_sizes: the size of the temporary table.

The above three indicators come from:

Thd- > tmp_tables_usedthd- > tmp_tables_disk_usedthd- > tmp_tables_size

The position of the increase of these three metrics is as follows in the free_tmp_table function:

Thd- > tmp_tables_used++; if (entry- > file) {thd- > tmp_tables_size + = entry- > file- > stats.data_file_length; if (entry- > file- > ht- > db_type! = DB_TYPE_HEAP) thd- > tmp_tables_disk_used++;}

InnoDB_trx_id: ID of things, that is, trx- > idjinjinzhiyuo!

< transaction id */ 5、第五部分优化器相关信息 # QC_Hit: No Full_scan: No Full_join: No Tmp_table: No Tmp_table_on_disk: No # Filesort: No Filesort_on_disk: No Merge_passes: 0 这一行来自于如下代码： my_b_printf(&log_file, "# QC_Hit: %s Full_scan: %s Full_join: %s Tmp_table: %s " "Tmp_table_on_disk: %s\n" \ "# Filesort: %s Filesort_on_disk: %s Merge_passes: %lu\n", ((thd->

Query_plan_flags & QPLAN_QC)? "Yes": "No"), (thd- > query_plan_flags & QPLAN_FULL_SCAN)? "Yes": "No"), (thd- > query_plan_flags & QPLAN_FULL_JOIN)? "Yes": "No"), (thd- > query_plan_flags & QPLAN_TMP_TABLE)? "Yes": "No"), (thd- > query_plan_flags & QPLAN_TMP_DISK)? "Yes": "No"), (thd- > query_plan_flags & QPLAN_FILESORT)? "Yes": "No"), (thd- > query_plan_flags & QPLAN_FILESORT_DISK)? "Yes": "No")

Note a processing technique here, where each bit in the query_plan_flags represents a meaning, so that storage can store enough information while having very little storage space, which is a common way in Cmax Clipper +.

QC_Hit: No: whether query cache is hit.

Full_scan: this is equivalent to the meaning of Select_scan, whether a full scan has been performed, including using index.

Full_join: this is equivalent to the meaning of Select_full_join, whether the index is used by the driven table, and YES if it is not used.

Consider the following implementation plan

Mysql > desc select *, sleep (1) from testuin a minute testuin1b where a.id1=b.id1 +- -+ | id | select_type | table | partitions | type | possible_keys | key | key_len | ref | rows | Extra | + -+-+-- + | 1 | SIMPLE | a | NULL | | ALL | NULL | NULL | NULL | NULL | 5 | 100.00 | NULL | | 1 | SIMPLE | b | NULL | ALL | NULL | NULL | NULL | NULL | 5 | 100.00 | Using where | Using join buffer (Block Nested Loop) | +-- +- -+ 2 rows in set 1 warning (0.00 sec)

The output is as follows:

# QC_Hit: No Full_scan: Yes Full_join: Yes

Tmp_table: whether or not a temporary table is used is set in the function create_tmp_table.

Tmp_table_on_disk: whether the disk temporary table is used, and if so, the innodb engine is set in the create_innodb_tmp_table function.

Filesort: whether it is sorted or not is set in the function filesort.

Filesort_on_disk: whether disk sorting is used is also set in the function filesort, but it is determined whether a disk sort file is needed before setting it.

Merge_passes: the number of times for multipath merging and sorting.

Variable query_plan_fsort_passes collects information about file sort passes

Acquired during query execution.

6. Part VI InnoDB-related information

# InnoDB_IO_r_ops: 0 InnoDB_IO_r_bytes: 0 InnoDB_IO_r_wait: 0.000000 # InnoDB_rec_lock_wait: 0.000000 InnoDB_queue_wait: 0.000000 # InnoDB_pages_distinct: 0

This line comes from the following code:

Char buf [3] [20]; snprintf (buf [0], 20, ".6f", thd- > innodb_io_reads_wait_timer / 1000000.0); snprintf (buf [1], 20, ".6f", thd- > innodb_lock_que_wait_timer / 1000000.0); snprintf (buf [2], 20, ".6f", thd- > innodb_innodb_que_wait_timer / 1000000.0) If (& log_file, "# InnoDB_IO_r_ops:% lu InnoDB_IO_r_bytes:% llu"InnoDB_IO_r_wait:% s\ n" # InnoDB_rec_lock_wait:% s InnoDB_queue_wait:% s\ n "# InnoDB_pages_distinct:% lu\ n", thd- > innodb_io_reads, thd- > innodb_io_read Buf [0], buf [1], buf [2], thd- > innodb_page_access) = (uint)-1)

InnoDB_IO_r_ops: the number of physical IO reads.

InnoDB_IO_r_bytes: the total number of bytes read by the physical IO.

InnoDB_IO_r_wait: the time that physical IO reads wait. Innodb uses BUF_IO_READ to mark physical io reads as busy, referring to the function buf_wait_for_read.

InnoDB_rec_lock_wait: the time it takes to wait for a row lock. Set in the function que_thr_end_lock_wait.

InnoDB_queue_wait: the time spent waiting to enter the innodb engine is set in the function srv_conc_enter_innodb_with_atomics. (refer to http://blog.itpub.net/7728585/viewspace-2140446/)

InnoDB_pages_distinct: the number of pages accessed by innodb, including physical and logical IO, set by the _ increment_page_get_statistics function at the end of the function buf_page_get_gen.

7. Part VII set timestamp

SET timestamp=1527753496

This sentence comes from the source code. Note that the source code comment interpretation is the current time (current_utime) of the server obtained.

/ * This info used to show up randomly, depending on whether the query checked the query start time or not. Now we always write current timestamp to the slow log * / end= my_stpcpy (end, ", timestamp="); end= int10_to_str ((long) (current_utime / 1000000), end, 10); if (end! = buff) {* end++=';'; * end='\ n' If (my_b_write (& log_file, (uchar*) "SET", 4) | | my_b_write (& log_file, (uchar*) buff + 1, (uint) (end-buff) goto err;}

VII. Summary

This article through the query source code to explain some of the MySQL slow query related knowledge, mainly explains the slow query is based on what standard to record, while the meaning of each index in the output, of course, this is only my own results, if there are different opinions can be discussed together.

Remarks stack frame 1:

The frame of this stack mainly tracks the changes of Rows_examined and join- > examined_rows++;

(gdb) info bNum Type Disp Enb Address What1 breakpoint keep y 0x0000000000ebd5f3 in main (int Char**) at / root/mysql5.7.14/percona-server-5.7.14-7/sql/main.cc:25 breakpoint already hit 1 time4 breakpoint keep y 0x000000000155b94f in do_select (JOIN*) at / root/mysql5.7.14/percona-server-5.7.14-7/sql/sql_executor.cc:872 breakpoint already hit 5 times 5 breakpoint keep y 0x000000000155ca39 in evaluate_join_record (JOIN* QEP_TAB*) at / root/mysql5.7.14/percona-server-5.7.14-7/sql/sql_executor.cc:1473 breakpoint already hit 20 times 6 breakpoint keep y 0x00000000019b4313 in ha_innobase::index_first (uchar*) at / root/mysql5.7.14/percona-server-5.7.14-7/storage/innobase/handler/ha _ innodb.cc:9547 breakpoint already hit 4 times 7 breakpoint keep y 0x00000000019b45cd in ha_innobase::rnd_next (uchar*) at / root/mysql5.7.14/percona-server-5.7.14-7/storage/innobase/handler/ha_innodb.cc:96518 breakpoint keep y 0x00000000019b2ba6 in ha_innobase::index_read (uchar* Uchar const*, uint Ha_rkey_function) at / root/mysql5.7.14/percona-server-5.7.14-7/storage/innobase/handler/ha_innodb.cc:9004 breakpoint already hit 3 times 9 breakpoint keep y 0x00000000019b4233 in ha_innobase::index_next (uchar*) at / root/mysql5.7.14/percona-server-5.7.14-7/storage/innobase/handler/ha_innodb.cc:9501 breakpoint already hit 5 times # 0 ha_innobase::index_next (this=0x7fff2cbc6b40 Buf=0x7fff2cbc7080 "\ 375\ n") at / root/mysql5.7.14/percona-server-5.7.14-7/storage/innobase/handler/ha_innodb.cc:9501 # 1 0x0000000000f680d8 in handler::ha_index_next (this=0x7fff2cbc6b40 Buf=0x7fff2cbc7080 "\ 375\ n") at / root/mysql5.7.14/percona-server-5.7.14-7/sql/handler.cc:3269 # 2 0x000000000155fa02 in join_read_next (info=0x7fff2c007750) at / root/mysql5.7.14/percona-server-5.7.14-7/sql/sql_executor.cc:2660 # 3 0x000000000155c397 in sub_select (join=0x7fff2c007020, qep_tab=0x7fff2c007700 End_of_records=false) at / root/mysql5.7.14/percona-server-5.7.14-7/sql/sql_executor.cc:1274 # 4 0x000000000155bd06 in do_select (join=0x7fff2c007020) at / root/mysql5.7.14/percona-server-5.7.14-7/sql/sql_executor.cc:944 # 5 0x0000000001559bdc in JOIN::exec (this=0x7fff2c007020) at / root/mysql5.7.14/percona-server-5.7.14-7/sql/sql_executor.cc:199 # 6 0x00000000015f9ea6 in handle_query (thd=0x7fff2c000b70, lex=0x7fff2c003150 Result=0x7fff2c006cd0, added_options=0, removed_options=0) at / root/mysql5.7.14/percona-server-5.7.14-7/sql/sql_select.cc:184 # 7 0x00000000015acd05 in execute_sqlcom_select (thd=0x7fff2c000b70, all_tables=0x7fff2c006688) at / root/mysql5.7.14/percona-server-5.7.14-7/sql/sql_parse.cc:5391 # 8 0x00000000015a5320 in mysql_execute_command (thd=0x7fff2c000b70 First_level=true) at / root/mysql5.7.14/percona-server-5.7.14-7/sql/sql_parse.cc:2889 # 9 0x00000000015adcd6 in mysql_parse (thd=0x7fff2c000b70, parser_state=0x7ffff035b600) at / root/mysql5.7.14/percona-server-5.7.14-7/sql/sql_parse.cc:5836 # 10 0x00000000015a1b95 in dispatch_command (thd=0x7fff2c000b70, com_data=0x7ffff035bd70 Command=COM_QUERY) at / root/mysql5.7.14/percona-server-5.7.14-7/sql/sql_parse.cc:1447 # 11 0x00000000015a09c6 in do_command (thd=0x7fff2c000b70) at / root/mysql5.7.14/percona-server-5.7.14-7/sql/sql_parse.cc:1010 # 12 0x00000000016e29d0 in handle_connection (arg=0x3859ae0) at / root/mysql5.7.14/percona-server-5.7.14-7 * Thread.cc:312 # 13 0x0000000001d7bfdc in pfs_spawn_thread (arg=0x38607b0) at / root/mysql5.7.14/percona-server-5.7.14-7/storage/perfschema/pfs.cc:2188 # 14 0x0000003f74807aa1 in start_thread () from / lib64/libpthread.so.0 # 15 0x0000003f740e8bcd in clone () from / lib64/libc.so.6 is the principle of slow query records in MySQL The editor believes that there are some knowledge points that we may see or use in our daily work. I hope you can learn more from this article. For more details, please follow the industry information channel.

Welcome to subscribe "Shulou Technology Information " to get latest news, interesting things and hot topics in the IT industry, and controls the hottest and latest Internet news, technology news and IT industry trends.