search

oceanbase / obproxy

A proxy server for OceanBase Database.
https://open.oceanbase.com
Other
114 stars 79 forks source link

ODP+logproxy使用binlog模式异常 #53

Open xiaotouming1112222 opened 6 months ago

xiaotouming1112222 commented 6 months ago

一、背景： 测试ODP(4.2.1) + OB(4.2) + logproxy(2.0.0-bp/2.0.0)的可行性。

二、现象描述：

  1. 直接连接到 oblogproxy 执行 show master status 并发执行没有问题

  2. 通过 obproxy 连接上，执行 show master status 并发执行会有问题，ODP会偶发连接不上binlog service，任务失败

3.通过java sdk监听binlog数据 没有问题，即使通过sysbench并发写入时，监听也不会报错

4.相关报错的日志 mysql 客户端： MySQL [test]> show master status; ERROR 2006 (HY000): MySQL server has gone away No connection. Trying to reconnect...

obclient客户端： obclient [test]> show master status; ERROR 10025 (HY000): OBProxy connect binlog service failed obclient [test]> show master status; ERROR 2013 (HY000): Lost connection to MySQL server during query

obproxy报错： [2024-02-05 17:18:59.773184] WARN [PROXY.SM] handle_server_setup_error (ob_mysql_sm.cpp:8405) [909028][Y0-00007F822169B950] [lt=7] [dc=0] trace_log(transstate.tracelog= | dropped=0) [2024-02-05 17:18:59.773191] INFO [PROXY.SS] ob_mysql_server_session.cpp:153 [909028][Y0-00007F822169B950] [lt=6] [dc=0] server session do_io_close((this={ss_id:826839, server_sessid:3221828618, server_ip:{xxx:2881}, is_inited:true, magic:19136237, state:1, server_vc:0x7f822d8797d0, client_session:{this:0x7f821a355770, is_proxy_mysql_client:false, is_waiting_trans_first_request:false, need_delete_cluster:false, is_first_dml_sql_got:false, vc_ready_killed:false, active:true, magic:19132429, conn_decrease:true, current_tid:909028, cs_id:109585, proxy_sessid:740971881263490271, session_info:{is_inited:true, priv_info:{has_all_privilege:false, cs_id:109585, user_priv_set:133009965054, cluster_name:"xxx", tenant_name:"tp_tenant", user_name:"root"}, version:{common_hot_sys_var_version:0, common_sys_var_version:0, mysql_hot_sys_var_version:0, mysql_sys_var_version:0, hot_sys_var_version:1, sys_var_version:6, user_var_version:1, db_name_version:1, last_insert_id_version:0, sess_info_version:3}, hash_version:{common_hot_sys_var_version:0, common_sys_var_version:0, mysql_hot_sys_var_version:0, mysql_sys_var_version:0, hot_sys_var_version:0, sys_var_version:0, user_var_version:0, db_name_version:0, last_insert_id_version:0, sess_info_version:0}, val_hash:{common_hot_sys_var_hash:0, common_cold_sys_var_hash:0, mysql_hot_sys_var_hash:0, mysql_cold_sys_var_hash:0, hot_sys_var_hash:0, cold_sys_var_hash:0, user_var_hash:0}, global_vars_version:0, is_global_vars_changed:false, is_trans_specified:false, is_user_idc_name_set:false, is_read_consistency_set:false, idc_name:"", cluster_id:0, real_meta_cluster_name:"", safe_read_snapshot:1, syncing_safe_read_snapshot:0, route_policy:1, proxy_route_policy:3, user_identity:0, global_vars_version:0, is_read_only_user:false, is_request_follower_user:false, obproxy_force_parallel_query_dop:1, ob20_request:{remain_payload_len:0, ob20_request_received_done:false, ob20_header:{ob 20 protocol header:{compressed_len:0, seq:0, non_compressed_len:0}, magic_num:0, header_checksum:0, connection_id:0, request_id:0, pkt_seq:0, payloadlen:0, version:0, flag.flags:0, reserved:0}}, client_cap:0, server_cap:916303, last_server_addr:{Not IP address [0]:0}, last_server_sess_id:0, init_sql:""}, dummy_ldc:{use_ldc:true, idc_name:"default_idc", item_count:3, site_start_index_array:[[0]0, [1]3, [2]3, [3]3], item_array:[[0]{idc_type:"SAME_IDC", zone_type:"ReadWrite", replica:{server:"xxx:2881", is_dup_replica:false, role:"FOLLOWER", type:"FULL"}, is_merging:false, is_partition_server:false, is_force_congested:false, is_used:false}, [1]{idc_type:"SAME_IDC", zone_type:"ReadWrite", replica:{server:"xxx:2881", is_dup_replica:false, role:"FOLLOWER", type:"FULL"}, is_merging:false, is_partition_server:false, is_force_congested:false, is_used:false}, [2]{idc_type:"SAME_IDC", zone_type:"ReadWrite", replica:{server:"xxx:2881", is_dup_replica:false, role:"FOLLOWER", type:"FULL"}, is_merging:false, is_partition_server:false, is_force_congested:false, is_used:false}], pl:null, ts:0x7f823f588a80, readonly_exist_status:"READONLY_ZONE_NOT_EXIST"}, dummy_entry:0x7f822c980410, server_state_version:6, cur_ss:0x7f822b953230, bound_ss:null, lii_ss:null, cluster_resource:{this:0x7f822b1af080, ref_count:50, is_inited:true, cluster_info_key:{cluster_name:{config_string:"xxx"}, cluster_id:0}, cr_state:"CR_AVAIL", version:4, last_access_time_ns:1707124739771791698, deleting_completed_thread_num:0, fetch_rslist_task_count:0, fetch_idc_list_task_count:0, last_idc_list_refresh_time_ns:1707122165422588354, last_rslist_refresh_time_ns:0, server_state_version:6}, client_vc:0x7f822172b8a0, using_ldg:false, trace_stats:NULL}, transact_count:1, server_trans_stat:1, session_info:{cap:916303, ob_server:, version:{common_hot_sys_var_version:0, common_sys_var_version:0, mysql_hot_sys_var_version:0, mysql_sys_var_version:0, hot_sys_var_version:1, sys_var_version:6, user_var_version:1, db_name_version:1, last_insert_id_version:0, sess_info_version:3}, val_hash:{common_hot_sys_var_hash:0, common_cold_sys_var_hash:0, mysql_hot_sys_var_hash:0, mysql_cold_sys_var_hash:0, hot_sys_var_hash:0, cold_sys_var_hash:0, user_var_hash:0}, checksum_switch:1, server_type:1}}, servervc=0x7f822d8797d0, this=0x7f822b953230) [2024-02-05 17:18:59.773291] INFO [PROXY.SS] ob_mysql_server_session.cpp:190 [909028][Y0-00007F822169B950] [lt=98] [dc=0] server session is closing(ss_id=826839, server_sessid=3221828618, server_ip={xxx:2881}, cs_id=109585, proxy_sessid=740971881263490271) [2024-02-05 17:18:59.773302] INFO [PROXY.TXN] ob_mysql_transact.cpp:5761 [909028][Y0-00007F822169B950] [lt=4] [dc=0] [ObMysqlTransact::handle_server_connection_break](client_ip={xxx:15876}, server_ip={xxx3:2881}, cs_id=109585, proxy_sessid=740971881263490271, ss_id=0, server_sessid=0, sm_id=1785581, proxy_user_name=xxx, database_name=test, server_state="INTERNAL_ERROR", request_cmd="Quit", sql_cmd="Quit", sql=) [2024-02-05 17:18:59.773311] INFO [PROXY.SM] ob_mysql_sm.cpp:9000 [909028][Y0-00007F822169B950] [lt=8] [dc=0] [setup_error_transfer] Now closing connection caused by OB_MYSQL_COM_QUIT(sm_id=1785581, request_cmd="Quit", sql_cmd="Quit", sql=) [2024-02-05 17:18:59.773316] INFO [PROXY.SS] ob_mysql_client_session.cpp:652 [909028][Y0-00007F822169B950] [lt=3] [dc=0] client session do_io_close((this={this:0x7f821a355770, is_proxy_mysql_client:false, is_waiting_trans_first_request:false, need_delete_cluster:false, is_first_dml_sql_got:false, vc_ready_killed:false, active:true, magic:19132429, conn_decrease:true, current_tid:909028, cs_id:109585, proxy_sessid:740971881263490271, session_info:{is_inited:true, priv_info:{has_all_privilege:false, cs_id:109585, user_priv_set:133009965054, cluster_name:"xxx", tenant_name:"tp_tenant", user_name:"root"}, version:{common_hot_sys_var_version:0, common_sys_var_version:0, mysql_hot_sys_var_version:0, mysql_sys_var_version:0, hot_sys_var_version:1, sys_var_version:6, user_var_version:1, db_name_version:1, last_insert_id_version:0, sess_info_version:3}, hash_version:{common_hot_sys_var_version:0, common_sys_var_version:0, mysql_hot_sys_var_version:0, mysql_sys_var_version:0, hot_sys_var_version:0, sys_var_version:0, user_var_version:0, db_name_version:0, last_insert_id_version:0, sess_info_version:0}, val_hash:{common_hot_sys_var_hash:0, common_cold_sys_var_hash:0, mysql_hot_sys_var_hash:0, mysql_cold_sys_var_hash:0, hot_sys_var_hash:0, cold_sys_var_hash:0, user_var_hash:0}, global_vars_version:0, is_global_vars_changed:false, is_trans_specified:false, is_user_idc_name_set:false, is_read_consistency_set:false, idc_name:"", cluster_id:0, real_meta_cluster_name:"", safe_read_snapshot:1, syncing_safe_read_snapshot:0, route_policy:1, proxy_route_policy:3, user_identity:0, global_vars_version:0, is_read_only_user:false, is_request_follower_user:false, obproxy_force_parallel_query_dop:1, ob20_request:{remain_payload_len:0, ob20_request_received_done:false, ob20_header:{ob 20 protocol header:{compressed_len:0, seq:0, non_compressed_len:0}, magic_num:0, header_checksum:0, connection_id:0, request_id:0, pkt_seq:0, payloadlen:0, version:0, flag.flags:0, reserved:0}}, client_cap:0, server_cap:916303, last_server_addr:{Not IP address [0]:0}, last_server_sess_id:0, init_sql:""}, dummy_ldc:{use_ldc:true, idc_name:"default_idc", item_count:3, site_start_index_array:[[0]0, [1]3, [2]3, [3]3], item_array:[[0]{idc_type:"SAME_IDC", zone_type:"ReadWrite", replica:{server:"xxx:2881", is_dup_replica:false, role:"FOLLOWER", type:"FULL"}, is_merging:false, is_partition_server:false, is_force_congested:false, is_used:false}, [1]{idc_type:"SAME_IDC", zone_type:"ReadWrite", replica:{server:"xxx.174:2881", is_dup_replica:false, role:"FOLLOWER", type:"FULL"}, is_merging:false, is_partition_server:false, is_force_congested:false, is_used:false}, [2]{idc_type:"SAME_IDC", zone_type:"ReadWrite", replica:{server:"xxx.183:2881", is_dup_replica:false, role:"FOLLOWER", type:"FULL"}, is_merging:false, is_partition_server:false, is_force_congested:false, is_used:false}], pl:null, ts:0x7f823f588a80, readonly_exist_status:"READONLY_ZONE_NOT_EXIST"}, dummy_entry:0x7f822c980410, server_state_version:6, cur_ss:null, bound_ss:null, lii_ss:null, cluster_resource:{this:0x7f822b1af080, ref_count:50, is_inited:true, cluster_info_key:{cluster_name:{config_string:"xxx"}, cluster_id:0}, cr_state:"CR_AVAIL", version:4, last_access_time_ns:1707124739771791698, deleting_completed_thread_num:0, fetch_rslist_task_count:0, fetch_idc_list_task_count:0, last_idc_list_refresh_time_ns:1707122165422588354, last_rslist_refresh_time_ns:0, server_state_version:6}, client_vc:0x7f822172b8a0, using_ldg:false, trace_stats:NULL}, clientvc=0x7f822172b8a0, this=0x7f821a355770) [2024-02-05 17:18:59.773361] INFO [PROXY.SS] ob_mysql_server_session.cpp:153 [909028][Y0-00007F822169B950] [lt=43] [dc=0] server session do_io_close((this={ss_id:826838, server_sessid:660, server_ip:{xxx:2983}, is_inited:true, magic:19136237, state:3, server_vc:0x7f822d873650, client_session:{this:0x7f821a355770, is_proxy_mysql_client:false, is_waiting_trans_first_request:false, need_delete_cluster:false, is_first_dml_sql_got:false, vc_ready_killed:false, active:false, magic:19132429, conn_decrease:true, current_tid:909028, cs_id:109585, proxy_sessid:740971881263490271, session_info:{is_inited:true, priv_info:{has_all_privilege:false, cs_id:109585, user_priv_set:133009965054, cluster_name:"xxx", tenant_name:"tp_tenant", user_name:"root"}, version:{common_hot_sys_var_version:0, common_sys_var_version:0, mysql_hot_sys_var_version:0, mysql_sys_var_version:0, hot_sys_var_version:1, sys_var_version:6, user_var_version:1, db_name_version:1, last_insert_id_version:0, sess_info_version:3}, hash_version:{common_hot_sys_var_version:0, common_sys_var_version:0, mysql_hot_sys_var_version:0, mysql_sys_var_version:0, hot_sys_var_version:0, sys_var_version:0, user_var_version:0, db_name_version:0, last_insert_id_version:0, sess_info_version:0}, val_hash:{common_hot_sys_var_hash:0, common_cold_sys_var_hash:0, mysql_hot_sys_var_hash:0, mysql_cold_sys_var_hash:0, hot_sys_var_hash:0, cold_sys_var_hash:0, user_var_hash:0}, global_vars_version:0, is_global_vars_changed:false, is_trans_specified:false, is_user_idc_name_set:false, is_read_consistency_set:false, idc_name:"", cluster_id:0, real_meta_cluster_name:"", safe_read_snapshot:1, syncing_safe_read_snapshot:0, route_policy:1, proxy_route_policy:3, user_identity:0, global_vars_version:0, is_read_only_user:false, is_request_follower_user:false, obproxy_force_parallel_query_dop:1, ob20_request:{remain_payload_len:0, ob20_request_received_done:false, ob20_header:{ob 20 protocol header:{compressed_len:0, seq:0, non_compressed_len:0}, magic_num:0, header_checksum:0, connection_id:0, request_id:0, pkt_seq:0, payloadlen:0, version:0, flag.flags:0, reserved:0}}, client_cap:0, server_cap:916303, last_server_addr:{Not IP address [0]:0}, last_server_sess_id:0, init_sql:""}, dummy_ldc:{use_ldc:true, idc_name:"default_idc", item_count:3, site_start_index_array:[[0]0, [1]3, [2]3, [3]3], item_array:[[0]{idc_type:"SAME_IDC", zone_type:"ReadWrite", replica:{server:"xxx:2881", is_dup_replica:false, role:"FOLLOWER", type:"FULL"}, is_merging:false, is_partition_server:false, is_force_congested:false, is_used:false}, [1]{idc_type:"SAME_IDC", zone_type:"ReadWrite", replica:{server:"xxx:2881", is_dup_replica:false, role:"FOLLOWER", type:"FULL"}, is_merging:false, is_partition_server:false, is_force_congested:false, is_used:false}, [2]{idc_type:"SAME_IDC", zone_type:"ReadWrite", replica:{server:"xxx:2881", is_dup_replica:false, role:"FOLLOWER", type:"FULL"}, is_merging:false, is_partition_server:false, is_force_congested:false, is_used:false}], pl:null, ts:0x7f823f588a80, readonly_exist_status:"READONLY_ZONE_NOT_EXIST"}, dummy_entry:0x7f822c980410, server_state_version:6, cur_ss:null, bound_ss:null, lii_ss:null, cluster_resource:{this:0x7f822b1af080, ref_count:50, is_inited:true, cluster_info_key:{cluster_name:{config_string:"xxx"}, cluster_id:0}, cr_state:"CR_AVAIL", version:4, last_access_time_ns:1707124739771791698, deleting_completed_thread_num:0, fetch_rslist_task_count:0, fetch_idc_list_task_count:0, last_idc_list_refresh_time_ns:1707122165422588354, last_rslist_refresh_time_ns:0, server_state_version:6}, client_vc:0x7f822172b8a0, using_ldg:false, trace_stats:NULL}, transact_count:1, server_trans_stat:0, session_info:{cap:0, ob_server:, version:{common_hot_sys_var_version:0, common_sys_var_version:0, mysql_hot_sys_var_version:0, mysql_sys_var_version:0, hot_sys_var_version:1, sys_var_version:6, user_var_version:1, db_name_version:0, last_insert_id_version:0, sess_info_version:1}, val_hash:{common_hot_sys_var_hash:0, common_cold_sys_var_hash:0, mysql_hot_sys_var_hash:0, mysql_cold_sys_var_hash:0, hot_sys_var_hash:0, cold_sys_var_hash:0, user_var_hash:0}, checksum_switch:1, server_type:1}}, servervc=0x7f822d873650, this=0x7f822b950d10) [2024-02-05 17:18:59.773453] INFO [PROXY.SS] ob_mysql_server_session.cpp:190 [909028][Y0-00007F822169B950] [lt=81] [dc=0] server session is closing(ss_id=826838, server_sessid=660, server_ip={xxx:2983}, cs_id=109585, proxy_sessid=740971881263490271) [2024-02-05 17:18:59.773464] INFO [PROXY.SS] ob_mysql_server_session.cpp:153 [909028][Y0-00007F822169B950] [lt=5] [dc=0] server session do_io_close((this={ss_id:826837, server_sessid:3221550586, server_ip:{xxx.174:2881}, is_inited:true, magic:19136237, state:3, server_vc:0x7f822d87a670, client_session:{this:0x7f821a355770, is_proxy_mysql_client:false, is_waiting_trans_first_request:false, need_delete_cluster:false, is_first_dml_sql_got:false, vc_ready_killed:false, active:false, magic:19132429, conn_decrease:true, current_tid:909028, cs_id:109585, proxy_sessid:740971881263490271, session_info:{is_inited:true, priv_info:{has_all_privilege:false, cs_id:109585, user_priv_set:133009965054, cluster_name:"xxx", tenant_name:"tp_tenant", user_name:"root"}, version:{common_hot_sys_var_version:0, common_sys_var_version:0, mysql_hot_sys_var_version:0, mysql_sys_var_version:0, hot_sys_var_version:1, sys_var_version:6, user_var_version:1, db_name_version:1, last_insert_id_version:0, sess_info_version:3}, hash_version:{common_hot_sys_var_version:0, common_sys_var_version:0, mysql_hot_sys_var_version:0, mysql_sys_var_version:0, hot_sys_var_version:0, sys_var_version:0, user_var_version:0, db_name_version:0, last_insert_id_version:0, sess_info_version:0}, val_hash:{common_hot_sys_var_hash:0, common_cold_sys_var_hash:0, mysql_hot_sys_var_hash:0, mysql_cold_sys_var_hash:0, hot_sys_var_hash:0, cold_sys_var_hash:0, user_var_hash:0}, global_vars_version:0, is_global_vars_changed:false, is_trans_specified:false, is_user_idc_name_set:false, is_read_consistency_set:false, idc_name:"", cluster_id:0, real_meta_cluster_name:"", safe_read_snapshot:1, syncing_safe_read_snapshot:0, route_policy:1, proxy_route_policy:3, user_identity:0, global_vars_version:0, is_read_only_user:false, is_request_follower_user:false, obproxy_force_parallel_query_dop:1, ob20_request:{remain_payload_len:0, ob20_request_received_done:false, ob20_header:{ob 20 protocol header:{compressed_len:0, seq:0, non_compressed_len:0}, magic_num:0, header_checksum:0, connection_id:0, request_id:0, pkt_seq:0, payloadlen:0, version:0, flag.flags:0, reserved:0}}, client_cap:0, server_cap:916303, last_server_addr:{Not IP address [0]:0}, last_server_sess_id:0, init_sql:""}, dummy_ldc:{use_ldc:true, idc_name:"default_idc", item_count:3, site_start_index_array:[[0]0, [1]3, [2]3, [3]3], item_array:[[0]{idc_type:"SAME_IDC", zone_type:"ReadWrite", replica:{server:"xxx:2881", is_dup_replica:false, role:"FOLLOWER", type:"FULL"}, is_merging:false, is_partition_server:false, is_force_congested:false, is_used:false}, [1]{idc_type:"SAME_IDC", zone_type:"ReadWrite", replica:{server:"xxx:2881", is_dup_replica:false, role:"FOLLOWER", type:"FULL"}, is_merging:false, is_partition_server:false, is_force_congested:false, is_used:false}, [2]{idc_type:"SAME_IDC", zone_type:"ReadWrite", replica:{server:"xxx:2881", is_dup_replica:false, role:"FOLLOWER", type:"FULL"}, is_merging:false, is_partition_server:false, is_force_congested:false, is_used:false}], pl:null, ts:0x7f823f588a80, readonly_exist_status:"READONLY_ZONE_NOT_EXIST"}, dummy_entry:0x7f822c980410, server_state_version:6, cur_ss:null, bound_ss:null, lii_ss:null, cluster_resource:{this:0x7f822b1af080, ref_count:50, is_inited:true, cluster_info_key:{cluster_name:{config_string:"xxx"}, cluster_id:0}, cr_state:"CR_AVAIL", version:4, last_access_time_ns:1707124739771791698, deleting_completed_thread_num:0, fetch_rslist_task_count:0, fetch_idc_list_task_count:0, last_idc_list_refresh_time_ns:1707122165422588354, last_rslist_refresh_time_ns:0, server_state_version:6}, client_vc:0x7f822172b8a0, using_ldg:false, trace_stats:NULL}, transact_count:2, server_trans_stat:0, session_info:{cap:916303, ob_server:, version:{common_hot_sys_var_version:0, common_sys_var_version:0, mysql_hot_sys_var_version:0, mysql_sys_var_version:0, hot_sys_var_version:1, sys_var_version:6, user_var_version:1, db_name_version:1, last_insert_id_version:0, sess_info_version:1}, val_hash:{common_hot_sys_var_hash:0, common_cold_sys_var_hash:0, mysql_hot_sys_var_hash:0, mysql_cold_sys_var_hash:0, hot_sys_var_hash:0, cold_sys_var_hash:0, user_var_hash:0}, checksum_switch:1, server_type:1}}, servervc=0x7f822d87a670, this=0x7f822b953e90) [2024-02-05 17:18:59.773553] INFO [PROXY.SS] ob_mysql_server_session.cpp:190 [909028][Y0-00007F822169B950] [lt=81] [dc=0] server session is closing(ss_id=826837, server_sessid=3221550586, server_ip={xxx.174:2881}, cs_id=109585, proxy_sessid=740971881263490271) [2024-02-05 17:18:59.773572] INFO [PROXY.CS] ob_mysql_client_session.cpp:94 [909028][Y0-00007F822169B950] [lt=4] [dc=0] client session destroy(cs_id=109585, proxy_sessid=740971881263490271, client_vc=NULL) [2024-02-05 17:18:59.773585] INFO [PROXY.SM] ob_mysql_sm.cpp:9653 [909028][Y0-00007F822169B950] [lt=4] [dc=0] deallocating sm(sm_id=1785581) [2024-02-05 17:18:59.775521] INFO [PROXY.SOCK] ob_connection.cpp:369 [909087][Y0-0000000000000000] [lt=8] [dc=0] connection accepted(client={xxx:15878}, server={0.0.0.0:2883}, accepted_fd=184, listen_fd=176) [2024-02-05 17:18:59.775549] INFO [PROXY.NET] ob_mysql_session_accept.cpp:36 [909028][Y0-00007F8221906960] [lt=3] [dc=0] [ObMysqlSessionAccept:main_event] accepted connection(netvc=0x7f822e6a1a40, client_ip={xxx:15878}) [2024-02-05 17:18:59.775563] INFO [PROXY.NET] ob_unix_net_vconnection.cpp:1255 [909028][Y0-00007F8221906960] [lt=7] [dc=0] vip connect(protocol=6, fd=184, vid=0, vaddr={xxx:2883}, caddr={xxx:15878}, daddr={xxx:2883}) [2024-02-05 17:18:59.775572] INFO [PROXY.CS] ob_mysql_client_session.cpp:370 [909028][Y0-00007F8221906960] [lt=8] [dc=0] client session born(cs_id=109586, proxy_sessid=0, is_local_connection=false, client_vc=0x7f822e6a1a40, client_fd=184, client_addr="xxx:15878") [2024-02-05 17:18:59.775582] INFO [PROXY.CS] ob_mysql_client_session.cpp:241 [909028][Y0-00007F8221906960] [lt=5] [dc=0] Starting new transaction using sm(cs_id=109586, get_transact_count()=0, sm_id=1785582) [2024-02-05 17:18:59.775588] INFO [PROXY.SM] ob_mysql_sm.cpp:521 [909028][Y0-00007F8221906960] [lt=4] [dc=0] the request already in buffer, continue to handle it(buffer len=0, is_auth_rquest=true) [2024-02-05 17:18:59.775592] WARN [PROXY] get_cluster_name (ob_session_field_mgr.cpp:617) [909028][Y0-00007F8221906960] [lt=3] [dc=0] fail to get cluster name(ret=-4018) [2024-02-05 17:18:59.775597] WARN [PROXY] get_tenant_name (ob_session_field_mgr.cpp:629) [909028][Y0-00007F8221906960] [lt=4] [dc=0] fail to get tenant name(ret=-4018) [2024-02-05 17:18:59.776538] INFO [PROXY.SM] ob_mysql_sm.cpp:1979 [909028][Y0-00007F8221906960] [lt=2] [dc=0] final client capability flag in negotiation(last_client_cap=0, is_client_support_ob20=false) [2024-02-05 17:18:59.776546] INFO [PROXY] ob_vip_tenant_conn.cpp:162 [909028][Y0-00007F8221906960] [lt=6] [dc=0] vip tenant connect is not in vip_tenant_conn_cache(key_name=tp_tenant#xxx|, ret=-4018) [2024-02-05 17:18:59.776551] INFO [PROXY.SM] ob_mysql_sm.cpp:2563 [909028][Y0-00007F8221906960] [lt=5] [dc=0] client login audit(client_addr={xxx:15878}, hsr.clustername=xxx, hsr.tenantname=tp_tenant, hsr.username=root, status="success") [2024-02-05 17:18:59.776728] INFO [PROXY.SS] ob_mysql_server_session.cpp:106 [909028][Y0-00007F8221906960] [lt=7] [dc=0] server session born(ss_id=826840, server_ip={xxx.174:2881}, cs_id=109586, proxy_sessid=0, server_type=1) [2024-02-05 17:18:59.776810] INFO [PROXY.TXN] ob_mysql_transact.cpp:4726 [909028][Y0-00007F8221906960] [lt=10] [dc=0] succ to set proxy_sessid(cs_id=109586, proxy_sessid=740971881263490272, server_ip={xxx.174:2881}, ss_id=826840, server_sessid=3221550594, is_proxy_mysql_client=false, ss_fd=185, client_addr="xxx:15878") [2024-02-05 17:18:59.777418] INFO [PROXY] ob_proxy_session_info_handler.cpp:713 [909028][Y0-00007F8221906960] [lt=8] [dc=0] get global vars version(value=0, version=0) [2024-02-05 17:18:59.777429] INFO [PROXY] ob_proxy_session_info_handler.cpp:746 [909028][Y0-00007F8221906960] [lt=6] [dc=0] succ to set ob_capability_flag in negotiation(client_cap=0, server_cap=916303, orig_client_cap=0, orig_server_cap=916303, client_support_ob_v2=false, server_support_checksum=true, server_support_ob_v2=true, is_auth_request=true) [2024-02-05 17:18:59.777438] INFO [PROXY] ob_proxy_session_info_handler.cpp:773 [909028][Y0-00007F8221906960] [lt=6] [dc=0] succ to set checksum_switch(enable_transmission_checksum=1, old_switch=1, is_auth_request=true) [2024-02-05 17:18:59.777475] INFO [PROXY] ob_session_field_mgr.cpp:1250 [909028][Y0-00007F8221906960] [lt=3] [dc=0] user variable not exist(name=_min_cluster_version, ret=-4018) [2024-02-05 17:18:59.777899] INFO [PROXY] ob_proxy_session_info_handler.cpp:773 [909028][Y0-00007F8221906960] [lt=5] [dc=0] succ to set checksum_switch(enable_transmission_checksum=1, old_switch=1, is_auth_request=false) [2024-02-05 17:18:59.778407] INFO [PROXY] ob_table_entry_cont.cpp:682 [909002][Y0-00007F8221906960] [lt=24] [dc=0] get table entry from remote succ((newest_tableentry={{this:0x7f8237a8ab70, ref_count:1, cr_version:0, cr_id:0, create_time_us:1707124739778402, last_valid_time_us:1707124739778395, last_access_time_us:1707124739778395, last_update_time_us:0, schema_version:0, tenant_version:0, time_for_expired:0, state:"AVAIL"}, this:0x7f8237a8ab70, is_inited:true, is_dummy_entry:false, is_entry_from_rslist:false, is_empty_entry_allowed:false, is_need_force_flush:false, has_dup_replica:false, cr_id:0, name:{cluster_name:"xxx", tenant_name:"tp_tenant", database_name:"oceanbase", package_name:"", table_name:"__all_binlog_dummy"}, table_id:18446744073709551615, table_type:"UNKNOWN", part_num:0, replica_num:0, buf_len:53, buf_start:0x7f8237a8ac78, first_pl:{replica_count:1, locations:[[0]{server:"xxx:2983", is_dup_replica:false, role:"FOLLOWER", type:"FULL"}]}}) [2024-02-05 17:18:59.778589] INFO [PROXY.SS] ob_mysql_server_session.cpp:106 [909028][Y0-00007F8221906960] [lt=5] [dc=0] server session born(ss_id=826841, server_ip={xxx:2983}, cs_id=109586, proxy_sessid=740971881263490272, server_type=1) [2024-02-05 17:18:59.898762] INFO [PROXY.SM] ob_mysql_sm.cpp:10217 [909028][Y0-00007F8221906960] [lt=9] [dc=0] Slow Query: ((client_ip={xxx:15878}, server_ip={xxx:2983}, obproxy_client_port={xxx:56906}, server_trace_id=, route_type=ROUTE_TYPE_MAX, user_name=root, tenant_name=tp_tenant, cluster_name=xxx, logic_database_name=, logic_tenant_name=, ob_proxy_protocol=0, cs_id=109586, proxy_sessid=740971881263490272, ss_id=826841, server_sessid=661, sm_id=1785582, cmd_size_stats={client_request_bytes:23, server_request_bytes:23, server_response_bytes:297, client_response_bytes:297}, cmd_time_stats={client_transaction_idle_time_us=0, client_request_read_time_us=5, client_request_analyze_time_us=4, cluster_resource_create_time_us=0, pl_lookup_time_us=0, pl_process_time_us=0, bl_lookup_time_us=310, bl_process_time_us=0, congestion_control_time_us=0, congestion_process_time_us=0, do_observer_open_time_us=148, server_connect_time_us=129, server_sync_session_variable_time_us=79840, server_send_saved_login_time_us=39856, server_send_use_database_time_us=0, server_send_session_variable_time_us=39983, server_send_session_user_variable_time_us=0, server_send_all_session_variable_time_us=0, server_send_start_trans_time_us=0, server_send_xa_start_time_us=0, server_send_init_sql_time_us=0, build_server_request_time_us=9, plugin_compress_request_time_us=0, prepare_send_request_to_server_time_us=80591, server_request_write_time_us=3, server_process_request_time_us=115, server_response_read_time_us=39906, plugin_decompress_response_time_us=0, server_response_analyze_time_us=1, ok_packet_trim_time_us=0, client_response_write_time_us=7, request_total_time_us=120625}, sql=show master status, trans_internal_routing_state=not in trans) [2024-02-05 17:18:59.898928] WARN [PROXY.SM] handle_server_setup_error (ob_mysql_sm.cpp:8405) [909028][Y0-00007F8221906960] [lt=4] [dc=0] trace_log(transstate.tracelog= | dropped=0) [2024-02-05 17:18:59.898936] INFO [PROXY.SS] ob_mysql_server_session.cpp:153 [909028][Y0-00007F8221906960] [lt=7] [dc=0] server session do_io_close((this={ss_id:826840, server_sessid:3221550594, server_ip:{xxx.174:2881}, is_inited:true, magic:19136237, state:1, server_vc:0x7f822d8797d0, client_session:{this:0x7f821a355770, is_proxy_mysql_client:false, is_waiting_trans_first_request:false, need_delete_cluster:false, is_first_dml_sql_got:false, vc_ready_killed:false, active:true, magic:19132429, conn_decrease:true, current_tid:909028, cs_id:109586, proxy_sessid:740971881263490272, session_info:{is_inited:true, priv_info:{has_all_privilege:false, cs_id:109586, user_priv_set:133009965054, cluster_name:"xxx", tenant_name:"tp_tenant", user_name:"root"}, version:{common_hot_sys_var_version:0, common_sys_var_version:0, mysql_hot_sys_var_version:0, mysql_sys_var_version:0, hot_sys_var_version:1, sys_var_version:6, user_var_version:1, db_name_version:1, last_insert_id_version:0, sess_info_version:1}, hash_version:{common_hot_sys_var_version:0, common_sys_var_version:0, mysql_hot_sys_var_version:0, mysql_sys_var_version:0, hot_sys_var_version:0, sys_var_version:0, user_var_version:0, db_name_version:0, last_insert_id_version:0, sess_info_version:0}, val_hash:{common_hot_sys_var_hash:0, common_cold_sys_var_hash:0, mysql_hot_sys_var_hash:0, mysql_cold_sys_var_hash:0, hot_sys_var_hash:0, cold_sys_var_hash:0, user_var_hash:0}, global_vars_version:0, is_global_vars_changed:false, is_trans_specified:false, is_user_idc_name_set:false, is_read_consistency_set:false, idc_name:"", cluster_id:0, real_meta_cluster_name:"", safe_read_snapshot:1, syncing_safe_read_snapshot:0, route_policy:1, proxy_route_policy:3, user_identity:0, global_vars_version:0, is_read_only_user:false, is_request_follower_user:false, obproxy_force_parallel_query_dop:1, ob20_request:{remain_payload_len:0, ob20_request_received_done:false, ob20_header:{ob 20 protocol header:{compressed_len:0, seq:0, non_compressed_len:0}, magic_num:0, header_checksum:0, connection_id:0, request_id:0, pkt_seq:0, payloadlen:0, version:0, flag.flags:0, reserved:0}}, client_cap:0, server_cap:916303, last_server_addr:{Not IP address [0]:0}, last_server_sess_id:0, init_sql:""}, dummy_ldc:{use_ldc:true, idc_name:"default_idc", item_count:3, site_start_index_array:[[0]0, [1]3, [2]3, [3]3], item_array:[[0]{idc_type:"SAME_IDC", zone_type:"ReadWrite", replica:{server:"xxx.174:2881", is_dup_replica:false, role:"FOLLOWER", type:"FULL"}, is_merging:false, is_partition_server:false, is_force_congested:false, is_used:false}, [1]{idc_type:"SAME_IDC", zone_type:"ReadWrite", replica:{server:"xxx.173:2881", is_dup_replica:false, role:"FOLLOWER", type:"FULL"}, is_merging:false, is_partition_server:false, is_force_congested:false, is_used:false}, [2]{idc_type:"SAME_IDC", zone_type:"ReadWrite", replica:{server:"xxx.183:2881", is_dup_replica:false, role:"FOLLOWER", type:"FULL"}, is_merging:false, is_partition_server:false, is_force_congested:false, is_used:false}], pl:null, ts:0x7f823f588a80, readonly_exist_status:"READONLY_ZONE_NOT_EXIST"}, dummy_entry:0x7f822c980410, server_state_version:6, cur_ss:0x7f822b953e90, bound_ss:null, lii_ss:null, cluster_resource:{this:0x7f822b1af080, ref_count:50, is_inited:true, cluster_info_key:{cluster_name:{config_string:"xxx"}, cluster_id:0}, cr_state:"CR_AVAIL", version:4, last_access_time_ns:1707124739898815076, deleting_completed_thread_num:0, fetch_rslist_task_count:0, fetch_idc_list_task_count:0, last_idc_list_refresh_time_ns:1707122165422588354, last_rslist_refresh_time_ns:0, server_state_version:6}, client_vc:0x7f822e6a1a40, using_ldg:false, trace_stats:NULL}, transact_count:3, server_trans_stat:1, session_info:{cap:916303, ob_server:, version:{common_hot_sys_var_version:0, common_sys_var_version:0, mysql_hot_sys_var_version:0, mysql_sys_var_version:0, hot_sys_var_version:1, sys_var_version:6, user_var_version:1, db_name_version:1, last_insert_id_version:0, sess_info_version:1}, val_hash:{common_hot_sys_var_hash:0, common_cold_sys_var_hash:0, mysql_hot_sys_var_hash:0, mysql_cold_sys_var_hash:0, hot_sys_var_hash:0, cold_sys_var_hash:0, user_var_hash:0}, checksum_switch:1, server_type:1}}, servervc=0x7f822d8797d0, this=0x7f822b953e90) [2024-02-05 17:18:59.899038] INFO [PROXY.SS] ob_mysql_server_session.cpp:190 [909028][Y0-00007F8221906960] [lt=100] [dc=0] server session is closing(ss_id=826840, server_sessid=3221550594, server_ip={xxx.174:2881}, cs_id=109586, proxy_sessid=740971881263490272) [2024-02-05 17:18:59.899053] INFO [PROXY.TXN] ob_mysql_transact.cpp:5761 [909028][Y0-00007F8221906960] [lt=5] [dc=0] [ObMysqlTransact::handle_server_connection_break](client_ip={xxx:15878}, server_ip={xxx.174:2881}, cs_id=109586, proxy_sessid=740971881263490272, ss_id=0, server_sessid=0, sm_id=1785582, proxy_user_name=root@tp_tenant#xxx, database_name=test, server_state="INTERNAL_ERROR", request_cmd="Quit", sql_cmd="Quit", sql=) [2024-02-05 17:18:59.899062] INFO [PROXY.SM] ob_mysql_sm.cpp:9000 [909028][Y0-00007F8221906960] [lt=8] [dc=0] [setup_error_transfer] Now closing connection caused by OB_MYSQL_COM_QUIT(sm_id=1785582, request_cmd="Quit", sql_cmd="Quit", sql=) [2024-02-05 17:18:59.899067] INFO [PROXY.SS] ob_mysql_client_session.cpp:652 [909028][Y0-00007F8221906960] [lt=3] [dc=0] client session do_io_close((this={this:0x7f821a355770, is_proxy_mysql_client:false, is_waiting_trans_first_request:false, need_delete_cluster:false, is_first_dml_sql_got:false, vc_ready_killed:false, active:true, magic:19132429, conn_decrease:true, current_tid:909028, cs_id:109586, proxy_sessid:740971881263490272, session_info:{is_inited:true, priv_info:{has_all_privilege:false, cs_id:109586, user_priv_set:133009965054, cluster_name:"xxx", tenant_name:"tp_tenant", user_name:"root"}, version:{common_hot_sys_var_version:0, common_sys_var_version:0, mysql_hot_sys_var_version:0, mysql_sys_var_version:0, hot_sys_var_version:1, sys_var_version:6, user_var_version:1, db_name_version:1, last_insert_id_version:0, sess_info_version:1}, hash_version:{common_hot_sys_var_version:0, common_sys_var_version:0, mysql_hot_sys_var_version:0, mysql_sys_var_version:0, hot_sys_var_version:0, sys_var_version:0, user_var_version:0, db_name_version:0, last_insert_id_version:0, sess_info_version:0}, val_hash:{common_hot_sys_var_hash:0, common_cold_sys_var_hash:0, mysql_hot_sys_var_hash:0, mysql_cold_sys_var_hash:0, hot_sys_var_hash:0, cold_sys_var_hash:0, user_var_hash:0}, global_vars_version:0, is_global_vars_changed:false, is_trans_specified:false, is_user_idc_name_set:false, is_read_consistency_set:false, idc_name:"", cluster_id:0, real_meta_cluster_name:"", safe_read_snapshot:1, syncing_safe_read_snapshot:0, route_policy:1, proxy_route_policy:3, user_identity:0, global_vars_version:0, is_read_only_user:false, is_request_follower_user:false, obproxy_force_parallel_query_dop:1, ob20_request:{remain_payload_len:0, ob20_request_received_done:false, ob20_header:{ob 20 protocol header:{compressed_len:0, seq:0, non_compressed_len:0}, magic_num:0, header_checksum:0, connection_id:0, request_id:0, pkt_seq:0, payloadlen:0, version:0, flag.flags:0, reserved:0}}, client_cap:0, server_cap:916303, last_server_addr:{Not IP address [0]:0}, last_server_sess_id:0, init_sql:""}, dummy_ldc:{use_ldc:true, idc_name:"default_idc", item_count:3, site_start_index_array:[[0]0, [1]3, [2]3, [3]3], item_array:[[0]{idc_type:"SAME_IDC", zone_type:"ReadWrite", replica:{server:"xxx.174:2881", is_dup_replica:false, role:"FOLLOWER", type:"FULL"}, is_merging:false, is_partition_server:false, is_force_congested:false, is_used:false}, [1]{idc_type:"SAME_IDC", zone_type:"ReadWrite", replica:{server:"xxx.173:2881", is_dup_replica:false, role:"FOLLOWER", type:"FULL"}, is_merging:false, is_partition_server:false, is_force_congested:false, is_used:false}, [2]{idc_type:"SAME_IDC", zone_type:"ReadWrite", replica:{server:"xxx.183:2881", is_dup_replica:false, role:"FOLLOWER", type:"FULL"}, is_merging:false, is_partition_server:false, is_force_congested:false, is_used:false}], pl:null, ts:0x7f823f588a80, readonly_exist_status:"READONLY_ZONE_NOT_EXIST"}, dummy_entry:0x7f822c980410, server_state_version:6, cur_ss:null, bound_ss:null, lii_ss:null, cluster_resource:{this:0x7f822b1af080, ref_count:50, is_inited:true, cluster_info_key:{cluster_name:{config_string:"xxx"}, cluster_id:0}, cr_state:"CR_AVAIL", version:4, last_access_time_ns:1707124739898815076, deleting_completed_thread_num:0, fetch_rslist_task_count:0, fetch_idc_list_task_count:0, last_idc_list_refresh_time_ns:1707122165422588354, last_rslist_refresh_time_ns:0, server_state_version:6}, client_vc:0x7f822e6a1a40, using_ldg:false, trace_stats:NULL}, clientvc=0x7f822e6a1a40, this=0x7f821a355770) [2024-02-05 17:18:59.899110] INFO [PROXY.SS] ob_mysql_server_session.cpp:153 [909028][Y0-00007F8221906960] [lt=43] [dc=0] server session do_io_close((this={ss_id:826841, server_sessid:661, server_ip:{xxx:2983}, is_inited:true, magic:19136237, state:3, server_vc:0x7f822d87a670, client_session:{this:0x7f821a355770, is_proxy_mysql_client:false, is_waiting_trans_first_request:false, need_delete_cluster:false, is_first_dml_sql_got:false, vc_ready_killed:false, active:false, magic:19132429, conn_decrease:true, current_tid:909028, cs_id:109586, proxy_sessid:740971881263490272, session_info:{is_inited:true, priv_info:{has_all_privilege:false, cs_id:109586, user_priv_set:133009965054, cluster_name:"xxx", tenant_name:"tp_tenant", user_name:"root"}, version:{common_hot_sys_var_version:0, common_sys_var_version:0, mysql_hot_sys_var_version:0, mysql_sys_var_version:0, hot_sys_var_version:1, sys_var_version:6, user_var_version:1, db_name_version:1, last_insert_id_version:0, sess_info_version:1}, hash_version:{common_hot_sys_var_version:0, common_sys_var_version:0, mysql_hot_sys_var_version:0, mysql_sys_var_version:0, hot_sys_var_version:0, sys_var_version:0, user_var_version:0, db_name_version:0, last_insert_id_version:0, sess_info_version:0}, val_hash:{common_hot_sys_var_hash:0, common_cold_sys_var_hash:0, mysql_hot_sys_var_hash:0, mysql_cold_sys_var_hash:0, hot_sys_var_hash:0, cold_sys_var_hash:0, user_var_hash:0}, global_vars_version:0, is_global_vars_changed:false, is_trans_specified:false, is_user_idc_name_set:false, is_read_consistency_set:false, idc_name:"", cluster_id:0, real_meta_cluster_name:"", safe_read_snapshot:1, syncing_safe_read_snapshot:0, route_policy:1, proxy_route_policy:3, user_identity:0, global_vars_version:0, is_read_only_user:false, is_request_follower_user:false, obproxy_force_parallel_query_dop:1, ob20_request:{remain_payload_len:0, ob20_request_received_done:false, ob20_header:{ob 20 protocol header:{compressed_len:0, seq:0, non_compressed_len:0}, magic_num:0, header_checksum:0, connection_id:0, request_id:0, pkt_seq:0, payloadlen:0, version:0, flag.flags:0, reserved:0}}, client_cap:0, server_cap:916303, last_server_addr:{Not IP address [0]*:0}, last_server_sess_id:0, init_sql:""}, dummy_ldc:{use_ldc:true, idc_name:"default_idc", item_count:3, site_start_index_array:[[0]0, [1]3, [2]3, [3]3], item_array:[[0]{idc_type:"SAME_IDC", zone_type:"ReadWrite", replica:{server:"xxx.174:2881", is_dup_replica:false, role:"FOLLOWER", type:"FULL"}, is_merging:false, is_partition_server:false, is_force_congested:false, is_used:false}, [1]{idc_type:"SAME_IDC", zone_type:"ReadWrite", replica:{server:"xxx.173:2881", is_dup_replica:false, role:"FOLLOWER", type:"FULL"}, is_merging:false, is_partition_server:false, is_force_congested:false, is_used:false}, [2]{idc_type:"SAME_IDC", zone_type:"ReadWrite", replica:{server:"xxx.183:2881", is_dup_replica:false, role:"FOLLOWER", type:"FULL"}, is_merging:false, is_partition_server:false, is_force_congested:false, is_used:false}], pl:null, ts:0x7f823f588a80, readonly_exist_status:"READONLY_ZONE_NOT_EXIST"}, dummy_entry:0x7f822c980410, server_state_version:6, cur_ss:null, bound_ss:null, lii_ss:null, cluster_resource:{this:0x7f822b1af080, ref_count:50, is_inited:true, cluster_info_key:{cluster_name:{config_string:"xxx"}, cluster_id:0}, cr_state:"CR_AVAIL", version:4, last_access_time_ns:1707124739898815076, deleting_completed_thread_num:0, fetch_rslist_task_count:0, fetch_idc_list_task_count:0, last_idc_list_refresh_time_ns:1707122165422588354, last_rslist_refresh_time_ns:0, server_state_version:6}, client_vc:0x7f822e6a1a40, using_ldg:false, trace_stats:NULL}, transact_count:1, server_trans_stat:0, session_info:{cap:0, ob_server:, version:{common_hot_sys_var_version:0, common_sys_var_version:0, mysql_hot_sys_var_version:0, mysql_sys_var_version:0, hot_sys_var_version:1, sys_var_version:6, user_var_version:1, db_name_version:0, last_insert_id_version:0, sess_info_version:1}, val_hash:{common_hot_sys_var_hash:0, common_cold_sys_var_hash:0, mysql_hot_sys_var_hash:0, mysql_cold_sys_var_hash:0, hot_sys_var_hash:0, cold_sys_var_hash:0, user_var_hash:0}, checksum_switch:1, server_type:1}}, servervc=0x7f822d87a670, this=0x7f822b950d10) [2024-02-05 17:18:59.899204] INFO [PROXY.SS] ob_mysql_server_session.cpp:190 [909028][Y0-00007F8221906960] [lt=81] [dc=0] server session is closing(ss_id=826841, server_sessid=661, server_ip={xxx:2983}, cs_id=109586, proxy_sessid=740971881263490272) [2024-02-05 17:18:59.899223] INFO [PROXY.CS] ob_mysql_client_session.cpp:94 [909028][Y0-00007F8221906960] [lt=5] [dc=0] client session destroy(cs_id=109586, proxy_sessid=740971881263490272, client_vc=NULL) [2024-02-05 17:18:59.899237] INFO [PROXY.SM] ob_mysql_sm.cpp:9653 [909028][Y0-00007F8221906960] [lt=4] [dc=0] deallocating sm(sm_id=1785582) [2024-02-05 17:18:59.902731] INFO [PROXY.SOCK] ob_connection.cpp:369 [909086][Y0-0000000000000000] [lt=17] [dc=0] connection accepted(client={xxx:15882}, server={0.0.0.0:2883}, accepted_fd=178, listen_fd=176) [2024-02-05 17:18:59.902755] INFO [PROXY.NET] ob_mysql_session_accept.cpp:36 [909028][Y0-00007F822169B950] [lt=3] [dc=0] [ObMysqlSessionAccept:main_event] accepted connection(netvc=0x7f822172b8a0, client_ip={xxx:15882}) [2024-02-05 17:18:59.902767] INFO [PROXY.NET] ob_unix_net_vconnection.cpp:1255 [909028][Y0-00007F822169B950] [lt=5] [dc=0] vip connect(protocol=6, fd=178, vid=0, vaddr={xxx:2883}, caddr={xxx:15882}, daddr={xxx:2883}) [2024-02-05 17:18:59.902775] INFO [PROXY.CS] ob_mysql_client_session.cpp:370 [909028][Y0-00007F822169B950] [lt=7] [dc=0] client session born(cs_id=109587, proxy_sessid=0, is_local_connection=false, client_vc=0x7f822172b8a0, client_fd=178, client_addr="xxx:15882") [2024-02-05 17:18:59.902785] INFO [PROXY.CS] ob_mysql_client_session.cpp:241 [909028][Y0-00007F822169B950] [lt=5] [dc=0] Starting new transaction using sm(cs_id=109587, get_transact_count()=0, sm_id=1785583) [2024-02-05 17:18:59.902791] INFO [PROXY.SM] ob_mysql_sm.cpp:521 [909028][Y0-00007F822169B950] [lt=4] [dc=0] the request already in buffer, continue to handle it(buffer len=0, is_auth_rquest=true) [2024-02-05 17:18:59.902794] WARN [PROXY] get_cluster_name (ob_session_field_mgr.cpp:617) [909028][Y0-00007F822169B950] [lt=3] [dc=0] fail to get cluster name(ret=-4018) [2024-02-05 17:18:59.902799] WARN [PROXY] get_tenant_name (ob_session_field_mgr.cpp:629) [909028][Y0-00007F822169B950] [lt=5] [dc=0] fail to get tenant name(ret=-4018) [2024-02-05 17:18:59.903673] INFO [PROXY.SM] ob_mysql_sm.cpp:1979 [909028][Y0-00007F822169B950] [lt=3] [dc=0] final client capability flag in negotiation(last_client_cap=0, is_client_support_ob20=false) [2024-02-05 17:18:59.903680] INFO [PROXY] ob_vip_tenant_conn.cpp:162 [909028][Y0-00007F822169B950] [lt=5] [dc=0] vip tenant connect is not in vip_tenant_conn_cache(key_name=tp_tenant#xxx|, ret=-4018) [2024-02-05 17:18:59.903683] INFO [PROXY.SM] ob_mysql_sm.cpp:2563 [909028][Y0-00007F822169B950] [lt=3] [dc=0] client login audit(client_addr={xxx:15882}, hsr.clustername=xxx, hsr.tenantname=tp_tenant, hsr.username=root, status="success") [2024-02-05 17:18:59.903824] INFO [PROXY.SS] ob_mysql_server_session.cpp:106 [909028][Y0-00007F822169B950] [lt=6] [dc=0] server session born(ss_id=826842, server_ip={xxx.173:2881}, cs_id=109587, proxy_sessid=0, server_type=1) [2024-02-05 17:18:59.903915] INFO [PROXY.TXN] ob_mysql_transact.cpp:4726 [909028][Y0-00007F822169B950] [lt=6] [dc=0] succ to set proxy_sessid(cs_id=109587, proxy_sessid=740971881263490273, server_ip={xxx.173:2881}, ss_id=826842, server_sessid=3221830820, is_proxy_mysql_client=false, ss_fd=185, client_addr="xxx:15882") [2024-02-05 17:18:59.904530] INFO [PROXY] ob_proxy_session_info_handler.cpp:713 [909028][Y0-00007F822169B950] [lt=10] [dc=0] get global vars version(value=0, version=0) [2024-02-05 17:18:59.904542] INFO [PROXY] ob_proxy_session_info_handler.cpp:746 [909028][Y0-00007F822169B950] [lt=6] [dc=0] succ to set ob_capability_flag in negotiation(client_cap=0, server_cap=916303, orig_client_cap=0, orig_server_cap=916303, client_support_ob_v2=false, server_support_checksum=true, server_support_ob_v2=true, is_auth_request=true) [2024-02-05 17:18:59.904551] INFO [PROXY] ob_proxy_session_info_handler.cpp:773 [909028][Y0-00007F822169B950] [lt=5] [dc=0] succ to set checksum_switch(enable_transmission_checksum=1, old_switch=1, is_auth_request=true) [2024-02-05 17:18:59.904590] INFO [PROXY] ob_session_field_mgr.cpp:1250 [909028][Y0-00007F822169B950] [lt=2] [dc=0] user variable not exist(name=_min_cluster_version, ret=-4018) [2024-02-05 17:18:59.905033] INFO [PROXY] ob_proxy_session_info_handler.cpp:773 [909028][Y0-00007F822169B950] [lt=4] [dc=0] succ to set checksum_switch(enable_transmission_checksum=1, old_switch=1, is_auth_request=false) [2024-02-05 17:18:59.905541] INFO [PROXY] ob_table_entry_cont.cpp:682 [909002][Y0-00007F822169B950] [lt=25] [dc=0] get table entry from remote succ((newest_tableentry={{this:0x7f8237a90000, ref_count:1, cr_version:0, cr_id:0, create_time_us:1707124739905537, last_valid_time_us:1707124739905524, last_access_time_us:1707124739905524, last_update_time_us:0, schema_version:0, tenant_version:0, time_for_expired:0, state:"AVAIL"}, this:0x7f8237a90000, is_inited:true, is_dummy_entry:false, is_entry_from_rslist:false, is_empty_entry_allowed:false, is_need_force_flush:false, has_dup_replica:false, cr_id:0, name:{cluster_name:"xxx", tenant_name:"tp_tenant", database_name:"oceanbase", package_name:"", table_name:"__all_binlog_dummy"}, table_id:18446744073709551615, table_type:"UNKNOWN", part_num:0, replica_num:0, buf_len:53, buf_start:0x7f8237a90108, first_pl:{replica_count:1, locations:[[0]{server:"xxx:2983", is_dup_replica:false, role:"FOLLOWER", type:"FULL"}]}}) [2024-02-05 17:18:59.905716] INFO [PROXY.SS] ob_mysql_server_session.cpp:106 [909028][Y0-00007F822169B950] [lt=5] [dc=0] server session born(ss_id=826843, server_ip={xxx:2983}, cs_id=109587, proxy_sessid=740971881263490273, server_type=1)