V3.1.2
更新时间：2022-02-24 21:38:13
OceanBase 数据库问题排查主要依赖进程日志、内部表以及代码的执行流程。本文介绍如何通过进程日志和内部表排查 OceanBase 数据库的通用问题。
进程日志
由于内部表的功能针对性较强，对于不明确的问题，我们推荐您优先使用进程日志排查问题。
OceanBase 数据库的进程日志分为 observer.log、rootservice.log 和 election.log。其中 election.log 记录选举相关日志，rootservice.log 记录 rootservice 模块的日志，observer.log 记录通用日志。
日志内容格式
OceanBase 数据库的进程日志格式如下：
[2021-06-11 16:30:02.372655] ERROR [BOOTSTRAP] bootstrap (ob_service.cpp:2656) [32075][428][YB420A27C94E-0005C47950223003] [lt=3] [dc=0] failed to prepare boot strap(rs_list=[region:"sys_region", zone:"z1", server:"127.0.0.1:2882",
region:"sys_region", zone:"z2", server:"127.0.0.2:2882", region:"sys_region", zone:"z3", server:"127.0.0.3:2882"], ret=-4012) BACKTRACE:0x90a107e 0x90090c1
0x24d1eef 0x24d1b3b 0x24d1900 0x66678b1 0x882bb40 0x8912d74 0x91c24f8 0x8a5d45f
0x8a5d08d 0x8a5841f 0x8a5770d 0x8a57b17 0x2a55b14 0x8ebc475 0x8eb9e4e 0x8eb46ef
其中，
[2021-06-11 16:30:02.372655]是时间戳。ERROR是日志级别。日志级别有INFO、WARN、TRACE和DEBUG。
[BOOTSTRAP]是模块名称，其他模块还有 SQL、STORAGE、COMMON 等。bootstrap是函数名。
ob_service.cpp:2656是文件名和行号。[32075]是线程 ID。
[428]是协程编号。[YB420A27C94E-0005C47950223003]是trace_id，同一个请求携带同一个trace_id。
[lt=3]是日志前端格式化时间，通常无意义。[dc=0]无意义。
failed to prepare boot strap及之后内容是日志的具体内容。ret=-4012表示错误码为 -4012，-4012 的语义是OB_TIMEOUT，可以通过ob_errno.h查询。BACKTRACE是调用栈的地址，可以通过 addr2line 等工具解析函数的调用栈。
日志名称格式
进程日志名称后缀中的数字表示该日志文件中最后一条日志的时间戳。例如，observer.log.20210617143216 后缀中的 20210617143216 表示该文件最后一条日志的时间戳是 2021-06-17 14:32:16。 带有 wf 后缀的文件只记录 WARN 及以上级别的日志。您可以通过配置项 enable_syslog_wf 关闭 wf 日志。 更多日志文件的配置项请通过 sys 租户执行 show parameters like '%syslog%' 命令查看。
TRACE 能力
OceanBase 数据库打印进程日志时会携带 trace_id，一个请求执行的整个生命周期都会携带同一个 trace_id，因此在进程日志中搜索 trace_id 可以拿到一个请求的全部执行过程。
last_trace_id
使用 select last_trace_id(); 语句可以直接查看上一条语句的执行节点和 trace_id，然后在日志中运行 grep 命令查找相关信息。
obclient> SELECT last_trace_id();
+--------------------------------------------------------+
| last_trace_id() |
+--------------------------------------------------------+
| 127.0.0.1:2882, TraceId: YB427F000001-0005C4DB8B546938 |
+--------------------------------------------------------+
1 row in set (0.01 sec)
grep "YB427F000001-0005C4DB8B546938" observer.log
trace_log
OceanBase 数据库支持执行请求时打开 trace_log。您可以通过以下两种方式打开 trace_log：
通过 Hint 中的
trace_log字段，这种方式只对携带 Hint 的当前语句生效。使用 Hint 要求 OBClient 在连接 OceanBase 数据库时携带-c选项，否则 Hint 会被忽略。更多 Hint 操作，参考 Optimizer Hint。通过 Session 变量
ob_enable_trace_log，这种方式对这个 Session 的后续所有语句生效。
打开 trace_log 后，通过 SHOW TRACE 语句可以拿到上一次的 trace_log，从而获取 trace_id。同时 SHOW TRACE 还可以看到这条请求大致的性能统计。
obclient> SHOW TRACE;
+------------------------------+----------------------------------------------------------------------------+------+
| Title | KeyValue | Time |
+------------------------------+----------------------------------------------------------------------------+------+
| process begin | in_queue_time:12, receive_ts:1623988240448815, enqueue_ts:1623988240448816 | 0 |
| query begin | trace_id:YC1E64586A5D-0005C4C77E56FA98 | 2 |
| parse begin | stmt:"select count(*) from t1", stmt_len:23 | 49 |
| pc get plan begin | | 7 |
| pc get plan end | | 18 |
| transform_with_outline begin | | 2 |
| transform_with_outline end | | 45 |
| resolve begin | | 22 |
| resolve end | | 130 |
| transform begin | | 40 |
| transform end | | 138 |
| optimizer begin | | 2 |
| get location cache begin | | 96 |
| get location cache end | | 108 |
| optimizer end | | 272 |
| cg begin | | 0 |
| cg end | | 984 |
| execution begin | arg1:false, end_trans_cb:false | 78 |
| do open plan begin | plan_id:197 | 29 |
| sql start stmt begin | | 1 |
| sql start stmt end | | 1 |
| execute plan begin | | 0 |
| execute plan end | | 9 |
| sql start participant begin | | 0 |
| sql start participant end | | 1 |
| do open plan end | | 0 |
| table scan begin | | 11 |
| table scan end | | 42 |
| start_close_plan begin | | 1344 |
| start_end_participant begin | | 13 |
| start_end_participant end | | 1 |
| start_close_plan end | | 1 |
| start_auto_end_plan begin | | 2 |
| start_auto_end_plan end | | 1 |
| execution end | | 2 |
| query end | | 52 |
| NULL | PHY_SCALAR_AGGREGATE | |
| t1 | PHY_TABLE_SCAN | |
+------------------------------+----------------------------------------------------------------------------+------+
38 rows in set (0.01 sec)
使用示例如下：
# 语句级
obclient> SELECT /*+ trace_log=on */c1 FROM t1 LIMIT 2;
obclient> SHOW TRACE;
# Session 级
obclient> SET ob_enable_trace_log = 'ON';
obclient> SELECT COUNT(*) FROM t1;
obclient> SHOW TRACE;
根据线程 ID 搜索日志
如果您未找到有效的 trace_id，或者 OceanBase 数据库的某些后台线程未设置 trace_id，您可以根据线程 ID 搜索日志。例如：
grep -F "[32075]" observer.log
内部表
OceanBase 数据库的内部表比较多，本节仅介绍部分常见的通用表，其他类型的内部表（例如集群管控、性能视图、迁移复制、合并转储等）参考 系统视图。
本文中的内部表默认是 root 用户在 sys 租户的 OceanBase 数据库中可见的表（连接串示例：obclient -u root@sys -D oceanbase），下文不再指定数据库名称。
表的基础信息
您可以通过系统租户的 __all_virtual_table 表可以获取 table_id、table_name 等基本信息。
obclient> DESCRIBE __all_virtual_table;
+--------------------------------------+---------------------+------+-----+----------------+-------+
| Field | Type | Null | Key | Default | Extra |
+--------------------------------------+---------------------+------+-----+----------------+-------+
| tenant_id | bigint(20) | NO | PRI | NULL | |
| table_id | bigint(20) | NO | PRI | NULL | |
| gmt_create | timestamp(6) | NO | | NULL | |
| gmt_modified | timestamp(6) | NO | | NULL | |
| table_name | varchar(256) | NO | | | |
| database_id | bigint(20) | NO | | NULL | |
| table_type | bigint(20) | NO | | NULL | |
| load_type | bigint(20) | NO | | NULL | |
| def_type | bigint(20) | NO | | NULL | |
| rowkey_column_num | bigint(20) | NO | | NULL | |
| index_column_num | bigint(20) | NO | | NULL | |
| max_used_column_id | bigint(20) | NO | | NULL | |
| replica_num | bigint(20) | NO | | NULL | |
| autoinc_column_id | bigint(20) | NO | | NULL | |
| auto_increment | bigint(20) unsigned | YES | | 1 | |
| read_only | bigint(20) | NO | | NULL | |
| rowkey_split_pos | bigint(20) | NO | | NULL | |
| compress_func_name | varchar(128) | NO | | NULL | |
| expire_condition | varchar(4096) | NO | | NULL | |
| is_use_bloomfilter | bigint(20) | NO | | NULL | |
| comment | varchar(4096) | NO | | | |
| block_size | bigint(20) | NO | | NULL | |
| collation_type | bigint(20) | NO | | NULL | |
| data_table_id | bigint(20) | YES | | NULL | |
| index_status | bigint(20) | NO | | NULL | |
| tablegroup_id | bigint(20) | NO | | NULL | |
| progressive_merge_num | bigint(20) | NO | | NULL | |
| index_type | bigint(20) | NO | | NULL | |
| part_level | bigint(20) | NO | | NULL | |
| part_func_type | bigint(20) | NO | | NULL | |
| part_func_expr | varchar(4096) | NO | | NULL | |
| part_num | bigint(20) | NO | | NULL | |
| sub_part_func_type | bigint(20) | NO | | NULL | |
| sub_part_func_expr | varchar(4096) | NO | | NULL | |
| sub_part_num | bigint(20) | NO | | NULL | |
| create_mem_version | bigint(20) | NO | | NULL | |
| schema_version | bigint(20) | NO | | NULL | |
| view_definition | longtext | NO | | NULL | |
| view_check_option | bigint(20) | NO | | NULL | |
| view_is_updatable | bigint(20) | NO | | NULL | |
| zone_list | varchar(8192) | NO | | NULL | |
| primary_zone | varchar(128) | YES | | NULL | |
| index_using_type | bigint(20) | NO | | 0 | |
| parser_name | varchar(128) | YES | | NULL | |
| index_attributes_set | bigint(20) | YES | | 0 | |
| locality | varchar(4096) | NO | | | |
| tablet_size | bigint(20) | NO | | 134217728 | |
| pctfree | bigint(20) | NO | | 10 | |
| previous_locality | varchar(4096) | NO | | | |
| max_used_part_id | bigint(20) | NO | | -1 | |
| partition_cnt_within_partition_table | bigint(20) | NO | | -1 | |
| partition_status | bigint(20) | YES | | 0 | |
| partition_schema_version | bigint(20) | YES | | 0 | |
| max_used_constraint_id | bigint(20) | YES | | NULL | |
| session_id | bigint(20) | YES | | 0 | |
| pk_comment | varchar(4096) | NO | | | |
| sess_active_time | bigint(20) | YES | | 0 | |
| row_store_type | varchar(128) | YES | | FLAT_ROW_STORE | |
| store_format | varchar(128) | YES | | | |
| duplicate_scope | bigint(20) | YES | | 0 | |
| binding | tinyint(4) | YES | | 0 | |
| progressive_merge_round | bigint(20) | YES | | 0 | |
| storage_format_version | bigint(20) | YES | | 2 | |
| table_mode | bigint(20) | NO | | 0 | |
| encryption | varchar(128) | YES | | | |
| tablespace_id | bigint(20) | NO | | -1 | |
| drop_schema_version | bigint(20) | NO | | -1 | |
| is_sub_part_template | tinyint(4) | NO | | 1 | |
| dop | bigint(20) | NO | | 1 | |
| character_set_client | bigint(20) | NO | | 0 | |
| collation_connection | bigint(20) | NO | | 0 | |
| auto_part_size | bigint(20) | NO | | -1 | |
| auto_part | tinyint(4) | NO | | 0 | |
+--------------------------------------+---------------------+------+-----+----------------+-------+
73 rows in set (0.00 sec)
Location 信息
OceanBase 数据库是分布式数据库，与传统数据库相比，需要 Location 信息来定位处理请求的具体节点。OceanBase 数据库使用 Paxos 协议做副本同步，对于 DML 请求和 Read Latest 类型的查询，都会路由到目标分区的 Leader 节点处理。
Location 信息分为三级，即核心表 __all_core_table（系统租户的 1 号表）的位置，系统表的位置，普通表的位置。location 信息相关的内部表中，role 字段为 1 表示 Leader，2 表示 Follower。
核心表的位置信息可以通过系统租户的
__all_virtual_core_meta_table表来查询，核心表所在的 OceanBase 数据库节点是 rootserver，所以也可以通过__all_server表的with_rootserver字段找到核心表 Leader 的位置。系统表的位置信息可以通过系统租户的
__all_root_table查询。
- 普通表的位置信息可以通过
meta_table表查询，对于系统租户，可以查询__all_virtual_meta_table。对于普通租户，可以查询__all_tenant_meta_table。
sql_audit
OceanBase 数据库支持 SQL 监控，可以通过配置项 enable_sql_audit（默认打开）和 Session 变量 ob_enable_sql_audit（默认打开）控制。监控信息存储在 gv$sql_audit 视图中。您通过 query_sql 等字段搜索目标 SQL 语句的监控记录获取 trace_id、执行时间、返回行数等信息。
sql_audit 表的容量有限，早期的记录可能会被后来的请求覆盖，sql_audit 表的容量可以通过配置项 sql_audit_queue_size、sql_audit_memory_limit 以及 Session 变量 ob_sql_audit_percentage 设置。
obclient> select * from gv$sql_audit where query_sql like 'select count(*) from t1%'\G
*************************** 1. row ***************************
SVR_IP: 127.0.0.1
SVR_PORT: 3102
REQUEST_ID: 20
SQL_EXEC_ID: 12803933
TRACE_ID: YC1E64586A5D-0005C4C77E56FA98
SID: 3221639668
CLIENT_IP: 127.0.0.1
CLIENT_PORT: 38101
TENANT_ID: 1001
TENANT_NAME: my_tenant
EFFECTIVE_TENANT_ID: 1001
USER_ID: 1100611139404777
USER_NAME: my_user
USER_GROUP: 0
USER_CLIENT_IP: 127.0.0.1
DB_ID: 1100611139404776
DB_NAME: test
SQL_ID: 69AE2D9E3BF106CE009F93EFAF925EC8
QUERY_SQL: select count(*) from t1
PLAN_ID: 197
AFFECTED_ROWS: 0
RETURN_ROWS: 1
PARTITION_CNT: 1
RET_CODE: 0
QC_ID: 0
DFO_ID: 0
SQC_ID: 0
WORKER_ID: 0
EVENT: system internal wait
P1TEXT:
P1: 0
P2TEXT:
P2: 0
P3TEXT:
P3: 0
LEVEL: 0
WAIT_CLASS_ID: 100
WAIT_CLASS#: 0
WAIT_CLASS: OTHER
STATE: MAX_WAIT TIME ZERO
WAIT_TIME_MICRO: 0
TOTAL_WAIT_TIME_MICRO: 0
TOTAL_WAITS: 0
RPC_COUNT: 0
PLAN_TYPE: 1
IS_INNER_SQL: 0
IS_EXECUTOR_RPC: 0
IS_HIT_PLAN: 0
REQUEST_TIME: 1623988240448815
ELAPSED_TIME: 3465
NET_TIME: 0
NET_WAIT_TIME: 0
QUEUE_TIME: 20
DECODE_TIME: 1
GET_PLAN_TIME: 1960
EXECUTE_TIME: 1460
APPLICATION_WAIT_TIME: 0
CONCURRENCY_WAIT_TIME: 0
USER_IO_WAIT_TIME: 0
SCHEDULE_TIME: 0
ROW_CACHE_HIT: 0
BLOOM_FILTER_CACHE_HIT: 0
BLOCK_CACHE_HIT: 0
BLOCK_INDEX_CACHE_HIT: 0
DISK_READS: 0
RETRY_CNT: 0
TABLE_SCAN: 1
CONSISTENCY_LEVEL: 3
MEMSTORE_READ_ROW_COUNT: 1
SSSTORE_READ_ROW_COUNT: 0
REQUEST_MEMORY_USED: 2096128
EXPECTED_WORKER_COUNT: 0
USED_WORKER_COUNT: 0
SCHED_INFO:
FUSE_ROW_CACHE_HIT: 0
PS_STMT_ID: 0
TRANSACTION_HASH: 0
REQUEST_TYPE: 2
IS_BATCHED_MULTI_STMT: 0
OB_TRACE_INFO:
PLAN_HASH: 2598000370345801882
LOCK_FOR_READ_TIME: 0
WAIT_TRX_MIGRATE_TIME: 0
1 row in set (0.65 sec)