在使用EMQX5.0时,进行会话断开重连的测试,断开期间如果发送QoS0的消息,如果是10条一下,可以正常接收,如果是10条以上,就取不回来。如果是QoS2的消息,目前测试40条,都是可以正常取回。
目前从技术文档中了解到的是mqtt.mqueue_store_qos0 = true和mqtt.max_mqueue_len,但是设置了都没有效果,这个需要修该哪个配置属性或者dashboard中哪个选项可以起到作用
先打开 debug 日志,检查一下消息流程,看有没有消息被拒绝或者丢弃。
从主题监控上看,消息全部流入全部流出
我看了下,ENQX的配置,mqueue_priorities = “disabled”
“mqueue_store_qos0” = true。其中保留qos0的属性多了个双引号,会不会导致这个属性没生效
大概不会。还是要看 debug 日志。
大佬,这是发布消息后,重新连接会话时的日志,麻烦帮看下什么原因,我看数据都读取了。
2023-12-14T08:00:17.812927+00:00 [debug] msg: emqx_cm_clean_down, mfa: emqx_cm:clean_down/1, line: 743, client_id: <<“test003”>>
2023-12-14T08:00:17.813176+00:00 [debug] msg: mqtt_packet_sent, mfa: emqx_connection:serialize_and_inc_stats_fun/1, line: 870, peername: 172.16.3.7:56357, clientid: test003, packet: PUBLISH(Q0, R0, D0, Topic=test100003, PacketId=undefined, Payload={“type”:“real”,“sn”:“TN002”,“time”:“2023-10-09 17:11:35”,“data”:{“C1_D1”:[{“id”:“Tag1584”,“desc”:“1#\x{9006}\x{53D8}\x{7535}\x{7F51}\x{8FC7}\x{9891}”,“quality”:“0”,“value”:“15.000”}]}}), tag: MQTT
2023-12-14T08:00:17.813474+00:00 [debug] msg: mqtt_packet_sent, mfa: emqx_connection:serialize_and_inc_stats_fun/1, line: 870, peername: 172.16.3.7:56357, clientid: test003, packet: PUBLISH(Q0, R0, D0, Topic=test100003, PacketId=undefined, Payload={“type”:“real”,“sn”:“TN002”,“time”:“2023-10-09 17:11:35”,“data”:{“C1_D1”:[{“id”:“Tag1584”,“desc”:“2#\x{9006}\x{53D8}\x{7535}\x{7F51}\x{8FC7}\x{9891}”,“quality”:“0”,“value”:“15.000”}]}}), tag: MQTT
2023-12-14T08:00:17.813706+00:00 [debug] msg: mqtt_packet_sent, mfa: emqx_connection:serialize_and_inc_stats_fun/1, line: 870, peername: 172.16.3.7:56357, clientid: test003, packet: PUBLISH(Q0, R0, D0, Topic=test100003, PacketId=undefined, Payload={“type”:“real”,“sn”:“TN002”,“time”:“2023-10-09 17:11:35”,“data”:{“C1_D1”:[{“id”:“Tag1584”,“desc”:“3#\x{9006}\x{53D8}\x{7535}\x{7F51}\x{8FC7}\x{9891}”,“quality”:“0”,“value”:“15.000”}]}}), tag: MQTT
2023-12-14T08:00:17.813926+00:00 [debug] msg: mqtt_packet_sent, mfa: emqx_connection:serialize_and_inc_stats_fun/1, line: 870, peername: 172.16.3.7:56357, clientid: test003, packet: PUBLISH(Q0, R0, D0, Topic=test100003, PacketId=undefined, Payload={“type”:“real”,“sn”:“TN002”,“time”:“2023-10-09 17:11:35”,“data”:{“C1_D1”:[{“id”:“Tag1584”,“desc”:“4#\x{9006}\x{53D8}\x{7535}\x{7F51}\x{8FC7}\x{9891}”,“quality”:“0”,“value”:“15.000”}]}}), tag: MQTT
2023-12-14T08:00:17.814140+00:00 [debug] msg: mqtt_packet_sent, mfa: emqx_connection:serialize_and_inc_stats_fun/1, line: 870, peername: 172.16.3.7:56357, clientid: test003, packet: PUBLISH(Q0, R0, D0, Topic=test100003, PacketId=undefined, Payload={“type”:“real”,“sn”:“TN002”,“time”:“2023-10-09 17:11:35”,“data”:{“C1_D1”:[{“id”:“Tag1584”,“desc”:“5#\x{9006}\x{53D8}\x{7535}\x{7F51}\x{8FC7}\x{9891}”,“quality”:“0”,“value”:“15.000”}]}}), tag: MQTT
2023-12-14T08:00:17.814369+00:00 [debug] msg: mqtt_packet_sent, mfa: emqx_connection:serialize_and_inc_stats_fun/1, line: 870, peername: 172.16.3.7:56357, clientid: test003, packet: PUBLISH(Q0, R0, D0, Topic=test100003, PacketId=undefined, Payload={“type”:“real”,“sn”:“TN002”,“time”:“2023-10-09 17:11:35”,“data”:{“C1_D1”:[{“id”:“Tag1584”,“desc”:“6#\x{9006}\x{53D8}\x{7535}\x{7F51}\x{8FC7}\x{9891}”,“quality”:“0”,“value”:“15.000”}]}}), tag: MQTT
2023-12-14T08:00:17.814588+00:00 [debug] msg: mqtt_packet_sent, mfa: emqx_connection:serialize_and_inc_stats_fun/1, line: 870, peername: 172.16.3.7:56357, clientid: test003, packet: PUBLISH(Q0, R0, D0, Topic=test100003, PacketId=undefined, Payload={“type”:“real”,“sn”:“TN002”,“time”:“2023-10-09 17:11:35”,“data”:{“C1_D1”:[{“id”:“Tag1584”,“desc”:“7#\x{9006}\x{53D8}\x{7535}\x{7F51}\x{8FC7}\x{9891}”,“quality”:“0”,“value”:“15.000”}]}}), tag: MQTT
2023-12-14T08:00:17.814794+00:00 [debug] msg: mqtt_packet_sent, mfa: emqx_connection:serialize_and_inc_stats_fun/1, line: 870, peername: 172.16.3.7:56357, clientid: test003, packet: PUBLISH(Q0, R0, D0, Topic=test100003, PacketId=undefined, Payload={“type”:“real”,“sn”:“TN002”,“time”:“2023-10-09 17:11:35”,“data”:{“C1_D1”:[{“id”:“Tag1584”,“desc”:“8#\x{9006}\x{53D8}\x{7535}\x{7F51}\x{8FC7}\x{9891}”,“quality”:“0”,“value”:“15.000”}]}}), tag: MQTT
2023-12-14T08:00:17.815006+00:00 [debug] msg: mqtt_packet_sent, mfa: emqx_connection:serialize_and_inc_stats_fun/1, line: 870, peername: 172.16.3.7:56357, clientid: test003, packet: PUBLISH(Q0, R0, D0, Topic=test100003, PacketId=undefined, Payload={“type”:“real”,“sn”:“TN002”,“time”:“2023-10-09 17:11:35”,“data”:{“C1_D1”:[{“id”:“Tag1584”,“desc”:“9#\x{9006}\x{53D8}\x{7535}\x{7F51}\x{8FC7}\x{9891}”,“quality”:“0”,“value”:“15.000”}]}}), tag: MQTT
2023-12-14T08:00:17.815243+00:00 [debug] msg: mqtt_packet_sent, mfa: emqx_connection:serialize_and_inc_stats_fun/1, line: 870, peername: 172.16.3.7:56357, clientid: test003, packet: PUBLISH(Q0, R0, D0, Topic=test100003, PacketId=undefined, Payload={“type”:“real”,“sn”:“TN002”,“time”:“2023-10-09 17:11:35”,“data”:{“C1_D1”:[{“id”:“Tag1584”,“desc”:“10#\x{9006}\x{53D8}\x{7535}\x{7F51}\x{8FC7}\x{9891}”,“quality”:“0”,“value”:“15.000”}]}}), tag: MQTT
2023-12-14T08:00:17.815483+00:00 [debug] msg: mqtt_packet_sent, mfa: emqx_connection:serialize_and_inc_stats_fun/1, line: 870, peername: 172.16.3.7:56357, clientid: test003, packet: PUBLISH(Q0, R0, D0, Topic=test100003, PacketId=undefined, Payload={“type”:“real”,“sn”:“TN002”,“time”:“2023-10-09 17:11:35”,“data”:{“C1_D1”:[{“id”:“Tag1584”,“desc”:“11#\x{9006}\x{53D8}\x{7535}\x{7F51}\x{8FC7}\x{9891}”,“quality”:“0”,“value”:“15.000”}]}}), tag: MQTT
2023-12-14T08:00:17.815714+00:00 [debug] msg: mqtt_packet_sent, mfa: emqx_connection:serialize_and_inc_stats_fun/1, line: 870, peername: 172.16.3.7:56357, clientid: test003, packet: PUBLISH(Q0, R0, D0, Topic=test100003, PacketId=undefined, Payload={“type”:“real”,“sn”:“TN002”,“time”:“2023-10-09 17:11:35”,“data”:{“C1_D1”:[{“id”:“Tag1584”,“desc”:“12#\x{9006}\x{53D8}\x{7535}\x{7F51}\x{8FC7}\x{9891}”,“quality”:“0”,“value”:“15.000”}]}}), tag: MQTT
2023-12-14T08:00:17.837901+00:00 [debug] msg: raw_bin_received, mfa: emqx_connection:when_bytes_in/3, line: 771, peername: 172.16.3.7:56357, clientid: test003, bin: 820F0001000A7465737431303030303302, size: 17, type: hex
2023-12-14T08:00:17.838087+00:00 [debug] msg: mqtt_packet_received, mfa: emqx_connection:handle_msg/2, line: 567, peername: 172.16.3.7:56357, clientid: test003, packet: SUBSCRIBE(Q1, R0, D0, PacketId=1 TopicFilters=[test100003(#{nl => 0,qos => 2,rap => 0,rh => 0})]), tag: MQTT
2023-12-14T08:00:17.838320+00:00 [info] msg: authorization_permission_allowed, mfa: emqx_authz:log_allowed/1, line: 380, peername: 172.16.3.7:56357, clientid: test003, topic: test100003, ipaddr: {172,16,3,7}, source: file, username: undefined
2023-12-14T08:00:17.838580+00:00 [debug] msg: subscribe, mfa: emqx_trace:subscribe/3, line: 78, peername: 172.16.3.7:56357, clientid: test003, topic: test100003, sub_id: <<“test003”>>, sub_opts: #{nl => 0,qos => 2,rap => 0,rh => 0,sub_props => #{}}, tag: SUBSCRIBE
2023-12-14T08:00:17.838823+00:00 [debug] msg: mqtt_packet_sent, mfa: emqx_connection:serialize_and_inc_stats_fun/1, line: 870, peername: 172.16.3.7:56357, clientid: test003, packet: SUBACK(Q0, R0, D0, PacketId=1, ReasonCodes=[2]), tag: MQTT
2023-12-14T08:00:17.839110+00:00 [debug] msg: insert_channel_info, mfa: emqx_cm:insert_channel_info/3, line: 166, peername: 172.16.3.7:56357, clientid: test003
2023-12-14T08:00:20.229226+00:00 [debug] msg: raw_bin_received, mfa: emqx_connection:when_bytes_in/3, line: 771, peername: 172.16.3.7:2700, clientid: aaa1702521984705, bin: C000, size: 2, type: hex
2023-12-14T08:00:20.229548+00:00 [debug] msg: mqtt_packet_received, mfa: emqx_connection:handle_msg/2, line: 567, peername: 172.16.3.7:2700, clientid: aaa1702521984705, packet: PINGREQ(Q0, R0, D0), tag: MQTT
2023-12-14T08:00:20.229796+00:00 [debug] msg: mqtt_packet_sent, mfa: emqx_connection:serialize_and_inc_stats_fun/1, line: 870, peername: 172.16.3.7:2700, clientid: aaa1702521984705, packet: PINGRESP(Q0, R0, D0), tag: MQTT
这个时间点有大量的缓存消息投递下去,但客户端同时也发上来一个 MQTT 订阅请求上来,它可能是在等 PUBACK。
虽然 emqx 已经把 PUBACK 投递下去了(到了 TCP 协议栈),但是它肯定是排在那些缓存消息的后面的。如果客户端没从网络中先把前面的缓存消息读出来,那么 TCP 窗口就会满,导致最后的 PUBACK 发不到客户端那边去。
这是一个我们曾经见到过的情况,问题在客户端 MQTT SDK。可以通过抓包来确认你是不是碰到了这个问题。另外一个快速验证方法是把订阅调用暂时移除,再试一次。
解决办法是不要让客户端死等在 PUBACK 上,不要用同步订阅方法,而是使用异步订阅。