mqtt断连问题

2024-01-11T07:35:31.634576+00:00 [debug] msg: unsubscribe, mfa: emqx_trace:unsubscribe/2, line: 84, peername: 36.21.211.62:64450, clientid: 6c9ca02a2b0641499a42efec71b4dd4b, topic: ezviz/waitingroom-msg/e967820a851a40069e393599312f9983, sub_opts: #{nl => 0,qos => 2,rap => 0,rh => 0,sub_props => #{},subid => <<“6c9ca02a2b0641499a42efec71b4dd4b”>>}, tag: UNSUBSCRIBE
2024-01-11T07:35:31.634782+00:00 [debug] msg: mqtt_packet_received, mfa: emqx_connection:handle_msg/2, line: 569, peername: 36.21.211.62:64450, clientid: 6c9ca02a2b0641499a42efec71b4dd4b, packet: UNSUBSCRIBE(Q1, R0, D0, PacketId=27 TopicFilters=[vcs/room-msg/e967820a851a40069e393599312f9983]), tag: MQTT
2024-01-11T07:35:31.634908+00:00 [debug] msg: mqtt_packet_received, mfa: emqx_connection:handle_msg/2, line: 569, peername: 36.21.211.62:64450, clientid: 6c9ca02a2b0641499a42efec71b4dd4b, packet: UNSUBSCRIBE(Q1, R0, D0, PacketId=28 TopicFilters=[vcs/6c9ca02a2b0641499a42efec71b4dd4b]), tag: MQTT
2024-01-11T07:35:31.635019+00:00 [debug] msg: unsubscribe, mfa: emqx_trace:unsubscribe/2, line: 84, peername: 36.21.211.62:64450, clientid: 6c9ca02a2b0641499a42efec71b4dd4b, topic: vcs/6c9ca02a2b0641499a42efec71b4dd4b, sub_opts: #{nl => 0,qos => 2,rap => 0,rh => 0,sub_props => #{},subid => <<“6c9ca02a2b0641499a42efec71b4dd4b”>>}, tag: UNSUBSCRIBE
2024-01-11T07:35:31.635158+00:00 [debug] msg: mqtt_packet_received, mfa: emqx_connection:handle_msg/2, line: 569, peername: 36.21.211.62:64450, clientid: 6c9ca02a2b0641499a42efec71b4dd4b, packet: UNSUBSCRIBE(Q1, R0, D0, PacketId=29 TopicFilters=[ezviz/waitingroomclient/6c9ca02a2b0641499a42efec71b4dd4b]), tag: MQTT
2024-01-11T07:35:31.635257+00:00 [debug] msg: mqtt_packet_received, mfa: emqx_connection:handle_msg/2, line: 569, peername: 36.21.211.62:64450, clientid: 6c9ca02a2b0641499a42efec71b4dd4b, packet: UNSUBSCRIBE(Q1, R0, D0, PacketId=30 TopicFilters=[vcs/roomclient/6c9ca02a2b0641499a42efec71b4dd4b]), tag: MQTT
2024-01-11T07:35:31.635362+00:00 [debug] msg: mqtt_packet_received, mfa: emqx_connection:handle_msg/2, line: 569, peername: 36.21.211.62:64450, clientid: 6c9ca02a2b0641499a42efec71b4dd4b, packet: UNSUBSCRIBE(Q1, R0, D0, PacketId=31 TopicFilters=[ezviz/waitingroom-msg/e967820a851a40069e393599312f9983]), tag: MQTT
2024-01-11T07:35:31.635451+00:00 [debug] msg: mqtt_packet_received, mfa: emqx_connection:handle_msg/2, line: 569, peername: 36.21.211.62:64450, clientid: 6c9ca02a2b0641499a42efec71b4dd4b, packet: DISCONNECT(Q0, R0, D0, ReasonCode=0), tag: MQTT
2024-01-11T07:35:31.635529+00:00 [debug] msg: mqtt_packet_sent, mfa: emqx_connection:serialize_and_inc_stats_fun/1, line: 872, peername: 36.21.211.62:64450, clientid: 6c9ca02a2b0641499a42efec71b4dd4b, packet: UNSUBACK(Q0, R0, D0, PacketId=21), tag: MQTT
2024-01-11T07:35:31.635660+00:00 [debug] msg: insert_channel_info, mfa: emqx_cm:insert_channel_info/3, line: 155, peername: 36.21.211.62:64450, clientid: 6c9ca02a2b0641499a42efec71b4dd4b
2024-01-11T07:35:31.635742+00:00 [debug] msg: mqtt_packet_sent, mfa: emqx_connection:serialize_and_inc_stats_fun/1, line: 872, peername: 36.21.211.62:64450, clientid: 6c9ca02a2b0641499a42efec71b4dd4b, packet: UNSUBACK(Q0, R0, D0, PacketId=22), tag: MQTT
2024-01-11T07:35:31.635849+00:00 [debug] msg: insert_channel_info, mfa: emqx_cm:insert_channel_info/3, line: 155, peername: 36.21.211.62:64450, clientid: 6c9ca02a2b0641499a42efec71b4dd4b
2024-01-11T07:35:31.635923+00:00 [debug] msg: mqtt_packet_sent, mfa: emqx_connection:serialize_and_inc_stats_fun/1, line: 872, peername: 36.21.211.62:64450, clientid: 6c9ca02a2b0641499a42efec71b4dd4b, packet: UNSUBACK(Q0, R0, D0, PacketId=23), tag: MQTT
2024-01-11T07:35:31.636019+00:00 [debug] msg: insert_channel_info, mfa: emqx_cm:insert_channel_info/3, line: 155, peername: 36.21.211.62:64450, clientid: 6c9ca02a2b0641499a42efec71b4dd4b
2024-01-11T07:35:31.636099+00:00 [debug] msg: mqtt_packet_sent, mfa: emqx_connection:serialize_and_inc_stats_fun/1, line: 872, peername: 36.21.211.62:64450, clientid: 6c9ca02a2b0641499a42efec71b4dd4b, packet: UNSUBACK(Q0, R0, D0, PacketId=24), tag: MQTT
2024-01-11T07:35:31.636191+00:00 [debug] msg: insert_channel_info, mfa: emqx_cm:insert_channel_info/3, line: 155, peername: 36.21.211.62:64450, clientid: 6c9ca02a2b0641499a42efec71b4dd4b
2024-01-11T07:35:31.636270+00:00 [debug] msg: mqtt_packet_sent, mfa: emqx_connection:serialize_and_inc_stats_fun/1, line: 872, peername: 36.21.211.62:64450, clientid: 6c9ca02a2b0641499a42efec71b4dd4b, packet: UNSUBACK(Q0, R0, D0, PacketId=25), tag: MQTT
2024-01-11T07:35:31.636390+00:00 [debug] msg: insert_channel_info, mfa: emqx_cm:insert_channel_info/3, line: 155, peername: 36.21.211.62:64450, clientid: 6c9ca02a2b0641499a42efec71b4dd4b
2024-01-11T07:35:31.636475+00:00 [debug] msg: mqtt_packet_sent, mfa: emqx_connection:serialize_and_inc_stats_fun/1, line: 872, peername: 36.21.211.62:64450, clientid: 6c9ca02a2b0641499a42efec71b4dd4b, packet: UNSUBACK(Q0, R0, D0, PacketId=26), tag: MQTT
2024-01-11T07:35:31.636594+00:00 [debug] msg: insert_channel_info, mfa: emqx_cm:insert_channel_info/3, line: 155, peername: 36.21.211.62:64450, clientid: 6c9ca02a2b0641499a42efec71b4dd4b
2024-01-11T07:35:31.636665+00:00 [debug] msg: mqtt_packet_sent, mfa: emqx_connection:serialize_and_inc_stats_fun/1, line: 872, peername: 36.21.211.62:64450, clientid: 6c9ca02a2b0641499a42efec71b4dd4b, packet: UNSUBACK(Q0, R0, D0, PacketId=27), tag: MQTT
2024-01-11T07:35:31.636759+00:00 [debug] msg: insert_channel_info, mfa: emqx_cm:insert_channel_info/3, line: 155, peername: 36.21.211.62:64450, clientid: 6c9ca02a2b0641499a42efec71b4dd4b
2024-01-11T07:35:31.636826+00:00 [debug] msg: mqtt_packet_sent, mfa: emqx_connection:serialize_and_inc_stats_fun/1, line: 872, peername: 36.21.211.62:64450, clientid: 6c9ca02a2b0641499a42efec71b4dd4b, packet: UNSUBACK(Q0, R0, D0, PacketId=28), tag: MQTT
2024-01-11T07:35:31.636930+00:00 [debug] msg: insert_channel_info, mfa: emqx_cm:insert_channel_info/3, line: 155, peername: 36.21.211.62:64450, clientid: 6c9ca02a2b0641499a42efec71b4dd4b
2024-01-11T07:35:31.636997+00:00 [debug] msg: mqtt_packet_sent, mfa: emqx_connection:serialize_and_inc_stats_fun/1, line: 872, peername: 36.21.211.62:64450, clientid: 6c9ca02a2b0641499a42efec71b4dd4b, packet: UNSUBACK(Q0, R0, D0, PacketId=29), tag: MQTT
2024-01-11T07:35:31.637088+00:00 [debug] msg: insert_channel_info, mfa: emqx_cm:insert_channel_info/3, line: 155, peername: 36.21.211.62:64450, clientid: 6c9ca02a2b0641499a42efec71b4dd4b
2024-01-11T07:35:31.637167+00:00 [debug] msg: mqtt_packet_sent, mfa: emqx_connection:serialize_and_inc_stats_fun/1, line: 872, peername: 36.21.211.62:64450, clientid: 6c9ca02a2b0641499a42efec71b4dd4b, packet: UNSUBACK(Q0, R0, D0, PacketId=30), tag: MQTT
2024-01-11T07:35:31.637265+00:00 [debug] msg: insert_channel_info, mfa: emqx_cm:insert_channel_info/3, line: 155, peername: 36.21.211.62:64450, clientid: 6c9ca02a2b0641499a42efec71b4dd4b
2024-01-11T07:35:31.637334+00:00 [debug] msg: mqtt_packet_sent, mfa: emqx_connection:serialize_and_inc_stats_fun/1, line: 872, peername: 36.21.211.62:64450, clientid: 6c9ca02a2b0641499a42efec71b4dd4b, packet: UNSUBACK(Q0, R0, D0, PacketId=31), tag: MQTT
2024-01-11T07:35:31.637424+00:00 [debug] msg: insert_channel_info, mfa: emqx_cm:insert_channel_info/3, line: 155, peername: 36.21.211.62:64450, clientid: 6c9ca02a2b0641499a42efec71b4dd4b
2024-01-11T07:35:31.637479+00:00 [debug] msg: socket_force_closed, mfa: emqx_connection:handle_msg/2, line: 615, peername: 36.21.211.62:64450, clientid: 6c9ca02a2b0641499a42efec71b4dd4b, reason: normal, tag: SOCKET
2024-01-11T07:35:31.637669+00:00 [error] msg: unexpected_sock_close, mfa: emqx_channel:handle_info/2, line: 1266, peername: 36.21.211.62:64450, clientid: 6c9ca02a2b0641499a42efec71b4dd4b, reason: tcp_closed
2024-01-11T07:35:31.637764+00:00 [error] msg: unexpected_sock_close, mfa: emqx_channel:handle_info/2, line: 1266, peername: 36.21.211.62:64450, clientid: 6c9ca02a2b0641499a42efec71b4dd4b, reason: einval
2024-01-11T07:35:31.637827+00:00 [error] msg: unexpected_sock_close, mfa: emqx_channel:handle_info/2, line: 1266, peername: 36.21.211.62:64450, clientid: 6c9ca02a2b0641499a42efec71b4dd4b, reason: einval
2024-01-11T07:35:31.637929+00:00 [error] msg: unexpected_sock_close, mfa: emqx_channel:handle_info/2, line: 1266, peername: 36.21.211.62:64450, clientid: 6c9ca02a2b0641499a42efec71b4dd4b, reason: einval
2024-01-11T07:35:31.638014+00:00 [error] msg: unexpected_sock_close, mfa: emqx_channel:handle_info/2, line: 1266, peername: 36.21.211.62:64450, clientid: 6c9ca02a2b0641499a42efec71b4dd4b, reason: einval
2024-01-11T07:35:31.638092+00:00 [error] msg: unexpected_sock_close, mfa: emqx_channel:handle_info/2, line: 1266, peername: 36.21.211.62:64450, clientid: 6c9ca02a2b0641499a42efec71b4dd4b, reason: einval
2024-01-11T07:35:31.638169+00:00 [error] msg: unexpected_sock_close, mfa: emqx_channel:handle_info/2, line: 1266, peername: 36.21.211.62:64450, clientid: 6c9ca02a2b0641499a42efec71b4dd4b, reason: einval
2024-01-11T07:35:31.638257+00:00 [error] msg: unexpected_sock_close, mfa: emqx_channel:handle_info/2, line: 1266, peername: 36.21.211.62:64450, clientid: 6c9ca02a2b0641499a42efec71b4dd4b, reason: einval
2024-01-11T07:35:31.638330+00:00 [error] msg: unexpected_sock_close, mfa: emqx_channel:handle_info/2, line: 1266, peername: 36.21.211.62:64450, clientid: 6c9ca02a2b0641499a42efec71b4dd4b, reason: einval
2024-01-11T07:35:31.638405+00:00 [error] msg: unexpected_sock_close, mfa: emqx_channel:handle_info/2, line: 1266, peername: 36.21.211.62:64450, clientid: 6c9ca02a2b0641499a42efec71b4dd4b, reason: einval
2024-01-11T07:35:31.638473+00:00 [error] msg: unexpected_sock_close, mfa: emqx_channel:handle_info/2, line: 1266, peername: 36.21.211.62:64450, clientid: 6c9ca02a2b0641499a42efec71b4dd4b, reason: einval
2024-01-11T07:35:31.638554+00:00 [error] msg: unexpected_sock_close, mfa: emqx_channel:handle_info/2, line: 1266, peername: 36.21.211.62:64450, clientid: 6c9ca02a2b0641499a42efec71b4dd4b, reason: einval

请问这种日志是因为tcp四次挥手没有完成吗,同一个clientID在断开后重新连接,发现连接不上服务端了

这个是远端主动断开了连接。
einval 是地址不可用了。早就完成了tcp 握手了。一般是这台机器的端口不足了,或者有什么其它异常。

请问除了端口不足还有什么情况吗,我们情况是同一个clientID重连之后会报这个错误,但是有时候很快就能连接上,有时候要等个10秒左右,比如下面两段日志


这次隔了9s才重新连接上

这次马上就能连接上

这个环境我们的连接数应该不算多

这个重连不上的问题概率比较小,偶尔才会出现一次,如果是远端主动断开连接的话,跟网络是不是也有关系

仔细看了这个日志。对于同一个 ip 端口用 clientid 相同,可以判断他是同一条 tcp 连接。

  1. 它先收到了 tcp_closed ,下一步应该是直接关掉这个客户端线程。
  2. 但是这个线程收到了一些来的消息,没发出去,这里他想对一个已经 tcp_closed的socket发信息,就发生了 * einval - Invalid argument *,发送不出去。

根据这推断,这个 einval 不是原因,只是一个连着的现象。真正的原因是第一个 tcp_closed。可以在出问题的那个客户端日志里面捞捞。看有没有什么异常触发让他关掉socket的动作。

麻烦问一下你用的 emqx 版本是多少,查了下在最新的4 和 5 版本上都已经对这个错误做了优化了,不会再发生这样的误导。(但原因应该还是你的重连程序主动断开的 tcp_closed)

我们用的版本是5.0.20

我想请问一下如果客户端网络不行的话会出现这种问题吗,我们好几个不同设备的客户端都会出现这种问题,或者跟服务端有没有关系

你好请问一下,我的设备发送了重连的时候发送了Unsubscribe报文和Disconnect报文,但是服务端这边好像并没有断开,而是5分钟后(我们设置的会话最长存在时间)才过期清除,请问这是为什么,这种情况发生后,设备再去重连就会报异常,并且也没有连接报文发送