客户端断开连接，服务端收到如下warn session_stepdown_request_timeout

1010875980 · 2022 年10 月 9 日 05:11

环境信息

EMQX 版本：4.4.9
操作系统及版本：ubuntu
其他

问题描述

客户端断开连接，服务端收到如下warn。想问下，这种是什么原因导致的告警，会产生什么后果？

配置文件及日志

2022-10-09T12:02:18.181730+08:00 [warning] archdata-3@192.168.22.201:56018 action: {takeover,‘begin’}, file: emqx_cm.erl, line: 352, mfa: {emqx_cm,request_stepdown,3}, msg: session_stepdown_request_timeout, pid: <0.3268.0>, stale_channel: [{status,waiting},{message_queue_len,110},{current_stacktrace,[{emqx_shared_sub,dispatch_with_ack,5,[{file,“emqx_shared_sub.erl”},{line,191}]},{emqx_shared_sub,dispatch,5,[{file,“emqx_shared_sub.erl”},{line,142}]},{emqx_broker,do_route,2,[{file,“emqx_broker.erl”},{line,249}]},{emqx_broker,’-route/2-fun-0-’,3,[{file,“emqx_broker.erl”},{line,237}]},{lists,foldl,3,[{file,“lists.erl”},{line,1267}]},{emqx_session,publish,3,[{file,“emqx_session.erl”},{line,324}]},{emqx_channel,do_publish,3,[{file,“emqx_channel.erl”},{line,621}]},{emqx_connection,with_channel,3,[{file,“emqx_connection.erl”},{line,694}]},{emqx_connection,process_msg,2,[{file,“emqx_connection.erl”},{line,394}]},{emqx_connection,process_msg,2,[{file,“emqx_connection.erl”},{line,400}]},{emqx_connection,handle_recv,3,[{file,“emqx_connection.erl”},{line,358}]},{proc_lib,wake_up,3,[{file,“proc_lib.erl”},{line,236}]}]}]
2022-10-09T12:02:18.197113+08:00 [warning] archdata-3@192.168.22.201:56018 [Channel] The PUBREL PacketId 31824 is not found.
2022-10-09T12:02:18.199485+08:00 [warning] archdata-3@192.168.22.201:56018 [Channel] The PUBREL PacketId 31825 is not found.
2022-10-09T12:02:18.202679+08:00 [warning] archdata-3@192.168.22.201:56018 [Channel] The PUBREL PacketId 31826 is not found.
2022-10-09T12:02:18.212579+08:00 [warning] archdata-3@192.168.22.201:56018 [Channel] The PUBREL PacketId 31827 is not found.
2022-10-09T12:02:18.230490+08:00 [warning] archdata-3@192.168.22.201:56018 [Channel] The PUBREL PacketId 31828 is not found.
2022-10-09T12:02:18.233025+08:00 [warning] archdata-3@192.168.22.201:56018 [Channel] The PUBREL PacketId 31829 is not found.
2022-10-09T12:02:18.234235+08:00 [warning] archdata-3@192.168.22.201:56018 [Channel] The PUBREL PacketId 31830 is not found.
2022-10-09T12:02:18.235496+08:00 [warning] archdata-3@192.168.22.201:56018 [Channel] The PUBREL PacketId 31831 is not found.
2022-10-09T12:02:18.236398+08:00 [warning] archdata-3@192.168.22.201:56018 [Channel] The PUBREL PacketId 31832 is not found.
2022-10-09T12:02:18.238485+08:00 [warning] archdata-3@192.168.22.201:56018 [Channel] The PUBREL PacketId 31833 is not found.
2022-10-09T12:02:18.240491+08:00 [warning] archdata-3@192.168.22.201:56018 [Channel] The PUBREL PacketId 31834 is not found.
2022-10-09T12:02:18.241836+08:00 [warning] archdata-3@192.168.22.201:56018 [Channel] The PUBREL PacketId 31835 is not found.
2022-10-09T12:02:18.243057+08:00 [warning] archdata-3@192.168.22.201:56018 [Channel] The PUBREL PacketId 31836 is not found.
2022-10-09T12:02:18.244199+08:00 [warning] archdata-3@192.168.22.201:56018 [Channel] The PUBREL PacketId 31837 is not found.
2022-10-09T12:02:18.245736+08:00 [warning] archdata-3@192.168.22.201:56018 [Channel] The PUBREL PacketId 31838 is not found.
2022-10-09T12:02:18.247167+08:00 [warning] archdata-3@192.168.22.201:56018 [Channel] The PUBREL PacketId 31839 is not found.
2022-10-09T12:02:18.248281+08:00 [warning] archdata-3@192.168.22.201:56018 [Channel] The PUBREL PacketId 31840 is not found.
2022-10-09T12:02:18.249359+08:00 [warning] archdata-3@192.168.22.201:56018 [Channel] The PUBREL PacketId 31841 is not found.
2022-10-09T12:02:18.250458+08:00 [warning] archdata-3@192.168.22.201:56018 [Channel] The PUBREL PacketId 31842 is not found.
2022-10-09T12:02:18.251366+08:00 [warning] archdata-3@192.168.22.201:56018 [Channel] The PUBREL PacketId 31843 is not found.
2022-10-09T12:02:18.252349+08:00 [warning] archdata-3@192.168.22.201:56018 [Channel] The PUBREL PacketId 31844 is not found.

heeejianbo · 2022 年10 月 9 日 06:04

1010875980:

archdata-3@192.168.22.201:56018 action: {takeover,‘begin’}, file: emqx_cm.erl, line: 352, mfa: {emqx_cm,request_stepdown,3}, msg: session_stepdown_request_timeout, pid: <0.3268.0>, stale_channel: [{status,waiting},{message_queue_len,110},{current_stacktrace,[{emqx_shared_sub,dispatch_with_ack,5,[{file,“emqx_shared_sub.erl”},{line,191}]},{emqx_shared_sub,dispatch,5,[{file,“emqx_shared_sub.erl”},{line,142}]},{emqx_broker,do_route,2,[{file,“emqx_broker.erl”},{line,249}]},{emqx_broker,’-route/2-fun-0-’,3,[{file,“emqx_broker.erl”},{line,237}]},{lists,foldl,3,[{file,“lists.erl”},{line,1267}]},{emqx_session,publish,3,[{file,“emqx_session.erl”},{line,324}]},{emqx_channel,do_publish,3,[{file,“emqx_channel.erl”},{line,621}]},{emqx_connection,with_channel,3,[{file,“emqx_connection.erl”},{line,694}]},{emqx_connection,process_msg,2,[{file,“emqx_connection.erl”},{line,394}]},{emqx_connection,process_msg,2,[{file,“emqx_connection.erl”},{line,400}]},{emqx_connection,handle_recv,3,[{file,“emqx_connection.erl”},{line,358}]},{proc_lib,wake_up,3,[{file,“proc_lib.erl”},{line,236}]}]}]

关键的是这行日志，原因是 archdata-3 这个客户端投递共享订阅消息时太慢了（阻塞了 110 条消息）。

检查下这个客户端是需要发那些消息，这些消息的共享订阅消费者投递应该太慢了，导致拖慢了发布者

1010875980 · 2022 年10 月 9 日 08:50

目前监控到是 archdata-3 这个客户端先offline，close，reconnect 。然后服务端产生了上述警告。我在共享订阅同时使用了 qos 2 来投递和消费消息。并且将 shared_dispatch_ack_enabled 设置为了 true。

1010875980 · 2022 年10 月 9 日 08:52

我暂时不确定客户端为什么会关闭重连，我再监控看看。