rumqttd: Non graceful disconnects do not send last will

[wvffle]

Expected Behavior

When client drops connection non-gracefully, the last will should be sent

Current Behavior

Last will is never sent.

Context

pub async fn start_broker () -> Result<()> {
  let mut mqtt_options = HashMap::new();

  mqtt_options.insert("1".to_string(), ServerSettings {
    name: "v4-1".to_string(),
    listen: "0.0.0.0:1883".parse()?,
    tls: None,
    next_connection_delay_ms: 1,
    connections: ConnectionSettings {
      connection_timeout_ms: 60000,
      max_payload_size: 20480,
      max_inflight_count: 100,
      dynamic_filters: false,
      auth: None,
      external_auth: None,
    }
  });

  let mut broker = Broker::new(Config {
    id: 0,
    v4: Some(mqtt_options),
    router: RouterConfig {
      max_connections: 1000,
      max_outgoing_packet_count: 200,
      max_segment_size: 104857600,
      max_segment_count: 10,
      custom_segment: None,
      initialized_filters: None,
      ..Default::default()
    },
    ..Default::default()
  });

  println!("Starting MQTT broker...");
  broker.start()?;
  Ok(())
}
```

* Operating System: Linux
* Toolchain version: rustc 1.77.0-nightly (e51e98dde 2023-12-31)

[swanandx]

Hey, is rumqttd showing that client is disconnected in logs? this might be related to #777 (comment)

also can you confirm what keepalive time is used by the client?

You can try setting some keepalive time for client, or set TCP Keepalive options in linux using sysctl ( or other utility )

Thank you!

[wvffle]

Hey, thanks for the reply!

I've set the log level to trace and there's no info when the client disconnects. The keepalive is set to 10s and when client is connected I can clearly see the packets, but when it non-gracefully disconnects, it can hang for minutes without any logs.

The tcp_keepalive_time was set to 7200 on my machine, I've tried setting it to 5s with:

sysctl -w net.ipv4.tcp_keepalive_time=5 net.ipv4.tcp_keepalive_intvl=5 net.ipv4.tcp_keepalive_probes=3

However broker still doesn't know about the disconnected client even after couple of minutes.

The last logs of that device are:

Jan 08 14:04:19.697 TRACE remote_link{tenant_id=None connection_id=1}: rumqttd::link::remote: Packets read from network, count = 1
Jan 08 14:04:19.697 DEBUG run:[>] incoming{connection_id=1}:incoming_payload{client_id="LpSw8HMXt3D_kqqMWZOw6"}:pubrel{pkid=1}: rumqttd::router::routing: Appended to commitlog: devices/#[0, 5) pkid=1
Jan 08 14:04:19.697 TRACE run:[>] incoming{connection_id=1}:incoming_payload{client_id="LpSw8HMXt3D_kqqMWZOw6"}:pubrel{pkid=1}: rumqttd::router::scheduler: reschedule Caughtup -> Ready tracker_id="LpSw8HMXt3D_kqqMWZOw6"
Jan 08 14:04:19.697  INFO run:[>] incoming{connection_id=1}:incoming_payload{client_id="LpSw8HMXt3D_kqqMWZOw6"}:pubrel{pkid=1}: rumqttd::router::routing: close time.busy=231µs time.idle=12.6µs
Jan 08 14:04:19.698 TRACE run:[>] incoming{connection_id=1}:incoming_payload{client_id="LpSw8HMXt3D_kqqMWZOw6"}: rumqttd::router::scheduler: reschedule Caughtup -> Ready tracker_id="app"
Jan 08 14:04:19.698 ERROR run:[>] incoming{connection_id=1}:incoming_payload{client_id="LpSw8HMXt3D_kqqMWZOw6"}: rumqttd::router::routing: close time.busy=434µs time.idle=11.4µs
Jan 08 14:04:19.698 ERROR run:[>] incoming{connection_id=1}: rumqttd::router::routing: close time.busy=543µs time.idle=18.5µs
Jan 08 14:04:19.698 TRACE run:[<] outgoing{connection_id=1}: rumqttd::router::routing: Consuming requests
Jan 08 14:04:19.698 TRACE run:[<] outgoing{connection_id=1}:outgoing_ack{client_id="LpSw8HMXt3D_kqqMWZOw6"}: rumqttd::router::routing: Ack added for pkid 1 pkid=1
Jan 08 14:04:19.698 DEBUG run:[<] outgoing{connection_id=1}:outgoing_ack{client_id="LpSw8HMXt3D_kqqMWZOw6"}: rumqttd::router::routing: Acks sent to device acks_count=1
Jan 08 14:04:19.698  INFO run:[<] outgoing{connection_id=1}:outgoing_ack{client_id="LpSw8HMXt3D_kqqMWZOw6"}: rumqttd::router::routing: close time.busy=136µs time.idle=11.9µs
Jan 08 14:04:19.698 TRACE run:[<] outgoing{connection_id=1}: rumqttd::router::scheduler: pause Ready -> Caughtup tracker_id="LpSw8HMXt3D_kqqMWZOw6"
Jan 08 14:04:19.698  INFO run:[<] outgoing{connection_id=1}: rumqttd::router::routing: close time.busy=365µs time.idle=13.4µs

[swanandx]

The keepalive is set to 10s

then it should have disconnected the client ( regardless of how are we disconnecting )

I ran rumqttd, and then connected modified rumqttc ( which doesn't send pings ) to it, I am able to replicate the behavior locally!

so the actual issue seems to be MQTT keepalive isn't being used at all, thus inactive clients aren't disconnected! I will open a PR to fix this ASAP :)

[swanandx]

This issues should be fixed by #784 , if it is possible, can you checkout & verify?

Thank you so much for pointing out the issue 🚀

[wvffle]

@swanandx: The PR worked great!

[swanandx]

closing this issue as PR #784 is merged! feel free to reopen if required :)