emqx集群节点单点故障

EMQX
1

本版号5.0.18
系统centos7.6

生产环境

9/8日中午10点开始，消息流量有降低，没觉得是中间件的问题。9/11日发现流量还是低于正常水平。进行了简单的排查，初步发现集群中有一个节点的服务挂了。

简单看了一下emqx的log，发现其中有大量的error内容:

[error] msg: unexpected_event, mfa: emqtt:handle_event/4, line: 1434, clietntid: <<“bridge:mqtt:ALL:74062:emqx@172.23.1.22”>>, event: flush, event_type: cast, state: connected

请问这个是什么原因造成的，接下来应该如何排查故障。
目前网上调查没有相关的资料。

此故障是造成节点服务挂掉的原因吗？

2

本条日志不会导致节点down。

麻烦上传脱敏后的完整日志，只有这一条日志无法定位问题。

想知道：

  • 发生这条日志前有什么异常日志么
  • 节点down的直接原因
3

你好，我找到了节点down掉的日志，
其中三个节点的ip分别是：
172.23.1.18,172.23.1.22,172.23.1.48

3-09-11T09:24:02.871939+08:00 [error] Mnesia(‘emqx@172.23.1.22’): ** ERROR ** Mnesia post_commit hook failed: error:badarg, Stacktrace:[{mria_rlog_server,dispatch,3,[{file,“mria_rlog_server.erl”},{line,105}]},{mnesia_hook,do_post_commit,2,[{file,“mnesia_hook.erl”},{line,69}]},{mnesia_tm,do_commit,3,[{file,“mnesia_tm.erl”},{line,1788}]},{mnesia_tm,do_async_dirty,3,[{file,“mnesia_tm.erl”},{line,489}]},{mnesia_tm,doit_loop,1,[{file,“mnesia_tm.erl”},{line,213}]},{mnesia_sp,init_proc,4,[{file,“mnesia_sp.erl”},{line,34}]},{proc_lib,init_p_do_apply,3,[{file,“proc_lib.erl”},{line,226}]}]
2023-09-11T09:24:02.874133+08:00 [error] message=channel_closed driver=tcp socket=“#Port<0.16>” action=stopping
2023-09-11T09:24:02.934165+08:00 [error] Mnesia(‘emqx@172.23.1.22’): ** ERROR ** Mnesia post_commit hook failed: error:badarg, Stacktrace:[{mria_rlog_server,dispatch,3,[{file,“mria_rlog_server.erl”},{line,105}]},{mnesia_hook,do_post_commit,2,[{file,“mnesia_hook.erl”},{line,69}]},{mnesia_tm,do_commit,3,[{file,“mnesia_tm.erl”},{line,1788}]},{mnesia_tm,do_async_dirty,3,[{file,“mnesia_tm.erl”},{line,489}]},{mnesia_tm,doit_loop,1,[{file,“mnesia_tm.erl”},{line,213}]},{mnesia_sp,init_proc,4,[{file,“mnesia_sp.erl”},{line,34}]},{proc_lib,init_p_do_apply,3,[{file,“proc_lib.erl”},{line,226}]}]
2023-09-11T09:24:07.853989+08:00 [error] Mria(Membership): Failed to ping emqx@172.23.1.18

4

image
image1617×905 118 KB

这是前后的日志，暂时没发现别的异常

5

post_commit的错误，我们已经在5.1.0上修了：chore(ekka): Bump version to 0.15.2 by ieQu1 · Pull Request #10809 · emqx/emqx · GitHub
对应的changelog：https://www.emqx.io/docs/zh/v5.1/changes/changes-5.1.html#e5-1-0

推荐先看看版本的changelog：EMQX Changelogs | EMQ
在测试环境上升级到v5.1的最新版本，测试没问题，再考虑升级。

但是光看post_commit error 这个日志并不会导致节点down， 能上传一下这个节点down时间点的最后的日志么，

6

好的，我把整个日志发给您。
因为上传文件大小受限，我把tar包切割了。
同时受限于文件类型，请下载后改一下文件名:
emqx.log.22.tar.gz0
emqx.log.22.tar.gz1
emqx.log.22.tar.gz2

emqx.log.22.tar.0.gz (4 MB)
emqx.log.22.tar1.gz (4 MB)
emqx.log.22.tar2.gz (2.8 MB)

7

为什么只有emqx.log.22.tar.gz0能找开，其它的都打不开的。。
tar -xvf emqx.log.22.tar.gz1
tar: Error opening archive: Unrecognized archive format

8

您试一下 tar -xvf emqx.log.22.tar.*

9

https://drfs.ctcontents.com/file/48162279/932987859/b2b563/emqx.log.22.tar.gz
我传网盘了，如果还不行您试试这个

10

都不行，
网盘
{

  • “code”: 400,
  • “message_en”: “File does not exist.”,
  • “message_zh”: “文件不存在。”

}

11

https://url79.ctfile.com/f/48162279-932987859-555430?p=1224 (访问密码: 1224)
试试这个呢

12

不好意思， 我没有这个网盘的会员，下载不了

13

链接: 百度网盘 请输入提取码 提取码: qtme 复制这段内容后打开百度网盘手机App，操作更方便哦
您试试这个呢

14

看了全部日志，只有上面2个错，没有其它的。能找到节点down具体的时间点是什么？

15

好的，我补充一下情况。

9/11 早上9点左右发现流量有下降，当时发现18节点的dashboard打不开，22节点也不行。当时只有48节点是正常的。
登录环境以后，在18节点确认cluster status，发现22节点挂了。

image

在22节点确认cluster status ，发现18节点挂了。
image

但实际在各自节点确认的时候，结果也不一样；
18节点好像还在，但是其实已经没有服务了

image
image1067×251 176 KB

22节点确实挂了
image

我把18和48的日志也上传了，请确认一下吧。

链接: 百度网盘 请输入提取码 提取码: n99v 复制这段内容后打开百度网盘手机App，操作更方便哦
链接: 百度网盘 请输入提取码 提取码: nuqy 复制这段内容后打开百度网盘手机App，操作更方便哦

16

image
image1872×959 99.3 KB

这个是流量下降的记录

17

日志都看了。还是没找到为什么节点不见了，

  1. 怀疑是内存还是cpu超了被操作系统杀了？ 里面有点queue full，可以用：dmesg 命令看看操作系统干了啥，有没有被kill的日志。
  2. 这个unexpected event flush 不会影响你的业务么，怎么所有的节点都在报，正常进也会报这个错么？
18
  1. 怀疑是内存还是cpu超了被操作系统杀了？ 里面有点queue full，可以用：dmesg 命令看看操作系统干了啥，有没有被kill的日志。
    》》》具体的问题出现在8号，8号的日志好像被覆盖了，我去看看dmesg。
  2. 这个unexpected event flush 不会影响你的业务么，怎么所有的节点都在报，正常进也会报这个错么？
    》》》》 我不知道这个是咋回事啊，一头雾水。目前看没影响
19

dmesg命令打完出来一堆东西啊，有关键字吗，得筛一下。

还有一个截图是当时故障期间dashboard有报错。

5bd8c3e16e0f2b3b5b8548b0ca72a2b
5bd8c3e16e0f2b3b5b8548b0ca72a2b1872×959 154 KB

20

这个dashboard上的报错说明，从48的角度看，22是已经挂掉了。
dmesg 找error就行。

PS：你应该是通过zip包安装的，缺少systemed的支持，他可以帮你在节点挂掉的时候，重启emqx。
这样可能在还没找到原因前，降低影响。

systemd支持需要通过dep 或apt方式装。 Download EMQX
如果是生产环境不能改，可以自己写一个emqx.service 来配置systemd。