【 使用环境 】 测试环境
【 OB or 其他组件 】OB
【 使用版本 】4.2.1-10BP
【问题描述】
如图显示，当前正在执行的sql为java应用执行的sql。已经395s了。
直接copy上图中info中的sql在navicat执行。秒出结果。
怎么排查问题···
是不是第一次硬解析导致的慢？有再次在java上执行么
1 个赞
这个sql执行好多次了。有时候快， 有时候就卡着不动了。
java和navicat连接都是通过obproxy连接的
1 个赞
麻烦发一下执行计划看看
explain extended
麻烦跟根据sql id
查询下select * from GV$OB_SQL_AUDIT where sql_id=‘xxxxxx’;
jdbc的url脱敏发下
1 个赞
jdbc:mysql://192.xxx.xxx.xxx:2883/xxxxx?zeroDateTimeBehavior=convertToNull&allowMultiQueries=true&useTimezone=true&serverTimezone=GMT%2B8
1 个赞
当前已无法复现卡sql的情况。但是java应用重新执行这个sql。sqlid还是和之前截图的一致
| SVR_PORT | REQUEST_ID | SQL_EXEC_ID | TRACE_ID | SID | CLIENT_IP | CLIENT_PORT | TENANT_ID | TENANT_NAME | EFFECTIVE_TENANT_ID | USER_ID | USER_NAME | USER_GROUP | USER_CLIENT_IP | DB_ID | DB_NAME | SQL_ID | PLAN_ID | AFFECTED_ROWS | RETURN_ROWS | PARTITION_CNT | RET_CODE | QC_ID | DFO_ID | SQC_ID | WORKER_ID | EVENT | P1TEXT | P1 | P2TEXT | P2 | P3TEXT | P3 | LEVEL | WAIT_CLASS_ID | WAIT_CLASS# | WAIT_CLASS | STATE | WAIT_TIME_MICRO | TOTAL_WAIT_TIME_MICRO | TOTAL_WAITS | RPC_COUNT | PLAN_TYPE | IS_INNER_SQL | IS_EXECUTOR_RPC | IS_HIT_PLAN | REQUEST_TIME | ELAPSED_TIME | NET_TIME | NET_WAIT_TIME | QUEUE_TIME | DECODE_TIME | GET_PLAN_TIME | EXECUTE_TIME | APPLICATION_WAIT_TIME | CONCURRENCY_WAIT_TIME | USER_IO_WAIT_TIME | SCHEDULE_TIME | ROW_CACHE_HIT | BLOOM_FILTER_CACHE_HIT | BLOCK_CACHE_HIT | DISK_READS | RETRY_CNT | TABLE_SCAN | CONSISTENCY_LEVEL | MEMSTORE_READ_ROW_COUNT | SSSTORE_READ_ROW_COUNT | DATA_BLOCK_READ_CNT | DATA_BLOCK_CACHE_HIT | INDEX_BLOCK_READ_CNT | INDEX_BLOCK_CACHE_HIT | BLOCKSCAN_BLOCK_CNT | BLOCKSCAN_ROW_CNT | PUSHDOWN_STORAGE_FILTER_ROW_CNT | REQUEST_MEMORY_USED | EXPECTED_WORKER_COUNT | USED_WORKER_COUNT | SCHED_INFO | FUSE_ROW_CACHE_HIT | PS_CLIENT_STMT_ID | PS_INNER_STMT_ID | TX_ID | SNAPSHOT_VERSION | REQUEST_TYPE | IS_BATCHED_MULTI_STMT | OB_TRACE_INFO | PLAN_HASH | LOCK_FOR_READ_TIME | PARAMS_VALUE | RULE_NAME | PARTITION_HIT | TX_INTERNAL_ROUTING | TX_STATE_VERSION | FLT_TRACE_ID | NETWORK_WAIT_TIME |
|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|
| 2882 | 210439193 | 719250788 | YB42C0A8007C-00062B52672C6F26-0-0 | 3221626779 | 192.168.0.124 | 11996 | 1002 | epean | 1002 | 500003 | epean_trade_test | 0 | 192.168.6.177 | 500005 | ep_trade_test | 6C12176CD408A1901A2F9EC00B44AA83 | 806295 | 0 | 0 | 8 | 0 | 0 | 0 | 0 | 0 | px loop condition wait | address | 140517387122384 | 0 | 0 | 0 | 104 | 4 | CONCURRENCY | WAITED SHORT TIME | 1072 | 3418 | 5 | 1 | 3 | 0 | 0 | 0 | 1744248207524856 | 18490 | 0 | 3 | 33 | 1 | 15190 | 3240 | 0 | 3418 | 988 | 0 | 0 | 0 | 40 | 2 | 0 | 0 | 3 | 1 | 222 | 3 | 3 | 6 | 3 | 0 | 0 | 0 | 6417248 | 0 | 0 | 0 | -1 | -1 | 0 | 1744248207540115067 | 2 | 0 | 5282984146276229343 | 0 | 1 | 0 | 0 | 00063262-6ecf-4386-d6ed-7ec3bb305564 | 0 | ||||||
| 2882 | 210439195 | 719250799 | YB42C0A8007C-00062B52672C6F28-0-0 | 3221626779 | 192.168.0.124 | 11996 | 1002 | epean | 1002 | 500003 | epean_trade_test | 0 | 192.168.6.177 | 500005 | ep_trade_test | 6C12176CD408A1901A2F9EC00B44AA83 | 806295 | 0 | 0 | 8 | 0 | 0 | 0 | 0 | 0 | px loop condition wait | address | 140521165113584 | 0 | 0 | 0 | 104 | 4 | CONCURRENCY | WAITED SHORT TIME | 1042 | 1448 | 2 | 1 | 3 | 0 | 0 | 1 | 1744248207554301 | 9157 | 0 | 2 | 35 | 1 | 103 | 9001 | 0 | 1448 | 0 | 0 | 0 | 0 | 36 | 0 | 0 | 0 | 3 | 0 | 4372 | 2188 | 2188 | 8746 | 2187 | 0 | 0 | 0 | 2022696 | 0 | 0 | 0 | -1 | -1 | 0 | 1744248207554464647 | 2 | 0 | 5282984146276229343 | 0 | 1 | 0 | 0 | 0 | |||||||
| 2882 | 210439197 | 719250802 | YB42C0A8007C-00062B52672C6F2A-0-0 | 3221626779 | 192.168.0.124 | 11996 | 1002 | epean | 1002 | 500003 | epean_trade_test | 0 | 192.168.6.177 | 500005 | ep_trade_test | 6C12176CD408A1901A2F9EC00B44AA83 | 806295 | 0 | 9 | 8 | 0 | 0 | 0 | 0 | 0 | px loop condition wait | address | 140524562499824 | 0 | 0 | 0 | 104 | 4 | CONCURRENCY | WAITED SHORT TIME | 1078 | 5494 | 6 | 1 | 3 | 0 | 0 | 1 | 1744248207575933 | 17885 | 0 | 2 | 66 | 1 | 87 | 17716 | 0 | 5494 | 0 | 0 | 109 | 0 | 82 | 0 | 0 | 0 | 3 | 9 | 4073 | 2099 | 2099 | 8060 | 2098 | 0 | 0 | 0 | 2887656 | 0 | 0 | 0 | -1 | -1 | 0 | 1744248207576106900 | 2 | 0 | 5282984146276229343 | 0 | 1 | 0 | 0 | 0 | |||||||
| 2882 | 210439315 | 719250975 | YB42C0A8007C-00062B52672C6F2F-0-0 | 3221626779 | 192.168.0.124 | 11996 | 1002 | epean | 1002 | 500003 | epean_trade_test | 0 | 192.168.6.177 | 500005 | ep_trade_test | 6C12176CD408A1901A2F9EC00B44AA83 | 806295 | 0 | 1010 | 8 | 0 | 0 | 0 | 0 | 0 | px loop condition wait | address | 140509649651952 | 0 | 0 | 0 | 104 | 4 | CONCURRENCY | WAITED SHORT TIME | 1112 | 45332 | 79 | 1 | 3 | 0 | 0 | 1 | 1744248209545001 | 221685 | 0 | 3 | 34 | 0 | 112 | 221519 | 0 | 42285 | 14195 | 0 | 1 | 0 | 1306 | 168 | 0 | 0 | 3 | 4111 | 57032 | 33182 | 33014 | 124372 | 33167 | 12 | 23479 | 0 | 4929840 | 0 | 0 | 0 | -1 | -1 | 0 | 1744248209545173770 | 2 | 0 | 5282984146276229343 | 0 | 1 | 0 | 0 | 0 | |||||||
| 2882 | 210440472 | 719252902 | YB42C0A8007C-00062B52672C6F4D-0-0 | 3221626779 | 192.168.0.124 | 11996 | 1002 | epean | 1002 | 500003 | epean_trade_test | 0 | 192.168.6.177 | 500005 | ep_trade_test | 6C12176CD408A1901A2F9EC00B44AA83 | 806295 | 0 | 65 | 8 | 0 | 0 | 0 | 0 | 0 | px loop condition wait | address | 140530145118448 | 0 | 0 | 0 | 104 | 4 | CONCURRENCY | WAITED SHORT TIME | 979 | 1329 | 2 | 1 | 3 | 0 | 0 | 1 | 1744248221518102 | 34685 | 0 | 3 | 48 | 1 | 126 | 34490 | 0 | 1329 | 0 | 0 | 14 | 0 | 203 | 3 | 0 | 0 | 3 | 424 | 12585 | 6739 | 6736 | 26094 | 6736 | 2 | 3794 | 0 | 3623272 | 0 | 0 | 0 | -1 | -1 | 0 | 1744248221518304470 | 2 | 0 | 5282984146276229343 | 0 | 1 | 0 | 0 | 0 | |||||||
| 2882 | 210440516 | 719253040 | YB42C0A8007C-00062B520E5748D5-0-0 | 3221626779 | 192.168.0.124 | 11996 | 1002 | epean | 1002 | 500003 | epean_trade_test | 0 | 192.168.6.177 | 500005 | ep_trade_test | 6C12176CD408A1901A2F9EC00B44AA83 | 806295 | 0 | 0 | 8 | 0 | 0 | 0 | 0 | 0 | px loop condition wait | address | 140515326642416 | 0 | 0 | 0 | 104 | 4 | CONCURRENCY | WAITED SHORT TIME | 1078 | 1489 | 3 | 1 | 3 | 0 | 0 | 1 | 1744248223100197 | 12319 | 0 | 4 | 28 | 0 | 116 | 12159 | 0 | 1489 | 0 | 0 | 0 | 0 | 55 | 0 | 0 | 0 | 3 | 0 | 4856 | 2610 | 2610 | 10074 | 2609 | 0 | 0 | 0 | 2476776 | 0 | 0 | 0 | -1 | -1 | 0 | 1744248223100362450 | 2 | 0 | 5282984146276229343 | 0 | 1 | 0 | 0 | 0 | |||||||
| 2882 | 210440518 | 719253055 | YB42C0A8007C-00062B52672C6F52-0-0 | 3221626779 | 192.168.0.124 | 11996 | 1002 | epean | 1002 | 500003 | epean_trade_test | 0 | 192.168.6.177 | 500005 | ep_trade_test | 6C12176CD408A1901A2F9EC00B44AA83 | 806295 | 0 | 0 | 8 | 0 | 0 | 0 | 0 | 0 | px loop condition wait | address | 140521953642736 | 0 | 0 | 0 | 104 | 4 | CONCURRENCY | WAITED SHORT TIME | 957 | 1349 | 2 | 1 | 3 | 0 | 0 | 1 | 1744248223119628 | 59373 | 0 | 3 | 59 | 0 | 176 | 59082 | 0 | 1349 | 0 | 0 | 0 | 0 | 84 | 0 | 0 | 0 | 3 | 1 | 40159 | 21196 | 21196 | 82526 | 21185 | 11 | 18716 | 0 | 3984520 | 0 | 0 | 0 | -1 | -1 | 0 | 1744248223119930371 | 2 | 0 | 5282984146276229343 | 0 | 1 | 0 | 0 | 00063262-6fbd-38b8-6e48-0d58884017dd | 0 | ||||||
| 2882 | 210440520 | 719253066 | YB42C0A8007C-00062B52672C6F54-0-0 | 3221626779 | 192.168.0.124 | 11996 | 1002 | epean | 1002 | 500003 | epean_trade_test | 0 | 192.168.6.177 | 500005 | ep_trade_test | 6C12176CD408A1901A2F9EC00B44AA83 | 806295 | 0 | 0 | 8 | 0 | 0 | 0 | 0 | 0 | px loop condition wait | address | 140521953642736 | 0 | 0 | 0 | 104 | 4 | CONCURRENCY | WAITED SHORT TIME | 887 | 1237 | 2 | 1 | 3 | 0 | 0 | 1 | 1744248223184791 | 8299 | 0 | 2 | 39 | 0 | 78 | 8170 | 0 | 1237 | 0 | 0 | 0 | 0 | 30 | 0 | 0 | 0 | 3 | 0 | 3282 | 1730 | 1730 | 6740 | 1729 | 0 | 0 | 0 | 2427752 | 0 | 0 | 0 | -1 | -1 | 0 | 1744248223184924368 | 2 | 0 | 5282984146276229343 | 0 | 1 | 0 | 0 | 0 | |||||||
| 2882 | 210440522 | 719253068 | YB42C0A8007C-00062B52672C6F56-0-0 | 3221626779 | 192.168.0.124 | 11996 | 1002 | epean | 1002 | 500003 | epean_trade_test | 0 | 192.168.6.177 | 500005 | ep_trade_test | 6C12176CD408A1901A2F9EC00B44AA83 | 806295 | 0 | 0 | 8 | 0 | 0 | 0 | 0 | 0 | px loop condition wait | address | 140521953642736 | 0 | 0 | 0 | 104 | 4 | CONCURRENCY | WAITED SHORT TIME | 880 | 1214 | 2 | 1 | 3 | 0 | 0 | 1 | 1744248223196433 | 17226 | 0 | 2 | 31 | 1 | 96 | 17083 | 0 | 1214 | 0 | 0 | 0 | 0 | 69 | 0 | 0 | 0 | 3 | 0 | 9262 | 4784 | 4784 | 18824 | 4781 | 2 | 3664 | 0 | 2524904 | 0 | 0 | 0 | -1 | -1 | 0 | 1744248223196580556 | 2 | 0 | 5282984146276229343 | 0 | 1 | 0 | 0 | 0 | |||||||
| 2882 | 210440526 | 719253071 | YB42C0A8007C-00062B52672C6F58-0-0 | 3221626779 | 192.168.0.124 | 11996 | 1002 | epean | 1002 | 500003 | epean_trade_test | 0 | 192.168.6.177 | 500005 | ep_trade_test | 6C12176CD408A1901A2F9EC00B44AA83 | 806295 | 0 | 0 | 8 | 0 | 0 | 0 | 0 | 0 | px loop condition wait | address | 140521953642736 | 0 | 0 | 0 | 104 | 4 | CONCURRENCY | WAITED SHORT TIME | 824 | 1208 | 2 | 1 | 3 | 0 | 0 | 1 | 1744248223217224 | 35282 | 0 | 2 | 31 | 0 | 60 | 35179 | 0 | 1208 | 0 | 0 | 0 | 0 | 71 | 0 | 0 | 0 | 3 | 0 | 17616 | 9885 | 9885 | 37376 | 9880 | 4 | 6876 | 0 | 3866536 | 0 | 0 | 0 | -1 | -1 | 0 | 1744248223217331707 | 2 | 0 | 5282984146276229343 | 0 | 1 | 0 | 0 | 0 |
YB42C0A8007C-00062B52672C6F2F-0-0
麻烦根据这个trace id ，grep一下observer的日志
刚刚又复现了。我用最新复现的 trace_id过滤日志。
结果如下
跟踪查看日志，发现这个日志一直在刷
INFO [RPC.OBMYSQL] print_session_info (ob_sql_nio.cpp:1023) [5935][sql_nio0][T0][Y0-0000000000000000-0-0] [lt=44] [sql nio session](*s={this:0x7fcf20dc0030, session_id:3221590385, trace_id:YB42C0A8007C-00062B51BA37EB77-0-0, sql_handling_stage:11, sql_initiative_shutdown:false, fd:179, err:0, last_decode_time:1744258272666784, last_write_time:1744258272664699, pending_write_task:{buf:null, sz:0}, need_epoll_trigger_write:false, consume_size:100183, pending_flag:1, may_handling_flag:true, handler_close_flag:false})
同样的条件， java连接查询卡350+s。
navicat查询秒出。 都是返回1000+行数据
给你看的表格。是都没卡住的情况
1 个赞
ob版本，jdbc版本是什么。
麻烦提供一下sql和建表sql这边尝试复现一下
我这边在查询前，对 查询的表做了一次update。 和这个有关吗。
查询使用的优先从副本。
应该是有关系的。不进行update时候有触发过这种查询慢场景么
不先update，直接查询没有出现过问题。
但这是什么原理···
先update后查询。 查询要等待update数据同步到从副本？
不应该吧。而且这个问题不是必然复现
优先从副本你怎么设置的
刚刚检查了下。 测试集群，obproxy_read_consistency 我之前已经改回了0. 所以应该还是优先读主副本的。。。