1 引言
上篇文章我们讲解了 OBProxy 的安装部署，在实践时，大家还可能因为机器环境、操作顺序不对等问题导致安装部署失败，这时候可以到 OceanBase 的开源社区 问答 板块提问，会有专业的工程师回答你的问题。（也可以加入钉群：33254054 和技术同学面对面交流）完成了 OBProxy 的安装部署后，就可以使用 OBProxy 访问 OceanBase 数据库了。
刚开始使用 OBProxy ，排查问题和运维 OBProxy 是大家将要遇到的拦路虎。因此，本章我们将详细讲解 问题排查手段和服务运维方法 ，让大家更轻松的使用 OBProxy ，并成为 OBProxy 的专家。
OBProxy 是数据库访问链路上重要的一环，结合本文内容，大家可以举一反三，多多思考分布式系统的链路追踪、问题排查等内容，这对理解分布式系统有很大的帮助。好了，现在我们开始吧！
2 问题排查
大部分情况下，排查问题是需要团队协同完成的，下面我会介绍一些规范和思路，方便大家交流和解决问题。
2.1 描述问题
遇到问题时，我们首先需要描述清楚问题，最好是能够复现问题，这样才能让研发同学有效的解决问题。比如在 OceanBase 开源社区的问答版里提问时，建议描述问题可以用如下的模版：
<!-- 为了避免多次沟通确认，提升效率，请提供以下信息 -->【 使用环境 】生产环境 or 测试环境【 OB or 其他组件 】【 使用版本 】【问题描述】清晰明确描述问题【复现路径】问题出现前后相关操作【问题现象及影响】
【附件】
复制代码
这里推荐大家按照要求填写，填写内容的同时，也利于大家将问题梳理的更清楚。问题描述建议至少要包括以下两点：
问题时间：对于不好复现的问题，时间信息有利于进行问题梳理，方便对齐问题。客户端报错：客户端报错包含丰富的信息（SQL、堆栈、执行时间等），详细的信息对排查问题非常有帮助；当有结论时，可以前后对照结果，进一步验证结论。
2.2 分析问题
描述完问题后，对于问题排查人员，就需要分析问题。在分析问题前，首先要全局了解数据库访问链路，主要包含以下模块：
从全局再去看局部，思路会更清晰。OBProxy 和各个模块都有交互，大家有空可以多了解和学习下应用、LB 和 ObServer 的知识。当分析问题时，按照从前往后（从应用端开始）的顺序一个个分析，先确定哪个模块的问题，再确定模块的具体问题。
下面介绍一些低效的问题排查方法，大家尽量避免：
客户说应用使用数据库报错，直接去 OBProxy 的日志目录搜索 WARN 和 ERROR 级别日志，如果日志打印不规范或者 WARN/ERROR 日志太多，这种方法就十分的低效，甚至和客户问题没任何关系。客户说有数据库连接断了，我跳过了中间环节，直接从 OceanBase 数据库开始排查，结果未发现问题。
2.3 归类问题
本小节对 OBProxy 常见问题进行归类，方便大家在分析 OBProxy 模块时有更好的思路。从业务视角去看，OBProxy 的问题主要包含以下几类，下图中 ODP 是 OBProxy 的简称。
登录失败：绝大部分都是某个地方配置出现问题，比较容易复现和排查。
SQL 执行：出现问题种类很多，有些疑难问题很难排查 。
返回错误：后端服务返回明确的错误码，根据错误码去 OBServer 和 OBProxy 断排查。
慢 SQL：需要确定每个模块的耗时，找到瓶颈点去优化，除了 2.2 中的模块，网络也是一个重要因素。
断连接：和慢 SQL 类似，需要先排查哪个模块主动断开连接（主动发送 FIN 报文），然后排查具体模块。
2.4 总结
经过前面内容介绍，大家就有了问题排查的方法论，但这只是万里长征第一步，因为文章篇幅有限，没有在继续深入介绍下去，后面有一些简单例子，方便大家进一步了解。大家还需要不断的实战总结，才能面对问题做到游刃有余。
3 OBProxy 日志
解决 OBProxy 的问题时，有三大法宝：OBProxy 日志、Linux 命令（网络命令、系统命令和文本命令）和 OceanBase 云平台（OceanBase Cloud Platform，简称 OCP）。其中 Linux 命令和监控平台的知识点十分通用，网络上资料很多，大家可以自学，掌握后对大家排查问题帮助很大。
本节我们主要介绍和 OBProxy 关系比较紧密的日志部分，OBProxy 的日志有多种类别，我们将介绍每种日志的作用，帮助大家排查问题。
3.1 错误日志
错误日志的文件名叫做 obproxy_error.log，错误日志会记录执行错误的请求，包括 OBProxy 自身错误和 OBServer 返回错误。我们以 select obproxy_error from dual 做测试，其中 obproxy_error 字段没有加引号，会被当作列处理，导致执行失败。客户端报错如下：
MySQL [test]> select obproxy_error from dual;ERROR 1054 (42S22): Unknown column 'obproxy_error' in 'field list'
复制代码
打开 obproxy_error.log，内容如下：
2022-07-11 10:26:09.358231,undefined,,,,ob9988.zhixin.lm.xx.xx.xx.xx:sys:test,OB_MYSQL,,,COM_QUERY,SELECT,failed,1054,select obproxy_error from dual,42423us,454us,0us,41222us,Y0-7F4B1EF653A0,,,,0,xx.xx.xx.xx:33041,Unknown column 'obproxy_error' in 'field list'
# 日志通过逗号分隔，如果SQL中有逗号，会通过%2C替代，通过tr ',' '\n'替换结果如下
1,2022-07-11 10:26:09.358231 #日志打印时间2,undefined # sharding模式下逻辑租户名3, # 无需关注，内部使用4, # 无需关注，内部使用5, # sharding模式下逻辑库名6,ob9988.zhixin.lm.xx.xx.xx.xx:sys:test # 物理库信息（cluster:tenant:database）7,OB_MYSQL # 数据库类型8, # 逻辑表名9, # 物理表名10,COM_QUERY # SQL 命令（COM_QUERY、COM_STMT_PREPARE等）11,SELECT # SQL 类型12,failed # 执行结果（success/failed）13,1054 # 错误码（succ时为空）14,select obproxy_error from dual # SQL语句15,42423us # 执行总耗时（ms，包括内部 SQL 执行耗时16,454us # 预执行时间17,0us # 建立连接时间18,41222us # 数据库执行时间19,Y0-7F4B1EF653A0 # OBProxy内部日志trace_id20, # 无需关注，内部使用21, # 无需关注，内部使用22, # 无需关注，内部使用23,0 # 无需关注，内部使用24,xx.xx.xx.xx:33041 # 路由到的ObServer的地址信息25,Unknown column 'obproxy_error' in 'field list' # 报错信息
复制代码
3.2 审计日志
审计日志的文件名叫做 obproxy_digest.log，审计日志记录执行时间大于参数 query_digest_time_threshold 阈值（默认 100ms）的请求和错误响应请求。对于 3.1 中的例子，我们从 obproxy_digest.log 中也可以看到日志。
2022-07-11 10:26:09.358221,undefined,,,,ob9988.zhixin.lm.xx.xx.xx.xx:sys:test,OB_MYSQL,,,COM_QUERY,SELECT,failed,1054,select obproxy_error from dual,42423us,454us,0us,41222us,Y0-7F4B1EF653A0,,,,0,xx.xx.xx.xx:33041
复制代码
除了执行错误 SQL，我们使用 select sleep(3) from dual 模仿慢 SQL，执行后，查看 obproxy_digest.log，可以看到 OBProxy 执行花费了 409us，ObServer 执行花了 3039883us 。内容如下：
2022-07-11 14:32:51.758265,undefined,,,,ob9988.zhixin.lm.xx.xx.xx.xx:sys:test,OB_MYSQL,,,COM_QUERY,SELECT,success,,select sleep(3),3041116us,409us,0us,3039883us,Y0-7F4B1CEA13A0,,,,0,xx.xx.xx.xx:33041
日志分析
1,2022-07-11 14:32:51.758265 #日志打印时间2,undefined # sharding模式下逻辑租户名3, # 无需关注，内部使用4, # 无需关注，内部使用5, # sharding模式下逻辑库名6,ob9988.zhixin.lm.100.88.147.179:sys:test # 物理库信息（cluster:tenant:database）7,OB_MYSQL # 数据库类型8, # 逻辑表名9, # 物理表名10,COM_QUERY # SQL 命令（COM_QUERY、COM_STMT_PREPARE等）11,SELECT # SQL 类型12,success # 执行结果（success/failed）13, # 错误码（succ时为空）14,select sleep(3) # SQL语句15,3041116us # 执行总耗时（ms，包括内部 SQL 执行耗时16,409us # 预执行时间17,0us # 建立连接时间18,3039883us # 数据库执行时间19,Y0-7F4B1CEA13A0 # OBProxy内部日志trace_id20, # 无需关注，内部使用21, # 无需关注，内部使用22, # 无需关注，内部使用23,0 # 无需关注，内部使用24,xx.xx.xx.xx:33041 # 路由到的ObServer的地址信息
复制代码
3.3 慢日志
慢日志的文件名叫做 obproxy_slow.log ，慢日志记录执行时间大于 slow_query_time_threshold 阈值（默认 500ms）的请求。如上节 SQL select sleep(3) from dual 在 obproxy_slow.log 中也有记录，内容如下：
2022-07-11 14:32:51.758270,undefined,,,,ob9988.zhixin.lm.xx.xx.xx.xx:sys:test,OB_MYSQL,,,COM_QUERY,SELECT,success,,select sleep(3),3041116us,409us,0us,3039883us,Y0-7F4B1CEA13A0,,,,0,xx.xx.xx.xx:33041
复制代码
慢日志的日志格式和审计日志的格式相同，此处不在介绍。
对于慢 SQL，在 obproxy.log 也会有记录，关键字是 Slow Query ，obproxy.log 中记录的信息更加详细，如上面的 SQL，搜索 obproxy.log 得到：
[2022-07-11 14:32:51.758195] WARN [PROXY.SM] update_cmd_stats (ob_mysql_sm.cpp:8425) [74744][Y0-7F4B1CEA13A0] [lt=7] [dc=0] Slow Query: ((client_ip={127.0.0.1:50422}, // 发送SQL的客户端地址server_ip={xx.xx.xx.xx:33041}, // SQL被路由到的目标BOServerobproxy_client_port={xx.xx.xx.xx:52052}, // 和OBServer连接的本地地址server_trace_id=Y81100B7C0535-0005E3460FBBE3CD-0-0, // 目标OBServer中执行过程中的trace idroute_type=ROUTE_TYPE_NONPARTITION_UNMERGE_LOCAL, // SQL使用的路由策略user_name=root, // 用户名tenant_name=sys, // 租户名cluster_name=ob9988.zhixin.lm.100.88.147.179, // 集群名logic_database_name=, // 逻辑库名logic_tenant_name=, // 逻辑租户名ob_proxy_protocol=0, // 协议类型cs_id=14, // client login时看到的connection id, proxy分配proxy_sessid=7230691598940700681, // client 访问ob时内部记录connection idss_id=21, server_sessid=3221588238, // SQL在目标observer中的connection id, observer 分配sm_id=14, cmd_size_stats={ client_request_bytes:20, // client发给proxy的请求包大小 server_request_bytes:38, // OBProxy发给目标observer的请求包大小 server_response_bytes:0, // 目标observer发给proxy的响应包大小 client_response_bytes:71}, // OBProxy发给client的响应包大小cmd_time_stats={ client_transaction_idle_time_us=0, // 在事务中该条SQL与上一条SQL执行结束之间的间隔时间, 即client事务间隔时间 client_request_read_time_us=97, // OBProxy从client socket读取请求包的耗时 client_request_analyze_time_us=95, // OBProxy分析client的SQL耗时 cluster_resource_create_time_us=0, // OBProxy创建集群资源耗时(仅首次访问集群时需要创建) pl_lookup_time_us=0, // 根据SQL获取涉及路由表的耗时 pl_process_time_us=0, // 对涉及路由表的进行筛选排序的耗时 congestion_control_time_us=21, // 根据SQL获取涉及黑名单信息的耗时 congestion_process_time_us=3, // 对涉及黑名单的进行检查过滤的耗时 do_observer_open_time_us=55, // 对目标observer获取可用连接的耗时, 包含connect_time server_connect_time_us=0, // 对目标observer创建连接的耗时 server_sync_session_variable_time_us=0, // 对选择的目标连接进行初始化的耗时, 包括saved_login, 同步db, 同步系统变量, 同步last_insert_id, 同步start_trans server_send_saved_login_time_us=0, // 对选择的目标连接进行saved login耗时 server_send_use_database_time_us=0, // 对选择的目标连接同步db耗时 server_send_session_variable_time_us=0, // 对选择的目标连接同步已修改的系统变量耗时 server_send_all_session_variable_time_us=0, // 对选择的目标连接同步所有系统耗时 server_send_last_insert_id_time_us=0, // 对选择的目标连接同步last_insert_id耗时 server_send_start_trans_time_us=0, // 对选择的目标连接同步start_trans/begin耗时 build_server_request_time_us=23, // 构建对目标server的请求包的耗时 plugin_compress_request_time_us=0, // 对请求包进行压缩耗时 prepare_send_request_to_server_time_us=409, // OBProxy接受到客户端请求，到转发到observer执行前总计时间，正常应该是前面所有时间之和 server_request_write_time_us=32, // OBProxy向目标server socket发送请求包的耗时 server_process_request_time_us=3039883, // 目标server该执行SQL的耗时 server_response_read_time_us=67, // OBProxy从目标server socket读取响应包的耗时 plugin_decompress_response_time_us=59, // 对响应包进行解压缩耗时 server_response_analyze_time_us=70, // 对响应包进行分析的耗时 ok_packet_trim_time_us=0, // 对响应包trim掉最后一个ok包的耗时 client_response_write_time_us=185, // OBProxy向client socket发送响应包的耗时 request_total_time_us=3041116}, // OBProxy处理该请求总时间, 等于前面所有耗时之和sql=select sleep(3) //client的请求SQL)
复制代码
上面内容非常的详细，方便定位慢 SQL 问题。对于每个部分的含义，大家可以参考第一篇《OceanBase 改写系列一：OceanBase 查询改写实践概述》中讲的 SQL 执行流程（确认下文章和链接是否正确）去对应。
3.4 统计日志
统计日志的文件名叫做 obproxy_stat.log。 统计日志默认每分钟（monitor_stat_dump_interval 参数控制）输出一次。通过该日志可以查看 OBProxy 一分钟内 SQL 的执行情况，举个例子，查看 OBProxy 是否有请求流量，看该日志记录即可。参考例子如下：
2022-07-11 10:26:59.499204,undefined,,ob9988.zhixin.lm.xx.xx.xx.xx:sys:test,OB_MYSQL,SELECT,success,,1,1,0,0,41480us,332us,40369us
日志分析
1,2022-07-11 10:26:59.499204 #日志打印时间2,undefined # sharding模式下逻辑租户名3, # sharding模式下逻辑库名4,ob9988.zhixin.lm.xx.xx.xx.xx:sys:test # 物理库信息（cluster:tenant:database）5,OB_MYSQL # 数据库类型6,SELECT # SQL 类型7,success # 执行结果（success/failed）8, # 错误码（succ时为空）9,1 # 总请求数量1 # 30 ms ~ 100 ms 请求数量0 # 100 ms ~ 500 ms 请求数量0 # 大于 500 ms 请求数量41480us # 执行总耗时（ms，包括内部 SQL 执行耗时）332us # 预执行时间40369u # 数据库执行时间
复制代码
3.5 主日志
主日志的文件名叫做 obproxy.log，有 DEBUG、TRACE、INFO、ERROR 四种级别，通过 syslog_level 参数控制，当需要进一步排查问题原因时，通过 trace_id 字段可以过滤得到一个 session 上的所有日志，查看 obproxy.log 要求对 OBProxy 的代码实现非常熟悉，有一定技术难度。感兴趣同学可以查看 OBProxy 源代码。
3.6 总结
OBProxy 的日志在排查问题时非常的有用，掌握上面内容可以应对大部分的 OBProxy 问题。本节对日志格式做了介绍，并结合例子进一步说明，相信大家可以快速掌握。
4 服务运维
OBProxy 有一个管理员账号 root@proxysys ，为了安全，我们对该账号的登录地址做了限制，要求大家本机登录进行运维操作。下面我们将从配置管理和内部命令两方面做详细介绍。
4.1 配置管理
OBProxy 的配置参数参考文档参数说明。使用 root@proxysys 登录，就可以查看和修改配置项：
# 查看日志级别
MySQL [(none)]> show proxyconfig like '%syslog_level%';+--------------+-------+-----------------------------------------------------------------------------------+-------------+---------------+| name | value | info | need_reboot | visible_level |+--------------+-------+-----------------------------------------------------------------------------------+-------------+---------------+| syslog_level | DEBUG | specifies the current level of logging: DEBUG, TRACE, INFO, WARN, USER_ERR, ERROR | false | USER |+--------------+-------+-----------------------------------------------------------------------------------+-------------+---------------+
# 修改日志级别为INFO
MySQL [(none)]> alter proxyconfig set syslog_level = INFO;Query OK, 0 rows affected (0.01 sec)
复制代码
对于 show proxyconfig 的输入，各字段含义如下：
name：配置名，所有配置项名字可以从参数说明文档获取。
value：配置内容，主要是整型和字符串格式。当内容不合法时会报错。
info：描述配置参数的具体信息。
need_reboot：表示参数是否重启生效。这里需要注意有些参数虽然不需要重启，但有时只对新的连接生效。
4.2 内部命令
内部命令只在 OBProxy 上执行，不会转发给 OBServer，主要用于获取 OBProxy 的内部状态或者修改内部行为。这部分内容和原理关系紧密，本节只做简要介绍，后续大家对 OBProxy 有更深入了解后可以再学习。
5 总结
本章内容是对 OBProxy 的问题排查总结，这些方法凝聚了 OBProxy 技术专家多年的心血，经过了大量的实战检验。不仅可以用来学习，也可以作为手册，当遇到 OBProxy 问题时翻阅查看相关内容说明，希望能帮助到大家！
6 课后互动
6.1 上期互动
obproxyd.sh 脚本对 OBProxy 进程做了探活，请问探活方法是什么？除了脚本中的方法，还有哪些探活方法？这些方法有什么优缺点，请举例说明。
obproxyd.sh 通过查看/proc/$pid 文件是否存进行探活。还可以通过检测端口是否在监听确认是否存活。这两种方法做到进程级别探测，但某些场景下，如果进程异常不能执行业务逻辑就无法探测到，更进一步可以发送应用心跳报文进行检测。
6.2 本期互动
小明想查看所有经过 OBProxy 的 SQL，请问有什么办法？
评论