mq客户端异常断线重连失败

环境信息

  • EMQ X 版本:4.2.1
  • 操作系统及版本:linux cenos7.9
  • 其他

问题描述

两台客户端连接上了emqx接收消息,测试运行一段时间(10来天吧)会出现断开重连的情况,一台能连接上,另一台连接不上,而且是在同一时间断开重连
这一台是连接不上的日志:

---MQTT连接异常:Unable to connect to server
engine|2021-11-30 15:07:12.107|[MQTT Ping: engine-test-1]|ERROR|o.eclipse.paho.mqttv5.client.internal.ClientState.logToJsr47(210)|engine-test-1: Timed out as no activity, keepAlive=60,000,000,000 lastOutboundActivity=5,781,585,183,163,891 lastInboundActivity=5,781,525,179,593,904 time=5,781,645,183,630,211 lastPing=5,781,585,183,166,651

连接断开,正在重连
engine|2021-11-30 15:05:12.104|[MQTT Rec: engine-test-1]|INFO|com.dgindusoft.mqtt.MqttPushClient.connect(69)|MQTT连接成功

上面显示连接成功实际没有成功,当然连接后再次订阅也没有订阅成功

这一台是连接上的日志:

---MQTT连接异常:Unable to connect to server
engine|2021-11-30 15:06:12.496|[MQTT Rec: engine-test-2]|ERROR|com.dgindusoft.mqtt.MqttPushClient.connect(73)|---MQTT连接异常:Not authorized.
engine|2021-11-30 15:06:17.830|[MQTT Rec: engine-test-2]|ERROR|com.dgindusoft.mqtt.MqttPushClient.connect(73)|---MQTT连接异常:Not authorized.
engine|2021-11-30 15:06:23.165|[MQTT Rec: engine-test-2]|ERROR|com.dgindusoft.mqtt.MqttPushClient.connect(73)|---MQTT连接异常:Not authorized.

连接断开,正在重连
engine|2021-11-30 15:05:12.104|[MQTT Rec: engine-test-2]|INFO|com.dgindusoft.mqtt.MqttPushClient.connect(69)|MQTT连接成功
engine|2021-11-30 15:05:12.104|[MQTT Call: engine-test-2]|INFO|com.dgindusoft.mqtt.PushCallback.connectComplete(147)|---connectComplete
engine|2021-11-30 15:05:12.415|[MQTT Call: engine-test-2]|INFO|com.dgindusoft.mqtt.PushCallback.connectComplete(183)|初始化设备总数:10,上线设备数量:7
engine|2021-11-30 15:06:12.161|[MQTT Rec: engine-test-2]|INFO|com.dgindusoft.mqtt.PushCallback.disconnected(209)|连接断开,正在重连
engine|2021-11-30 15:06:28.500|[MQTT Call: engine-test-2]|INFO|com.dgindusoft.mqtt.PushCallback.connectComplete(147)|---connectComplete
engine|2021-11-30 15:06:28.500|[MQTT Rec: engine-test-2]|INFO|com.dgindusoft.mqtt.MqttPushClient.connect(69)|MQTT连接成功
engine|2021-11-30 15:06:28.788|[MQTT Call: engine-test-2]|INFO|com.dgindusoft.mqtt.PushCallback.connectComplete(183)|初始化设备总数:10,上线设备数量:5

这个连接成功,也订阅成功了

看下 emqx 这边的日志呢?

这一台应该是连接不上的:

2021-11-30 15:05:12.923 [error] <<"thing-R8GGOF01">>@192.168.10.12:10716 [ACL http] Request ACL path /mqtt/acl, error: {closed,
                                               "The connection was lost."}
2021-11-30 15:05:14.938 [warning] Received gun_down with closed
2021-11-30 15:05:15.790 [warning] Received gun_down with closed


2021-11-30 15:05:36.441 [warning] Received gun_down with closed
2021-11-30 15:05:36.447 [warning] Received gun_down with closed
2021-11-30 15:05:37.717 [warning] [SYSMON] long_schedule warning: pid = <0.1849.131>, info: [{timeout,242},
                                                  {in,
                                                   {emqx_connection,
                                                    handle_msg,2}},
                                                  {out,
                                                   {emqx_connection,
                                                    handle_msg,2}}]
[{initial_call,{proc_lib,init_p,5}},
 {current_function,{logger_config,level_to_int,1}},
 {registered_name,[]},
 {status,running},
 {message_queue_len,21},
 {group_leader,<0.1397.0>},
 {priority,normal},
 {trap_exit,false},
 {reductions,206217},
 {last_calls,false},
 {catchlevel,2},
 {trace,0},
 {suspending,[]},
 {sequential_trace_token,[]},
 {error_handler,error_handler},
 {memory,25080},
 {total_heap_size,2962},
 {heap_size,376},
 {stack_size,15},
 {min_heap_size,233}]
2021-11-30 15:05:39.370 [warning] Received gun_down with closed
2021-11-30 15:05:39.376 [warning] Received gun_down with closed
2021-11-30 15:05:39.382 [warning] Received gun_down with closed

这一台应该最后是连接上的:

2021-11-30 15:05:13.619 [error] <<"thing-843IRIN7">>@192.168.10.12:19208 [ACL http] Request ACL path /mqtt/acl, error: {closed,
                                               "The connection was lost."}
2021-11-30 15:05:14.619 [warning] Received gun_down with closed
2021-11-30 15:05:14.624 [warning] Received gun_down with closed

2021-11-30 15:06:18.419 [warning] Received gun_down with normal
2021-11-30 15:06:20.363 [warning] Received gun_down with closed
2021-11-30 15:06:23.210 [error] <<"engine-test-2">>@192.168.10.11:36914 [Auth http] Deny connection from path: /mqtt/auth, response http code: 403
2021-11-30 15:06:23.211 [warning] <<"engine-test-2">>@192.168.10.11:36914 [Channel] Client engine-test-2 (Username: 'dgis') login failed for not_authorized
2021-11-30 15:06:24.101 [warning] Received gun_down with normal
2021-11-30 15:06:24.104 [warning] Received gun_down with normal
2021-11-30 15:06:24.211 [warning] Received gun_down with closed

看日志的话应该是因为你用了 HTTP 认证鉴权服务,但是 EMQ X 和 HTTP Server 的连接断开了,导致无法通过鉴权,所以订阅失败。

至于 MQTT 客户端为什么会断开连接,这部分日志里面看不出来。

好的 谢谢