客户端连上几秒钟又断开

tantantan · 2023 年12 月 12 日 02:02

环境

Dokcer

EMQX 版本：5.3.2
操作系统版本：centos 8

日志如下：

重现此问题的步骤

xxx
xxx
xxx

预期行为

实际行为

Shawn · 2023 年12 月 12 日 02:06

authorization 失败，可能是没有权限导致订阅失败，所以客户端断开了。

tantantan · 2023 年12 月 12 日 02:20

怎么添加权限呢我是默认的配置就添加了一个用户其它的没有更改

tantantan · 2023 年12 月 12 日 02:21

之前都是好好的，从昨天开始就客户端有这种情况了

tantantan · 2023 年12 月 12 日 02:24

我只要添加了这样的订阅就会完全连不上

tantantan · 2023 年12 月 12 日 02:43

我开启了debug日志日志显示了这样的信息

tantantan · 2023 年12 月 12 日 04:03

2023-12-12T11:57:24.193994+08:00 [debug] msg: mqtt_packet_received, mfa: emqx_channel:handle_in/2(331), peername: XXX.XXX.XXX.XXX:21379, clientid: mqttx_test, packet: CONNECT(Q0, R0, D0, ClientId=mqttx_test, ProtoName=MQTT, ProtoVsn=5, CleanStart=true, KeepAlive=60, Username=bdiot, Password=******), tag: MQTT
2023-12-12T11:57:24.194136+08:00 [debug] msg: authentication_result, mfa: emqx_authn_chains:authenticate/2(163), peername: XXX.XXX.XXX.XXX:21379, clientid: mqttx_test, reason: empty_chain, result: ignore, tag: AUTHN
2023-12-12T11:57:24.194622+08:00 [debug] msg: insert_channel_info, mfa: emqx_cm:insert_channel_info/3(159), peername: XXX.XXX.XXX.XXX:21379, clientid: mqttx_test
2023-12-12T11:57:24.194779+08:00 [debug] msg: mqtt_packet_sent, mfa: emqx_connection:serialize_and_inc_stats_fun/1(877), peername: XXX.XXX.XXX.XXX:21379, clientid: mqttx_test, packet: CONNACK(Q0, R0, D0, AckFlags=0, ReasonCode=0), tag: MQTT
2023-12-12T11:57:24.243082+08:00 [debug] msg: raw_bin_received, mfa: emqx_connection:when_bytes_in/3(778), peername: XXX.XXX.XXX.XXX:21379, clientid: mqttx_test, bin: 8210F8D300000A646174615F7075622F2300, size: 18, type: hex
2023-12-12T11:57:24.243278+08:00 [debug] msg: mqtt_packet_received, mfa: emqx_connection:handle_msg/2(575), peername: XXX.XXX.XXX.XXX:21379, clientid: mqttx_test, packet: SUBSCRIBE(Q1, R0, D0, PacketId=63699 TopicFilters=[data_pub/#(#{nl => 0,qos => 0,rap => 0,rh => 0})]), tag: MQTT
2023-12-12T11:57:24.243399+08:00 [debug] msg: authorization_module_nomatch, mfa: emqx_authz:do_authorize/4(527), peername: XXX.XXX.XXX.XXX:21379, clientid: mqttx_test, topic: data_pub/#, ipaddr: {219,135,26,210}, module: emqx_authz_client_info, pub_sub: #{action_type => subscribe,qos => 0}, tag: AUTHZ, username: <<"bdiot">>
2023-12-12T11:57:24.243560+08:00 [info] msg: authorization_permission_allowed, mfa: emqx_authz:log_allowed/1(507), peername: XXX.XXX.XXX.XXX:21379, clientid: mqttx_test, topic: data_pub/#, ipaddr: {219,135,26,210}, source: file, username: <<"bdiot">>
2023-12-12T11:57:24.243680+08:00 [debug] msg: subscribe, mfa: emqx_trace:subscribe/3(79), peername: XXX.XXX.XXX.XXX:21379, clientid: mqttx_test, topic: data_pub/#, sub_id: <<"mqttx_test">>, sub_opts: #{nl => 0,qos => 0,rap => 0,rh => 0,sub_props => #{}}, tag: SUBSCRIBE
2023-12-12T11:57:24.244041+08:00 [debug] msg: mqtt_packet_sent, mfa: emqx_connection:serialize_and_inc_stats_fun/1(877), peername: XXX.XXX.XXX.XXX:21379, clientid: mqttx_test, packet: SUBACK(Q0, R0, D0, PacketId=63699, ReasonCodes=[0]), tag: MQTT
2023-12-12T11:57:24.244664+08:00 [debug] msg: insert_channel_info, mfa: emqx_cm:insert_channel_info/3(159), peername: XXX.XXX.XXX.XXX:21379, clientid: mqttx_test
2023-12-12T11:57:24.244916+08:00 [debug] msg: mqtt_packet_sent, mfa: emqx_connection:serialize_and_inc_stats_fun/1(877), peername: XXX.XXX.XXX.XXX:21379, clientid: mqttx_test, packet: PUBLISH(Q0, R1, D0, Topic=data_pub/00501423040600002499, PacketId=undefined, Payload={"id":"00501423040600002499","sid":1,"c":"r","d":["kyj_001","kyj_002","kyj_005","kyj_006","kyj_007","kyj_013","kyj_014","kyj_015","kyj_019","kyj_020","kyj_021","kyj_153","kyj_154","kyj_155","kyj_156","kyj_157"]}), tag: MQTT
2023-12-12T11:57:24.245070+08:00 [debug] msg: mqtt_packet_sent, mfa: emqx_connection:serialize_and_inc_stats_fun/1(877), peername: XXX.XXX.XXX.XXX:21379, clientid: mqttx_test, packet: PUBLISH(Q0, R1, D0, Topic=data_pub/00501423040600002607, PacketId=undefined, Payload={"id":"00501423040600002607","sid":1,"c":"r","d":["kyj_001","kyj_002","kyj_005","kyj_006","kyj_007","kyj_013","kyj_014","kyj_015","kyj_019","kyj_020","kyj_021"]}), tag: MQTT
2023-12-12T11:57:24.245203+08:00 [debug] msg: mqtt_packet_sent, mfa: emqx_connection:serialize_and_inc_stats_fun/1(877), peername: XXX.XXX.XXX.XXX:21379, clientid: mqttx_test, packet: PUBLISH(Q0, R1, D0, Topic=data_pub/00501423052200001029, PacketId=undefined, Payload={"id":"00501423052200001029","sid":1,"c":"r","d":["kyj_001","kyj_002","kyj_005","kyj_006","kyj_007","kyj_013","kyj_014","kyj_015","kyj_019","kyj_020","kyj_021"]}), tag: MQTT
2023-12-12T11:57:24.245311+08:00 [debug] msg: mqtt_packet_sent, mfa: emqx_connection:serialize_and_inc_stats_fun/1(877), peername: XXX.XXX.XXX.XXX:21379, clientid: mqttx_test, packet: PUBLISH(Q0, R1, D0, Topic=data_pub/00501423053000006771, PacketId=undefined, Payload={"id":"00501423053000006771","sid":1,"c":"r","d":["kyj_001","kyj_002","kyj_005","kyj_006","kyj_007","kyj_013","kyj_014","kyj_015","kyj_019","kyj_020","kyj_021","kyj_102","kyj_154"]}), tag: MQTT
2023-12-12T11:57:24.245403+08:00 [debug] msg: mqtt_packet_sent, mfa: emqx_connection:serialize_and_inc_stats_fun/1(877), peername: XXX.XXX.XXX.XXX:21379, clientid: mqttx_test, packet: PUBLISH(Q0, R1, D0, Topic=data_pub/00501423053000007674, PacketId=undefined, Payload={"id":"00501423053000007674","sid":1,"c":"r","d":["kyj_001","kyj_002","kyj_005","kyj_006","kyj_007","kyj_013","kyj_014","kyj_015","kyj_019","kyj_020","kyj_021","kyj_102","kyj_154"]}), tag: MQTT
2023-12-12T11:57:24.245533+08:00 [debug] msg: mqtt_packet_sent, mfa: emqx_connection:serialize_and_inc_stats_fun/1(877), peername: XXX.XXX.XXX.XXX:21379, clientid: mqttx_test, packet: PUBLISH(Q0, R1, D0, Topic=data_pub/00501423053000008147, PacketId=undefined, Payload={"id":"00501423053000008147","sid":1,"c":"r","d":["kyj_001","kyj_002","kyj_005","kyj_006","kyj_007","kyj_013","kyj_014","kyj_015","kyj_019","kyj_020","kyj_021","kyj_102","kyj_154"]}), tag: MQTT
2023-12-12T11:57:24.245633+08:00 [debug] msg: mqtt_packet_sent, mfa: emqx_connection:serialize_and_inc_stats_fun/1(877), peername: XXX.XXX.XXX.XXX:21379, clientid: mqttx_test, packet: PUBLISH(Q0, R1, D0, Topic=data_pub/00501423053000008274, PacketId=undefined, Payload={"id":"00501423053000008274","sid":1,"c":"r","d":["kyj_001","kyj_002","kyj_005","kyj_006","kyj_007","kyj_013","kyj_014","kyj_015","kyj_019","kyj_020","kyj_021","kyj_102","kyj_154"]}), tag: MQTT
2023-12-12T11:57:24.245720+08:00 [debug] msg: mqtt_packet_sent, mfa: emqx_connection:serialize_and_inc_stats_fun/1(877), peername: XXX.XXX.XXX.XXX:21379, clientid: mqttx_test, packet: PUBLISH(Q0, R1, D0, Topic=data_pub/00501423053000008453, PacketId=undefined, Payload={"id":"00501423053000008453","sid":1,"c":"r","d":["kyj_001","kyj_002","kyj_005","kyj_006","kyj_007","kyj_013","kyj_014","kyj_015","kyj_019","kyj_020","kyj_021","kyj_102","kyj_154"]}), tag: MQTT
2023-12-12T11:57:24.245813+08:00 [debug] msg: mqtt_packet_sent, mfa: emqx_connection:serialize_and_inc_stats_fun/1(877), peername: XXX.XXX.XXX.XXX:21379, clientid: mqttx_test, packet: PUBLISH(Q0, R1, D0, Topic=data_pub/00501423053000009072, PacketId=undefined, Payload={"id":"00501423053000009072","sid":1,"c":"r","d":["kyj_001","kyj_002","kyj_005","kyj_006","kyj_007","kyj_013","kyj_014","kyj_015","kyj_019","kyj_020","kyj_021","kyj_102","kyj_154"]}), tag: MQTT
2023-12-12T11:57:24.245917+08:00 [debug] msg: mqtt_packet_sent, mfa: emqx_connection:serialize_and_inc_stats_fun/1(877), peername: XXX.XXX.XXX.XXX:21379, clientid: mqttx_test, packet: PUBLISH(Q0, R1, D0, Topic=data_pub/00501423053000009433, PacketId=undefined, Payload={"id":"00501423053000009433","sid":1,"c":"r","d":["kyj_001","kyj_002","kyj_005","kyj_006","kyj_007","kyj_013","kyj_014","kyj_015","kyj_019","kyj_020","kyj_021","kyj_102","kyj_154"]}), tag: MQTT
2023-12-12T11:57:24.246035+08:00 [debug] msg: mqtt_packet_sent, mfa: emqx_connection:serialize_and_inc_stats_fun/1(877), peername: XXX.XXX.XXX.XXX:21379, clientid: mqttx_test, packet: PUBLISH(Q0, R1, D0, Topic=data_pub/00501423053000010848, PacketId=undefined, Payload={"id":"00501423053000010848","sid":1,"c":"r","d":["kyj_001","kyj_002","kyj_005","kyj_006","kyj_007","kyj_013","kyj_014","kyj_015","kyj_019","kyj_020","kyj_021","kyj_102","kyj_154"]}), tag: MQTT

2023-12-12T11:57:24.276545+08:00 [debug] msg: emqx_connection_terminated, mfa: emqx_connection:terminate/2(668), peername: XXX.XXX.XXX.XXX:21379, clientid: mqttx_test, reason: {shutdown,tcp_closed}, tag: SOCKET
2023-12-12T11:57:24.276710+08:00 [info] msg: terminate, mfa: emqx_connection:terminate/2(673), peername: XXX.XXX.XXX.XXX:21379, clientid: mqttx_test, reason: {shutdown,tcp_closed}
2023-12-12T11:57:24.276915+08:00 [debug] msg: emqx_cm_clean_down, mfa: emqx_cm:clean_down/1(689), client_id: <<"mqttx_test">>

这是完整的日志可以帮忙看看嘛

Shawn · 2023 年12 月 12 日 05:51

从你这一次的日志里看，订阅主题是成功的，SUBACK 返回的是成功码。
客户端订阅完成后 emqx 下发了好几个 retain 消息过去，然后客户端主动断开了：

如果你不希望使用 retain 消息，或者不清楚 retain 消息是做什么的，就需要禁用 retain 功能。Dashboad 上依次点击集群配置 - MQTT 配置 - 保留消息，然后将启用保留消息选项关闭。

http://你的 emqx 的IP地址:18083/#/mqtt/retainer

tantantan · 2023 年12 月 12 日 06:06

刚才关闭了保留消息并更换了新的clientid问题依然存在

tantantan · 2023 年12 月 12 日 08:49

[os_mon] memory supervisor port (memsup): Erlang has closed
[os_mon] cpu supervisor port (cpu_sup): Erlang has closed
[os_mon] memory supervisor port (memsup): Erlang has closed
[os_mon] cpu supervisor port (cpu_sup): Erlang has closed
2023-12-12T16:46:44.915170+08:00 [debug] XXX.XXX.XXX.XXX:43266 [MQTT] RECV CONNECT(Q0, R0, D0, ClientId=mqttx_test520520, ProtoName=MQIsdp, ProtoVsn=3, CleanStart=true, KeepAlive=60, Username=admin, Password=******)
2023-12-12T16:46:44.915609+08:00 [debug] mqttx_test520520@XXX.XXX.XXX.XXX:43266 client_id: <<"mqttx_test520520">>, file: emqx_cm.erl, line: 116, mfa: {emqx_cm,insert_channel_info,3}, msg: insert_channel_info, pid: <0.6271.0>
2023-12-12T16:46:44.915844+08:00 [debug] mqttx_test520520@XXX.XXX.XXX.XXX:43266 [MQTT] SEND CONNACK(Q0, R0, D0, AckFlags=0, ReasonCode=0)
2023-12-12T16:46:45.030798+08:00 [debug] mqttx_test520520@XXX.XXX.XXX.XXX:43266 [MQTT] RECV <<130,15,184,33,0,10,100,97,116,97,95,112,117,98,47,35,0>>
2023-12-12T16:46:45.030958+08:00 [debug] mqttx_test520520@XXX.XXX.XXX.XXX:43266 [MQTT] RECV SUBSCRIBE(Q1, R0, D0, PacketId=47137, TopicFilters=[{<<"data_pub/#">>,#{nl => 0,qos => 0,rap => 0,rh => 0}}])
2023-12-12T16:46:45.031445+08:00 [debug] mqttx_test520520@XXX.XXX.XXX.XXX:43266 [MQTT] SEND SUBACK(Q0, R0, D0, PacketId=47137, ReasonCodes=[0])
2023-12-12T16:46:45.032125+08:00 [debug] mqttx_test520520@XXX.XXX.XXX.XXX:43266 [MQTT] SEND PUBLISH(Q0, R1, D0, Topic=data_pub/868488076135803, PacketId=undefined, Payload=<<"{\"id\":\"868488076135803\",\"sid\":1,\"c\":\"r\",\"d\":[\"kyj_001\",\"kyj_002\",\"kyj_013\",\"kyj_019\",\"kyj_020\",\"kyj_101\",\"kyj_153\",\"kyj_154\"]}">>)
2023-12-12T16:46:45.038138+08:00 [debug] mqttx_test520520@XXX.XXX.XXX.XXX:43266 [MQTT] SEND PUBLISH(Q0, R1, D0, Topic=data_pub/869329060096602, PacketId=undefined, Payload=<<"{\"id\":\"869329060096602\",\"sid\":1,\"c\":\"r\",\"d\":[\"kyj_001\",\"kyj_002\",\"kyj_013\",\"kyj_019\",\"kyj_020\",\"kyj_101\",\"kyj_153\",\"kyj_154\"]}">>)
2023-12-12T16:46:45.038205+08:00 [debug] mqttx_test520520@XXX.XXX.XXX.XXX:43266 [MQTT] SEND PUBLISH(Q0, R1, D0, Topic=data_pub/00501423053000007674, PacketId=undefined, Payload=<<"{\"id\":\"00501423053000007674\",\"sid\":1,\"c\":\"r\",\"d\":[\"kyj_001\",\"kyj_002\",\"kyj_005\",\"kyj_006\",\"kyj_007\",\"kyj_013\",\"kyj_014\",\"kyj_015\",\"kyj_019\",\"kyj_020\",\"kyj_021\",\"kyj_102\",\"kyj_154\"]}">>)
2023-12-12T16:46:45.038278+08:00 [debug] mqttx_test520520@XXX.XXX.XXX.XXX:43266 [MQTT] SEND PUBLISH(Q0, R1, D0, Topic=data_pub/869329060096693, PacketId=undefined, Payload=<<"{\"id\":\"869329060096693\",\"sid\":1,\"c\":\"r\",\"d\":[\"kyj_001\",\"kyj_002\",\"kyj_013\",\"kyj_019\",\"kyj_020\",\"kyj_101\",\"kyj_153\",\"kyj_154\"]}">>)
2023-12-12T16:46:45.047863+08:00 [debug] mqttx_test520520@XXX.XXX.XXX.XXX:43266 file: emqx_connection.erl, line: 520, mfa: {emqx_connection,terminate,2}, msg: terminate, pid: <0.6271.0>, reason: {shutdown,tcp_closed}

我把版本更换到4.3.11 得到了这样的日志，请帮忙回答一下紧急

Shawn · 2023 年12 月 13 日 03:30

换老版本的话用 4.4.19, 你需要先清理一下 retain 消息，然后把 retain 插件关掉：

./bin/emqx_ctl retainer clean
./bin/emqx_ctl plugins unload emqx_retainer

另外客户端收到 retain 消息（或者任何其他消息）就断开的问题需要你自己调查一下。

tantantan · 2023 年12 月 13 日 03:42

docker 安装的怎么清理呢
另外这一条日志有没有参考呢

23-12-13T11:39:00.802683+08:00 [debug] mqttx_test857857@xxxxxxx54326 file: emqx_connection.erl, line: 788, mfa: {emqx_connection,check_oom,1}, msg: check_oom, pid: <0.3935.1>, policy: #{max_heap_size => 8388608,message_queue_len => 10000}

块引用

tantantan · 2023 年12 月 13 日 03:43

而且ws连接是正常的 mqtt连接就不行

Shawn · 2023 年12 月 13 日 03:46

Docker 就进入容器内部，执行这个命令。

这个是在检查当前连接使用的内存大小，如果过大会被杀掉。但你这个只是一个 debug 日志，看起来没有杀。

tantantan:

另外这一条日志有没有参考呢

23-12-13T11:39:00.802683+08:00 [debug] mqttx_test857857@xxxxxxx54326 file: emqx_connection.erl, line: 788, mfa: {emqx_connection,check_oom,1}, msg: check_oom, pid: <0.3935.1>, policy: #{max_heap_size => 8388608,message_queue_len => 10000}

tcp_closed 是客户端主动断开的。收到消息就断，提示客户端程序可能崩溃了。

tantantan · 2023 年12 月 13 日 03:48

似乎没有作用

kevin0501 · 2023 年12 月 13 日 06:10

我的运行一段时间就和MQTT代理离线了，最后发现MqttClient_WaitType收到MQTT代理返回pingresp的时候死锁了。加日志发现在上一个操作中只有rc = wm_SemLock(&client->lockRecv); 后面没有wm_SemUnlock(&client->lockRecv);