OceanBase 集群合并超时 Timeout 排查方法

适用版本

OceanBase 数据库 V2.x、V3.x 版本。

问题现象

OCP 白屏界面持续告警如下：

告警事件详情

告警概述：`alarm_template_id=0:ob_cluster=longrun_clu-1661252982` OB 集群合并超时。

告警详情：集群：loxxxxx_clu，告警：OceanBase 集群合并超时。查看告警处理建议

问题原因

合并超时的原因较多，常见的有：

• 存在失败的索引（fail to check column checksum(ret=-4023) / fail to check global index column checksum(tmp_ret=-4023)）。

• 内存不够了，一般都伴随有 -4013/-4030 错误。

• 系统压力过大。

解决方法

1. 先确定合并没有被人为地 suspend。

   obclient [oceanbase]> select * from __all_zone where name like 'merge_status';
   

   返回结果如下。

   +----------------------------+----------------------------+-------+--------------+-------+---------+
   | gmt_create                 | gmt_modified               | zone  | name         | value | info    |
   +----------------------------+----------------------------+-------+--------------+-------+---------+
   | 2023-01-17 16:00:49.129141 | 2023-02-06 05:00:31.168383 |       | merge_status |     2 | TIMEOUT |
   | 2023-01-17 16:00:49.130846 | 2023-02-06 05:00:31.167974 | zone1 | merge_status |     2 | TIMEOUT |
   | 2023-01-17 16:00:49.132154 | 2023-02-06 05:00:31.170983 | zone2 | merge_status |     2 | TIMEOUT |
   | 2023-01-17 16:00:49.133628 | 2023-02-06 05:00:31.173545 | zone3 | merge_status |     2 | TIMEOUT |
   +----------------------------+----------------------------+-------+--------------+-------+---------+
   4 rows in set (0.002 sec)
   

   obclient [oceanbase]> select * from __all_zone where name like '%suspend%';
   

   返回结果如下。

   +----------------------------+----------------------------+-------+-----------------+-------+------+
   | gmt_create                 | gmt_modified               | zone  | name            | value | info |
   +----------------------------+----------------------------+-------+-----------------+-------+------+
   | 2023-01-17 16:00:49.130749 | 2023-01-17 16:00:49.130749 | zone1 | suspend_merging |     0 |      |
   | 2023-01-17 16:00:49.132045 | 2023-01-17 16:00:49.132045 | zone2 | suspend_merging |     0 |      |
   | 2023-01-17 16:00:49.133525 | 2023-01-17 16:00:49.133525 | zone3 | suspend_merging |     0 |      |
   +----------------------------+----------------------------+-------+-----------------+-------+------+
   3 rows in set (0.002 sec)
   

   上述查询结果中 suspend_merging 都是 0，代表合并没有被人为地 suspend。

2. 找到 Root Service 机器所在。

   obclient [oceanbase]> select * from __all_server;
   

   返回结果如下：

   +----------------------------+----------------------------+-------------+----------+----+-------+------------+-----------------+--------+-----------------------+------------------------------------------------------------------------------------------+-----------+--------------------+--------------+----------------+-------------------+
   | gmt_create                 | gmt_modified               | svr_ip      | svr_port | id | zone  | inner_port | with_rootserver | status | block_migrate_in_time | build_version                                                                            | stop_time | start_service_time | first_sessid | with_partition | last_offline_time |
   +----------------------------+----------------------------+-------------+----------+----+-------+------------+-----------------+--------+-----------------------+------------------------------------------------------------------------------------------+-----------+--------------------+--------------+----------------+-------------------+
   | 2023-01-17 16:00:40.295411 | 2023-02-09 22:35:16.805489 | xxx.xxx.xxx.3 |     2882 |  1 | zone1 |       2881 |               1 | active |                     0 | 2.2.77_115000012023010607-d254caed0ebc5d09f8d2c54db1ec805c5246af17(Jan  6 2023 08:01:08) |         0 |   1675953316598190 |            0 |              1 |                 0 |
   | 2023-01-17 16:00:40.283123 | 2023-02-09 22:35:16.829138 | xxx.xxx.xxx.4 |     2882 |  2 | zone2 |       2881 |               0 | active |                     0 | 2.2.77_115000012023010607-d254caed0ebc5d09f8d2c54db1ec805c5246af17(Jan  6 2023 08:01:08) |         0 |   1675953316786665 |            0 |              1 |                 0 |
   | 2023-01-17 16:00:40.288818 | 2023-02-09 22:31:22.730172 | xxx.xxx.xxx.5 |     2882 |  3 | zone3 |       2881 |               0 | active |                     0 | 2.2.77_115000012023010607-d254caed0ebc5d09f8d2c54db1ec805c5246af17(Jan  6 2023 08:01:08) |         0 |   1675953081486316 |            0 |              1 |                 0 |
   +----------------------------+----------------------------+-------------+----------+----+-------+------------+-----------------+--------+-----------------------+------------------------------------------------------------------------------------------+-----------+--------------------+--------------+----------------+-------------------+
   3 rows in set (0.001 sec)
   

   上述查询结果中 xxx.xxx.xxx.3 机器的 with_rootserver=1，代表当前 Root Service 机器是 xxx.xxx.xxx.3 这台机器。

3. 在 Root Service 机器的 rootservice.log 中搜索关键字 replica not merged。

   [root@n153 log]# grep "replica not merged" rootservice.log | tail -1
   

   返回结果如下。

   [2023-02-10 13:03:59.180893] INFO  [RS] ob_partition_table_util.cpp:264 [1660590][670][YB42AC140F03-0005F444DD371DBB] [lt=49] replica not merged to version(version=46, replica={table_id:{value:1100611139453960, first:1001, second:50184}, partition_id:0, partition_cnt:0, zone:"zone2", server:"xxx.xxx.xxx.4:2882", sql_port:2881, unit_id:1001, role:2, member_list:[{server:"xxx.xxx.xxx.3:2882", timestamp:1674009516277381}, {server:"xxx.xxx.xxx.4:2882", timestamp:1674009516277381}, {server:"xxx.xxx.xxx.5:2882", timestamp:1674009516277381}], row_count:73, data_size:2097152, data_version:45, data_checksum:4202363821, row_checksum:row:[0], modify_time_us:1675892556966166, create_time_us:1674009516288648, member_time_us:1674009516277381, is_original_leader:false, in_member_list:true, rebuild:false, to_leader_time:1675890737033695, replica_status:"REPLICA_STATUS_NORMAL", replica_type:0, required_size:2097152, status:"REPLICA_STATUS_NORMAL", is_restore:0, partition_checksum:0, quorum:3, recovery_timestamp:0, fail_list:"", property:{memstore_percent_:100}})
   

   根据上述查询结果发现 server:"xxx.xxx.xxx.4:2882" 上的 {table_id:{value:1100611139453960 副本的版本号没有被推上去。

4. 在对应的 Server 的 observer.log 里面搜索合并相关的报错。

   [root@n154 log]# grep "dag_ret:-" observer.log
   

   返回结果如下。

   [2023-02-10 13:06:03.025465] INFO  [COMMON] ob_dag_scheduler.cpp:1209 [1539465][432][YB42AC140F04-0005F444D771B8CE] [lt=6] dag finished(dag={ObIDag:{this:0x7f98b32a3d80, type:10, name:"DAG_MINI_MERGE", id:YB42AC140F04-0005F444D771B8CE, dag_ret:-5001, dag_status:3, start_time:1676005562986458, tenant_id:1002}, param:{merge_type:2, merge_version:"0-0-0", pkey:{tid:1101710651151115, partition_id:0, part_cnt:0}, index_id:1101710651151115, schedule_merge_type:2, pg_key:{tid:1101710651151115, partition_id:0, part_cnt:0}}, sstable_version_range:{multi_version_start:1675620010979101, base_version:1675533610762816, snapshot_version:1675620010979101}}, dag_ret=-5001, runtime=38998, dag_cnt=0, dag_cnts_[dag.get_type()]=0)
   [2023-02-10 13:07:04.261405] INFO  [COMMON] ob_dag_scheduler.cpp:1209 [1539467][436][YB42AC140F04-0005F444D771B8D0] [lt=5] dag finished(dag={ObIDag:{this:0x7f917b65eb00, type:10, name:"DAG_MINI_MERGE", id:YB42AC140F04-0005F444D771B8D0, dag_ret:-5001, dag_status:3, start_time:1676005624206322, tenant_id:1002}, param:{merge_type:2, merge_version:"0-0-0", pkey:{tid:1101710651151115, partition_id:0, part_cnt:0}, index_id:1101710651151115, schedule_merge_type:2, pg_key:{tid:1101710651151115, partition_id:0, part_cnt:0}}, sstable_version_range:{multi_version_start:1675620010979101, base_version:1675533610762816, snapshot_version:1675620010979101}}, dag_ret=-5001, runtime=55074, dag_cnt=0, dag_cnts_[dag.get_type()]=0)
   

   根据上述查询结果可以得到 traceId 为 YB42AC140F04-0005F444D771B8D0，再使用这个 traceId 在 observer.log 里面过滤一下。

   日志中报错如下。

   get table schema failed(ret=-5001, table_id=1101710651151115)
   fail to get table schema(ret=-5001, ret="OB_ERR_PARSE_SQL", table_id=1101710651151115)
   

5. 查询出现问题的 table 的定义。

   [root@n154 log]# mysql -hxxx.xxx.xxx.xxx -uroot@sys -P2881 -pOceanBase4321%% -A oceanbase
   

   obclient [oceanbase]> select * from __all_virtual_table where table_id=1101710651151115;
   

   +-----------+------------------+----------------------------+----------------------------+------------+------------------+------------+-----------+----------+-------------------+------------------+--------------------+-------------+-------------------+----------------+-----------+------------------+--------------------+------------------+--------------------+---------+------------+----------------+---------------+--------------+---------------+-----------------------+------------+------------+----------------+----------------+----------+--------------------+--------------------+--------------+--------------------+------------------+-----------------+-------------------+-------------------+-----------+--------------+------------------+-------------+----------------------+----------+-------------+---------+-------------------+------------------+--------------------------------------+------------------+--------------------------+------------------------+------------+------------+------------------+--------------------+--------------+-----------------+---------+-------------------------+------------------------+------------+------------+---------------+---------------------+----------------------+-----+----------------------+----------------------+
   | tenant_id | table_id         | gmt_create                 | gmt_modified               | table_name | database_id      | table_type | load_type | def_type | rowkey_column_num | index_column_num | max_used_column_id | replica_num | autoinc_column_id | auto_increment | read_only | rowkey_split_pos | compress_func_name | expire_condition | is_use_bloomfilter | comment | block_size | collation_type | data_table_id | index_status | tablegroup_id | progressive_merge_num | index_type | part_level | part_func_type | part_func_expr | part_num | sub_part_func_type | sub_part_func_expr | sub_part_num | create_mem_version | schema_version   | view_definition | view_check_option | view_is_updatable | zone_list | primary_zone | index_using_type | parser_name | index_attributes_set | locality | tablet_size | pctfree | previous_locality | max_used_part_id | partition_cnt_within_partition_table | partition_status | partition_schema_version | max_used_constraint_id | session_id | pk_comment | sess_active_time | row_store_type     | store_format | duplicate_scope | binding | progressive_merge_round | storage_format_version | table_mode | encryption | tablespace_id | drop_schema_version | is_sub_part_template | dop | character_set_client | collation_connection |
   +-----------+------------------+----------------------------+----------------------------+------------+------------------+------------+-----------+----------+-------------------+------------------+--------------------+-------------+-------------------+----------------+-----------+------------------+--------------------+------------------+--------------------+---------+------------+----------------+---------------+--------------+---------------+-----------------------+------------+------------+----------------+----------------+----------+--------------------+--------------------+--------------+--------------------+------------------+-----------------+-------------------+-------------------+-----------+--------------+------------------+-------------+----------------------+----------+-------------+---------+-------------------+------------------+--------------------------------------+------------------+--------------------------+------------------------+------------+------------+------------------+--------------------+--------------+-----------------+---------+-------------------------+------------------------+------------+------------+---------------+---------------------+----------------------+-----+----------------------+----------------------+
   |      1002 | 1101710651151115 | 2023-02-05 03:31:42.387119 | 2023-02-05 03:31:42.387119 | z0case     | 1101710651032552 |          3 |         0 |        1 |                 1 |                0 |                 18 |          -1 |                 0 |              1 |         0 |                0 | lz4_1.0            |                  |                  0 |         |      16384 |             45 |             0 |            1 |            -1 |                     0 |          0 |          0 |              0 |                |        1 |                  0 |                    |            1 |                 45 | 1675539102383456 |                 |                 0 |                 0 |           |              |                0 | NULL        |                    0 |          |   134217728 |       0 |                   |                0 |                                    0 |                0 |                        0 |                      0 |          0 |            |                0 | encoding_row_store | DYNAMIC      |               0 |       0 |                       1 |                      3 |        256 |            |            -1 |                  -1 |                    1 |   1 |                    0 |                    0 |
   +-----------+------------------+----------------------------+----------------------------+------------+------------------+------------+-----------+----------+-------------------+------------------+--------------------+-------------+-------------------+----------------+-----------+------------------+--------------------+------------------+--------------------+---------+------------+----------------+---------------+--------------+---------------+-----------------------+------------+------------+----------------+----------------+----------+--------------------+--------------------+--------------+--------------------+------------------+-----------------+-------------------+-------------------+-----------+--------------+------------------+-------------+----------------------+----------+-------------+---------+-------------------+------------------+--------------------------------------+------------------+--------------------------+------------------------+------------+------------+------------------+--------------------+--------------+-----------------+---------+-------------------------+------------------------+------------+------------+---------------+---------------------+----------------------+-----+----------------------+----------------------+
   1 row in set (0.367 sec)
   

   obclient [oceanbase]> select * from __all_virtual_database where database_id=1101710651032552;
   

   返回结果如下。

   +-----------+------------------+----------------------------+----------------------------+---------------+-------------+-----------+--------------+----------------+-------------+-----------+-----------------------+---------------+---------------------+
   | tenant_id | database_id      | gmt_create                 | gmt_modified               | database_name | replica_num | zone_list | primary_zone | collation_type | comment     | read_only | default_tablegroup_id | in_recyclebin | drop_schema_version |
   +-----------+------------------+----------------------------+----------------------------+---------------+-------------+-----------+--------------+----------------+-------------+-----------+-----------------------+---------------+---------------------+
   |      1002 | 1101710651032552 | 2023-01-17 16:04:40.840071 | 2023-02-02 20:50:54.956295 | test          |          -1 |           | NULL         |             45 | test schema |         0 |                    -1 |             0 |                  -1 |
   +-----------+------------------+----------------------------+----------------------------+---------------+-------------+-----------+--------------+----------------+-------------+-----------+-----------------------+---------------+---------------------+
   1 row in set (0.010 sec)
   

   obclient [oceanbase]> select * from __all_tenant where tenant_id=1002;
   

   返回结果如下。

   +----------------------------+----------------------------+-----------+-------------+-------------+-------------------+-------------------+--------+----------------+------+-----------+-----------------------+---------------------------------------------+---------------------+-------------------+------------------------+-----------------------------+-----------------------+--------------------+------------------+----------------------+---------------+
   | gmt_create                 | gmt_modified               | tenant_id | tenant_name | replica_num | zone_list         | primary_zone      | locked | collation_type | info | read_only | rewrite_merge_version | locality                                    | logonly_replica_num | previous_locality | storage_format_version | storage_format_work_version | default_tablegroup_id | compatibility_mode | drop_tenant_time | status               | in_recyclebin |
   +----------------------------+----------------------------+-----------+-------------+-------------+-------------------+-------------------+--------+----------------+------+-----------+-----------------------+---------------------------------------------+---------------------+-------------------+------------------------+-----------------------------+-----------------------+--------------------+------------------+----------------------+---------------+
   | 2023-02-07 06:31:33.104741 | 2023-02-07 06:31:33.104741 |      1002 | mysql       |          -1 | zone1;zone2;zone3 | zone1;zone2,zone3 |      0 |              0 |      |         0 |                     0 | FULL{1}@zone1, FULL{1}@zone2, FULL{1}@zone3 |                   0 |                   |                      3 |                           2 |                    -1 |                  0 |               -1 | TENANT_STATUS_NORMAL |             0 |
   +----------------------------+----------------------------+-----------+-------------+-------------+-------------------+-------------------+--------+----------------+------+-----------+-----------------------+---------------------------------------------+---------------------+-------------------+------------------------+-----------------------------+-----------------------+--------------------+------------------+----------------------+---------------+
   1 row in set (0.005 sec)
   

   在对应的 database 中查看该表的 schema 定义。

   [root@n154 log]# mysql -hxxx.xxx.xxx.3 -P2883 -uroot@mysql#xxxxxxx_xxx -pxxxxxxxxx#_ -Dtest -A -c
   

   obclient [test]> desc z0case;
   

   返回结果如下。

   ERROR 1064 (42000): You have an error in your SQL syntax; check the manual that corresponds to your OceanBase version for the right syntax to use near 'FROM DUAL' at line 1
   

   obclient [test]> show create table z0case;
   

   返回结果如下。

   ERROR 1064 (42000): You have an error in your SQL syntax; check the manual that corresponds to your OceanBase version for the right syntax to use near 'FROM DUAL' at line 1
   

   此处执行的 desc 命令出现报错，经过分析，可能与租户的 init_connect 参数设置有关系，查询租户的 init_connect 参数设置如下。

   obclient [test]> show variables like 'init_connect';
   

   返回结果如下。

   +---------------+---------------+
   | Variable_name | Value         |
   +---------------+---------------+
   | init_connect  | call p1(4711) |
   +---------------+---------------+
   1 row in set (0.003 sec)
   

   通过查询 init_connect 参数设置，发现该环境因执行过 pquery，部分系统变量存在错乱，该 init_connect 缺省的值是空的，将这个变量值恢复为缺省值。

   obclient [test]> set global init_connect="";
   Query OK, 0 rows affected (0.069 sec)
   

6. 再次检查出现问题的 table 的定义。

   obclient [test]> desc z0case;
   

   返回结果如下。

   ERROR 1064 (42000): You have an error in your SQL syntax; check the manual that corresponds to your OceanBase version for the right syntax to use near 'FROM DUAL' at line 1
   

   obclient [test]> show create table z0case;
   

   返回结果如下。

   ERROR 1064 (42000): You have an error in your SQL syntax; check the manual that corresponds to your OceanBase version for the right syntax to use near 'FROM DUAL' at line 1
   

   obclient [test]> show variables like 'init_connect';
   

   返回结果如下。

   +---------------+---------------+
   | Variable_name | Value         |
   +---------------+---------------+
   | init_connect  |               |
   +---------------+---------------+
   1 row in set (0.003 sec)
   

   根据上述查询，还是存在报错，则通过 __all_virtual_ddl_operation 查询该表的定义。

   obclient> select * from oceanbase.__all_virtual_ddl_operation where table_id =1099511627876;
   

   返回结果如下。

   +-----------+----------------+----------------------------+----------------------------+---------+-------------+---------------+---------------+---------------+----------------+----------------+------------------------------------------------------------------------------------------------------------------------+----------------+
   | tenant_id | schema_version | gmt_create                 | gmt_modified               | user_id | database_id | database_name | tablegroup_id | table_id      | table_name     | operation_type |                                                                                                           ddl_stmt_str | exec_tenant_id |
   +-----------+----------------+----------------------------+----------------------------+---------+-------------+---------------+---------------+---------------+----------------+----------------+------------------------------------------------------------------------------------------------------------------------+----------------+
   |      1002 |          10344 | 2023-07-20 16:40:57.368022 | 2023-07-20 16:40:57.368022 |       0 |  1125215588 |               |             0 | 1099511627876 |                |           1651 |  CREATE TABLE Z0CASE(z0_test0 varchar(100) , z0_test1 char(50), z0_test2 timestamp AS (cast(z0_test0 AS CHAR(100) ))); |              1 |
   +-----------+----------------+----------------------------+----------------------------+---------+-------------+---------------+---------------+---------------+----------------+----------------+------------------------------------------------------------------------------------------------------------------------+----------------+
   

   经过上述查询发现 z0case 表内含有一个生成列，再结合之前搜索到的日志中的 get generated column expr failed(ret=-5001) 和 cascaded generated column failed(ret=-5001)，初步怀疑跟生成列可能有些关系，可以简单验证一下。

   obclient>  CREATE TABLE t1(z0_test0 varchar(100) , z0_test1 char(50));
   

   obclient> desc t1;
   

   返回结果如下。

   +----------+--------------+------+-----+---------+-------+
   | Field    | Type         | Null | Key | Default | Extra |
   +----------+--------------+------+-----+---------+-------+
   | z0_test0 | varchar(100) | YES  |     | NULL    |       |
   | z0_test1 | char(50)     | YES  |     | NULL    |       |
   +----------+--------------+------+-----+---------+-------+
   

   obclient>  CREATE TABLE t2(z0_test0 varchar(100) , z0_test1 char(50), z0_test2 timestamp AS (cast(z0_test0 AS CHAR(100) )));
   

   obclient> desc t2;
   

   返回结果如下。

   ERROR 1064 (42000): You have an error in your SQL syntax; check the manual that corresponds to your OceanBase version for the right syntax to use near 'FROM DUAL' at line 1
   

   通过上述验证得知，多了一个生成列就会导致 desc 和 show create table 报错，该问题是确认的产品问题。 ​ 对于合并 timeout 的问题，可以先通过 Drop 该表（如果这张表可以删除的话）来先解决一下。

   obclient [test]> drop table z0case;
   

   如果 Drop Table 时返回如下结果，则只能删除对应的业务租户来恢复环境。

   ERROR 1064 (42000): You have an error in your SQL syntax; check the manual that corresponds to your OceanBase version for the right syntax to use near 'FROM DUAL' at line 1
   

7. 删除有问题的租户后，集群的合并就可以正常进行了。