nRF5340: MQTT subscribe failed

Hi Support team,

The communication of my net-core of nRF5340 is working well, and I want to try mqtt subscription, but it always fails, could you help give me some hints?

I try to do the subscription in the  event handler of MQTT_EVT_CONNACK:

#define SPARKPLUGB_NCMD         "spBv1.0/BDS/NCMD/Node1/#"
#define SPARKPLUGB_DCMD         "spBv1.0/BDS/DCMD/Node1/#"

int sparkb_sub_cmd(struct mqtt_client *const client)
{
    struct mqtt_topic cmdTopic[2];
	cmdTopic[0].topic.utf8 = (uint8_t *)SPARKPLUGB_NCMD;
	cmdTopic[0].topic.size = strlen(SPARKPLUGB_NCMD);
	cmdTopic[0].qos = MQTT_QOS_0_AT_MOST_ONCE;
	cmdTopic[1].topic.utf8 = (uint8_t *)SPARKPLUGB_DCMD;
	cmdTopic[1].topic.size = strlen(SPARKPLUGB_DCMD);
	cmdTopic[1].qos = MQTT_QOS_0_AT_MOST_ONCE;

	struct mqtt_subscription_list sub_param = {
		.list = cmdTopic,
		.list_count = 2,
		.message_id = 0U
	};

	return mqtt_subscribe(client, &sub_param);
}

In void mqtt_evt_handler(struct mqtt_client *const client, const struct mqtt_evt *evt)
{
	int err;

	switch (evt->type) {
		case MQTT_EVT_CONNACK:
			if (evt->result != 0) {
				LOG_ERR("-----[MQTT_EVT_CONNACK] MQTT connect failed %d", evt->result);
				break;
			}

			g_connected = true;
			LOG_INF("-----[MQTT_EVT_CONNACK] MQTT client connected!");
			
			//Upon connect successful, subscribe to sparkplug NCMD and DCMD msgs. A production should handle MQTT connect failures.
			err = sparkb_sub_cmd(client);
			if (err != 0) {
				LOG_ERR("-----[MQTT_EVT_CONNACK] Failed to subscribe sparkplug NCMD and DCMD: %d", err);
			}

			break;

The MQTT connection succeded, but the subscription is failed, the error code is -22 (#define  EINVAL 22   /* Invalid argument */), the trace as below:

[00:00:25.672,332] <inf> main: modem_test() successful!
[00:00:25.905,395] <inf> mqtttest: mqtt_connect OK, rc is 0
[00:00:26.146,850] <inf> mqtttest: do zsock_poll() 2s, ret = 1
[00:00:26.146,972] <inf> mqtttest: -----[MQTT_EVT_CONNACK] MQTT client connected!
[00:00:26.147,003] <err> mqtttest: -----[MQTT_EVT_CONNACK] Failed to subscribe sparkplug NCMD and DCMD: -22

The published two topics "spBv1.0/BDS/NCMD/Node1/#" and "spBv1.0/BDS/DCMD/Node1/#" by other mqtt clients, so these two topics have existed on the MQTT server.

Could you help have a look and give some hints as to why subscriptions always fail? Thank you very much.

Best regards,
Yanpeng Wu

  • Hi,

    The message ID is not permitted to be 0 by the specification.

    In addition, you might run into a problem where sub_param is used after it is deallocated, as it is currently just allocated on the stack.

    Best regards,

    Didrik

  • Hi Didrik,

    Thanks for your guidance. It's true, the subscription is successful when I set the .message_id = sys_rand32_get(). The sub_param created as a local variable and on the stack is no problem, and it can work well(I guess the mqtt API uses 'pass by value' or be called synchronously), I can publish success when the subscription fails.


    But a new problem occurred after the successful subscription, I received an MQTT_EVT_DISCONNEC and the evt->result is -105, the trace is:

    [00:00:49.091,186] <inf> mqtttest: -----[MQTT_EVT_DISCONNECT] MQTT client disconnected -105
               //#define ENOBUFS 105 /* No buffer space available */

    Why just subscribing to two topics will cause 'No buffer space available' and lose the MQTT connection? Looking forward to your comments.

    Best regards,
    Yanpeng Wu

  • Update: for the error code ENOBUFS 105 /* No buffer space available */, I tried to increase the mqtt client rx_buffer and tx_buffer big enough, but still with the same error.

    Should I increase the socket buffer CONFIG_NET_SOCKETS_SERVICE_STACK_SIZE?
    The socket session was closed by receiving MQTT_EVT_DISCONNECT, is the session closed by mqtt server or local mqtt stack?

    Thank you very much.
  • What happens before you get disconnected? E.g. are you sending data to or from the device?

    I can't find anywhere in the mqtt library that returns -ENOBUFS, so I think the error is coming from somewhere else, such as you rmodem driver.

    Can you enable logging further down in the IP stack to see if we can find where the error comes from?

  • Hi Didrik,

    Thank you for your reply. Before MQTT-Connection, I did some modem-test by sending UDP packets. Then init and connect MQTT, nothing MQTT data sent before MQTT-Connection.
    Maybe the error is from the socket or modem driver, just as you said. Could you tell me how to enable logging in IP stack? thank you very much.

    I tried three scenarios, and the results showed it was closely related to the modem(I used ublox SARA-R4 modem and the cellular modem driver, and communication works well), I summarized here:


    1. If not do the subscription, can connect and publish messages successfully forever.


    2. If do the subscription in the MQTT_EVT_CONNACK(just after connect success), it showed that the calling mqtt_subscribe() success, bu no MQTT_EVT_SUBACK received.
    and modem dropped one or two frames, then received a MQTT_EVT_DISCONNECT, trace as below:

    [00:00:26.106,201] <inf> mqtttest: mqtt_connect OK, rc is 0
    [00:00:26.410,339] <inf> mqtttest: do zsock_poll() 2s, ret = 1
    [00:00:26.410,491] <err> mqtttest: -----[mqtt_evt_handler]
    [00:00:26.410,522] <inf> mqtttest: -----[MQTT_EVT_CONNACK] MQTT client connected!
    [00:00:26.415,863] <err> mqtttest: -----[MQTT_EVT_CONNACK] Success to subscribe sparkplug NCMD and DCMD: 0  //------just call mqtt_subscribe() success, but no MQTT_EVT_SUBACK received
    [00:00:26.415,924] <wrn> sparkplugb: PUBLISH NODE BIRTH
    [00:00:26.431,457] <wrn> sparkplugb: PUBLISH DEVICE BIRTH
    [00:00:26.441,314] <wrn> sparkplugb: PUBLISH DEVICE DATA
    [00:00:26.673,339] <wrn> modem_ppp: Dropped frame, no net_pkt available                         //------modem dropped frame
    [00:00:32.954,010] <wrn> modem_ppp: Dropped frame, no net_pkt available                         //------modem dropped frame
    [00:00:36.930,206] <err> mqtttest: -----[mqtt_evt_handler]
    [00:00:36.930,236] <inf> mqtttest: -----[MQTT_EVT_DISCONNECT] MQTT client disconnected -105     //------received MQTT_EVT_DISCONNECT, MQTT session was closed.
    [00:00:36.931,182] <wrn> main: NetworkCore - Hello 1                                            //------The error code is ENOBUFS 105	/* No buffer space available */
    [00:00:46.932,922] <wrn> sparkplugb: PUBLISH DEVICE DATA
    [00:00:46.934,020] <wrn> main: NetworkCore - Hello 2

    3. If not do the subscription in the MQTT_EVT_CONNACK, after 20 successful publishing, then do the subscription, no MQTT_EVT_SUBACK received.
    and modem dropped some frames, then received an MQTT_EVT_DISCONNECT, trace as below:

    [00:03:17.068,511] <wrn> sparkplugb: PUBLISH DEVICE DATA
    [00:03:17.075,256] <wrn> main: NetworkCore - Hello 18
    [00:03:27.077,026] <wrn> sparkplugb: PUBLISH DEVICE DATA
    [00:03:27.083,374] <wrn> main: NetworkCore - Hello 19
    [00:03:37.085,113] <wrn> sparkplugb: PUBLISH DEVICE DATA
    [00:03:37.090,270] <err> main: -----[MAIN] Success to subscribe sparkplug NCMD and DCMD: 0    //------just call mqtt_subscribe() success, but no MQTT_EVT_SUBACK received
    [00:03:37.090,301] <wrn> main: NetworkCore - Hello 20                                         //------these 20 publishing message can be received by other client.
    [00:03:37.817,718] <wrn> modem_ppp: Dropped frame, no net_pkt available                       //------modem start to drop some frames
    [00:03:47.092,071] <wrn> sparkplugb: PUBLISH DEVICE DATA
    [00:03:47.100,219] <wrn> main: NetworkCore - Hello 21
    [00:03:47.534,118] <wrn> modem_ppp: Dropped frame, no net_pkt available
    [00:03:47.534,393] <wrn> modem_ppp: Dropped frame, no net_pkt available
    [00:03:48.049,682] <wrn> modem_ppp: Dropped frame, no net_pkt available
    [00:03:48.691,741] <wrn> modem_ppp: Dropped frame, no net_pkt available
    [00:03:49.570,770] <wrn> modem_ppp: Dropped frame, no net_pkt available
    [00:03:50.929,687] <wrn> modem_ppp: Dropped frame, no net_pkt available
    [00:03:52.939,666] <wrn> modem_ppp: Dropped frame, no net_pkt available
    [00:03:55.969,879] <wrn> modem_ppp: Dropped frame, no net_pkt available
    [00:03:57.102,020] <wrn> sparkplugb: PUBLISH DEVICE DATA                                      //------after that, the following publishing message can not be received by other client.
    [00:03:57.103,210] <wrn> main: NetworkCore - Hello 22                      
    [00:04:00.630,584] <wrn> modem_ppp: Dropped frame, no net_pkt available
    [00:04:07.104,919] <wrn> sparkplugb: PUBLISH DEVICE DATA
    [00:04:07.106,079] <wrn> main: NetworkCore - Hello 23
    [00:04:07.697,479] <wrn> modem_ppp: Dropped frame, no net_pkt available
    [00:04:17.107,818] <wrn> sparkplugb: PUBLISH DEVICE DATA
    [00:04:17.108,123] <err> mqtttest: -----[mqtt_evt_handler]
    [00:04:17.108,154] <inf> mqtttest: -----[MQTT_EVT_DISCONNECT] MQTT client disconnected -128   //------received MQTT_EVT_DISCONNECT, MQTT session was closed.
    [00:04:17.109,161] <wrn> main: NetworkCore - Hello 24                                         //------BUT the error code is ENOTCONN 128  /* Socket is not connected */
    [00:04:27.110,900] <wrn> sparkplugb: PUBLISH DEVICE DATA
    [00:04:27.111,999] <wrn> main: NetworkCore - Hello 25
    [00:04:37.113,830] <wrn> sparkplugb: PUBLISH DEVICE DATA
    [00:04:37.114,929] <wrn> main: NetworkCore - Hello 26
    [00:04:47.116,668] <wrn> sparkplugb: PUBLISH DEVICE DATA

Related