OBServer 中的非预期报错如何抓日志排错

背景
很多社区版的用户，在遇到非预期报错后，会到 OceanBase 论坛中进行提问，这是一个很好的解决问题的方法。不仅会有很多热心用户帮您来解决问题，还会有专业的值班同学来为大家服务。
但也有部分刚来社区的新用户，提问时只提供一个错误码，这往往是不够的。一般还需要附带上OBServer 版本信息、执行的操作序列，以及相关日志信息，以便值班的技术支持同学在本地复现和协助排查根因。
如果只提供一个错误码和对应的报错信息 Internal error，大概率是看不出问题原因的，还需要用户协助提供这个错误码对应的日志信息。
在遇到非预期的报错时，需要提供一些信息，并捞取 OBServer 的日志上传到论坛。
收集报错相关的信息
提供信息的目的是为了在本地环境中复现遇到的问题，通常需要提供如下信息：
● 组件版本和部署方式，例如:OceanBase_CE-v4.3.5.1单机部署。(为了能在相同的环境中，复现遇到的问题)
● 报错涉及的表结构。(为了能在相同的环境中，复现遇到的问题)
● 导致报错的 SQL 执行序列。(为了能在相同的环境中，复现遇到的问题)
● 报错对应的日志信息。
连接数据库，并登录用户租户
obclient -h127.0.0.1 -P2881 -uroot@mysql_tenant -A -Dtest
组件版本获取
在连接数据库时能看到组件版本
[root@iZbp16d52pf92miva1xqx2Z ~]# obclient -h127.0.0.1 -P2881 -uroot@mysql_tenant -A -Dtest
Welcome to the OceanBase. Commands end with ; or \g.
Your OceanBase connection id is 3221491724
Server version: OceanBase_CE 4.3.5.1 (r101010042025042417-0c7ffd37c2904f4d8191fb2d056738a93cce6d1d) (Built Apr 24 2025 17:44:55)

Copyright © 2000, 2018, OceanBase and/or its affiliates. All rights reserved.

Type ‘help;’ or ‘\h’ for help. Type ‘\c’ to clear the current input statement.

obclient [test]>
或
obclient [test]> select version();
±-----------------------------+
| version() |
±-----------------------------+
| 5.7.25-OceanBase_CE-v4.3.5.1 |
±-----------------------------+
1 row in set (0.001 sec)
捞取报错对应的 OBServer 日志信息
模拟报错场景1
创建一张测试表
CREATE TABLE t1 (c1 TIMESTAMP CHECK(c1 + UNIX_TIMESTAMP() > ‘2025-07-30 01:02:03’));
输出如下报错：
obclient [test]> CREATE TABLE t1 (c1 TIMESTAMP CHECK(c1 + UNIX_TIMESTAMP() > ‘2025-07-30 01:02:03’));
ERROR 3814 (HY000): An expression of a check constraint contains disallowed function.
ERROR 3814 (HY000): An expression of a check constraint contains disallowed function。(expression 表达 表示)
这个报错信息说： check 约束里包含了不允许出现的系统函数。
但 check 约束里有多个系统函数，分别是 ADD（+）、GREATER_THAN（>）和 UNIX_TIMESTAMP。具体是哪个或者哪几个系统函数不被允许出现在 check 约束中，以及为何不允许出现？在这个报错信息里，都是看不出来的。
可通过获取日志，然后从日志中获得报错的详细信息。采用获得日志的办法由以下4种，以第一种办法为
捞日志方法1：select last_trace_id()
单点架构
获取报错SQL 的 trace id
在同一个 session 中，紧接着报错的 SQL，去执行 select last_trace_id()(中间不要插入其他 SQL)，获取这条报错 SQL 的 trace id。
obclient [test]> select last_trace_id();
±----------------------------------+
| last_trace_id() |
±----------------------------------+
| YB427F000001-00063A2A3ECD0FE7-0-0 |
±----------------------------------+
1 row in set (0.000 sec)
说明：通过 last_trace_id() 获取到的 trace id 可能会有差异，请以实际查询结果为准。
退出连接串
obclient [test]> quit
Bye
切换到报错日志所在的目录
cd /home/admin/oceanbase/observer/log
定位日志
搜一下对应 SQL 的 trace id（记得要把下面命令里的 YB427F000001-00063A2A3ECD0FE7-0-0 替换成你自己通过执行 last_trace_id 返回的 trace id，类似于：YB427F000001-00063A2A3ECD0FE7-0-0）。
grep YB427F000001-00063A2A3ECD0FE7-0-0 *
如果相关的日志量比较大，还可以通过 vi 编辑器打开和阅读，或者重定向输出到某个新文件等。
grep YB427F000001-00063A2A3ECD0FE7-0-0 * | vi -
通过vim中查找内容 /error=3814 (3814 需换成报错内容，不同场景下的报错代码不一样)
输出如下：

集群架构
获取报错SQL 的 trace id
在同一个 session 中，紧接着报错的 SQL，去执行 select last_trace_id()(中间不要插入其他 SQL)，获取这条报错 SQL 的 trace id。
obclient [test]> select last_trace_id();
±----------------------------------+
| last_trace_id() |
±----------------------------------+
| YB427F000001-00063A2A3DBD3DFE-0-0 |
±----------------------------------+
1 row in set (0.000 sec)
说明：通过 last_trace_id() 获取到的 trace id 可能会有差异，请以实际查询结果为准。
获取接收请求的 OBServer 的 ip 和 port
可以通过执行 select * from oceanbase.gv$o{b}_{s}q{l}_{a}uditwheretrac{e}_{i}d{=}^{\prime }YB427F000001-00063A2A3DBD3DFE-0-0^{\prime };获取接收请求的OBServer的ip和port，然后到对应ip的节点上的日志文件里greptrac{e}_{i}d。select\ast fromoceanbase.gv$ob_sql_audit where trace_id = ‘YB427F000001-00063A2A3DBD3DFE-0-0’;
输出如下：
±----------±---------±-----------±------------±----------------------------------±-----------±----------±------------±----------±-------------±--------------------±--------±----------±-----------±---------------±-------±--------±---------------------------------±------------------------------------------------------------------------------------±--------±--------------±------------±--------------±---------±------±-------±-------±----------±------±-------±-----±-------±-----±-------±-----±------±--------------±------------±-----------±-------------------±----------------±----------------------±------------±----------±----------±-------------±----------------±------------±-----------------±-------------±---------±--------------±-----------±------------±--------------±-------------±----------------------±----------------------±------------------±--------------±--------------±-----------------------±----------------±-----------±----------±-----------±------------------±------------------------±-----------------------±--------------------±---------------------±---------------------±----------------------±--------------------±------------------±--------------------------------±--------------------±----------------------±------------------±-----------±-------------------±------------------±-----------------±------±-----------------±-------------±----------------------±--------------±----------±-------------------±-------------±----------±--------------±--------------------±-----------------±-------------±------------±----------------±--------------±-------------±------------------------------±-----------------------------±-----------±--------±------------------±-------------------+
| SVR_IP | SVR_PORT | REQUEST_ID | SQL_EXEC_ID | TRACE_ID | SID | CLIENT_IP | CLIENT_PORT | TENANT_ID | TENANT_NAME | EFFECTIVE_TENANT_ID | USER_ID | USER_NAME | USER_GROUP | USER_CLIENT_IP | DB_ID | DB_NAME | SQL_ID | QUERY_SQL | PLAN_ID | AFFECTED_ROWS | RETURN_ROWS | PARTITION_CNT | RET_CODE | QC_ID | DFO_ID | SQC_ID | WORKER_ID | EVENT | P1TEXT | P1 | P2TEXT | P2 | P3TEXT | P3 | LEVEL | WAIT_CLASS_ID | WAIT_CLASS# | WAIT_CLASS | STATE | WAIT_TIME_MICRO | TOTAL_WAIT_TIME_MICRO | TOTAL_WAITS | RPC_COUNT | PLAN_TYPE | IS_INNER_SQL | IS_EXECUTOR_RPC | IS_HIT_PLAN | REQUEST_TIME | ELAPSED_TIME | NET_TIME | NET_WAIT_TIME | QUEUE_TIME | DECODE_TIME | GET_PLAN_TIME | EXECUTE_TIME | APPLICATION_WAIT_TIME | CONCURRENCY_WAIT_TIME | USER_IO_WAIT_TIME | SCHEDULE_TIME | ROW_CACHE_HIT | BLOOM_FILTER_CACHE_HIT | BLOCK_CACHE_HIT | DISK_READS | RETRY_CNT | TABLE_SCAN | CONSISTENCY_LEVEL | MEMSTORE_READ_ROW_COUNT | SSSTORE_READ_ROW_COUNT | DATA_BLOCK_READ_CNT | DATA_BLOCK_CACHE_HIT | INDEX_BLOCK_READ_CNT | INDEX_BLOCK_CACHE_HIT | BLOCKSCAN_BLOCK_CNT | BLOCKSCAN_ROW_CNT | PUSHDOWN_STORAGE_FILTER_ROW_CNT | REQUEST_MEMORY_USED | EXPECTED_WORKER_COUNT | USED_WORKER_COUNT | SCHED_INFO | FUSE_ROW_CACHE_HIT | PS_CLIENT_STMT_ID | PS_INNER_STMT_ID | TX_ID | SNAPSHOT_VERSION | REQUEST_TYPE | IS_BATCHED_MULTI_STMT | OB_TRACE_INFO | PLAN_HASH | LOCK_FOR_READ_TIME | PARAMS_VALUE | RULE_NAME | PARTITION_HIT | TX_INTERNAL_ROUTING | TX_STATE_VERSION | FLT_TRACE_ID | PL_TRACE_ID | PLSQL_EXEC_TIME | FORMAT_SQL_ID | STMT_TYPE | TOTAL_MEMSTORE_READ_ROW_COUNT | TOTAL_SSSTORE_READ_ROW_COUNT | PROXY_USER | SEQ_NUM | NETWORK_WAIT_TIME | PLSQL_COMPILE_TIME |
±----------±---------±-----------±------------±----------------------------------±-----------±----------±------------±----------±-------------±--------------------±--------±----------±-----------±---------------±-------±--------±---------------------------------±------------------------------------------------------------------------------------±--------±--------------±------------±--------------±---------±------±-------±-------±----------±------±-------±-----±-------±-----±-------±-----±------±--------------±------------±-----------±-------------------±----------------±----------------------±------------±----------±----------±-------------±----------------±------------±-----------------±-------------±---------±--------------±-----------±------------±--------------±-------------±----------------------±----------------------±------------------±--------------±--------------±-----------------------±----------------±-----------±----------±-----------±------------------±------------------------±-----------------------±--------------------±---------------------±---------------------±----------------------±--------------------±------------------±--------------------------------±--------------------±----------------------±------------------±-----------±-------------------±------------------±-----------------±------±-----------------±-------------±----------------------±--------------±----------±-------------------±-------------±----------±--------------±--------------------±-----------------±-------------±------------±----------------±--------------±-------------±------------------------------±-----------------------------±-----------±--------±------------------±-------------------+
| 127.0.0.1 | 2882 | 45157 | 282120 | YB427F000001-00063A2A3DBD3DFE-0-0 | 3221662635 | 127.0.0.1 | 38286 | 1002 | mysql_tenant | 1002 | 200001 | root | 0 | 127.0.0.1 | 500001 | test | D29DC264031589D10F2FE377468FC284 | CREATE TABLE t1 (c1 TIMESTAMP CHECK(c1 + UNIX_TIMESTAMP() > ‘2025-07-30 01:02:03’)) | 0 | 0 | 0 | 0 | -5991 | 0 | 0 | 0 | 0 | | | 0 | | 0 | | 0 | 0 | 100 | 0 | OTHER | MAX_WAIT TIME ZERO | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 1752805714919000 | 412 | 0 | 1 | 17 | 0 | 362 | 23 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | -1 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 41841152 | 0 | 0 | NULL | 0 | -1 | -1 | 0 | 0 | 2 | 0 | NULL | 0 | 0 | | | 1 | 0 | 0 | | NULL | 0 | | CREATE_TABLE | 0 | 0 | | 0 | 0 | 0 |
±----------±---------±-----------±------------±----------------------------------±-----------±----------±------------±----------±-------------±--------------------±--------±----------±-----------±---------------±-------±--------±---------------------------------±------------------------------------------------------------------------------------±--------±--------------±------------±--------------±---------±------±-------±-------±----------±------±-------±-----±-------±-----±-------±-----±------±--------------±------------±-----------±-------------------±----------------±----------------------±------------±----------±----------±-------------±----------------±------------±-----------------±-------------±---------±--------------±-----------±------------±--------------±-------------±----------------------±----------------------±------------------±--------------±--------------±-----------------------±----------------±-----------±----------±-----------±------------------±------------------------±-----------------------±--------------------±---------------------±---------------------±----------------------±--------------------±------------------±--------------------------------±--------------------±----------------------±------------------±-----------±-------------------±------------------±-----------------±------±-----------------±-------------±----------------------±--------------±----------±-------------------±-------------±----------±--------------±--------------------±-----------------±-------------±------------±----------------±--------------±-------------±------------------------------±-----------------------------±-----------±--------±------------------±-------------------+
1 row in set (0.036 sec)
退出连接串
obclient [test]> quit
Bye
切换到报错日志所在的服务器
xshell连上报错日志所在的服务器
切换到报错日志所在的目录
报错日志所在的服务器上切换到报错日志所在的目录
cd /home/admin/oceanbase/observer/log
定位日志
场景1：日志体量小
搜一下对应 SQL 的 trace id（记得要把下面命令里的 YB427F000001-00063A2A3DBD3DFE-0-0 替换成你自己通过执行 last_trace_id 返回的 trace id，类似于：YB427F000001-00063A2A3DBD3DFE-0-0）。
grep YB427F000001-00063A2A3DBD3DFE-0-0 *
如下：
observer.log:[2025-07-18 10:28:34.919195] WDIAG [SQL.RESV] check_deterministic_single (ob_raw_expr_util.cpp:2054) [2459][T1002_L0_G0][T1002][YB427F000001-00063A2A3DBD3DFE-0-0] [lt=12][errcode=-5991] deterministic expr is wrongly specified in CHECK constraint(ret=-5991, expr->get_expr_type()=542)
observer.log:[2025-07-18 10:28:34.919210] WDIAG [SQL.RESV] check_deterministic_single (ob_raw_expr_util.cpp:2058) [2459][T1002_L0_G0][T1002][YB427F000001-00063A2A3DBD3DFE-0-0] [lt=13][errcode=-5991] only pure sys function can be indexed(ret=-5991, check_status=3, *expr={item_type:“T_FUN_SYS_UNIX_TIMESTAMP”, result_type:{meta:{type:“”, collation:“binary”, coercibility:“NUMERIC”}, accuracy:{length:-1, precision:-1, scale:-1}, flag:0, calc_type:{type:“NULL”, collation:“invalid_type”, coercibility:“INVALID”}}, expr_info:[“IS_FUNC”, “IS_CUR_TIME”, “IS_CONST_EXPR”, “CNT_FUNC”, “CNT_CUR_TIME”], rel_id:[], func:“UNIX_TIMESTAMP”, children:[], enum_set_values:[], dblink_name:“”, dblink_id:18446744073709551615, local_session_var:{}, local_session_var_id:-1, mview_id:18446744073709551615, expr_hash:0})
observer.log:[2025-07-18 10:28:34.919247] WDIAG [SQL.RESV] check_deterministic (ob_raw_expr_util.cpp:2014) [2459][T1002_L0_G0][T1002][YB427F000001-00063A2A3DBD3DFE-0-0] [lt=33][errcode=-5991] fail to exec check_deterministic_single(cur_expr, check_status)(ret=-5991)

1. 第一行日志里，有一个关键字：deterministic expr。
2. 第二行日志里，有一个关键字：T_FUN_SYS_UNIX_TIMESTAMP。
3. 第三行及后面的日志暂时就先忽略了。一般来说，越后面的日志，和问题本身的关系就越小。

日志分析：
第一行日志说 UNIX_TIMESTAMP 不允许出现在 check 约束中，原因和 deterministic 表达式有关。
第二行日志明确说了 check 约束里出问题的系统函数是 UNIX_TIMESTAMP，排除了 ADD（+）和 GREATER_THAN（>）有问题的嫌疑。
大家自行查下关键字 deterministic，可以知道含义是 “确定性的”，而这个 UNIX_TIMESTAMP() 函数在不同时间执行，会返回不同的结果，明显属于 “非确定性（nondeterministic）” 函数。进而可以推测出在 check 约束中，只允许出现确定性函数，不允许出现 now、random 等非确定性函数。
obclient [test]> select UNIX_TIMESTAMP();
±-----------------+
| UNIX_TIMESTAMP() |
±-----------------+
| 1752806141 |
±-----------------+
1 row in set (0.001 sec)

obclient [test]> select UNIX_TIMESTAMP();
±-----------------+
| UNIX_TIMESTAMP() |
±-----------------+
| 1752806153 |
±-----------------+
1 row in set (0.000 sec)
补充说明：
● 日志里的报错信息如果写成：nondeterministic expr is wrongly specified in CHECK constraint，就更好理解了。这里应该是个笔误，但是并不太影响理解。
● 除了 check 约束表达式，类似于分区表达式、生成列表达式，也都不允许出现非确定性的函数。
场景2：日志大
扩展：如果相关的日志量比较大，还可以通过 vi 编辑器打开和阅读，或者重定向输出到某个新文件等。
grep YB427F000001-00063A2A3ECD0FE7-0-0 * | vi -
通过vim中查找内容 /error=3814 (3814 需换成报错内容，不同场景下的报错代码不一样)
输出如下：

日志分析同场景1
扩展：报错 SQL 之后已经执行了其他 SQL或者已经退出对应 session如何获取日志
上面实验里的方法在使用上，还是有一些限制，需要在在同一个 session 中，紧接着报错的 SQL，去执行 select last_trace_id()。
如果在报错 SQL 之后，已经执行了其他 SQL，或者已经退出对应 session。还可以在日志里通过 grep “keywords”，获取 trace_id。
cd /home/admin/oceanbase/observer/log
grep “CREATE TABLE t1 (” *
observer.log:[2025-06-12 18:27:44.717497] WDIAG [SQL] stmt_query (ob_sql.cpp:174) [2459][T1002_L0_G0][T1002][YB427F000001-0006375D6680819B-0-0] [lt=9][errcode=-5991] fail to handle text query(stmt=CREATE TABLE t1
…
然后就拿到 trace_id YB427F000001-0006375D6680819B-0-0 了。
接下来就回到了之前的方法，通过 trace_id 去 grep 出完整日志即可。
捞日志方法二：grep"ret=-errno"
第一种方法在使用上有一些限制，需要在在同一个 session 中，紧接着报错的 SQL，去执行select last_trace_id()
如果在报错 SQL 之后，已经执行了其他 SQL，或者已经退出对应 session，可以在日志里先通过 grep “ret=-errno”、获取 trace_id。

捞日志方法三：OCP 白屏捞日志
如果不喜欢在黑屏命令行中 grep 日志，可以用 OCP 提供的白屏日志服务关键字依然是 ret=-errno，而且更便捷地选择日志的时间范围，这里需要捞取的日志级别可以无脑全选。
发现如果是个分布式的集群，但是不想去每台节点都 grep 一把日志，还是用 OCP 的白屏日志收集比较好。
通过 OCP 白屏工具捞日志，这种方式可以一次性返回所有节点上的相关日志。
捞日志方法四：obdiag 捞日志
靖顺、渠磊两位老哥开发的 obdiag，也支持一键自动取多个节点捞日志，即使是分布式集群外加OBProxy，也能通过一条命令在黑屏环境下快速捞到日志。详见:OceanBase 敏捷诊断工具(obdiag)-- observer 日志收集。

课件链接：https://open.oceanbase.com/course/detail/12457