主备 switchover 前，主集群显示：不能访问集群

适用版本

OceanBase 数据库 V3.x 版本。

问题描述

主备集群环境：

• OceanBase 数据库版本：OceanBase 3.1.2（r20211019145543）
• 主集群：2-2-2 ，cluster_id=9998
• 备集群：1，cluster_id=9999

Switchover 状态信息。

问题原因

主集群 sys 租户队列堆积导致。

问题排查过程：

1. 在主集群中查看日志信息，发现以下异常。

   [2022-02-14 09:17:26.849497] WARN  [SERVER] send_session (ob_req_transport.cpp:303) [16725][450][Y13140BA6552F-0005D68940FC4CA9] [lt=7] [dc=0] send packet fail(dst="192.1.85.47:4882", s=0x7fba40d3b460)
   [2022-02-14 09:17:26.849536] WARN  [RPC.FRAME] send (ob_req_transport.h:269) [16725][450][Y13140BA6552F-0005D68940FC4CA9] [lt=17] [dc=0] send packet fail due to session timeout. It may be caused by tenant queue being full or deadlock in RPC server side, or someting else. Please look into it in the log of server side(easy_error=-47, req={pkt:{hdr_:{checksum_:3470579538, pcode_:287, hlen_:0, priority_:5, flags_:6151, tenant_id_:1, priv_tenant_id_:0, session_id_:0, trace_id_:20976815723823, timeout_:2000000, timestamp:1644801444848795, dst_cluster_id:9998, cost_time:{len:0, arrival_push_diff:0, push_pop_diff:0, pop_process_start_diff:0, process_start_end_diff:0, process_end_response_diff:0, packet_id:9307513160491, request_arrival_time:0}, compressor_type_:0, original_len_:0, src_cluster_id_:9998, seq_no_:0}, chid_:142021380, clen_:96, assemble:false, msg_count:0, payload:0}}, ret=-4012)
   [2022-02-14 09:17:26.849565] WARN  [RPC.OBRPC] rpc_call (ob_rpc_proxy.ipp:334) [16725][450][Y13140BA6552F-0005D68940FC4CA9] [lt=22] [dc=0] send rpc request fail fail(pcode=287)
   [2022-02-14 09:17:26.849591] WARN  [SHARE] get_cluster_info_by_rpc (ob_multi_cluster_util.cpp:375) [16725][450][Y13140BA6552F-0005D68940FC4CA9] [lt=7] [dc=0] failed to get cluster info(ret=-4711, cluster_info={cluster_id:-1, cluster_type:0, login_name:"", login_passwd:"", switchover_status:"SWITCHOVER_INVALID", cluster_status:0, switch_timestamp:0, is_sync:false, gc_snapshot_ts:-1, protection_mode:0, version:-1, protection_level:0}, timeout=2000000)
   [2022-02-14 09:17:26.849636] WARN  [SHARE] get_all_cluster_status (ob_multi_cluster_util.cpp:266) [16725][450][Y13140BA6552F-0005D68940FC4CA9] [lt=5] [dc=0] failed to get cluster info(ret=0, tmp_ret=-4711, cluster_addr={cluster_id:9998, cluster_type:1, cluster_status:1, timestamp:1644801207740583, cluster_name:"xinwen", addr_list:[{server:"192.1.85.47:4882", role:1, sql_port:4881, replica_type:0, reserved:0, property:{memstore_percent_:100}}, {server:"192.1.85.47:4886", role:2, sql_port:4885, replica_type:0, reserved:0, property:{memstore_percent_:100}}, {server:"192.1.85.47:4890", role:2, sql_port:4889, replica_type:0, reserved:0, property:{memstore_percent_:100}}], readonly_addr_list:[], cluster_idx:0, current_scn:-1, redo_transport_options:{net_timeout:30000000, reopen:300000000, max_failure:0, is_sync:false}, protection_level:0, sync_status:0, last_hb_ts:-1}, arg={need_check_sync:false, max_primary_schema_version:1644798485265920, primary_schema_versions:{tenant_schema_versions:[{tenant_id:1, schema_version:1644798485265920}, {tenant_id:1002, schema_version:1644134072109816}, {tenant_id:1003, schema_version:1643110360926552}]}, cluster_version:18446744073709551615, standby_became_primary_scn:-1}, cluster_info={cluster_id:-1, cluster_type:0, login_name:"", login_passwd:"", switchover_status:"SWITCHOVER_INVALID", cluster_status:0, switch_timestamp:0, is_sync:false, gc_snapshot_ts:-1, protection_mode:0, version:-1, protection_level:0})
   

   以上日志显示，因为 RPC 通讯异常，导致主集群状态异常。根据日志提示继续排查 RPC、网络以及 SYS 租户的 task queue 等状态。

   send packet fail due to session timeout. It may be caused by tenant queue being full or deadlock in RPC server side, or someting else. Please look into it in the log of server side
   

2. 尝试修改 rpc_timeout，将超时时间从 2s 增加到 4s，未能解决问题。

   obclient> alter system set rpc_timeout='4s';
   

3. 查看网络情况，未见异常。

   Average:        IFACE   rxpck/s   txpck/s    rxkB/s    txkB/s   rxcmp/s   txcmp/s  rxmcst/s
   Average:     enp1s0f0      0.00      0.00      0.00      0.00      0.00      0.00      0.00
   Average:     enp1s0f1      0.00      0.00      0.00      0.00      0.00      0.00      0.00
   Average:    veth9fe201b      0.00      0.00      0.00      0.00      0.00      0.00      0.00
   Average:        bond0   1032.91   1032.20     74.72     55.90      0.00      0.00      0.16
   Average:         eth2    518.08    520.22     37.39     28.56      0.00      0.00      0.08
   Average:         eth3    514.83    511.97     37.33     27.34      0.00      0.00      0.08
   Average:           lo   1846.87   1846.87    742.98    742.98      0.00      0.00      0.00
   Average:    veth1996db2      0.00      0.00      0.00      0.00      0.00      0.00      0.00
   Average:    vethd47b68a      0.00      0.00      0.00      0.00      0.00      0.00      0.00
   Average:      docker0      0.00      0.00      0.00      0.00      0.00      0.00      0.00
   

4. 查看 sys 租户 task queue 状态，发现有队列积压的情况。

   $grep "dump tenant info(tenant={id:1"  observer.log.20220214* | grep "req_queue:total_size=54"
   observer.log.20220214091544:[2022-02-14 09:15:44.438445] INFO  [SERVER.OMT] ob_multi_tenant.cpp:806 [16871][740][Y0-0000000000000000] [lt=17] [dc=0] dump tenant info(tenant={id:1, compat_mode:0, unit_min_cpu:"2.000000000000000000e+00", unit_max_cpu:"2.000000000000000000e+00", slice:"0.000000000000000000e+00", slice_remain:"0.000000000000000000e+00", token_cnt:2, sug_token_cnt:2, ass_token_cnt:2, lq_tokens:1, used_lq_tokens:0, stopped:false, idle_us:1918883, recv_hp_rpc_cnt:79922918, recv_np_rpc_cnt:30526796, recv_lp_rpc_cnt:0, recv_mysql_cnt:178, recv_task_cnt:22, recv_large_req_cnt:0, tt_large_quries:0, pop_normal_cnt:320831174, actives:2, workers:2, nesting workers:7, lq waiting workers:0, req_queue:total_size=54 queue[0]=42 queue[1]=0 queue[2]=12 queue[3]=0 queue[4]=0 queue[5]=0 , large queued:0, multi_level_queue:total_size=0 queue[0]=0 queue[1]=0 queue[2]=0 queue[3]=0 queue[4]=0 queue[5]=0 queue[6]=0 queue[7]=0 , recv_level_rpc_cnt:cnt[0]=0 cnt[1]=0 cnt[2]=0 cnt[3]=0 cnt[4]=0 cnt[5]=40129729 cnt[6]=46 cnt[7]=0 , group_map:null})
   

   根据 sys 租户的 dump tenant info 日志信息，发现 sys 租户的 cpu 数为 2，但其 worker 线程数也只有 2 个。查看集群的 cpu_quota_concurrency 参数，发现其值被修改为 1。

解决方法

sys 租户队列存在积压，通过调大 sys 租户 cpu、cpu_quota_concurrency 来提供更多的 worker 线程。

obclient> select * from v$ob_cluster;

+------------+--------------+----------------------------+--------------+----------------+------------------+-------------------+-------------------------------+------------------+----------------------------+--------------------+---------------------+---------------------+------------------------------+
| cluster_id | cluster_name | created                    | cluster_role | cluster_status | switchover#      | switchover_status | switchover_info               | current_scn      | standby_became_primary_scn | primary_cluster_id | protection_mode     | protection_level    | redo_transport_options       |
+------------+--------------+----------------------------+--------------+----------------+------------------+-------------------+-------------------------------+------------------+----------------------------+--------------------+---------------------+---------------------+------------------------------+
|       9998 | obcluster       | 2021-11-18 14:04:24.368638 | PRIMARY      | VALID          | 1644798485225472 | NOT ALLOWED       | CAN NOT ACCESS CLUSTERS: 9998 | 1644825168363277 |                          0 |               NULL | MAXIMUM PERFORMANCE | MAXIMUM PERFORMANCE | ASYNC NET_TIMEOUT = 30000000 |
+------------+--------------+----------------------------+--------------+----------------+------------------+-------------------+-------------------------------+------------------+----------------------------+--------------------+---------------------+---------------------+------------------------------+
1 row in set (5.01 sec)

obclient> alter system set cpu_quota_concurrency=2;
Query OK, 0 rows affected (0.05 sec)

obclient> select * from v$ob_cluster;

+------------+--------------+----------------------------+--------------+----------------+------------------+-------------------+-------------------------------+------------------+----------------------------+--------------------+---------------------+---------------------+------------------------------+
| cluster_id | cluster_name | created                    | cluster_role | cluster_status | switchover#      | switchover_status | switchover_info               | current_scn      | standby_became_primary_scn | primary_cluster_id | protection_mode     | protection_level    | redo_transport_options       |
+------------+--------------+----------------------------+--------------+----------------+------------------+-------------------+-------------------------------+------------------+----------------------------+--------------------+---------------------+---------------------+------------------------------+
|       9998 | obcluster       | 2021-11-18 14:04:24.368638 | PRIMARY      | VALID          | 1644798485225472 | TO STANDBY        | SYNCED STANDBY CLUSTERS: 9999 | 1644825522693186 |                          0 |               NULL | MAXIMUM PERFORMANCE | MAXIMUM PERFORMANCE | ASYNC NET_TIMEOUT = 30000000 |
+------------+--------------+----------------------------+--------------+----------------+------------------+-------------------+-------------------------------+------------------+----------------------------+--------------------+---------------------+---------------------+------------------------------+
1 row in set (0.16 sec)