OBServer-4.2.1.4-时钟偏差导致合并一直卡住

evan_ob · 2024 年5 月 22 日 17:40

【使用环境】测试环境

【 OB or 其他组件】OceanBase

【使用版本】4.2.1.4

【问题描述】
1.问题背景：由于某些问题导致集群OBServer所在机器时间不同步（机器发生过重启，ntp服务未启动），时间差异达到60s+，但集群仍然处于可读写状态，直到进行集群合并时才产生问题，时间落后的OBServer所在zone一直处于COMPACTING状态，合并无法完成。
2.基于 OceanBase 4.2.1.4 针对此问题进行复现，形成文档《OB4.X-时钟延迟-合并异常-测试》
a.架构：1-1-1
i. zone1: 10.186.64.161
ii.zone2:10.186.64.162
iii.zone3:10.186.64.163
iv.时钟源：10.186.64.160 （即，OCP节点）
b.场景一：将一台非RS节点OBServer系统时间调慢65s后，进行集群合并
i.10.186.64.161 作为RS节点，10.186.64.162保持正常，将10.186.64.163系统时间调慢65s
ii.结论：集群读写正常，合并时zone3一直处于COMPACTING状态，无法完成。
iii.解决方法，将租户leader切至zone3所在的OBServer节点或者将zone3所在OBServer节点系统时间调整为正确时间
iv.本场景涉及的日志文件以附件形式上传，含observer.log 、rootservice.log、election.log
v.以sys租户为例子查看zone3的 umerged_cnt 一直处于888的数量；zone1 和 zone2 则逐渐减少，直到合并完成。

3.问题：
a.实际测试结果：即使存在65s延迟，集群依然可以正常读写，此处表现是否不符合预期？疑似命中bug？

根据官网资料：OceanBase分布式数据库-海量数据笔笔算数
如果您计划部署分布式 OceanBase 集群，需要保证集群内各机器的时间同步，否则集群无法启动，服务在运行时也会出现异常。OceanBase 集群允许的时钟偏差不能超过 2s。当超过 2s 时，会出现无主情况。恢复时钟同步后，重启 OceanBase 集群，可以恢复正常。
b.集群机器之间时间存在差异，是否在日志中有打印信息呢？具体语句是什么呢？
c.OBServer机器的系统时间与合并之间的关联关系是什么呢？为什么OBServer机器之间的时间同步延迟过大会影响到合并呢？在日志中应该如何排查呢？

【复现路径】问题出现前后相关操作
1、将一台非RS节点OBServer系统时间调慢65s后，进行集群合并。
2、10.186.64.161 作为RS节点，10.186.64.162保持正常，将10.186.64.163系统时间调慢65s

【附件及日志】推荐使用OceanBase敏捷诊断工具obdiag收集诊断信息,详情参见链接（右键跳转查看）：
OB4.X-时钟延迟-合并异常-测试.pdf (1.1 MB)

王利博 · 2024 年5 月 22 日 18:15

机器间的时钟误差过大（超过100毫秒），可以利用ntpq、clockdiff等命令检查机器之间的时钟差异

evan_ob · 2024 年5 月 23 日 10:02

您好，请问有老师可以帮忙看一下吗，日志文件，希望能私发下老师

evan_ob · 2024 年5 月 23 日 10:12

您好，实际的场景是chrony服务挂掉导致节点之间时间不同步，这里设置误差是为了复现场景。主要问题是想知道为何follower（zone3）节点时钟落后高达1分钟的情况下，集群状态与读写仍正常，集群合并时follower (zone3)卡住了如何基于日志分析

王利博 · 2024 年5 月 23 日 11:18

提供下observer.log呢。
也可以使用obdiag来一键分析下： obdiag
obdiag rca run --scene=major_hold

evan_ob · 2024 年5 月 23 日 11:33

老师，请问下，您是社区工作人员么，日志我已经打包好了的

靖顺 · 2024 年5 月 23 日 11:35

卡合并的问题，先用obdiag根因分析一把，把分析结果发出来。
obdiag rca run --scene=major_hold

evan_ob · 2024 年5 月 23 日 14:43

major_hold_20240523143020.tar.gz (420 字节)
obdiag分析合并卡住.pdf (2.7 MB)
老师您好，文件已传，操作记录全程记录pdf可见

镜水 · 2024 年5 月 23 日 17:19

查下 GV$OB_COMPACTION_PROGRESS和 GV$OB_TABLET_COMPACTION_PROGRESS看下

evan_ob · 2024 年5 月 23 日 17:33

GV$OB_COMPACTION_PROGRESS.txt (74.0 KB)
老师，请查收

镜水 · 2024 年5 月 23 日 17:38

现在状态推了吗，我看17点已经有一次新合并了

evan_ob · 2024 年5 月 23 日 17:44

新合并是我重新复现了一下这个场景，之前的场景被我复原了

镜水 · 2024 年5 月 23 日 17:59

现在是什么状态？你能复现的话就保持在你说的合并卡住状态，然后再收集信息看看吧

evan_ob · 2024 年5 月 23 日 20:17

老师，我忘了停止ntp服务，延迟被拉平了，我现在把ntp停了，复现问题，过一段时间再采集 GV$OB_COMPACTION_PROGRESS和 GV$OB_TABLET_COMPACTION_PROGRESS 和 obdiag 信息给您

evan_ob · 2024 年5 月 24 日 10:03

老师好，目前还是卡住状态，取了相关信息如下，sql查询结果在 major_select.txt

major_select.txt (84.2 KB)

[root@10-186-64-160-ocp ~]# obdiag display-trace ec03bd6e-1970-11ef-9a74-02000aba40a0
[2024-05-24 09:57:05.849] [DEBUG] - cmd: []
[2024-05-24 09:57:05.850] [DEBUG] - opts: {‘scene’: ‘major_hold’, ‘store_dir’: ‘./rca/’, ‘input_parameters’: None, ‘c’: ‘/root/.obdiag/config.yml’}
[2024-05-24 09:57:05.851] [DEBUG] - mkdir /usr/local/oceanbase-diagnostic-tool/conf/inner_config.yml
[2024-05-24 09:57:05.861] [DEBUG] - mkdir /root/.obdiag/config.yml
[2024-05-24 09:57:07.478] [DEBUG] - connect databse …
[2024-05-24 09:57:07.482] [DEBUG] - RCAHandler.init store dir: ./rca/
[2024-05-24 09:57:07.482] [DEBUG] - rca result save_path is :./rca/
[2024-05-24 09:57:07.483] [DEBUG] - start get_observer_version_by_sql . input: {‘ob_cluster_name’: ‘obcluster’, ‘db_host’: ‘10.186.64.161’, ‘db_port’: ‘2883’, ‘tenant_sys’: {‘user’: ‘root@sys#ob4214’, ‘password’: ‘ZZQzzq123!!’}, ‘servers’: [{‘ip’: ‘10.186.64.161’, ‘ssh_username’: ‘root’, ‘ssh_password’: ‘ZZQzzq123’, ‘ssh_port’: ‘22’, ‘home_path’: ‘/home/admin/oceanbase’, ‘data_dir’: ‘/data/1’, ‘redo_dir’: ‘/data/log1’, ‘ssh_key_file’: ‘’, ‘ssh_type’: ‘remote’, ‘container_name’: None, ‘host_type’: ‘OBSERVER’, ‘ssher’: <common.ssh.SshHelper object at 0x7f6521efdc10>}, {‘ip’: ‘10.186.64.162’, ‘ssh_username’: ‘root’, ‘ssh_password’: ‘ZZQzzq123’, ‘ssh_port’: ‘22’, ‘home_path’: ‘/home/admin/oceanbase’, ‘data_dir’: ‘/data/1’, ‘redo_dir’: ‘/data/log1’, ‘ssh_key_file’: ‘’, ‘ssh_type’: ‘remote’, ‘container_name’: None, ‘host_type’: ‘OBSERVER’, ‘ssher’: <common.ssh.SshHelper object at 0x7f6521efdcd0>}, {‘ip’: ‘10.186.64.163’, ‘ssh_username’: ‘root’, ‘ssh_password’: ‘ZZQzzq123’, ‘ssh_port’: ‘22’, ‘home_path’: ‘/home/admin/oceanbase’, ‘data_dir’: ‘/data/1’, ‘redo_dir’: ‘/data/log1’, ‘ssh_key_file’: ‘’, ‘ssh_type’: ‘remote’, ‘container_name’: None, ‘host_type’: ‘OBSERVER’, ‘ssher’: <common.ssh.SshHelper object at 0x7f6521ee7c10>}]}
[2024-05-24 09:57:07.490] [DEBUG] - connect databse …
[2024-05-24 09:57:07.504] [DEBUG] - get_observer_version_by_sql ob_version_info is (‘5.7.25-OceanBase-v4.2.1.4’,)
[2024-05-24 09:57:07.505] [DEBUG] - RCAHandler.init get observer version: 4.2.1.4
[2024-05-24 09:57:07.505] [DEBUG] - RCAHandler.init get observer version: 4.2.1.4
[2024-05-24 09:57:07.505] [DEBUG] - [remote host 10.186.64.161] run cmd = [/home/admin/obproxy/bin/obproxy --version] start …
[2024-05-24 09:57:08.020] [DEBUG] - get obproxy version, run cmd = [/home/admin/obproxy/bin/obproxy --version]
[2024-05-24 09:57:08.021] [DEBUG] - [remote host 10.186.64.161] run cmd = [export LD_LIBRARY_PATH=/home/admin/obproxy/lib && /home/admin/obproxy/bin/obproxy --version] start …
[2024-05-24 09:57:08.113] [DEBUG] - get obproxy version with LD_LIBRARY_PATH,cmd:export LD_LIBRARY_PATH=/home/admin/obproxy/lib && /home/admin/obproxy/bin/obproxy --version, result:/home/admin/obproxy/bin/obproxy --version
[2024-05-24 09:57:08.114] [DEBUG] obproxy (OceanBase 4.1.0.0 20230323104822.el7)
[2024-05-24 09:57:08.114] [DEBUG] REVISION: 20230323104822-f00479cbe865e81c72211d398890b8058e5ea361
[2024-05-24 09:57:08.115] [DEBUG] BUILD_TIME: Mar 23 2023 10:55:16
[2024-05-24 09:57:08.115] [DEBUG] BUILD_FLAGS: -g -O2 -D_OB_VERSION=1000 -D_NO_EXCEPTION -D__STDC_LIMIT_MACROS -D__STDC_CONSTANT_MACROS -DNDEBUG -D__USE_LARGEFILE64 -D_FILE_OFFSET_BITS=64 -D_LARGE_FILE -D_LARGEFILE_SOURCE -D_LARGEFILE64_SOURCE -Wall -Wextra -Wunused-parameter -Wformat -Wconversion -Wno-deprecated -Wno-invalid-offsetof -finline-functions -fno-strict-aliasing -mtune=core2 -Wno-psabi -Wno-sign-compare -Wno-class-memaccess -Wno-deprecated-copy -Wno-ignored-qualifiers -Wno-aligned-new -Wno-format-truncation -Wno-literal-suffix -Wno-format-overflow -Wno-stringop-truncation -Wno-memset-elt-size -Wno-cast-function-type -Wno-address-of-packed-member -fno-omit-frame-pointer -fuse-ld=lld -ffunction-sections -Wl,–no-warn-symbol-ordering,–symbol-ordering-file,//home/admin/252_20230323104822694_475145676_code/rpm_workspace/obproxy-tmp.1388/BUILD/obproxy-4.1.0.0/hotfuncs.txt -DGCC_52 -DSUPPORT_SSE4_2 -DHAVE_SCHED_GETCPU -DHAVE_REALTIME_COARSE -DOB_HAVE_EVENTFD -DHAVE_FALLOCATE -DHAVA_BEYONDTRUST -DHAVE_MINIDUMP -Werror
[2024-05-24 09:57:08.115] [DEBUG]
[2024-05-24 09:57:08.115] [DEBUG] Copyright (c) 2007-2020 Alipay Inc.
[2024-05-24 09:57:08.115] [DEBUG]
[2024-05-24 09:57:08.116] [DEBUG] - RCAHandler.init get obproxy version: 4.1.0.0
[2024-05-24 09:57:08.116] [DEBUG] - RCAHandler.init get obproxy version: 4.1.0.0
[2024-05-24 09:57:08.151] [DEBUG] - RCAHandler init.cluster:obcluster, init.nodes:[{‘ip’: ‘10.186.64.161’, ‘ssh_username’: ‘root’, ‘ssh_port’: ‘22’, ‘home_path’: ‘/home/admin/oceanbase’, ‘data_dir’: ‘/data/1’, ‘redo_dir’: ‘/data/log1’, ‘ssh_key_file’: ‘’, ‘ssh_type’: ‘remote’, ‘container_name’: None, ‘host_type’: ‘OBSERVER’, ‘ssher’: <common.ssh.SshHelper object at 0x7f6521efdc10>}, {‘ip’: ‘10.186.64.162’, ‘ssh_username’: ‘root’, ‘ssh_port’: ‘22’, ‘home_path’: ‘/home/admin/oceanbase’, ‘data_dir’: ‘/data/1’, ‘redo_dir’: ‘/data/log1’, ‘ssh_key_file’: ‘’, ‘ssh_type’: ‘remote’, ‘container_name’: None, ‘host_type’: ‘OBSERVER’, ‘ssher’: <common.ssh.SshHelper object at 0x7f6521efdcd0>}, {‘ip’: ‘10.186.64.163’, ‘ssh_username’: ‘root’, ‘ssh_port’: ‘22’, ‘home_path’: ‘/home/admin/oceanbase’, ‘data_dir’: ‘/data/1’, ‘redo_dir’: ‘/data/log1’, ‘ssh_key_file’: ‘’, ‘ssh_type’: ‘remote’, ‘container_name’: None, ‘host_type’: ‘OBSERVER’, ‘ssher’: <common.ssh.SshHelper object at 0x7f6521ee7c10>}], init.obproxy_nodes:[{‘ip’: ‘10.186.64.161’, ‘ssh_username’: ‘root’, ‘ssh_port’: ‘22’, ‘home_path’: ‘/home/admin/obproxy’, ‘ssh_key_file’: ‘’, ‘ssh_type’: ‘ssh’, ‘container_name’: None, ‘host_type’: ‘OBPROXY’, ‘ssher’: <common.ssh.SshHelper object at 0x7f652043f880>}], init.store_dir:./rca/
[2024-05-24 09:57:08.152] [DEBUG] - major_hold store_dir:./rca//major_hold_20240524095708
[2024-05-24 09:57:08.152] [DEBUG] - major_hold init success
[2024-05-24 09:57:08.526] [WARNING] rca_scene.execute not need execute: MajorHoldScene not need execute

镜水 · 2024 年5 月 24 日 10:10

存储层已经合完了，看起来是RS受到了影响，你查下select * from __all_tablet_meta_table where tenant_id = 1001 and report_scn < 1716466470749632455;看下

镜水 · 2024 年5 月 24 日 10:12

再搜下select * from __all_tenant; select * from cdb_ob_ls_locations;看下

evan_ob · 2024 年5 月 24 日 10:24

cdb_ob_ls_locations.txt (11.0 KB)
老师，两条sql都查了，请查收～

镜水 · 2024 年5 月 24 日 10:34

到10.186.64.161机器上搜rs日志看看
搜一下grep “replica not merged” rootservice.log.xxx
grep “check updating merge status” rootservice.log.xxx

evan_ob · 2024 年5 月 24 日 10:41

chk_updating.txt.zip (637.6 KB)
replica_not_merged.txt (4.9 MB)