关于mqtt订阅主题崩溃问题排查，error: {{key_exists,16},...}

2025-03-30

字数统计: 784字 | 阅读时长≈ 4分

分享最近遇到的一个mqtt问题以及排查解决。

一、问题描述

问题表现为服务端mqtt订阅进程crash，会话数据丢失，服务端订阅进程重新拉起，订阅主题丢失。服务端未记录到明显错误，只看到订阅进程重新拉起的动作。

二、问题排查

在emqx节点日志找到错误日志，如下：

1
2

2025-03-30T06:57:23.551444+00:00 [error] crasher: initial call: emqx_connection:init/4, pid: <0.5987205.0>, registered_name: [], error: {{key_exists,16},[{gb_trees,insert_1,4,[{file,"gb_trees.erl"},{line,319}]},{gb_trees,insert_1,4,[{file,"gb_trees.erl"},{line,281}]},{gb_trees,insert,3,[{file,"gb_trees.erl"},{line,278}]},{emqx_inflight,insert,3,[{file,"emqx_inflight.erl"},{line,71}]},{emqx_session_mem,deliver_msg,3,[{file,"emqx_session_mem.erl"},{line,548}]},{emqx_session_mem,do_deliver,4,[{file,"emqx_session_mem.erl"},{line,518}]},{emqx_channel,do_handle_deliver,2,[{file,"emqx_channel.erl"},{line,993}]},{emqx_connection,with_channel,3,[{file,"emqx_connection.erl"},{line,830}]},{emqx_connection,process_msg,2,[{file,"emqx_connection.erl"},{line,484}]},{emqx_connection,handle_recv,3,[{file,"emqx_connection.erl"},{line,447}]},{proc_lib,wake_up,3,[{file,"proc_lib.erl"},{line,251}]}]}, ...
2025-03-30T06:57:23.552234+00:00 [error] supervisor: {esockd_connection_sup,<0.5987205.0>}, errorContext: connection_crashed, reason: {{key_exists,16},[{gb_trees,insert_1,4,[{file,"gb_trees.erl"},{line,319}]},{gb_trees,insert_1,4,[{file,"gb_trees.erl"},{line,281}]},{gb_trees,insert,3,[{file,"gb_trees.erl"},{line,278}]},{emqx_inflight,insert,3,[{file,"emqx_inflight.erl"},{line,71}]},{emqx_session_mem,deliver_msg,3,[{file,"emqx_session_mem.erl"},{line,548}]},{emqx_session_mem,do_deliver,4,[{file,"emqx_session_mem.erl"},{line,518}]},{emqx_channel,do_handle_deliver,2,[{file,"emqx_channel.erl"},{line,993}]},{emqx_connection,with_channel,3,[{file,"emqx_connection.erl"},{line,830}]},{emqx_connection,process_msg,2,[{file,"emqx_connection.erl"},{line,484}]},{emqx_connection,handle_recv,3,[{file,"emqx_connection.erl"},{line,447}]},{proc_lib,wake_up,3,[{file,"proc_lib.erl"},{line,251}]}]}, offender: [{pid,<0.5987205.0>},{name,connection},{mfargs,{emqx_connection,start_link,[#{listener => {ssl,default},limiter => #{connection => #{initial => 0,burst => 0,rate => infinity}},zone => default,enable_authn => true}]}}]

GPT分析结论：emqx的平衡二叉树gb_trees模块写入相同message_id的数据导致出现key_exists错误，最终导致emqx_session_mem崩溃

message_id为什么会重复？

message_id是一个16位无符号整数，范围1到65535，循环使用

emqx从v5.8.0开始，默认不再启用qos消息的自动重发机制（qos1/2消息publish后，服务端可能没有收到，所以也没有puback，导致消息一直存储在飞行窗口中，需要在mqtt配置消息重试间隔。）

三、解决方案

开始消息自动重试retry_interval,将默认值infinity更改为30秒
开启消息过期间隔

四、后感

emqx从v5.8.0开始，默认retry_interval为infinity，不对qos1/2消息进行自动重试了，具体看：EQMX v5.8.0不兼容变更更新

五、相关链接

本文作者： 暮秋人
本文链接： https://muqiuren.pages.dev/2025/03/mqtt-subscribe-crashed/
版权声明： 本博客所有文章除特别声明外，均采用 MIT 许可协议。转载请注明出处！