OBProxy 日志分析总结

OBProxy 是 OceanBase 数据库访问代理，又称为 ODP ，在 OceanBase 的使用中起着非常重要的作用。应用连接 OceanBase 数据库绝大部分操作都要经过 OBProxy 并且留下相关日志，所以 OBProxy 的日志分析对于分析诊断应用的 OceanBase 连接问题、SQL 性能问题有很大帮助。

OBProxy 在整体架构中作用

下图是 OceanBase 解决方案的最简架构图。

OceanBase 数据库是分布式数据库，通常以集群型态部署，集群里节点（OBServer）规模数量不定，1~N 都有可能。N 如果是 1 就当单机数据库用，通常 N 是 3 的倍数。不管规模多大，OceanBase 集群还能将机器资源分拆为多个独立的租户（实例）提供给业务使用。每个业务使用的数据库只是 OceanBase 集群资源的一部分。

分布式数据库不管规模如何以及型态如何，呈现给应用的都像一个单机数据库实例，或者称为逻辑实例/逻辑数据库。在连接方式上也要做到这点。OceanBase 的集群服务器不提供给业务直接连接，而是前端部署多个 OBProxy 组成 ODP 集群提供数据库代理功能。

ODP 集群是在 OCP 里部署的，将一组 OBProxy 称为集群主要是方便运维管理。如部署、升级、重启、参数修改、性能监控和告警等等。特别是参数修改，OBProxy 很多的时候，改参数工作量也不低。所以集群化管理是必要的。

ODP 集群跟 OB 集群关系并不严格是 1：1 关系。如果有多套 OB 集群，可以共用相同的 ODP 集群，也可以分别使用不通的 ODP 集群。为了简单起见，客户一般是在 OB 集群服务器里挑选一组服务器部署 ODP 集群，不通 OB 集群的 ODP 集群也分开使用。

多个 OBProxy 虽然称为 ODP 集群，实际上并无集群的基本能力（高可用和负载均衡）。每个 OBProxy 独立工作，都可以访问到 OceanBase 集群。ODP 集群的高可用和负载均衡要借助于负载均衡设备（LB 设备，如 F5、A10 或 SLB、LVS）。很多分布式数据库都有这个设计。

每个 OBProxy 都是 OceanBase 集群的代表，都具备 OB 集群的路由能力，包括连接路由、SQL 路由。ODP 还有个 OBSharding 版本，支持分库分表，是另外一种分布式数据库解决方案，跟 OceanBase 没有必然的联系，这个以后再专门介绍。这里说的 OBProxy 作为 OceanBase 的代理，只负责路由，不做 SQL 运算（如聚合、排序、去重等）。工作负载低所以总体吞吐能力可以很高。本文后面主要是通过 OBProxy 日志分析路由细节信息。

OBProxy 连接原理

应用连接 OBProxy 或者应用连接 LB 提供的 VIP 间接连接到 OBProxy，OBProxy 再根据应用连接账户创建到后端 OBServer 节点的连接并转发应用 SQL 到该节点执行。

如上图，把 OBProxy 跟左边应用或 LB 的连接称为前端连接，把 OBProxy 跟右边 OBServer 节点的连接称为后端连接。每个前端连接可能会映射到后端 1 或 N 个后端连接。对于一个具体的连接，N最大是租户的节点数，不是集群的节点数。

后端连接数初始状态是 1 个，在需要的时候 OBProxy 会额外创建到其他 OBServer 节点的连接。这个取决于连接要执行的 SQL 里要读写的数据和读策略。OceanBase 集群里可以动态调整租户里数据分布（即表的分布），访问数据在哪里，OBProxy 就可能路由到哪里。之所以说是可能，是因为实际场景非常丰富导致 OBProxy 的路由策略很多。这个这次也不展开。只需要知道 OBProxy 虽然为 OceanBase 集群提供负载均衡的能力，但是是被动的（主要由 OceanBase 集群里数据分布决定）。这点要跟 LB 设备的路由策略（主备、RR 等）区分开。

前端链接和后端连接的映射类似于 NAT 映射。如果查看 TCP 连接，能看到应用跟 OBProxy 有个 TCP 连接（应用端端口是临时端口，OBProxy 端端口是 2883），OBProxy 跟后端多个 OBServer 端也分别有一个 TCP 连接（OBProxy端端口是临时端口， OBServer 端端口是 2881）。了解这个是方便有时候需要用 tcpdump 分析连接异常问题。这个后端连接里的 OBProxy 的临时端口以及应用服务器的临时端口，都可以用命令 show processlist 或者在 OceanBase.__all_virtual_processlist 里查看，也能在 OBProxy 日志里查看。

OBProxy 日志里的 “ID”

OBProxy 的日志（obproxy.log）默认日志级别是 INFO，按照大小滚动输出。OBProxy 日志里有很多 ID 对应的是连接中创建的对象。如客户端连接标识、对象地址、客户端 IP和端口、服务端 OBServer 的 IP 和端口、会话 ID 等等。这些 ID 能帮助将前后端连接的联系串联起来，并能进一步跟 OBServer 的日志串联起来。这些 ID 都方便事后分析。

OBProxy 日志里的“事件”

OBProxy 的日志里有很多事件的记录。事件是我这里的观察总结，并不一定精确反映产品的研发逻辑。所谓事件包括监听连接成功、前端连接建立、后端连接建立；连接中的慢 SQL、慢事务；后端连接关闭、前端连接关闭、连接相关对象释放。

日志里的主要内容就这些，只不过很多连接的事件日志穿插在一起，分析起来需要一些技巧。可以先从 cs_id 入手搜索，然后逐步扩大搜索（多个关键词同时搜索）。

OBProxy 日志示例

OBProxy 日志可以在节点服务器上直接搜索，也可以在 OCP 里搜索。我更倾向于前者。

下面以 JAVA 应用报密码错误为例，演示一下相关的日志。尽管这个有点小题大作，目的主要是熟悉相关日志。

应用 JAVA 报错信息如下，其中关键信息就是 conn=205721 以及异常名称。

[2024-01-09 13:30:41.369][database-sync-63][,7063811cf0e2,][INFO][com.oceanbase.odc.service.connection.database.DatabaseService][399]: sync database failed, dataSourceId=3, error message=Failed to obtain JDBC Connection; nested exception is java.sql.SQLException: java.sql.SQLSyntaxErrorException: Could not connect to 10.0.0.62:2883 : (conn=205721) Access denied for user 'TPCC'@'xxx.xxx.xxx.xxx' (using password: YES)

OBProxy 日志搜索 205721 找到连接建立时的日志。

[2024-01-09 13:30:41.365079] INFO [PROXY.SOCK] ob_connection.cpp:350 [9978][Y0-0] [lt=80] [dc=0] connection accepted(client={10.0.0.64:21780}, server={0.0.0.0:2883}, accepted_fd=81, listen_fd=57)
[2024-01-09 13:30:41.365569] INFO [PROXY.NET] ob_mysql_session_accept.cpp:36 [9946][Y0-7F2420A0E260] [lt=9] [dc=0] [ObMysqlSessionAccept:main_event] accepted connection(netvc=0x7f2420a07d20, client_ip={10.0.0.64:21780})
[2024-01-09 13:30:41.365610] INFO [PROXY.NET] ob_unix_net_vconnection.cpp:1243 [9946][Y0-7F2420A0E260] [lt=15] [dc=0] vip connect(protocol=6, fd=81, vid=0, vaddr={10.0.0.64:2883}, caddr={10.0.0.64:21780}, daddr={10.0.0.62:2883})
[2024-01-09 13:30:41.365624] INFO [PROXY.CS] ob_mysql_client_session.cpp:365 [9946][Y0-7F2420A0E260] [lt=11] [dc=0] client session born(cs_id=205721, proxy_sessid=0, is_local_connection=false, client_vc=0x7f2420a07d20, client_fd=81, client_addr="10.0.0.64:21780")
[2024-01-09 13:30:41.365638] INFO [PROXY.CS] ob_mysql_client_session.cpp:236 [9946][Y0-7F2420A0E260] [lt=6] [dc=0] Starting new transaction using sm(cs_id=205721, get_transact_count()=0, sm_id=2612696)

上面看到了客户端连接建立时的信息，以及内部 sm_id=261296 。正常情况下，这个 sm_id 贯穿整个连接生命周期。如果日志不全的话，说明 OBProxy 自身异常过。

[2024-01-09 13:30:41.366475] INFO [PROXY.SM] ob_mysql_sm.cpp:2098 [9946][Y0-7F2420A0E260] [lt=10] [dc=0] client login audit(client_addr={10.0.0.64:21780}, hsr.cluster_name_=obdemo, hsr.tenant_name_=oboracle, hsr.user_name_="TPCC", status="success")
[2024-01-09 13:30:41.366725] INFO [PROXY.SS] ob_mysql_server_session.cpp:105 [9946][Y0-7F2420A0E260] [lt=7] [dc=0] server session born(ss_id=160972, server_ip={10.0.0.61:2881}, cs_id=205721, proxy_sessid=0, server_type=1)
[2024-01-09 13:30:41.366917] INFO [PROXY.TXN] ob_mysql_transact.cpp:3873 [9946][Y0-7F2420A0E260] [lt=10] [dc=0] succ to set proxy_sessid(cs_id=205721, proxy_sessid=720576206856221790, server_ip={10.0.0.61:2881}, ss_id=160972, server_sessid=3221509959, is_proxy_mysql_client=false, ss_fd=104, client_addr="10.0.0.64:21780")

上面看到后端连接建立日志，看到 ODP 后端连接的内部标识 ss_id 以及 proxy_sessid 等后端 OBServer 的节点 IP、会话 ID 等。如果是正常的连接，在执行 SQL 的过程中会有多个后端连接建立的日志，每个后端连接的 ss_id 不同。proxy_sessid 跟 cs_id 是一一对应的，同时可能对应多个 ss_id 。

上面的后端连接建立日志只是表示 TCP 连接建立成功，还没有到数据库账户验证阶段。下面就看到连接收到 VC_EVENT_EOS 事件，然后 ODP 连接开始关闭连接了。

[2024-01-09 13:30:41.369086] INFO [PROXY.SM] ob_mysql_sm.cpp:524 [9946][Y0-7F2420A0E260] [lt=4] [dc=0] ObMysqlSM::state_client_request_read(event="VC_EVENT_EOS", sm_id=2612696, client_vc=0x7f2420a07d20)
[2024-01-09 13:30:41.369108] WARN [PROXY.SM] setup_error_transfer (ob_mysql_sm.cpp:7627) [9946][Y0-7F2420A0E260] [lt=3] [dc=0] [setup_error_transfer] Now closing connection(sm_id=2612696, request_cmd="Sleep", sql_cmd="GET PIECE DATA", sql=)

这里 VC_EVENT_EOS 事件原因不明，经验多是后端连接发生异常中断。具体还要到 OBServer 日志里去确认。

我会在最后面补上 OBServer 日志。这里继续分析 OBProxy 日志。

[2024-01-09 13:30:41.369128] INFO [PROXY.SS] ob_mysql_client_session.cpp:647 [9946][Y0-7F2420A0E260] [lt=8] [dc=0] client session do_io_close((*this={this:0x7f242355cb30, 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:9946, cs_id:205721, proxy_sessid:720576206856221790, session_info:{is_inited:true, priv_info:{has_all_privilege:false, cs_id:205721, user_priv_set:-1, cluster_name:"obdemo", tenant_name:"oboracle", user_name:"TPCC"}, 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:0, real_meta_cluster_name:"", safe_read_snapshot:0, syncing_safe_read_snapshot:0, route_policy:1, proxy_route_policy:3, user_identity:0, global_vars_version:-1, is_read_only_user:false, is_request_follower_user:false}, dummy_ldc:{use_ldc:false, idc_name:"", item_count:1, site_start_index_array:[[0]0, [1]1, [2]1, [3]1], item_array:[[0]{idc_type:"SAME_IDC", zone_type:"ReadWrite", replica:{server:"10.0.0.61:2881", is_dup_replica:false, role:"FOLLOWER", type:"FULL"}, is_merging:false, is_partition_server:false, is_force_congested:false, is_used:true}], pl:null, ts:0x7f241fe59b00, readonly_exist_status:"READONLY_ZONE_NOT_EXIST"}, dummy_entry:0x7f2421611160, server_state_version:29, cur_ss:null, bound_ss:0x7f241f166860, lii_ss:null, cluster_resource:{this:0x7f241ef96080, ref_count:56, is_inited:true, cluster_info_key:{cluster_name:{config_string:"obdemo"}, cluster_id:0}, cr_state:"CR_AVAIL", version:37, last_access_time_ns:1704778241368305066, deleting_completed_thread_num:0, fetch_rslist_task_count:0, fetch_idc_list_task_count:0, last_idc_list_refresh_time_ns:1704771058327064253, last_rslist_refresh_time_ns:0, server_state_version:29}, client_vc:0x7f2420a07d20, using_ldg:false, trace_stats:NULL}, client_vc_=0x7f2420a07d20, this=0x7f242355cb30)
[2024-01-09 13:30:41.369184] INFO [PROXY.SS] ob_mysql_server_session.cpp:145 [9946][Y0-7F2420A0E260] [lt=55] [dc=0] server session do_io_close((*this={ss_id:160972, server_sessid:3221509959, server_ip:{10.0.0.61:2881}, is_inited:true, magic:19136237, state:2, server_vc:0x7f24203ebc60, client_session:{this:0x7f242355cb30, 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:9946, cs_id:205721, proxy_sessid:720576206856221790, session_info:{is_inited:true, priv_info:{has_all_privilege:false, cs_id:205721, user_priv_set:-1, cluster_name:"obdemo", tenant_name:"oboracle", user_name:"TPCC"}, 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:0, real_meta_cluster_name:"", safe_read_snapshot:0, syncing_safe_read_snapshot:0, route_policy:1, proxy_route_policy:3, user_identity:0, global_vars_version:-1, is_read_only_user:false, is_request_follower_user:false}, dummy_ldc:{use_ldc:false, idc_name:"", item_count:1, site_start_index_array:[[0]0, [1]1, [2]1, [3]1], item_array:[[0]{idc_type:"SAME_IDC", zone_type:"ReadWrite", replica:{server:"10.0.0.61:2881", is_dup_replica:false, role:"FOLLOWER", type:"FULL"}, is_merging:false, is_partition_server:false, is_force_congested:false, is_used:true}], pl:null, ts:0x7f241fe59b00, readonly_exist_status:"READONLY_ZONE_NOT_EXIST"}, dummy_entry:0x7f2421611160, server_state_version:29, cur_ss:null, bound_ss:0x7f241f166860, lii_ss:null, cluster_resource:{this:0x7f241ef96080, ref_count:56, is_inited:true, cluster_info_key:{cluster_name:{config_string:"obdemo"}, cluster_id:0}, cr_state:"CR_AVAIL", version:37, last_access_time_ns:1704778241368305066, deleting_completed_thread_num:0, fetch_rslist_task_count:0, fetch_idc_list_task_count:0, last_idc_list_refresh_time_ns:1704771058327064253, last_rslist_refresh_time_ns:0, server_state_version:29}, client_vc:0x7f2420a07d20, 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: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}, checksum_switch:1, server_type:1}}, server_vc_=0x7f24203ebc60, this=0x7f241f166860)
[2024-01-09 13:30:41.369268] INFO [PROXY.SS] ob_mysql_server_session.cpp:177 [9946][Y0-7F2420A0E260] [lt=56] [dc=0] server session is closing(ss_id=160972, server_sessid=3221509959, server_ip={10.0.0.61:2881}, cs_id=205721, proxy_sessid=720576206856221790)
[2024-01-09 13:30:41.369286] INFO [PROXY.CS] ob_mysql_client_session.cpp:93 [9946][Y0-7F2420A0E260] [lt=6] [dc=0] client session destroy(cs_id=205721, proxy_sessid=720576206856221790, client_vc=NULL)
[2024-01-09 13:30:41.369325] INFO [PROXY.SM] ob_mysql_sm.cpp:8179 [9946][Y0-7F2420A0E260] [lt=10] [dc=0] deallocating sm(sm_id=2612696)

这部分就是 ODP 关闭前端连接、后端连接以及释放内部连接对象标识的日志。不同的异常场景下，前端连接和后端连接关闭顺序会不一样（这里说的是日志出现的顺序，实际连接关闭的逻辑和顺序要看 ODP 代码）。此外就是日常总结经验了。但就这个密码错误而言，OBServer 节点给 OBProxy 节点回复了一个异常报文（要求断开连接），ODP 就主动关闭连接，先关闭前端连接后关闭后端连接。

但是，如果是连接正常退出，那看到的就是后端连接退出日志先出现，前端连接退出日志后出现。并且还能看到handle_server_connection_break 和 COM_QUIT 事件。

如果连接正常执行 SQL，还能看到 Slow Query 和 Slow transaction 日志，日志里会包含很多时间指标，用于深入分析请求延时异常问题。

需要注意的是 OBProxy 里 Slow Query 和 Slow transaction 并不一定是 SQL 或事务结束了才打印，而是会定时打印，即使 SQL 还在执行过程中，所以这个日志里的执行时间也只是代表日志打印的时候这个 SQL 和事务的持续时间（可能还没有结束）。当然如果跟踪最后一次日志打印，那也能推断出耗时的大概时间了。实际也不用这么麻烦，obproxy_slow.log 离最终也会记录慢 Query 的耗时。

OBServer 日志

根据 OBProxy 日志里的 server_ip 和 server_sessid 到对应的 OBServer 节点搜索对应时间段的日志，可以发现一些连接异常的线索。

[2024-01-09 13:30:41.366782] INFO [RPC.OBMYSQL] obsm_conn_callback.cpp:98 [36479][0][Y0-0000000000000000-0-0] [lt=16] [dc=0] new mysql sessid created(conn.sessid_=3221509959, support_ssl=false)
[2024-01-09 13:30:41.366841] INFO [RPC.OBMYSQL] obsm_conn_callback.cpp:115 [36479][0][Y0-0000000000000000-0-0] [lt=23] [dc=0] sm conn init succ(conn.sessid_=3221509959, sess.client_addr_="10.0.0.62:48868")
[2024-01-09 13:30:41.366886] INFO [RPC.OBMYSQL] ob_sql_nio.cpp:935 [36479][0][Y0-0000000000000000-0-0] [lt=26] [dc=0] accept one succ(*s={this:0x7f4de26d9430, session_id:3221509959, trace_id:Y0-0000000000000000-0-0, sql_handling_stage:-1, sql_initiative_shutdown:false, fd:351, err:0, last_decode_time:0, last_write_time:1704778241366835, pending_write_task:{buf:null, sz:0}, need_epoll_trigger_write:false, consume_size:0, pending_flag:0, may_handling_flag:true, handler_close_flag:false})

这是 OBServer 对应的连接建立日志。两边关联分析要看时间的时间，这就要求 OBProxy 跟 OBServer 的时间误差要很小，不过通常 OBProxy 也是部署在 OBServer 上的，彼此的时间误差一定会很小（有 NTP 同步保障以及监控预警，误差大集群节点会异常）。

在上面日志的后面就发现异常相关的原因，提示是 -4043 错误 以及 password error 。搜索 -4043 错误号对应的应该也是密码错误。为什么说应该是呢，因为文档错误码里没有这个😓

[2024-01-09 13:30:41.367440] INFO [SHARE.SCHEMA] ob_schema_getter_guard.cpp:2997 [35984][0][Y0-00060D88029AE887-0-0] [lt=28] [dc=0] password error(tenant_name=oboracle, user_name=TPCC, client_ip=10.0.0.64, host_name=%)
[2024-01-09 13:30:41.367467] INFO [SHARE.SCHEMA] ob_schema_getter_guard.cpp:3021 [35984][0][Y0-00060D88029AE887-0-0] [lt=22] [dc=0] password error(tenant_name=oboracle, user_name=TPCC, client_ip_=10.0.0.64, ret=-4043)
[2024-01-09 13:30:41.367481] WDIAG [SERVER] obmp_connect.cpp:588 [35984][0][Y0-00060D88029AE887-0-0] [lt=6] [dc=0][errcode=-4043] User access denied(login_info={tenant_name:"oboracle", user_name:"TPCC", client_ip:"10.0.0.64", db:"TPCC", scramble_str:"X#A]3'dGu7OiDWg~hkb("}, ret=-4043)
[2024-01-09 13:30:41.367510] WDIAG [SERVER] obmp_connect.cpp:1805 [35984][0][Y0-00060D88029AE887-0-0] [lt=13] [dc=0][errcode=-4043] load privilege info fail(pre_ret=-4043, ret=-4043, GCTX.status_=2)
[2024-01-09 13:30:41.367524] WDIAG [SERVER] obmp_connect.cpp:256 [35984][0][Y0-00060D88029AE887-0-0] [lt=11] [dc=0][errcode=-4043] fail to verify_identify(ret=-4043)
[2024-01-09 13:30:41.367550] INFO [SERVER] obmp_packet_sender.cpp:302 [35984][0][Y0-00060D88029AE887-0-0] [lt=5] [dc=0] sending error packet(ob_error=-4043, client error=1045, extra_err_info=NULL, lbt()="0x11273810 0xc94feff 0xc916dc8 0xc9349cf 0x5cbbf6e 0x11d6d5cb 0x11d6e59a 0x11d6eaa8 0xcf2b3e0 0x6058d24 0x10bf4a23 0x10bf487f 0x11bb0b7f")

密码认证错误后， OBServer 给 OBProxy 回了一个“异常报文”，日志事件是 sending error packet 。

最后也是 OBServer 关闭连接日志。

[2024-01-09 13:30:41.367630] INFO [SERVER] obmp_base.cpp:298 [35984][0][Y0-00060D88029AE887-0-0] [lt=12] [dc=0] free session successfully(ctx={has_inc_active_num:false, tenant_id:1002, sessid:3221509959, proxy_sessid:720576206856221790})
[2024-01-09 13:30:41.367656] WDIAG [SERVER] obmp_packet_sender.cpp:730 [35984][0][Y0-00060D88029AE887-0-0] [lt=16] [dc=0][errcode=0] server close connection(sessid=3221509959, proxy_sessid=720576206856221790, stack="0x11273810 0xc952ee7 0xc927b0e 0xc934391 0x5cbbf6e 0x11d6d5cb 0x11d6e59a 0x11d6eaa8 0xcf2b3e0 0x6058d24 0x10bf4a23 0x10bf487f 0x11bb0b7f")
[2024-01-09 13:30:41.367682] INFO [SERVER] obmp_connect.cpp:374 [35984][0][Y0-00060D88029AE887-0-0] [lt=11] [dc=0] MySQL LOGIN(direct_client_ip="10.0.0.62", client_ip=10.0.0.64, tenant_name=oboracle, tenant_id=1002, user_name=TPCC, host_name=xxx.xxx.xxx.xxx, sessid=3221509959, proxy_sessid=720576206856221790, sess_create_time=0, from_proxy=true, from_java_client=false, capability=683647786, proxy_capability=2639, use_ssl=false, c/s protocol="OB_MYSQL_COMPRESS_CS_TYPE", proc_ret=-4043, ret=0)
[2024-01-09 13:30:41.367759] WDIAG [RPC.OBMYSQL] ob_sql_nio.cpp:747 [36479][0][Y0-0000000000000000-0-0] [lt=12] [dc=0][errcode=-4015] close sql sock by user req(*s={this:0x7f4de26d9430, session_id:3221509959, trace_id:Y0-0000000000000000-0-0, sql_handling_stage:256, sql_initiative_shutdown:true, fd:351, err:5, last_decode_time:1704778241367050, last_write_time:1704778241367741, pending_write_task:{buf:null, sz:0}, need_epoll_trigger_write:false, consume_size:364, pending_flag:1, may_handling_flag:true, handler_close_flag:false})
[2024-01-09 13:30:41.367788] INFO [RPC.OBMYSQL] obsm_conn_callback.cpp:226 [36479][0][Y0-0000000000000000-0-0] [lt=20] [dc=0] kill and revert session(conn.sessid_=3221509959, proxy_sessid=720576206856221790, server_id=1, ret=0)
[2024-01-09 13:30:41.367817] INFO [RPC.OBMYSQL] ob_sql_nio.cpp:830 [36479][0][Y0-0000000000000000-0-0] [lt=17] [dc=0] can close safely, do destroy(*s={this:0x7f4de26d9430, session_id:3221509959, trace_id:Y0-0000000000000000-0-0, sql_handling_stage:256, sql_initiative_shutdown:true, fd:351, err:5, last_decode_time:1704778241367050, last_write_time:1704778241367741, pending_write_task:{buf:null, sz:0}, need_epoll_trigger_write:false, consume_size:364, pending_flag:1, may_handling_flag:false, handler_close_flag:false})
[2024-01-09 13:30:41.367840] INFO [RPC.OBMYSQL] obsm_conn_callback.cpp:154 [36479][0][Y0-0000000000000000-0-0] [lt=15] [dc=0] connection close(sessid=3221509959, proxy_sessid=720576206856221790, tenant_id=1002, server_id=1, from_proxy=true, from_java_client=false, c/s protocol="OB_MYSQL_COMPRESS_CS_TYPE", is_need_clear_sessid_=true, ret=0)

更多阅读

• OBCE V3 培训：应用到数据库全链路优化实验部分

• OB 数据库全链路分析案例：租户/用户白名单机制

• OBCE V3 培训实验：应用到数据库全链路分析（下）

• OBCE V3 培训实验：应用到数据库全链路分析（上）

• OB 社区版实战之手动部署 OBProxy