【 使用环境 】生产环境
【 OB or 其他组件 】OB
【 使用版本 】4.3.5.3
【问题描述】一个sql本来好好的,9点开始突然变慢,然后在09:25出现一个db file data read,此时plan_id改变,然后sql恢复
mysql> SELECT plan_id, FROM_UNIXTIME(request_time / 1000000) AS time_readable, elapsed_time / 1000000 AS elapsed_sec, execute_time / 1000000 AS execute_sec, queue_time / 1000000 aiit_sec, total_waits, event, wait_class, ret_code FROM gv$ob_sql_audit where sql_id = ‘11DEF3BCB4229A9A7289F801EF8588CB’ ORDER BY request_time DESC LIMIT 100;
±--------±-------------------------±------------±------------±----------±---------------------±------------±---------------±------------±---------------------------±-----------±---------+
| plan_id | time_readable | elapsed_sec | execute_sec | queue_sec | concurrency_wait_sec | io_wait_sec | total_wait_sec | total_waits | event | wait_class | ret_code |
±--------±-------------------------±------------±------------±----------±---------------------±------------±---------------±------------±---------------------------±-----------±---------+
| 251773 | 2026-04-16 10:23:12.3369 | 0.0072 | 0.0070 | 0.0000 | 0.0000 | 0.0000 | 0.0000 | 0 | | OTHER | 0 |
| 251773 | 2026-04-16 09:52:54.3590 | 0.0060 | 0.0060 | 0.0000 | 0.0000 | 0.0000 | 0.0000 | 0 | | OTHER | 0 |
| 251773 | 2026-04-16 09:51:34.4092 | 0.0063 | 0.0062 | 0.0000 | 0.0000 | 0.0000 | 0.0000 | 0 | | OTHER | 0 |
| 251773 | 2026-04-16 09:25:34.4814 | 0.0015 | 0.0014 | 0.0000 | 0.0000 | 0.0000 | 0.0000 | 0 | | OTHER | 0 |
| 251773 | 2026-04-16 09:25:33.7172 | 0.0005 | 0.0004 | 0.0000 | 0.0000 | 0.0000 | 0.0000 | 0 | | OTHER | 0 |
| 251773 | 2026-04-16 09:25:27.2855 | 0.0029 | 0.0029 | 0.0000 | 0.0000 | 0.0000 | 0.0000 | 1 | mysql response wait client | IDLE | 0 |
| 251773 | 2026-04-16 09:25:20.7937 | 0.0014 | 0.0013 | 0.0000 | 0.0000 | 0.0000 | 0.0000 | 0 | | OTHER | 0 |
| 251773 | 2026-04-16 09:25:13.4601 | 0.0040 | 0.0039 | 0.0000 | 0.0000 | 0.0000 | 0.0000 | 0 | | OTHER | 0 |
| 251773 | 2026-04-16 09:25:04.3626 | 0.0404 | 0.0148 | 0.0000 | 0.0000 | 0.0000 | 0.0153 | 4 | db file data read | USER_IO | 0 |
| 250566 | 2026-04-16 09:24:28.4228 | 331.6604 | 331.6571 | 0.0029 | 0.0000 | 0.0000 | 0.0000 | 1 | mysql response wait client | IDLE | 0 |
| 250566 | 2026-04-16 09:23:22.7510 | 91.8451 | 91.8374 | 0.0074 | 0.0000 | 0.0000 | 0.0000 | 1 | mysql response wait client | IDLE | 0 |
| 250566 | 2026-04-16 09:22:17.5174 | 588.2520 | 588.2441 | 0.0076 | 0.0000 | 0.0000 | 0.0000 | 1 | mysql response wait client | IDLE | 0 |
| 250566 | 2026-04-16 09:21:11.7683 | 324.1719 | 324.1710 | 0.0006 | 0.0000 | 0.0000 | 0.0000 | 1 | mysql response wait client | IDLE | 0 |
| 250566 | 2026-04-16 09:20:33.5705 | 824.3398 | 824.3331 | 0.0064 | 0.0000 | 0.0000 | 0.0000 | 1 | mysql response wait client | IDLE | 0 |
| 250566 | 2026-04-16 09:20:04.7460 | 701.7351 | 701.7293 | 0.0056 | 0.0000 | 0.0000 | 0.0000 | 2 | mysql response wait client | IDLE | 0 |
| 250566 | 2026-04-16 09:19:28.2416 | 332.9931 | 332.9889 | 0.0038 | 0.0000 | 0.0000 | 0.0000 | 1 | mysql response wait client | IDLE | 0 |
| 250566 | 2026-04-16 09:18:22.5328 | 90.5519 | 90.5439 | 0.0076 | 0.0000 | 0.0000 | 0.0000 | 1 | mysql response wait client | IDLE | 0 |
| 250566 | 2026-04-16 09:17:17.3205 | 584.9209 | 584.9202 | 0.0004 | 0.0000 | 0.0000 | 0.0000 | 1 | mysql response wait client | IDLE | 0 |
| 250566 | 2026-04-16 09:16:11.5670 | 323.9192 | 323.9192 | 0.0000 | 0.0000 | 0.0000 | 0.0000 | 1 | mysql response wait client | IDLE | 0 |
| 250566 | 2026-04-16 09:15:42.9392 | 815.9480 | 815.9479 | 0.0000 | 0.0000 | 0.0000 | 0.0000 | 1 | mysql response wait client | IDLE | 0 |
| 250566 | 2026-04-16 09:15:04.6530 | 703.5977 | 703.5976 | 0.0000 | 0.0000 | 0.0000 | 0.0000 | 2 | mysql response wait client | IDLE | 0 |
| 250566 | 2026-04-16 09:14:29.1736 | 321.6011 | 321.6010 | 0.0001 | 0.0000 | 0.0000 | 0.0000 | 1 | mysql response wait client | IDLE | 0 |
| 250566 | 2026-04-16 09:13:22.6969 | 89.8041 | 89.8041 | 0.0000 | 0.0000 | 0.0000 | 0.0000 | 1 | mysql response wait client | IDLE | 0 |
| 250566 | 2026-04-16 09:12:17.4718 | 578.4517 | 578.4517 | 0.0000 | 0.0000 | 0.0000 | 0.0000 | 1 | mysql response wait client | IDLE | 0 |
| 250566 | 2026-04-16 09:11:11.6406 | 330.8125 | 330.8124 | 0.0000 | 0.0000 | 0.0000 | 0.0000 | 1 | mysql response wait client | IDLE | 0 |
| 250566 | 2026-04-16 09:10:04.6372 | 700.4624 | 700.4623 | 0.0000 | 0.0000 | 0.0000 | 0.0000 | 2 | mysql response wait client | IDLE | 0 |
| 250566 | 2026-04-16 09:08:36.4322 | 93.3553 | 93.3552 | 0.0000 | 0.0000 | 0.0000 | 0.0000 | 1 | mysql response wait client | IDLE | 0 |
| 250566 | 2026-04-16 09:07:17.3390 | 585.4390 | 585.4388 | 0.0000 | 0.0000 | 0.0000 | 0.0000 | 1 | mysql response wait client | IDLE | 0 |
| 250566 | 2026-04-16 09:06:11.2227 | 327.6217 | 327.6216 | 0.0000 | 0.0000 | 0.0000 | 0.0000 | 1 | mysql response wait client | IDLE | 0 |
| 250566 | 2026-04-16 09:05:04.3249 | 716.2226 | 716.2225 | 0.0001 | 0.0000 | 0.0000 | 0.0000 | 2 | mysql response wait client | IDLE | 0 |
| 250566 | 2026-04-16 09:01:28.9985 | 336.5416 | 336.5415 | 0.0000 | 0.0000 | 0.0000 | 0.0000 | 1 | mysql response wait client | IDLE | 0 |
| 250566 | 2026-04-16 09:00:09.4938 | 714.3588 | 714.3587 | 0.0000 | 0.0000 | 0.0000 | 0.0000 | 2 | mysql response wait client | IDLE | 0 |
| 250566 | 2026-04-16 08:43:05.7446 | 1.7812 | 1.7811 | 0.0000 | 0.0000 | 0.0000 | 0.0000 | 0 | | OTHER | 0 |
| 250566 | 2026-04-16 06:45:52.2389 | 0.0021 | 0.0019 | 0.0001 | 0.0000 | 0.0000 | 0.0000 | 0 | | OTHER | 0 |
| 250566 | 2026-04-16 05:54:25.6481 | 0.0014 | 0.0014 | 0.0000 | 0.0000 | 0.0000 | 0.0000 | 0 | | OTHER | 0 |
| 250566 | 2026-04-16 05:54:10.3157 | 0.0018 | 0.0017 | 0.0000 | 0.0000 | 0.0000 | 0.0000 | 0 | | OTHER | 0 |
| 250566 | 2026-04-16 05:47:04.0654 | 0.0022 | 0.0021 | 0.0000 | 0.0000 | 0.0000 | 0.0000 | 0 | | OTHER | 0 |
±--------±-------------------------±------------±------------±----------±---------------------±------------±---------------±------------±---------------------------±-----------±---------+
37 rows in set (2.90 sec)
考虑到9点的时候有几个ddl被执行,会不会有所关联?ddl涉及到的表和慢sql查询的表不是同一张表。
mysql> SELECT query_sql, FROM_UNIXTIME(request_time / 1000000) AS time_readable, elapsed_time / 1000000 AS elapsed_sec, execute_time / 1000000 AS execute_sec, queue_time / 1000000 AS queue_sec, concurrency_wait_time / 1000000 AS concurrency_wait_sec, user_io_wait_time / 1000000 AS io_wait_sec, total_wait_time_micro / 1000000 AS total_wait_sec, total_waits, event, wait_class, ret_code FROM gv$ob_sql_audit where FROM_UNIXTIME(request_time / 1000000) > ‘2026-04-16 08:59:00’ and FROM_UNIXTIME(request_time / 1000000)< ‘2026-04-16 09:30:00’ and (query_sql like ‘alter%’ or query_sql like ‘truncate%’) order by request_time desc ;
±----------------------------------------------------------------------------------------------------------------±-------------------------±------------±------------±----------±---------------------±------------±---------------±------------±--------------------±-----------±---------+
| query_sql | time_readable | elapsed_sec | execute_sec | queue_sec | concurrency_wait_sec | io_wait_sec | total_wait_sec | total_waits | event | wait_class | ret_code |
±----------------------------------------------------------------------------------------------------------------±-------------------------±------------±------------±----------±---------------------±------------±---------------±------------±--------------------±-----------±---------+
| TRUNCATE TABLE xxdb.xxtable2 | 2026-04-16 09:00:07.6496 | 0.5589 | 0.5586 | 0.0000 | 0.0000 | 0.0000 | 0.4987 | 36 | sync rpc | NETWORK | 0 |
| TRUNCATE TABLE xxdb.xxtable1 | 2026-04-16 09:00:07.5128 | 0.4423 | 0.4422 | 0.0000 | 0.0000 | 0.0000 | 0.3693 | 29 | sync rpc | NETWORK | 0 |
| ALTER TABLE test.test_tbl1 ADD PARTITION (PARTITION P2026041709 VALUES LESS THAN (‘2026-04-17 10:00:00’)) | 2026-04-16 09:00:02.6376 | 0.7900 | 0.7892 | 0.0000 | 0.0000 | 0.0000 | 0.6514 | 1 | exec inner sql wait | OTHER | 0 |
| ALTER TABLE test.tbl2 DROP PARTITION P2026041602 | 2026-04-16 09:00:02.1633 | 0.4719 | 0.4539 | 0.0000 | 0.0000 | 0.0000 | 0.3779 | 395 | exec inner sql wait | OTHER | 0 |
| ALTER TABLE test.tbl2 ADD PARTITION (PARTITION P2026041612 VALUES LESS THAN (‘2026-04-16 13:00:00’)) | 2026-04-16 09:00:01.3846 | 0.7773 | 0.7766 | 0.0000 | 0.0000 | 0.0000 | 0.6411 | 1 | exec inner sql wait | OTHER | 0 |
| ALTER TABLE test.tbl1 DROP PARTITION P2026041508 | 2026-04-16 09:00:00.5301 | 0.8531 | 0.8356 | 0.0000 | 0.0000 | 0.0000 | 0.6926 | 413 | exec inner sql wait | OTHER | 0 |
| ALTER TABLE test.tbl1 ADD PARTITION (PARTITION P2026041612 VALUES LESS THAN (‘2026-04-16 13:00:00’)) | 2026-04-16 09:00:00.0203 | 0.5084 | 0.5079 | 0.0000 | 0.0000 | 0.0000 | 0.4192 | 1 | exec inner sql wait | OTHER | 0 |
±----------------------------------------------------------------------------------------------------------------±-------------------------±------------±------------±----------±---------------------±------------±---------------±------------±--------------------±-----------±---------+
7 rows in set (4.37 sec)
