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

原创董小姐 2025-07-21

143

背景

很多社区版的用户，在遇到非预期报错后，会到 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 (c) 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$ob_sql_audit where trace_id = 'YB427F000001-00063A2A3DBD3DFE-0-0'; 获取接收请求的 OBServer 的 ip 和 port，然后到对应 ip 的节点上的日志文件里 grep trace_id。

select * from oceanbase.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)

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

日志分析：

第一行日志说 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

墨力计划

「喜欢这篇文章，您的关注和赞赏是给作者最好的鼓励」

关注作者

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

背景

收集报错相关的信息

连接数据库，并登录用户租户

组件版本获取

捞取报错对应的 OBServer 日志信息

模拟报错场景1

捞日志方法1：select last_trace_id()

单点架构

获取报错SQL 的 trace id

退出连接串

切换到报错日志所在的目录

定位日志

集群架构

获取报错SQL 的 trace id

获取接收请求的 OBServer 的 ip 和 port

退出连接串

切换到报错日志所在的服务器

切换到报错日志所在的目录

定位日志

场景1：日志体量小

场景2：日志大

扩展：报错 SQL 之后已经执行了其他 SQL或者已经退出对应 session如何获取日志

捞日志方法二：grep"ret=-errno"

捞日志方法三：OCP 白屏捞日志

捞日志方法四：obdiag 捞日志

评论