查询表数据时命令被Killed

查询一个5千万的表数据时命令执行了1分多钟后就被Killed了。。。这个应该设置哪个超时参数?永久设置应该怎么设置?

提示具体错误信息,是事务错误还是单sql超时。
根据错误信息,文档中心搜一下就能看到

kill现象是什么?报什么错误了

就一条select * from ds1.tipt_advice_execute_plan_log 命令而已,没有错误,执行一分钟就被killed。

根据这条sql,在GV$OB_SQL_AUDIT这个表里找出对应的trace_id,然后根据trace_id过滤下错误日志,看下是什么原因导致的kill

这个是在GV$OB_SQL_AUDIT查询到的,能看出原因吗?

SVR_IP 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 QUERY_SQL 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
172.18.95.161 2882 1101187 23759546 YB42AC125FA1-0005FFC97118D64C-0-0 3222156995 172.18.95.159 35036 1004 jmzz_tenant 1004 200001 root 0 172.18.95.158 18446744073709551615 CEE1A1129847A1E62D001F13BC5A424E select * from ds1.tipt_advice_execute_plan_log 5666 0 13764585 1 -4009 0 0 0 0 0 0 0 0 100 0 OTHER MAX_WAIT TIME ZERO 0 0 0 0 1 0 0 1 1688712024853791 62891405 0 2 18 1 37 62891333 0 0 0 0 0 0 13260 0 0 1 3 0 13764664 13152 13152 109 108 13130 13765436 0 205088 0 0 \N 0 -1 -1 0 1688712024844894924 2 0 \N 12916817122871780169 0 1 0 0


需要根据这个trace_id,到observer的日志目录下,过滤日志内容,看下sql为什么被kill
grep “trace_id” observer.log*

RET_CODE=-4009 官方提示是相关IO错误。

你把timeout相关的变量提供出来,看一看:show variables like ‘%timeout%’;

这个是跟踪到的日志

[2023-07-07 16:58:28.836733] INFO [RPC.OBMYSQL] write_data (ob_sql_nio.cpp:393) [799531][T1004_L0_G0][T1004][YB42AC125FA1-0005FFC97118D66B-0-0] [lt=4] write cond wakeup
[2023-07-07 16:58:28.838552] INFO [RPC.OBMYSQL] write_data (ob_sql_nio.cpp:393) [799531][T1004_L0_G0][T1004][YB42AC125FA1-0005FFC97118D66B-0-0] [lt=10] write cond wakeup
[2023-07-07 16:58:28.902155] INFO [RPC.OBMYSQL] write_data (ob_sql_nio.cpp:393) [799531][T1004_L0_G0][T1004][YB42AC125FA1-0005FFC97118D66B-0-0] [lt=6] write cond wakeup
[2023-07-07 16:58:28.917828] INFO [RPC.OBMYSQL] write_data (ob_sql_nio.cpp:393) [799531][T1004_L0_G0][T1004][YB42AC125FA1-0005FFC97118D66B-0-0] [lt=12] write cond wakeup
[2023-07-07 16:58:29.097540] INFO [RPC.OBMYSQL] write_data (ob_sql_nio.cpp:393) [799531][T1004_L0_G0][T1004][YB42AC125FA1-0005FFC97118D66B-0-0] [lt=9] write cond wakeup
[2023-07-07 16:58:31.467888] INFO [RPC.OBMYSQL] write_data (ob_sql_nio.cpp:393) [799531][T1004_L0_G0][T1004][YB42AC125FA1-0005FFC97118D66B-0-0] [lt=8] write cond wakeup
[2023-07-07 16:58:32.544932] INFO [RPC.OBMYSQL] write_data (ob_sql_nio.cpp:393) [799531][T1004_L0_G0][T1004][YB42AC125FA1-0005FFC97118D66B-0-0] [lt=7] write cond wakeup
[2023-07-07 16:58:51.521751] INFO [RPC.OBMYSQL] print_session_info (ob_sql_nio.cpp:980) [40573][sql_nio0][T0][Y0-0000000000000000-0-0] [lt=10] [sql nio session](*s={this:0x7f36509c5290, fd:258, err:0, last_decode_time_:1688720308801658, last_write_time_:1688720331521735, read_buffer_.get_consume_sz():808, get_pending_flag():1, get_trace_id():YB42AC125FA1-0005FFC97118D66B-0-0})
[2023-07-07 16:59:07.241289] INFO [RPC.OBMYSQL] print_session_info (ob_sql_nio.cpp:980) [40573][sql_nio0][T0][Y0-0000000000000000-0-0] [lt=10] [sql nio session](*s={this:0x7f36509c5290, fd:258, err:0, last_decode_time_:1688720308801658, last_write_time_:1688720347241236, read_buffer_.get_consume_sz():808, get_pending_flag():1, get_trace_id():YB42AC125FA1-0005FFC97118D66B-0-0})
[2023-07-07 16:59:22.993065] INFO [RPC.OBMYSQL] print_session_info (ob_sql_nio.cpp:980) [40573][sql_nio0][T0][Y0-0000000000000000-0-0] [lt=7] [sql nio session](*s={this:0x7f36509c5290, fd:258, err:0, last_decode_time_:1688720308801658, last_write_time_:1688720362992954, read_buffer_.get_consume_sz():808, get_pending_flag():1, get_trace_id():YB42AC125FA1-0005FFC97118D66B-0-0})
[2023-07-07 16:59:26.980788] INFO [RPC.OBMYSQL] write_data (ob_sql_nio.cpp:393) [799531][T1004_L0_G0][T1004][YB42AC125FA1-0005FFC97118D66B-0-0] [lt=9] write cond wakeup
[2023-07-07 16:59:28.063419] INFO [RPC.OBMYSQL] write_data (ob_sql_nio.cpp:393) [799531][T1004_L0_G0][T1004][YB42AC125FA1-0005FFC97118D66B-0-0] [lt=10] write cond wakeup
[2023-07-07 16:59:29.063495] INFO [RPC.OBMYSQL] write_data (ob_sql_nio.cpp:393) [799531][T1004_L0_G0][T1004][YB42AC125FA1-0005FFC97118D66B-0-0] [lt=12] write cond wakeup
[2023-07-07 16:59:29.811814] WDIAG [RPC.OBMYSQL] handle_sock_event (ob_sql_nio.cpp:818) [40573][sql_nio0][T0][Y0-0000000000000000-0-0] [lt=11][errcode=-4015] sock error detect by epoll(mask=8221, *s={this:0x7f36509c5290, fd:258, err:5, last_decode_time_:1688720308801658, last_write_time_:1688720367063267, read_buffer_.get_consume_sz():808, get_pending_flag():1, get_trace_id():YB42AC125FA1-0005FFC97118D66B-0-0})
[2023-07-07 16:59:30.063551] INFO [RPC.OBMYSQL] write_data (ob_sql_nio.cpp:393) [799531][T1004_L0_G0][T1004][YB42AC125FA1-0005FFC97118D66B-0-0] [lt=8] write cond wakeup
[2023-07-07 16:59:30.063563] WDIAG [RPC.OBMYSQL] write_data (ob_sql_nio.cpp:398) [799531][T1004_L0_G0][T1004][YB42AC125FA1-0005FFC97118D66B-0-0] [lt=10][errcode=-4009] write data error(errno=104)
[2023-07-07 16:59:30.063568] WDIAG [RPC.OBMYSQL] push_close_req (ob_sql_nio.cpp:707) [799531][T1004_L0_G0][T1004][YB42AC125FA1-0005FFC97118D66B-0-0] [lt=5][errcode=-4015] user req close, and epoll thread already set error(*s={this:0x7f36509c5290, fd:258, err:5, last_decode_time_:1688720308801658, last_write_time_:1688720370063567, read_buffer_.get_consume_sz():808, get_pending_flag():2, get_trace_id():YB42AC125FA1-0005FFC97118D66B-0-0})
[2023-07-07 16:59:30.063578] WDIAG [SERVER] flush_buffer (obmp_packet_sender.cpp:936) [799531][T1004_L0_G0][T1004][YB42AC125FA1-0005FFC97118D66B-0-0] [lt=9][errcode=-4009] write response fail(ret=-4009)
[2023-07-07 16:59:30.063582] WDIAG [SERVER] try_encode_with (obmp_packet_sender.cpp:846) [799531][T1004_L0_G0][T1004][YB42AC125FA1-0005FFC97118D66B-0-0] [lt=3][errcode=-4009] failed to flush_buffer(ret=-4009, last_ret=-4019)
[2023-07-07 16:59:30.063586] WDIAG [SERVER] response_packet (obmp_packet_sender.cpp:284) [799531][T1004_L0_G0][T1004][YB42AC125FA1-0005FFC97118D66B-0-0] [lt=3][errcode=-4009] failed to encode packet(ret=-4009)
[2023-07-07 16:59:30.063589] WDIAG [SERVER] response_query_result (ob_query_driver.cpp:209) [799531][T1004_L0_G0][T1004][YB42AC125FA1-0005FFC97118D66B-0-0] [lt=3][errcode=-4009] response packet fail(ret=-4009, row=0x7f35518cef58, row_num=13792907, can_retry=false)
[2023-07-07 16:59:30.063594] WDIAG [SERVER] response_query_result (ob_query_driver.cpp:230) [799531][T1004_L0_G0][T1004][YB42AC125FA1-0005FFC97118D66B-0-0] [lt=4][errcode=-4009] fail to iterate and response(ret=-4009, row_num=13792907, can_retry=false)
[2023-07-07 16:59:30.063599] WDIAG [SERVER] response_result (ob_sync_plan_driver.cpp:101) [799531][T1004_L0_G0][T1004][YB42AC125FA1-0005FFC97118D66B-0-0] [lt=4][errcode=-4009] response query result fail(ret=-4009)
[2023-07-07 16:59:30.063637] WDIAG [STORAGE] reset (ob_access_service.cpp:1143) [799531][T1004_L0_G0][T1004][YB42AC125FA1-0005FFC97118D66B-0-0] [lt=2][errcode=-4389] guard used too much time(guard_used_us=61261128, ls_id={id:1002}, lbt()=“0xf0bba8c 0xbdea58c 0x4033e57 0x4032889 0x401ba5e 0x401af94 0x99592a1 0x401812b 0x3fb66b3 0x3fb33ec 0x3fb0562 0x3fabed9 0x3fa9d9a 0x3fa6768 0x6a0ad14 0xf3666c7 0xf35faca 0x7f36f7b723fb 0x7f36f7727c23”)
[2023-07-07 16:59:30.063656] INFO [SERVER] send_error_packet (obmp_packet_sender.cpp:311) [799531][T1004_L0_G0][T1004][YB42AC125FA1-0005FFC97118D66B-0-0] [lt=6] sending error packet(err=-4009, extra_err_info=NULL, lbt()=“0xf0bba8c 0x7f702dc 0x7f2d8b8 0x3fb6646 0x3fb33ec 0x3fb0562 0x3fabed9 0x3fa9d9a 0x3fa6768 0x6a0ad14 0xf3666c7 0xf35faca 0x7f36f7b723fb 0x7f36f7727c23”)
[2023-07-07 16:59:30.063671] INFO [SERVER] add_changed_session_info (obmp_utils.cpp:81) [799531][T1004_L0_G0][T1004][YB42AC125FA1-0005FFC97118D66B-0-0] [lt=5] success add system var to ok pack(str_kv={key:“ob_statement_trace_id”, value:“YB42AC125FA1-0005FFC97118D66B-0-0”}, change_var={id_:10037, old_val_:{“VARCHAR”:“Y0-0”, collation:“utf8mb4_general_ci”, coercibility:“SYSCONST”}}, new_val={“VARCHAR”:“YB42AC125FA1-0005FFC97118D66B-0-0”, collation:“utf8mb4_general_ci”, coercibility:“IMPLICIT”}, session.get_sessid()=3222217918, session.get_proxy_sessid()=12399077860797779456, change_var.id_=10037)
[2023-07-07 16:59:30.063695] INFO [SERVER] send_error_packet (obmp_packet_sender.cpp:472) [799531][T1004_L0_G0][T1004][YB42AC125FA1-0005FFC97118D66B-0-0] [lt=12] dump txn free route audit_record(value=5, session->get_sessid()=3222217918, session->get_proxy_sessid()=12399077860797779456)
[2023-07-07 16:59:30.063702] WDIAG [SERVER] do_process (obmp_query.cpp:848) [799531][T1004_L0_G0][T1004][YB42AC125FA1-0005FFC97118D66B-0-0] [lt=5][errcode=-4009] execute query fail(ret=-4009, timeout_timestamp=1688720808801658)
[2023-07-07 16:59:30.063718] WDIAG [SQL.SESSION] set_session_state_ (ob_basic_session_info.cpp:5458) [799531][T1004_L0_G0][T1004][YB42AC125FA1-0005FFC97118D66B-0-0] [lt=3][errcode=-5066] session is killed(ret=-5066, sessid_=3222217918, proxy_sessid_=12399077860797779456, state=1)
[2023-07-07 16:59:30.063730] WDIAG [RPC.OBMYSQL] async_write_data (ob_sql_sock_session.cpp:152) [799531][T1004_L0_G0][T1004][YB42AC125FA1-0005FFC97118D66B-0-0] [lt=6][errcode=-4009] sock has error(ret=-4009)
[2023-07-07 16:59:30.063735] WDIAG [SERVER] flush_buffer (obmp_packet_sender.cpp:932) [799531][T1004_L0_G0][T1004][YB42AC125FA1-0005FFC97118D66B-0-0] [lt=4][errcode=-4009] write response fail(ret=-4009)
[2023-07-07 16:59:30.063738] WDIAG [SERVER] process (obmp_query.cpp:436) [799531][T1004_L0_G0][T1004][YB42AC125FA1-0005FFC97118D66B-0-0] [lt=3][errcode=-4009] failed to flush_buffer(tmp_ret=-4009)
[2023-07-07 16:59:30.063743] TRACE [TRACE] after_process (obmp_base.cpp:142) [799531][T1004_L0_G0][T1004][YB42AC125FA1-0005FFC97118D66B-0-0] [lt=4] [slow query](TRACE=begin_ts=1688720308801665 2023-07-07 08:58:28.801665|[process_begin] u=0 in_queue_time:7, receive_ts:1688720308801658, enqueue_ts:1688720308801658|[start_sql] u=0 addr:{ip:“172.18.95.159”, port:65040}|[query_begin] u=1 trace_id:YB42AC125FA1-0005FFC97118D66B-0-0|[before_processor_run] u=1 |[session] u=0 sid:3222217918, tenant_id:1004|[calc_partition_location_begin] u=22 |[tl_calc_part_id_end] u=1 |[get_location_cache_begin] u=0 |[calc_partition_location_end] u=3 |[get_plan_type_end] u=2 |[pc_choose_plan] u=1 |[check_priv] u=2 |[plan_id] u=0 plan_id:5666|[do_open_plan_begin] u=2 plan_id:5666|[sql_start_stmt_begin] u=0 |[sql_start_stmt_end] u=9 |[exec_plan_begin] u=0 |[exec_plan_end] u=20 |[do_open_plan_end] u=0 |[storage_table_scan_begin] u=49 |[S_table_scan_begin] u=3 |[S_table_scan_end] u=50 |[storage_table_scan_end] u=0 |[close_plan_begin] u=61261770 |[S_revert_iter_begin] u=4 |[S_revert_iter_end] u=39 |[start_end_stmt] u=4 |[end_stmt] u=1 |[close_plan_end] u=0 |[affected_rows] u=0 affected_rows:-1|[store_found_rows] u=0 found_rows:0, return_rows:13792908|[auto_end_plan_begin] u=1 |[auto_end_plan_end] u=3 |[session] u=11 sid:3222217918, tenant_id:1004|[query_end] u=62 |[process_end] u=16 run_ts:1688720308801667|total_timeu=61262077)
[2023-07-07 16:59:30.812732] INFO [RPC.OBMYSQL] destroy (obsm_conn_callback.cpp:223) [40573][sql_nio0][T0][Y0-0000000000000000-0-0] [lt=7] connection close(sessid=3222217918, proxy_sessid=12399077860797779456, tenant_id=1004, server_id=3, from_proxy=true, from_java_client=false, c/s protocol=“OB_2_0_CS_TYPE”, is_need_clear_sessid_=true, ret=0, trace_id=YB42AC125FA1-0005FFC97118D66B-0-0, conn.pkt_rec_wrapper_=[start_pkt_pos_:7, cur_pkt_pos_:9, pkt_rec[0]:{send:obp_mysql_header_{len_:5760, seq_:3}, pkt_name:“PKT_OKP”, obp_mysql_header_.is_send_:1}, pkt_rec[1]:{send:obp20_header_:{payload_len:470, pkt_seq:0, req_id:5020112, flag_.flags:43, ext_flags:0}, obp_mysql_header_{len_:413, seq_:2}, pkt_name:“PKT_OKP”, obp_mysql_header_.is_send_:1}, pkt_rec[2]:{receive:obp20_header_:{payload_len:132, pkt_seq:0, req_id:5020113, flag_.flags:43, ext_flags:0}, obp_mysql_header_{len_:47, rec_:51, seq_:0}, obp_mysql_header_.type_:3, obp_mysql_header_.is_send_:0}, pkt_rec[3]:{send:obp_compess_header_{com_len:13255, com_seq:1}, obp20_header_:{payload_len:13227, pkt_seq:1, req_id:5020113, flag_.flags:9, ext_flags:0}, obp_mysql_header_{len_:49, seq_:2}, pkt_name:“PKT_RESHEAD”, obp_mysql_header_.is_send_:1}, pkt_rec[4]:{send:obp_compess_header_{com_len:13255, com_seq:1}, obp20_header_:{payload_len:13227, pkt_seq:1, req_id:5020113, flag_.flags:9, ext_flags:0}, obp_mysql_header_{pkt_num_:85, seq_:87}, pkt_name:“PKT_FIELD”, obp_mysql_header_.is_send_:1}, pkt_rec[5]:{send:obp_compess_header_{com_len:13255, com_seq:1}, obp20_header_:{payload_len:13227, pkt_seq:1, req_id:5020113, flag_.flags:9, ext_flags:0}, obp_mysql_header_{len_:9, seq_:88}, pkt_name:“PKT_EOF”, obp_mysql_header_.is_send_:1}, pkt_rec[6]:{send:obp_compess_header_{com_len:13255, com_seq:1}, obp20_header_:{payload_len:13227, pkt_seq:1, req_id:5020113, flag_.flags:9, ext_flags:0}, obp_mysql_header_{pkt_num_:13792907, seq_:227}, pkt_name:“PKT_ROW”, obp_mysql_header_.is_send_:1}, pkt_rec[7]:{send:obp_compess_header_{com_len:124, com_seq:33}, obp20_header_:{payload_len:96, pkt_seq:33, req_id:5020113, flag_.flags:10, ext_flags:0}, obp_mysql_header_{len_:21, seq_:228}, pkt_name:“PKT_ERR”, obp_mysql_header_.is_send_:1}, pkt_rec[8]:{send:obp_compess_header_{com_len:124, com_seq:33}, obp20_header_:{payload_len:96, pkt_seq:33, req_id:5020113, flag_.flags:10, ext_flags:0}, obp_mysql_header_{len_:75, seq_:229}, pkt_name:“PKT_OKP”, obp_mysql_header_.is_send_:1}], disconnect_state=4)


你自己客户端有设置什么吧,1分钟断开连接了,会话请求被关闭了

1 个赞