MQTT keep alive ping is not working for RP2040W (Pico W)

[vstokesjr]

Pico W SDK: 1.4.0 IDE: CLion on Ubuntu 22.04 running on a PC: GCC: 11.2.0 (Ubuntu 11.2.0-19ubuntu1) MQTT broker/server: Mosquitto 2.0.15 running on Ubuntu 22.04.

Issue: MQTT keep alive ping is not working for RP2040W (Pico W). _mqtt_cyclictimer() is never called. It seems that _timeouts::systimeout() never fires. The keep alive ping is never sent to the server thus causing the server to disconnect the client due to inactivity.

I added additional debugging output in apps/mqtt/mqtt.c to the following two functions:

static err_t mqtt_tcp_connect_cb( void *arg, struct altcp_pcb *tpcb, err_t err )
{
...
  /* Start cyclic timer */
  sys_timeout( MQTT_CYCLIC_TIMER_INTERVAL * 1000, mqtt_cyclic_timer, client );
  client->cyclic_tick = 0;
  LWIP_DEBUGF( MQTT_DEBUG_TRACE, ( "mqtt_tcp_connect_cb: mqtt_cyclic_timer: started\n" ) );
...
}

static void mqtt_cyclic_timer( void *arg )
{
  LWIP_DEBUGF( MQTT_DEBUG_TRACE, ( "mqtt_cyclic_timer: called\n" ) );
...
  if ( restart_timer )
  {
    sys_timeout( MQTT_CYCLIC_TIMER_INTERVAL * 1000, mqtt_cyclic_timer, arg );
    LWIP_DEBUGF( MQTT_DEBUG_TRACE, ( "mqtt_cyclic_timer: restarted\n" ) );
  }
}

I set the keep alive to 15 seconds:

....
  /* Initialize and configure the client info structure */
  struct mqtt_connect_client_info_t clientInfo;
  clientInfo.client_id = MQTT_CLIENT_ID;
  clientInfo.client_user = MQTT_USER;
  clientInfo.client_pass = MQTT_USER_PASSWD;
  clientInfo.keep_alive = 15;
  clientInfo.will_topic = NULL; /* set to NULL if will is not to be used, will_msg, will_qos and will retain are then ignored */
  clientInfo.will_msg = NULL;
  clientInfo.will_qos = 0;
  clientInfo.will_retain = 0;

  err = mqtt_client_connect(
    client,
    &brokerAddr,
    MQTT_PORT,
    mqttConnectionCallback,
    NULL,
    &clientInfo
  );
....

I get the following output when I run a simple MQTT client (built using the MQTT documentation provided) on the PICO W with debug enabled, You will note that the new debug messages added to _mqtt_cyclictimer() never appear.

Version: 7.95.49 (2271bb6 CY) CRC: b7a28ef3 Date: Mon 2021-11-29 22:50:27 PST Ucode Ver: 1043.2162 FWID 01-c51d9400
cyw43 loaded ok, mac 28:cd:c1:04:94:65
API: 12.2
Data: RaspberryPi.PicoW
Compiler: 1.29.4
ClmImport: 1.47.1
Customization: v5 22/06/24
Creation: 2022-06-24 06:55:08
connect status: joining
connect status: no ip
connect status: link up
mqtt_client_connect: Connecting to host: 10.3.17.26 at port:1883
mqtt_tcp_connect_cb: TCP connection established to server
mqtt_tcp_connect_cb: mqtt_cyclic_timer: started <<<<< NOTE THIS ENTRY (added by me)
mqtt_output_send: tcp_sndbuf: 11680 bytes, ringbuf_linear_available: 33, get 0, put 33
mqtt_parse_incoming: Remaining length after fixed header: 2
mqtt_parse_incoming: msg_idx: 4, cpy_len: 2, remaining 0
mqtt_message_received: Connect response code 0
mqtt_sub_unsub: Client (un)subscribe to topic "mqtt/test/in", id: 1
mqtt_output_send: tcp_sndbuf: 11680 bytes, ringbuf_linear_available: 19, get 33, put 52
mqtt_parse_incoming: Remaining length after fixed header: 3
mqtt_parse_incoming: msg_idx: 5, cpy_len: 3, remaining 0
mqtt_message_received: SUBACK response with id 1
mqtt_tcp_recv_cb: Recv pbuf=NULL, remote has closed connection
mqtt_client_connect: Connecting to host: 10.3.17.26 at port:1883
mqtt_tcp_connect_cb: TCP connection established to server
mqtt_tcp_connect_cb: mqtt_cyclic_timer: started <<<<< NOTE THIS ENTRY (added by me)
mqtt_output_send: tcp_sndbuf: 11680 bytes, ringbuf_linear_available: 33, get 0, put 33
mqtt_parse_incoming: Remaining length after fixed header: 2
mqtt_parse_incoming: msg_idx: 4, cpy_len: 2, remaining 0
mqtt_message_received: Connect response code 0
mqtt_sub_unsub: Client (un)subscribe to topic "mqtt/test/in", id: 1
mqtt_output_send: tcp_sndbuf: 11680 bytes, ringbuf_linear_available: 19, get 33, put 52
mqtt_parse_incoming: Remaining length after fixed header: 3
mqtt_parse_incoming: msg_idx: 5, cpy_len: 3, remaining 0
mqtt_message_received: SUBACK response with id 1
mqtt_tcp_recv_cb: Recv pbuf=NULL, remote has closed connection
mqtt_client_connect: Connecting to host: 10.3.17.26 at port:1883
mqtt_tcp_connect_cb: TCP connection established to server
mqtt_tcp_connect_cb: mqtt_cyclic_timer: started <<<<< NOTE THIS ENTRY (added by me)
mqtt_output_send: tcp_sndbuf: 11680 bytes, ringbuf_linear_available: 33, get 0, put 33
mqtt_parse_incoming: Remaining length after fixed header: 2
mqtt_parse_incoming: msg_idx: 4, cpy_len: 2, remaining 0
mqtt_message_received: Connect response code 0
....

The following log messages keep repeating on the Mosquitto broker/server:

1666607350: New connection from 10.3.17.135:52868 on port 1883.
1666607350: New client connected from 10.3.17.135:52868 as picow (p2, c1, k15, u'test').
1666607375: Client picow has exceeded timeout, disconnecting.
1666607380: New connection from 10.3.17.135:52869 on port 1883.
1666607380: New client connected from 10.3.17.135:52869 as picow (p2, c1, k15, u'test').
1666607405: Client picow has exceeded timeout, disconnecting.

[lurch]

ping @peterharperuk

[peterharperuk]

This just works for me using lwip in the pico-sdk. Suggest you don't use pico-extras for lwip