【 使用环境 】测试环境
【 OB or 其他组件 】obclient obproxy
【 使用版本 】4.0 beta
【问题描述】
obproxy是使用命令行带参数启动,启动后日志无报错,但obclient登录失败报【received malformed packet】错误,无法登录root@proxysys。使用mysql客户端登录是正常的。
[admin@bogon obproxy-ce]$ mysql -h127.1 -uroot@proxysys -P2883
Welcome to the MariaDB monitor. Commands end with ; or \g.
Your MySQL connection id is 2
Server version: 5.6.25
Copyright (c) 2000, 2018, Oracle, MariaDB Corporation Ab and others.
Type ‘help;’ or ‘\h’ for help. Type ‘\c’ to clear the current input statement.
MySQL [(none)]> quit
Bye
[admin@bogon obproxy-ce]$ obclient -h127.1 -uroot@proxysys -P2883
ERROR 2027 (HY000): received malformed packet
【复现路径】
操作系统centos7.9
obproxy启动参数如下:
/home/admin/obproxy-ce/bin/obproxy -p2883 -r’192.168.170.89:2881;192.168.170.89:3881;192.168.170.89:4881’ -c demo01 -e -o 'syslog_level=INFO,proxy_mem_limited=1G’
【问题现象及影响】
影响:obclient无法登录root@proxysys。
日志:
obclient登陆时,日志中对应请求的status是success:
[2022-11-03 15:53:34.224435] INFO [PROXY.SM] ob_mysql_sm.cpp:2212 [12105][Y0-00007F80108383A0] [lt=8] [dc=0] client login audit(client_addr={127.0.0.1:4630}, hsr.cluster_name_=demo01, hsr.tenant_name_=proxysys, hsr.user_name_=root, status=“success”)
但随后解析错误:
[2022-11-03 15:53:34.231073] INFO [PROXY.ICMD] ob_dds_config_handler.cpp:222 [12118][Y0-00007F8019706E20] [lt=0] [dc=0] succ to encode_eof_packet
[2022-11-03 15:53:43.145570] INFO [PROXY.ICMD] ob_show_config_handler.cpp:190 [12117][Y0-00007F8019706E20] [lt=0] [dc=0] succ to dump config(like_name=)
[2022-11-03 15:53:45.051484] INFO [PROXY.SM] ob_mysql_sm.cpp:8163 [12105][Y0-00007F80108383A0] [lt=4] [dc=0] [setup_error_transfer] Now closing connection caused by OB_MYSQL_COM_QUIT(sm_id=1, request_cmd=“Quit”, sql_cmd=“Quit”, sql=)
[2022-11-03 15:53:45.051547] INFO [PROXY.SS] ob_mysql_client_session.cpp:637 [12105][Y0-00007F80108383A0] [lt=53] [dc=0] client session do_io_close((*this={this:0x7f8011e1d230, 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:12105, cs_id:1, proxy_sessid:0, session_info:{is_inited:true, priv_info:{has_all_privilege:true, cs_id:1, user_priv_set:-1, cluster_name:“demo01”, tenant_name:“proxysys”, 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:0, sys_var_version:0, user_var_version:0, db_name_version:0, last_insert_id_version:0, sess_info_version:0}, 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:-1, is_global_vars_changed:false, is_trans_specified:false, is_user_idc_name_set:false, is_read_consistency_set:false, idc_name:"", cluster_id:-1, real_meta_cluster_name:"", safe_read_snapshot:0, syncing_safe_read_snapshot:0, route_policy:1, proxy_route_policy:3, user_identity:3, global_vars_version:-1, is_read_only_user:false, is_request_follower_user:false, 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, payload_len:0, version:0, flag_.flags:0, reserved:0}}, client_cap:0, server_cap:0}, dummy_ldc:{use_ldc:false, idc_name:"", item_count:0, site_start_index_array:[[0]0, [1]0, [2]0, [3]0], item_array:null, pl:null, ts:null, readonly_exist_status:“READONLY_ZONE_UNKNOWN”}, dummy_entry:null, server_state_version:0, cur_ss:null, bound_ss:null, lii_ss:null, cluster_resource:NULL, client_vc:0x7f8010828120, using_ldg:false, trace_stats:NULL}, client_vc_=0x7f8010828120, this=0x7f8011e1d230)
[2022-11-03 15:53:45.051642] INFO [PROXY.CS] ob_mysql_client_session.cpp:92 [12105][Y0-00007F80108383A0] [lt=86] [dc=0] client session destroy(cs_id=1, proxy_sessid=0, client_vc=NULL)
[2022-11-03 15:53:45.051689] INFO [PROXY.SM] ob_mysql_sm.cpp:8731 [12105][Y0-00007F80108383A0] [lt=4] [dc=0] deallocating sm(sm_id=1)
[2022-11-03 15:53:47.967309] INFO [PROXY.SOCK] ob_connection.cpp:367 [12129][Y0-0000000000000000] [lt=0] [dc=0] connection accepted(client={127.0.0.1:4632}, server={0.0.0.0:2883}, accepted_fd=56, listen_fd=54)
[2022-11-03 15:53:47.967442] INFO [PROXY.NET] ob_mysql_session_accept.cpp:36 [12105][Y0-00007F800E55E3A0] [lt=4] [dc=0] [ObMysqlSessionAccept:main_event] accepted connection(netvc=0x7f800e54e120, client_ip={127.0.0.1:4632})
[2022-11-03 15:53:47.967523] INFO [PROXY.NET] ob_unix_net_vconnection.cpp:1227 [12105][Y0-00007F800E55E3A0] [lt=59] [dc=0] vip connect(protocol=6, fd=56, vid=0, vaddr={127.0.0.1:2883}, caddr={127.0.0.1:4632}, daddr={127.0.0.1:2883})
[2022-11-03 15:53:47.967572] INFO [PROXY.CS] ob_mysql_client_session.cpp:364 [12105][Y0-00007F800E55E3A0] [lt=6] [dc=0] client session born(cs_id=2, proxy_sessid=0, is_local_connection=true, client_vc=0x7f800e54e120, client_fd=56, client_addr=“127.0.0.1:4632”)
[2022-11-03 15:53:47.967585] INFO [PROXY.CS] ob_mysql_client_session.cpp:235 [12105][Y0-00007F800E55E3A0] [lt=6] [dc=0] Starting new transaction using sm(cs_id=2, get_transact_count()=0, sm_id=2)
[2022-11-03 15:53:47.967591] INFO [PROXY.SM] ob_mysql_sm.cpp:508 [12105][Y0-00007F800E55E3A0] [lt=3] [dc=0] the request already in buffer, continue to handle it(buffer len=0, is_auth_rquest=true)
[2022-11-03 15:53:47.967597] WARN [PROXY] get_cluster_name (ob_session_field_mgr.cpp:617) [12105][Y0-00007F800E55E3A0] [lt=3] [dc=0] fail to get cluster name(ret=-4018)
[2022-11-03 15:53:47.967901] INFO [PROXY.SM] ob_mysql_sm.cpp:2212 [12105][Y0-00007F800E55E3A0] [lt=6] [dc=0] client login audit(client_addr={127.0.0.1:4632}, hsr.cluster_name_=demo01, hsr.tenant_name_=proxysys, hsr.user_name_=root, status=“success”)
[2022-11-03 15:53:47.968651] INFO [PROXY.ICMD] ob_dds_config_handler.cpp:222 [12118][Y0-00007F8019706E20] [lt=10] [dc=0] succ to encode_eof_packet
[2022-11-03 15:53:47.968998] INFO [PROXY.SM] ob_mysql_sm.cpp:570 [12105][Y0-00007F800E55E3A0] [lt=25] [dc=0] ObMysqlSM::state_client_request_read(event=“VC_EVENT_EOS”, sm_id=2, client_vc=0x7f800e54e120)
[2022-11-03 15:53:47.969022] INFO [PROXY.TXN] ob_mysql_transact.cpp:79 [12105][Y0-00007F800E55E3A0] [lt=22] [dc=0] [ObMysqlTransact::bad_request] parser marked request bad
[2022-11-03 15:53:47.969048] WARN [PROXY.SM] setup_error_transfer (ob_mysql_sm.cpp:8171) [12105][Y0-00007F800E55E3A0] [lt=25] [dc=0] [setup_error_transfer] Now closing connection(sm_id=2, request_cmd=“Sleep”, sql_cmd=“GET PIECE DATA”, sql=)
【附件】