设备异常重连,日志里有maybe_publish_will_msg_other_publish,且设置的遗嘱延时发送失效

环境

  • EMQX 版本: 5.6.0
  • 操作系统版本: K8S部署

设备上线时的属性

{
  "conn_props": {
    "Will-Delay-Interval": 30,
    "Session-Expiry-Interval": 60,
    "User-Property": {}
  },
  "peername": "****",
  "metadata": {
    "rule_id": "****"
  },
  "clientid": "***",
  "is_bridge": false,
  "keepalive": 30,
  "proto_ver": 5,
  "proto_name": "MQTT",
  "connected_at": 1754643302204,
  "receive_maximum": 500,
  "sockname": "****",
  "mountpoint": "undefined",
  "node": "****",
  "expiry_interval": 60,
  "event": "client.connected",
  "username": "******",
  "timestamp": 1754643302204,
  "clean_start": false
}

现象

设备在不停的重连,从采集到的事件来看为下列几个事件的循环
connect → disconnect(原因为tcp_closed) → will(遗嘱消息) → disconnect(原因为takenover)

问题描述

一开始我们看到disconnect(原因为takenover)时,下意识认为是有设备在互踢,查了很久发现并不是互踢。设备下线后,只要会话还在,即使是同一个设备发起重连也会出现takenover,即takenover与会话相关,出现takenover并不一定是有两个物理的设备在互踢。

现在主要想咨询 设备为什么下线以及设备所设置的遗嘱消息延时为什么没有生效?跟日志中的maybe_publish_will_msg_other_publish有关系吗?

从采集到的事件中可以看到,will几乎和disconnect发生在同一时间,这不符合设置的延时发送遗嘱消息的设置
image

emqx的日志中此设备的下线日志如下:

{
    "time": 1754643300833602,
    "level": "debug",
    "msg": "maybe_publish_will_msg_other_publish",
    "username": "****",
    "reason": "sock_closed",
    "pid": "<0.11310.2626>",
    "peername": "****",
    "mfa": "{emqx_channel,maybe_publish_will_msg,2}",
    "line": 2387,
    "clientid": "***"
}

takenover 就是会话接管(继承了上一次的会话。)
kicked 是互相踢。

全代码里面搜:
https://github.com/emqx/emqx/blob/cf505d237266cda891238f1a6346c3b2f8fdf0d4/apps/emqx/src/emqx_channel.erl#L3078-L3080
就这里会有这个 debug 日志 打出来。
这个 debug 日志只有在delay-interval为 0 时才会打印。

PS:我使用 mqttx 测试 delay 是正常的。你也可以试试。

但是看采集到的设备的建联事件里,conn_props里will-delay-interval为30,这个单位应该是秒吧,我理解这个说明遗嘱延迟设置为30s,为什么会是0呢?什么样的建联事件才表示遗嘱延迟设置成功呢?

客户端建联的属性设置问题,已定位问题原因