为什么客户端发布消息后收到客户机未连接的提示后连接断开自动重连

环境信息

  • EMQX 版本:4.4.3
  • 操作系统及版本:centos7
  • broker 2核 4G
    两台集群

问题描述

客户端发布消息后收到客户机未连接的提示,客户端到服务器的连接断开,然后自动重连,后又断开,然后收到订阅消息后发布消息又断开,一直死循环执行,这个是什么原因?如何解决?
还有正在进行过多的发布的日志,但是客户端没有断开重连。
查日志当时有消息积压。

配置文件及日志

emqx的日志:

2022-07-24T21:14:39.347617+08:00 [warning] emq-client_prod-7ca4b536@112.74.47.243:41164 [Session] Dropped msg due to mqueue is full: Message(Id=0005E48B8E0755C76AE600000BCD0052, QoS=1, Topic=topic/face/capture/request/AF9004-1742CB-0000FF, From=<<"AF9004-1742CB-0000FF">>, Flags=[], Headers=#{peerhost => {14,211,252,222}, properties => #{},proto_ver => 4,protocol => mqtt,username => <<"person">>})
2022-07-25T14:35:27.559397+08:00 [warning] emq-client_prod-1a6dfce5@120.77.41.86:59354 [Session] Dropped msg due to mqueue is full: Message(Id=0005E49A700A071E6AE6000034410006, QoS=1, Topic=topic/face/capture/request/D7879C-2EFECB-0000FF, From=<<"D7879C-2EFECB-0000FF">>, Flags=[], Headers=#{peerhost => {14,211,252,222}, properties => #{},proto_ver => 4,protocol => mqtt,username => <<"person">>})

mqtt客户端的日志:

2022-07-25 00:00:42.573|ERROR|-|MQTT Call: emq-client_prod-1a6dfce5|com.ameter.platform.passage.iot.common.protocol.mqtt.MqttClient|123|publish|emq publish error errorMsg=客户机未连接 , topic=topic/face/capture/response/D7879C-2EFECB-0000FF , payload={"reply":"ACK","cmd":"face","code":0,"sequence_no":413,"cap_time":"2022/07/24 21:03:27.954"} , qos=1 , retain=false
2022-07-25 00:00:57.688|INFO|-|http-nio-10888-exec-8|com.ameter.platform.passage.web.car.controller.DisplayEquipmentController|24|heartbeat|心跳设备 mac40AA56B037BD
2022-07-25 00:00:58.885|INFO|-|MQTT Call: emq-client_prod-1a6dfce5|com.ameter.platform.passage.person.manager.listener.MqttMessageCallback|120|connectComplete|MqttMessageCallback-->connectComplete->[MQTT] 连接成功,重新订阅主题...
2022-07-25 00:01:06.208|INFO|-|scheduled-pool-6|com.ameter.platform.passage.car.manager.task.HeartbeatDetectionTask|33|process|heartbeat detection start
2022-07-25 00:01:28.889|ERROR|-|MQTT Ping: emq-client_prod-1a6dfce5|org.eclipse.paho.client.mqttv3.internal.ClientState|210|logToJsr47|emq-client_prod-1a6dfce5: Timed out as no activity, keepAlive=15,000,000,000 lastOutboundActivity=25,015,741,850,164,867 lastInboundActivity=25,015,726,854,551,447 time=25,015,756,850,201,534 lastPing=25,015,741,850,167,366
2022-07-25 00:01:28.891|ERROR|-|MQTT Ping: emq-client_prod-1a6dfce5|com.ameter.platform.passage.person.manager.listener.MqttMessageCallback|51|connectionLost|MqttMessageCallback-->connectionLost->[MQTT] 断开连接...error:等待来自服务器的响应时超时
2022-07-25 00:01:28.904|ERROR|-|MQTT Call: emq-client_prod-1a6dfce5|com.ameter.platform.passage.iot.common.protocol.mqtt.MqttClient|133|subscribe|emq subscribe error errorMsg=等待来自服务器的响应时超时 , topicFilter=$queue/topic/face/manage/response/+ , qos=1
2022-07-25 00:01:28.904|ERROR|-|MQTT Call: emq-client_prod-1a6dfce5|com.ameter.platform.passage.iot.common.protocol.mqtt.MqttClient|133|subscribe|emq subscribe error errorMsg=客户机未连接 , topicFilter=$queue/topic/face/heart/request/+ , qos=0
2022-07-25 00:01:28.905|ERROR|-|MQTT Call: emq-client_prod-1a6dfce5|com.ameter.platform.passage.iot.common.protocol.mqtt.MqttClient|133|subscribe|emq subscribe error errorMsg=客户机未连接 , topicFilter=$queue/topic/face/capture/request/+ , qos=2

2022-07-25 00:01:53.907|INFO|-|DubboServerHandler-172.24.21.184:20882-thread-151|com.ameter.platform.passage.car.manager.component.push.QianyPushComponent|122|publishMqtt|publishMqtt, topic:/qiany/12ZA19ENN520754A/parking/config/request, payloadStr:{"utc_ts":1658678513,"cmd":"rs485","rs485ch1_data":[{"data":"qlUAAAAnABMBFAEAz+ZNR0czMDcgOS0xODAxbdKv"},{"data":"qlUAAAAnAAwCFAEAu7bTrbK0s7VMiK8="},{"data":"/QAdAQFbdjRdz+ZNR0czMDcgOS0xODAxu7bTrbK0s7U="}],"msg_id":"1658678513907EHJVvku","encode_type":"base64"}
2022-07-25 00:01:53.909|ERROR|-|DubboServerHandler-172.24.21.184:20882-thread-151|com.ameter.platform.passage.iot.common.protocol.mqtt.MqttClient|123|publish|emq publish error errorMsg=正在进行过多的发布 , topic=/qiany/12ZA19ENN520754A/parking/config/request , payload={"utc_ts":1658678513,"cmd":"rs485","rs485ch1_data":[{"data":"qlUAAAAnABMBFAEAz+ZNR0czMDcgOS0xODAxbdKv"},{"data":"qlUAAAAnAAwCFAEAu7bTrbK0s7VMiK8="},{"data":"/QAdAQFbdjRdz+ZNR0czMDcgOS0xODAxu7bTrbK0s7U="}],"msg_id":"1658678513907EHJVvku","encode_type":"base64"} , qos=1 , retain=true

看起来更像是你 MQTT 客户端使用不当造成的问题。

emqx 这行日志和不是下面这个客户端的,ID 对不上。你可以先试试日志追踪的功能,看看你客户端对应的,在 emqx 的 DEBUG 日志是什么

现场已经通过几次重启emqx和客户端恢复了,不知现在使用日志追踪功能还能查找到当时的问题吗?
当时的整体运行情况是这样的:我有两台emqx服务器做集群,两台应用服务器使用paho的mqtt客户端sdk通过emqx服务器订阅第三方设备发过来的数据,收到数据后发布消息应答设备收到数据的消息,设备如果没有收到应答的就一直重复发布开始的数据,于是emqx就出现消息积压队列满的情况。因为我只观察到两个现象(1.队列满,2.应用服务器一发应答消息就报客户机未连接断线重连),无法判断是因为队列满了无法应答给三方设备造成重发,还是因为别的原因导致三方设备对应答消息的订阅断开,而设备是第三方研发的,无法追踪到mqtt的实际运行情况。同样是这台设备,经常出现两个订阅里面只有一个订阅在,另一个订阅没有,这个是否说明可能设备的对接有问题,还是emqx订阅连接这一块也可能存在问题?当前emqx服务器的客户端数量才12个,应该不存在数量的问题。
另外为何应用服务器发布消息时收到客户机未连接的回复会断开连接重连emqx服务器?