obproxy 报错failed,1045,Access denied for user

AntTech_GASIPE · 2024 年10 月 24 日 16:12

【使用环境】生产环境
【 OB or 其他组件】
observer: 4.3.3
obproxy: 之前是4.3.1.0-4 昨天晚上才升级到4.3.2.0-26，两个版本下，都有这个错误日志
ocp: 4.3.2
【问题描述】
obproxy_err.log 日志中经常出现 failed,1045, Access denied for user 等错误日志：

grep 'Access denied for user' obproxy_error.log
2024-10-23 16:38:03.389199,proxy_OB01,,,,OB01:OB01:test_db,OB_MYSQL,,,OB_MYSQL_COM_STMT_RESET,,failed,1045,,356us,0us,0us,325us,Y0-00002B71E68BFBB0,,192.168.51.169:56878,,0,192.168.51.11:2881,Access denied for user,
2024-10-23 16:38:03.415633,proxy_OB01,,,,OB01:OB01:test_db,OB_MYSQL,,,OB_MYSQL_COM_STMT_SEND_PIECE_DATA,,failed,1045,,470us,0us,0us,429us,Y0-00002B71E6A7C110,,192.168.51.169:56898,,0,192.168.51.11:2881,Access denied for user,
2024-10-23 16:49:35.415085,proxy_OB01,,,,OB01:OB01:test_db,OB_MYSQL,,,OB_MYSQL_COM_STMT_EXECUTE,,failed,1045,,392us,50us,0us,272us,Y0-00002B819FCEC590,,192.168.51.169:57121,,0,192.168.51.11:2881,Access denied for user,
2024-10-23 17:29:16.653211,proxy_OB01,,,,OB01:OB01:test_db,OB_MYSQL,,,OB_MYSQL_COM_STMT_SEND_PIECE_DATA,,failed,1045,,244us,0us,0us,195us,Y0-00002B819FCEC2D0,,192.168.51.169:57479,,0,192.168.51.11:2881,Access denied for user,
2024-10-23 17:35:08.250855,proxy_OB01,,,,OB01:OB01:test_db,OB_MYSQL,,,OB_MYSQL_COM_STMT_SEND_PIECE_DATA,,failed,1045,,448us,0us,0us,426us,Y0-00002B819FCEC8D0,,192.168.51.169:57670,,0,192.168.51.11:2881,Access denied for user,
2024-10-23 17:35:08.251163,proxy_OB01,,,,OB01:OB01:test_db,OB_MYSQL,,,OB_MYSQL_COM_STMT_RESET,,failed,1045,,528us,8us,0us,462us,Y0-00002B819DAFC910,,192.168.51.169:57662,,0,192.168.51.11:2881,Access denied for user,
2024-10-23 18:50:49.421781,proxy_OB01,,,,OB01:OB01:test_db,OB_MYSQL,,,OB_MYSQL_COM_STMT_SEND_PIECE_DATA,,failed,1045,,382us,8us,0us,328us,Y0-00002B819FCEC0D0,,192.168.51.169:58892,,0,192.168.51.11:2881,Access denied for user,
2024-10-23 19:01:10.958299,proxy_OB01,,,,OB01:OB01:test_db,OB_MYSQL,,,OB_MYSQL_COM_STMT_EXECUTE,,failed,1045,,224us,0us,0us,224us,Y0-00002B819DAFC210,,192.168.51.169:59053,,0,192.168.51.11:2881,Access denied for user,
2024-10-23 19:10:31.608125,proxy_OB01,,,,OB01:OB01:test_db,OB_MYSQL,,,OB_MYSQL_COM_STMT_SEND_PIECE_DATA,,failed,1045,,123us,0us,0us,117us,Y0-00002B819DAFC210,,192.168.51.169:59158,,0,192.168.51.11:2881,Access denied for user,
2024-10-23 20:10:49.289317,proxy_OB01,,,,OB01:OB01:test_db,OB_MYSQL,,,OB_MYSQL_COM_STMT_SEND_PIECE_DATA,,failed,1045,,240us,0us,0us,228us,Y0-00002B819FCEC650,,192.168.51.169:59844,,0,192.168.51.11:2881,Access denied for user,
2024-10-23 21:16:10.305030,proxy_OB01,,,,OB01:OB01:test_db,OB_MYSQL,,,OB_MYSQL_COM_STMT_SEND_PIECE_DATA,,failed,1045,,159us,128us,0us,30us,Y0-00002B819DAFBC50,,192.168.51.169:60724,,0,192.168.51.11:2881,Access denied for user,
2024-10-23 21:55:32.064717,proxy_OB01,,,,OB01:OB01:test_db,OB_MYSQL,,,OB_MYSQL_COM_STMT_SEND_PIECE_DATA,,failed,1045,,396us,89us,0us,281us,Y0-00002B819DAFBD50,,192.168.51.169:61157,,0,192.168.51.11:2881,Access denied for user,
2024-10-23 22:00:40.046789,proxy_OB01,,,,OB01:OB01:test_db,OB_MYSQL,,,OB_MYSQL_COM_STMT_RESET,,failed,1045,,259us,0us,0us,245us,Y0-00002B819FCEC490,,192.168.51.169:61226,,0,192.168.51.11:2881,Access denied for user,
2024-10-23 22:05:42.186418,proxy_OB01,,,,OB01:OB01:test_db,OB_MYSQL,,,OB_MYSQL_COM_STMT_EXECUTE,,failed,1045,,958us,0us,0us,770us,Y0-00002B103B6069E0,,192.168.51.169:61316,,0,192.168.51.11:2881,Access denied for user,
2024-10-23 22:55:44.568186,proxy_OB01,,,,OB01:OB01:test_db,OB_MYSQL,,,OB_MYSQL_COM_STMT_EXECUTE,,failed,1045,,665us,0us,0us,413us,Y0-00002B103AA1AF00,,192.168.51.169:61858,,0,192.168.51.11:2881,Access denied for user,
2024-10-23 23:00:48.212530,proxy_OB01,,,,OB01:OB01:test_db,OB_MYSQL,,,OB_MYSQL_COM_STMT_SEND_PIECE_DATA,,failed,1045,,239us,0us,0us,239us,Y0-00002B103AA1AD40,,192.168.51.169:61932,,0,192.168.51.11:2881,Access denied for user,
2024-10-24 00:01:28.088049,proxy_OB01,,,,OB01:OB01:test_db,OB_MYSQL,,,OB_MYSQL_COM_STMT_EXECUTE,,failed,1045,,306us,0us,0us,285us,Y0-00002B103AA1AF40,,192.168.51.169:62569,,0,192.168.51.11:2881,Access denied for user,
2024-10-24 01:25:42.409408,proxy_OB01,,,,OB01:OB01:test_db,OB_MYSQL,,,OB_MYSQL_COM_STMT_EXECUTE,,failed,1045,,145us,0us,0us,145us,Y0-00002B103B606A60,,192.168.51.169:63477,,0,192.168.51.11:2881,Access denied for user,
2024-10-24 03:35:23.348777,proxy_OB01,,,,OB01:OB01:test_db,OB_MYSQL,,,OB_MYSQL_COM_STMT_EXECUTE,,failed,1045,,478us,0us,0us,478us,Y0-00002B103AA1A740,,192.168.51.169:64933,,0,192.168.51.11:2881,Access denied for user,
2024-10-24 03:53:02.012614,proxy_OB01,,,,OB01:OB01:test_db,OB_MYSQL,,,OB_MYSQL_COM_STMT_SEND_PIECE_DATA,,failed,1045,,153us,0us,0us,153us,Y0-00002B103B606720,,192.168.51.169:65149,,0,192.168.51.11:2881,Access denied for user,
2024-10-24 04:00:47.862123,proxy_OB01,,,,OB01:OB01:test_db,OB_MYSQL,,,OB_MYSQL_COM_STMT_SEND_PIECE_DATA,,failed,1045,,260us,4us,0us,226us,Y0-00002B103AA1AD80,,192.168.51.169:65235,,0,192.168.51.11:2881,Access denied for user,
2024-10-24 04:16:08.849438,proxy_OB01,,,,OB01:OB01:test_db,OB_MYSQL,,,OB_MYSQL_COM_STMT_SEND_PIECE_DATA,,failed,1045,,245us,0us,0us,155us,Y0-00002B103AA1AA00,,192.168.51.169:65391,,0,192.168.51.11:2881,Access denied for user,
2024-10-24 04:29:05.571587,proxy_OB01,,,,OB01:OB01:test_db,OB_MYSQL,,,OB_MYSQL_COM_STMT_SEND_PIECE_DATA,,failed,1045,,173us,0us,0us,165us,Y0-00002B103B606620,,192.168.51.169:65528,,0,192.168.51.11:2881,Access denied for user,
2024-10-24 05:52:21.623170,proxy_OB01,,,,OB01:OB01:test_db,OB_MYSQL,,,OB_MYSQL_COM_STMT_SEND_PIECE_DATA,,failed,1045,,612us,0us,0us,400us,Y0-00002B103AA1AC00,,192.168.51.169:50196,,0,192.168.51.11:2881,Access denied for user,
2024-10-24 07:53:29.790050,proxy_OB01,,,,OB01:OB01:test_db,OB_MYSQL,,,OB_MYSQL_COM_STMT_EXECUTE,,failed,1045,,628us,0us,0us,569us,Y0-00002B103B606960,,192.168.51.169:57671,,0,192.168.51.11:2881,Access denied for user,
2024-10-24 08:10:47.553538,proxy_OB01,,,,OB01:OB01:test_db,OB_MYSQL,,,OB_MYSQL_COM_STMT_SEND_PIECE_DATA,,failed,1045,,210us,0us,0us,185us,Y0-00002B103B606360,,192.168.51.169:58526,,0,192.168.51.11:2881,Access denied for user,
2024-10-24 08:10:47.613458,proxy_OB01,,,,OB01:OB01:test_db,OB_MYSQL,,,OB_MYSQL_COM_STMT_SEND_PIECE_DATA,,failed,1045,,190us,0us,0us,190us,Y0-00002B103B605AE0,,192.168.51.169:58560,,0,192.168.51.11:2881,Access denied for user,
2024-10-24 08:10:48.204561,proxy_OB01,,,,OB01:OB01:test_db,OB_MYSQL,,,OB_MYSQL_COM_STMT_RESET,,failed,1045,,284us,48us,0us,236us,Y0-00002B103AA1A140,,192.168.51.169:58615,,0,192.168.51.11:2881,Access denied for user,
2024-10-24 08:10:48.204604,proxy_OB01,,,,OB01:OB01:test_db,OB_MYSQL,,,OB_MYSQL_COM_STMT_RESET,,failed,1045,,69us,0us,0us,0us,Y0-00002B103AA1A140,,192.168.51.169:58615,,0,,Access denied for user,
2024-10-24 08:38:01.609043,proxy_OB01,,,,OB01:OB01:test_db,OB_MYSQL,,,OB_MYSQL_COM_STMT_SEND_PIECE_DATA,,failed,1045,,182us,1us,0us,181us,Y0-00002B103B605E20,,192.168.51.169:58932,,0,192.168.51.11:2881,Access denied for user,
2024-10-24 09:30:46.849568,proxy_OB01,,,,OB01:OB01:test_db,OB_MYSQL,,,OB_MYSQL_COM_STMT_SEND_PIECE_DATA,,failed,1045,,201us,5us,0us,171us,Y0-00002B103AA1A240,,192.168.51.169:59492,,0,192.168.51.11:2881,Access denied for user,
2024-10-24 11:41:06.999596,proxy_OB01,,,,OB01:OB01:test_db,OB_MYSQL,,,OB_MYSQL_COM_STMT_SEND_PIECE_DATA,,failed,1045,,434us,0us,0us,434us,Y0-00007F978D009DE0,,192.168.71.36:60053,,0,192.168.51.11:2881,Access denied for user,
2024-10-24 11:54:26.092092,proxy_OB01,,,,OB01:OB01:test_db,OB_MYSQL,,,OB_MYSQL_COM_STMT_EXECUTE,,failed,1045,,131us,0us,0us,131us,Y0-00007F978D4055C0,,192.168.51.169:61532,,0,192.168.51.11:2881,Access denied for user,
2024-10-24 12:00:27.989253,proxy_OB01,,,,OB01:OB01:test_db,OB_MYSQL,,,OB_MYSQL_COM_STMT_EXECUTE,,failed,1045,,188us,0us,0us,186us,Y0-00007F978D405800,,192.168.51.169:61633,,0,192.168.51.11:2881,Access denied for user,
2024-10-24 12:12:17.326814,proxy_OB01,,,,OB01:OB01:test_db,OB_MYSQL,,,OB_MYSQL_COM_STMT_SEND_PIECE_DATA,,failed,1045,,302us,0us,0us,302us,Y0-00007F978D405A40,,192.168.51.169:61790,,0,192.168.51.11:2881,Access denied for user,
2024-10-24 12:12:17.333840,proxy_OB01,,,,OB01:OB01:test_db,OB_MYSQL,,,OB_MYSQL_COM_STMT_RESET,,failed,1045,,234us,6us,0us,192us,Y0-00007F978D405580,,192.168.51.169:61792,,0,192.168.51.11:2881,Access denied for user,
2024-10-24 12:12:17.333883,proxy_OB01,,,,OB01:OB01:test_db,OB_MYSQL,,,OB_MYSQL_COM_STMT_RESET,,failed,1045,,19us,0us,0us,0us,Y0-00007F978D405580,,192.168.51.169:61792,,0,,Access denied for user,
2024-10-24 12:25:43.721648,proxy_OB01,,,,OB01:OB01:test_db,OB_MYSQL,,,OB_MYSQL_COM_STMT_RESET,,failed,1045,,355us,9us,0us,314us,Y0-00007F978D405A40,,192.168.51.169:61954,,0,192.168.51.11:2881,Access denied for user,
2024-10-24 12:25:43.721683,proxy_OB01,,,,OB01:OB01:test_db,OB_MYSQL,,,OB_MYSQL_COM_STMT_RESET,,failed,1045,,11us,0us,0us,0us,Y0-00007F978D405A40,,192.168.51.169:61954,,0,,Access denied for user,
2024-10-24 13:35:28.435861,proxy_OB01,,,,OB01:OB01:test_db,OB_MYSQL,,,OB_MYSQL_COM_STMT_EXECUTE,,failed,1045,,221us,0us,0us,221us,Y0-00007F978D405540,,192.168.51.169:62912,,0,192.168.51.11:2881,Access denied for user,
2024-10-24 15:25:22.390427,proxy_OB01,,,,OB01:OB01:test_db,OB_MYSQL,,,OB_MYSQL_COM_STMT_RESET,,failed,1045,,261us,0us,0us,215us,Y0-00007F978D405A00,,192.168.71.36:52218,,0,192.168.51.11:2881,Access denied for user,
2024-10-24 15:25:22.390593,proxy_OB01,,,,OB01:OB01:test_db,OB_MYSQL,,,OB_MYSQL_COM_STMT_RESET,,failed,1045,,0us,0us,0us,0us,Y0-00007F978D405A00,,192.168.71.36:52218,,0,,Access denied for user,

我抓取了obproxy_err.log 日志中最后几条报错，如下：

2024-10-24 15:24:59.651126,proxy_OB01,,,,OB01:OB01:test_db,OB_MYSQL,,,OB_MYSQL_COM_SLEEP,,failed,-4016,,252us,0us,0us,0us,Y0-00007F978D405540,,192.168.71.36:52185,,0,192.168.51.11:2881,Internal error,
2024-10-24 15:25:22.390427,proxy_OB01,,,,OB01:OB01:test_db,OB_MYSQL,,,OB_MYSQL_COM_STMT_RESET,,failed,1045,,261us,0us,0us,215us,Y0-00007F978D405A00,,192.168.71.36:52218,,0,192.168.51.11:2881,Access denied for user,
2024-10-24 15:25:22.390593,proxy_OB01,,,,OB01:OB01:test_db,OB_MYSQL,,,OB_MYSQL_COM_STMT_RESET,,failed,1045,,0us,0us,0us,0us,Y0-00007F978D405A00,,192.168.71.36:52218,,0,,Access denied for user,
2024-10-24 15:25:27.745156,proxy_OB01,,,,OB01:OB01:test_db,OB_MYSQL,,,OB_MYSQL_COM_STMT_FETCH,,failed,-4201,,440us,0us,0us,0us,Y0-00007F978D0097A0,,192.168.71.36:52230,,0,192.168.51.11:2881,hash map/set entry not exist,

根据最后几条错误中的日志流ID（Y0-00007F978D405540 这个字符串，不知道是不是叫日志流ID）和客户端IP:PROT (如：192.168.71.36:52218) 分别抓取了obproxy的所有日志记录如下：

Y0-00007F978D405540 192.168.71.36:52185 日志如下：

obproxy_diagnosis.log:[2024-10-24 15:24:59.647156] [3104][Y0-00007F978D405540] [LOGIN]([LOGIN](hsr={cluster_name:"OB01", tenant_name:"OB01", user_name:"s7", cluster_id:0, user_tenant_name:"s7@OB01", full_name:"s7@OB01#OB01", response:{capability_.capability:10199563, max_packet_size:1073741824, character_set:45, username:"s7@OB01", database:"test_db", auth_plugin_name:"mysql_native_password", connect_attrs:[[0]{key:"__mysql_client_type", value:"__ob_proxy"}, [1]{key:"__connection_id", value:"3221727299"}, [2]{key:"__proxy_connection_id", value:"13882401973896151646"}, [3]{key:"__cluster_name", value:"OB01"}, [4]{key:"__global_vars_version", value:"0"}, [5]{key:"__proxy_capability_flag", value:"3803735"}, [6]{key:"__proxy_scramble", value:"lSwupS
%~(Wm]z0N"}, [7]{key:"__client_ip", value:"192.168.71.36"}, [8]{key:"__proxy_version", value:"4.3.2.0"}, [9]{key:"__client_addr_port", value:"52185"}, [10]{key:"__client_session_id", value:"3970122"}, [11]{key:"__client_connect_time", value:"1729754699641257"}]}, is_clustername_from_default:true, has_tenant_username:true, has_cluster_username:false}, addr="192.168.71.36:52185", login_result="success")

obproxy_error.log:2024-10-24 15:24:59.651126,proxy_OB01,,,,OB01:OB01:test_db,OB_MYSQL,,,OB_MYSQL_COM_SLEEP,,failed,-4016,,252us,0us,0us,0us,Y0-00007F978D405540,,192.168.71.36:52185,,0,192.168.51.11:2881,Internal error,

obproxy.log:[2024-10-24 15:24:59.641243] INFO  [PROXY.NET] accept (ob_mysql_session_accept.cpp:36) [3104][Y0-00007F978D405540] [lt=0] [dc=0] [ObMysqlSessionAccept:main_event] accepted connection(netvc=0x7f978d3f5390, client_ip={192.168.71.36:52185})
obproxy.log:[2024-10-24 15:24:59.641272] INFO  [PROXY.NET] do_set_virtual_addr (ob_unix_net_vconnection.cpp:1256) [3104][Y0-00007F978D405540] [lt=0] [dc=0] vip connect(protocol=6, fd=365, vid=0, vaddr={192.168.71.36:2883}, caddr={192.168.71.36:52185}, daddr={192.168.51.11:2883}, remote_addr={192.168.71.36:52185})
obproxy.log:[2024-10-24 15:24:59.641286] INFO  [PROXY.CS] new_connection (ob_mysql_client_session.cpp:379) [3104][Y0-00007F978D405540] [lt=0] [dc=0] client session born(cs_id=3970122, proxy_sessid=0, is_local_connection=false, client_vc=0x7f978d3f5390, client_fd=365, client_addr="192.168.71.36:52185", is_proxy_client=false)
obproxy.log:[2024-10-24 15:24:59.642758] INFO  [PROXY.TXN] handle_handshake_pkt (ob_mysql_transact.cpp:5226) [3104][Y0-00007F978D405540] [lt=0] [dc=0] succ to set proxy_sessid(cs_id=3970122, proxy_sessid=13882401973896151646, server_ip={192.168.51.11:2881}, ss_id=11283, server_sessid=3221727299, is_proxy_mysql_client=false, ss_fd=370, client_addr="192.168.71.36:52185")
obproxy.log:[2024-10-24 15:24:59.651093] WDIAG [PROXY.SM] handle_obproxy_error_transfer (ob_mysql_sm.cpp:9750) [3104][Y0-00007F978D405540] [lt=0] [dc=0] [setup_error_transfer] Now closing connection(sm_id=25551, client_ip={192.168.71.36:52185}, request_cmd="Sleep", sql_cmd=NULL, sql=)

Y0-00007F978D405A00 192.168.71.36:52218 日志如下：

obproxy_diagnosis.log:[2024-10-24 15:25:22.383775] [3090][Y0-00007F978D405A00] [LOGIN]([LOGIN](hsr={cluster_name:"OB01", tenant_name:"OB01", user_name:"s7", cluster_id:0, user_tenant_name:"s7@OB01", full_name:"s7@OB01#OB01", response:{capability_.capability:10199563, max_packet_size:1073741824, character_set:45, username:"s7@OB01", database:"test_db", auth_plugin_name:"mysql_native_password", connect_attrs:[[0]{key:"__mysql_client_type", value:"__ob_proxy"}, [1]{key:"__connection_id", value:"3221728513"}, [2]{key:"__proxy_connection_id", value:"13882401973896151668"}, [3]{key:"__cluster_name", value:"OB01"}, [4]{key:"__global_vars_version", value:"0"}, [5]{key:"__proxy_capability_flag", value:"3803735"}, [6]{key:"__proxy_scramble", value:"5]#i7Z/
(k|"}, [7]{key:"__client_ip", value:"192.168.71.36"}, [8]{key:"__proxy_version", value:"4.3.2.0"}, [9]{key:"__client_addr_port", value:"52218"}, [10]{key:"__client_session_id", value:"3955723"}, [11]{key:"__client_connect_time", value:"1729754722379238"}]}, is_clustername_from_default:true, has_tenant_username:true, has_cluster_username:false}, addr="192.168.71.36:52218", login_result="success")

obproxy_error.log:2024-10-24 15:25:22.390427,proxy_OB01,,,,OB01:OB01:test_db,OB_MYSQL,,,OB_MYSQL_COM_STMT_RESET,,failed,1045,,261us,0us,0us,215us,Y0-00007F978D405A00,,192.168.71.36:52218,,0,192.168.51.11:2881,Access denied for user,
obproxy_error.log:2024-10-24 15:25:22.390593,proxy_OB01,,,,OB01:OB01:test_db,OB_MYSQL,,,OB_MYSQL_COM_STMT_RESET,,failed,1045,,0us,0us,0us,0us,Y0-00007F978D405A00,,192.168.71.36:52218,,0,,Access denied for user,

obproxy.log:[2024-10-24 15:25:22.379218] INFO  [PROXY.NET] accept (ob_mysql_session_accept.cpp:36) [3090][Y0-00007F978D405A00] [lt=0] [dc=0] [ObMysqlSessionAccept:main_event] accepted connection(netvc=0x7f978d3fbb40, client_ip={192.168.71.36:52218})
obproxy.log:[2024-10-24 15:25:22.379251] INFO  [PROXY.NET] do_set_virtual_addr (ob_unix_net_vconnection.cpp:1256) [3090][Y0-00007F978D405A00] [lt=0] [dc=0] vip connect(protocol=6, fd=341, vid=0, vaddr={192.168.71.36:2883}, caddr={192.168.71.36:52218}, daddr={192.168.51.11:2883}, remote_addr={192.168.71.36:52218})
obproxy.log:[2024-10-24 15:25:22.379262] INFO  [PROXY.CS] new_connection (ob_mysql_client_session.cpp:379) [3090][Y0-00007F978D405A00] [lt=0] [dc=0] client session born(cs_id=3955723, proxy_sessid=0, is_local_connection=false, client_vc=0x7f978d3fbb40, client_fd=341, client_addr="192.168.71.36:52218", is_proxy_client=false)
obproxy.log:[2024-10-24 15:25:22.380500] INFO  [PROXY.TXN] handle_handshake_pkt (ob_mysql_transact.cpp:5226) [3090][Y0-00007F978D405A00] [lt=0] [dc=0] succ to set proxy_sessid(cs_id=3955723, proxy_sessid=13882401973896151668, server_ip={192.168.51.11:2881}, ss_id=11313, server_sessid=3221728513, is_proxy_mysql_client=false, ss_fd=344, client_addr="192.168.71.36:52218")
obproxy.log:[2024-10-24 15:25:22.397703] INFO  [PROXY.TXN] handle_server_connection_break (ob_mysql_transact.cpp:6424) [3090][Y0-00007F978D405A00] [lt=0] [dc=0] [ObMysqlTransact::handle_server_connection_break](client_ip={192.168.71.36:52218}, server_ip={192.168.51.11:2881}, cs_id=3955723, proxy_sessid=13882401973896151668, ss_id=0, server_sessid=0, sm_id=25606, proxy_user_name=s7@OB01#OB01, database_name=test_db, server_state="CONNECTION_CLOSED", request_cmd="Quit", sql_cmd="Quit", sql=)

Y0-00007F978D0097A0 192.168.71.36:52230 日志如下：

obproxy_diagnosis.log:[2024-10-24 15:25:27.741367] [3099][Y0-00007F978D0097A0] [LOGIN]([LOGIN](hsr={cluster_name:"OB01", tenant_name:"OB01", user_name:"s7", cluster_id:0, user_tenant_name:"s7@OB01", full_name:"s7@OB01#OB01", response:{capability_.capability:10199563, max_packet_size:1073741824, character_set:45, username:"s7@OB01", database:"test_db", auth_plugin_name:"mysql_native_password", connect_attrs:[[0]{key:"__mysql_client_type", value:"__ob_proxy"}, [1]{key:"__connection_id", value:"3221728807"}, [2]{key:"__proxy_connection_id", value:"13882401973896151678"}, [3]{key:"__cluster_name", value:"OB01"}, [4]{key:"__global_vars_version", value:"0"}, [5]{key:"__proxy_capability_flag", value:"3803735"}, [6]{key:"__proxy_scramble", value:"k($Z>Sc}#Le}1@*""}, [7]{key:"__client_ip", value:"192.168.71.36"}, [8]{key:"__proxy_version", value:"4.3.2.0"}, [9]{key:"__client_addr_port", value:"52230"}, [10]{key:"__client_session_id", value:"3964943"}, [11]{key:"__client_connect_time", value:"1729754727736947"}]}, is_clustername_from_default:true, has_tenant_username:true, has_cluster_username:false}, addr="192.168.71.36:52230", login_result="success")

obproxy_error.log:2024-10-24 15:25:27.745156,proxy_OB01,,,,OB01:OB01:test_db,OB_MYSQL,,,OB_MYSQL_COM_STMT_FETCH,,failed,-4201,,440us,0us,0us,0us,Y0-00007F978D0097A0,,192.168.71.36:52230,,0,192.168.51.11:2881,hash map/set entry not exist,

obproxy.log:[2024-10-24 15:25:27.736926] INFO  [PROXY.NET] accept (ob_mysql_session_accept.cpp:36) [3099][Y0-00007F978D0097A0] [lt=0] [dc=0] [ObMysqlSessionAccept:main_event] accepted connection(netvc=0x7f978cffb1d0, client_ip={192.168.71.36:52230})
obproxy.log:[2024-10-24 15:25:27.736967] INFO  [PROXY.NET] do_set_virtual_addr (ob_unix_net_vconnection.cpp:1256) [3099][Y0-00007F978D0097A0] [lt=0] [dc=0] vip connect(protocol=6, fd=361, vid=0, vaddr={192.168.71.36:2883}, caddr={192.168.71.36:52230}, daddr={192.168.51.11:2883}, remote_addr={192.168.71.36:52230})
obproxy.log:[2024-10-24 15:25:27.736983] INFO  [PROXY.CS] new_connection (ob_mysql_client_session.cpp:379) [3099][Y0-00007F978D0097A0] [lt=0] [dc=0] client session born(cs_id=3964943, proxy_sessid=0, is_local_connection=false, client_vc=0x7f978cffb1d0, client_fd=361, client_addr="192.168.71.36:52230", is_proxy_client=false)
obproxy.log:[2024-10-24 15:25:27.738420] INFO  [PROXY.TXN] handle_handshake_pkt (ob_mysql_transact.cpp:5226) [3099][Y0-00007F978D0097A0] [lt=0] [dc=0] succ to set proxy_sessid(cs_id=3964943, proxy_sessid=13882401973896151678, server_ip={192.168.51.11:2881}, ss_id=11332, server_sessid=3221728807, is_proxy_mysql_client=false, ss_fd=362, client_addr="192.168.71.36:52230")
obproxy.log:[2024-10-24 15:25:27.745114] WDIAG [PROXY.SM] handle_obproxy_error_transfer (ob_mysql_sm.cpp:9750) [3099][Y0-00007F978D0097A0] [lt=0] [dc=0] [setup_error_transfer] Now closing connection(sm_id=25627, client_ip={192.168.71.36:52230}, request_cmd="Stmt fetch", sql_cmd=NULL, sql=���ط�e����)

淇铭 · 2024 年10 月 25 日 11:02

看着是连接有问题了用mysql连接有问题么？
例如：
mysql -hxx.xx.xx.xx -uroot@sys#obcluster -P2883 -p -A
obproxy_err.log obproxy_diagnosis.log obproxy.log 这三个日志在上传一下具体看看

AntTech_GASIPE · 2024 年10 月 25 日 14:16

连接没问题，就是偶尔就出来一下这种报错，这个报错会直接回报在程序客户端里（基本上5000次会出现3-5次报错），要是直接连observer 2881 一样的测试量，不会出现这个问题

淇铭 · 2024 年10 月 25 日 14:56

1、报错的时候 obproxy的连接数高么？大概多少连接数，obproxy的配置是？
2、obproxy的cpu和内存是否打满？内存和cpu波动大么？

AntTech_GASIPE · 2024 年10 月 25 日 15:30

1、报错的时候 obproxy的连接数高么？大概多少连接数，obproxy的配置是？
连接数都是稳定的，50-60之间， obproxy 和 observer在同一台机器部署，80核1T内存的服务器。

2、obproxy的cpu和内存是否打满？内存和cpu波动大么？
CPU 和内存使用量上面的监控图里有的，相对于服务器性能来说，都只用到一点点，波动不大。

辞霜 · 2024 年10 月 25 日 15:39

可以根据obproxy_error.log中的trace_id如Y0-00007F978D405540 去observer日志中抓取相关信息查看sql是什么原因失败的

淇铭 · 2024 年10 月 25 日 15:39

obproxy_err.log obproxy_diagnosis.log obproxy.log 这三个日志你发一下具体在看看

AntTech_GASIPE · 2024 年10 月 25 日 15:49

有试过的，但observer那边的日志里这些关键字去找，都是空的。没有匹配的日志

辞霜 · 2024 年10 月 25 日 16:09

从obproxy_diagnosis.log 审计日志观察你发的三个trace_id的连接都是属于未报错

AntTech_GASIPE · 2024 年10 月 27 日 19:46

log.zip (16.7 MB)

obproxy.log 日志量太大，选了三个都有报错的时间上传了。麻烦大佬再帮忙看看了。

辞霜 · 2024 年10 月 28 日 10:59

error日志中都是test_db用户的报错，Access denied for user这个报错是登录报错
[2024-10-27 15:18:57.392697] WDIAG [PROXY.SM] set_client_abort (ob_mysql_sm.cpp:8691) [245353][Y0-00002B79E1ACA610] [lt=0] [dc=0] client will abort soon(sm_id=364626, cs_id=3976673, proxy_sessid=0, ss_id=0, server_sessid=0, client_ip={127.0.0.1:63860}, server_ip={Not IP address [0]:0}
连不上服务端，可以去排查一下是否存在网络波动

AntTech_GASIPE · 2024 年10 月 28 日 11:35

网络都是内网机器，网络已经压测过了，没发现问题。
2024-10-27 15:18:57.392697 而且这条日志的时间范围，是没有出现Access denied for user这个报错的。并且出现Access denied for user 报错的日志，根据客户端IP:PORT是能抓出来相关登录成功的信息的。

辞霜 · 2024 年10 月 28 日 15:43

我是根据error日志的trace id在proxy日志查的
客户端–>proxy是成功的，proxy—>ob是失败的但是报错后会重试。
当前报错影响到了你的集群业务了么

AntTech_GASIPE · 2024 年10 月 28 日 15:48

对业务影响很大。
proxy 和 db 是同一台机器，那这个会是什么原因导致的呢？