OBProxy 日志分析总结

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

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 都方便事后分析。

字段名

含义

cs_id

ODP 内部标识前端连接的 ID。客户端连接  ODP  成功后运行  connection_Id()  返回值,能跟踪连接的完整生命周期。

ss_id

ODP 内部标识后端连接的 ID。

sm_id

ODP 连接管理的一个 内部 ID,能跟踪连接的完整生命周期。

proxy_sessid

ODP 标识客户端连接的 ID,会传递给后端  OBServer  节点。对关联分析有帮助。

server_sessid

ODP 后端连接在 OBServer 端的标识。对关联分析有帮助。

client

client_ip

caddr

client_addr

ODP 前端连接的客户端地址(包括 IP  和端口),对客户端 tcpdump 关联分析有帮助。

obproxy_client_port

ODP 后端连接的 ODP 地址(包括  IP  和临时端口),对后端连接 tcpdump 分析有帮助。

server_ip

ODP 后端连接的 OBServer地址(包括  IP  和连接端口  2881)。

OBProxy 日志里的“事件”

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

字段名

含义

connection accepted

accepted connection

客户端连接 ODP 监听成功。记录客户端的  IP 和临时端口,以及目标短监听地址  IP  和端口。

vip connect

记录客户端连接 ODP VIP 相关信息。包括客户端地址、VIP  地址和实际  ODP  地址(IP和端口)。

client session born

ODP 前端连接建立成功,记录前端连接的内部 cs_Id  以及客户端地址  IP  和端口。

Starting new transaction using sm

ODP 为客户端连接分配内部内存对象,记录 sm_id  。

server session born

ODP 发起后端连接,记录前端连接的 cs_id  和  后端 OBServer  地址(IP和端口  2881)。

succ to set proxy_sessid

ODP 后端连接建立成功,为后端连接分批 proxy_sessid  并传递给  OBServer  节点,以及记录前后端连接相关信息。

Slow Query:

后端连接的慢查询事件,包括登录事件、SQL  查询等。记录了  ODP  后端连接的详细信息以及集群和租户信息。

Slow Transaction:

后端连接的慢事务信息。包括  ODP 后端连接的详细信息以及集群和租户信息。

client session do_io_close 前端连接关闭事件。
server session do_io_closeserver session is closing 后端连接关闭事件。
setup_error_transfer 前端连接传输报错。记录了前端连接正在执行的 SQL,ODP  的  sm_id 和前端连接客户端地址。
client will abort soon 前端连接中断事件。
client session destroy 前端连接关闭事件。
deallocating sm ODP 释放客户端连接的内部内存对象。

日志里的主要内容就这些,只不过很多连接的事件日志穿插在一起,分析起来需要一些技巧。可以先从 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)