First and second transmission fails in nRF9160

[Yusuke]

hardware: nRF9160 DK 0.8.2
firmware: 0.7.0-29.alpha

I want to send data every a few seconds through MQTT. It fails in the first and second Tx after MQTT client initiation, and succeeds after that. It releases error = -57.
Why does it fails in the first and second Tx after initiation?

I tested the code below. I added four lines to mqtt_simple.
mqtt_simple: https://github.com/NordicPlayground/fw-nrfconnect-nrf/blob/master/samples/nrf9160/mqtt_simple/src/main.c

<main.c>

.
.
.
void main(void)
{
	int err;

	printk("The MQTT simple sample started\n");

	modem_configure();

	client_init(&client);

	err = mqtt_connect(&client);
	if (err != 0) {
		printk("ERROR: mqtt_connect %d\n", err);
		return;
	}

	err = fds_init(&client);
	if (err != 0) {
		printk("ERROR: fds_init %d\n", err);
		return;
	}

        k_sleep(20*1000); // ADD HERE
        err = data_publish(&client, MQTT_QOS_0_AT_MOST_ONCE, "a", strlen("a"));  // ADD HERE
        printk("err=%d\n", err); // ADD HERE
        printk("Send reset message\n"); // ADD HERE

	while (1) {
.
.
.

and the result is here. err=-57

***** Booting Zephyr OS v1.14.99-ncs1 *****
The MQTT simple sample started
LTE Link Connecting ...
LTE Link Connected!
IPv4 Address found 0x????????
Publishing: a
to topic: myPubTopic len: 10
err=-57
Send reset message
mqtt_input start
[mqtt_evt_handler:168] MQTT client connected!
Subscribing to: mySubTopic len 10
mqtt_input end
mqtt_input start
[mqtt_evt_handler:218] SUBACK packet id: 1234
mqtt_input end

Any advice?

[AndreasF]

Hi.

Looking in the SDK from when you call data_publish(&client, MQTT_QOS_0_AT_MOST_ONCE, "a", strlen("a")); I end up in the function verify_tx_state(client):

(in mqtt.c)

This returns -ENOTCONN which is -57.

So it seems that this is the error. What values and so on does the client struct have?

Best regards,

Andreas

[Yusuke]

Thank you for your reply!

It's hard to check all the params of mqtt_client as it has a lot of params.....

I compared my code with the lates mqtt_simple code
https://github.com/NordicPlayground/fw-nrfconnect-nrf/tree/master/samples/nrf9160/mqtt_simple

There are two differences.
1. Line 264 inet_ntop is added in the latest code.
2. I add password and username in my code. Also I change MQTT version to 3.1.0

<main.c>
.
.
#define MQTT_PASSWORD "password"
#define MQTT_USERNAME "username"
.
.
/**@brief Initialize the MQTT client structure
 */
static void client_init(struct mqtt_client *client)
{
	mqtt_client_init(client);

	broker_init();

        /* Add from here */
        static struct mqtt_utf8 password;
	static struct mqtt_utf8 user_name;

	password.utf8 = (u8_t *)MQTT_PASSWORD;
	password.size = strlen(MQTT_PASSWORD);
	user_name.utf8 = (u8_t *)MQTT_USERNAME;
	user_name.size = strlen(MQTT_USERNAME);
        /* to here */

	/* MQTT client configuration */
	client->broker = &broker;
	client->evt_cb = mqtt_evt_handler;
	client->client_id.utf8 = (u8_t *)CONFIG_MQTT_CLIENT_ID;
	client->client_id.size = strlen(CONFIG_MQTT_CLIENT_ID);
	client->password = &password; // Add here
	client->user_name = &user_name; // Add here
	client->protocol_version = MQTT_VERSION_3_1_0; // originally MQTT_VERSION_3_1_1

	/* MQTT buffers configuration */
	client->rx_buf = rx_buffer;
	client->rx_buf_size = sizeof(rx_buffer);
	client->tx_buf = tx_buffer;
	client->tx_buf_size = sizeof(tx_buffer);

	/* MQTT transport configuration */
	client->transport.type = MQTT_TRANSPORT_NON_SECURE;
}

Do you have any advice?

[Yusuke]

I added data_publish function to the original mqtt_simple program tested it. It doesn't work.

<main.c>
.
.

/**@brief Initialize the MQTT client structure
 */
static void client_init(struct mqtt_client *client)
{
	mqtt_client_init(client);

	broker_init();

	/* MQTT client configuration */
	client->broker = &broker;
	client->evt_cb = mqtt_evt_handler;
	client->client_id.utf8 = (u8_t *)CONFIG_MQTT_CLIENT_ID;
	client->client_id.size = strlen(CONFIG_MQTT_CLIENT_ID);
	client->password = NULL;
	client->user_name = NULL;
	client->protocol_version = MQTT_VERSION_3_1_1;

	/* MQTT buffers configuration */
	client->rx_buf = rx_buffer;
	client->rx_buf_size = sizeof(rx_buffer);
	client->tx_buf = tx_buffer;
	client->tx_buf_size = sizeof(tx_buffer);

	/* MQTT transport configuration */
	client->transport.type = MQTT_TRANSPORT_NON_SECURE;
}
.
.
void main(void)
{
	int err;

	printk("The MQTT simple sample started\n");

	modem_configure();

	client_init(&client);

	err = mqtt_connect(&client);
	if (err != 0) {
		printk("ERROR: mqtt_connect %d\n", err);
		return;
	}

	err = fds_init(&client);
	if (err != 0) {
		printk("ERROR: fds_init %d\n", err);
		return;
	}

        err = data_publish(&client, MQTT_QOS_0_AT_MOST_ONCE, "a", strlen("a")); // TODO ADD HERE. Does not work
        printk("err=%d\n", err);
        printk("Send reset message\n");

	while (1) {
		err = poll(&fds, 1, K_SECONDS(CONFIG_MQTT_KEEPALIVE));
		if (err < 0) {
			printk("ERROR: poll %d\n", errno);
			break;
		}

		err = mqtt_live(&client);
		if (err != 0) {
			printk("ERROR: mqtt_live %d\n", err);
			break;
		}

		if ((fds.revents & POLLIN) == POLLIN) {
			err = mqtt_input(&client);
			if (err != 0) {
				printk("ERROR: mqtt_input %d\n", err);
				break;
			}
		}

		if ((fds.revents & POLLERR) == POLLERR) {
			printk("POLLERR\n");
			break;
		}

		if ((fds.revents & POLLNVAL) == POLLNVAL) {
			printk("POLLNVAL\n");
			break;
		}
	}

	printk("Disconnecting MQTT client...\n");

	err = mqtt_disconnect(&client);
	if (err) {
		printk("Could not disconnect MQTT client. Error: %d\n", err);
	}
}

<prj.conf>
.
.
# Appliaction
#CONFIG_MQTT_PUB_TOPIC="/my/publish/topic"
#CONFIG_MQTT_SUB_TOPIC="/my/subscribe/topic"
#CONFIG_MQTT_CLIENT_ID="my-client-id"
#CONFIG_MQTT_BROKER_HOSTNAME="iot.eclipse.org"
#CONFIG_MQTT_BROKER_PORT=1883
.
.

***** Booting Zephyr OS v1.14.99-ncs1 *****
The MQTT simple sample started
LTE Link Connecting ...
LTE Link Connected!
IPv4 Address found ������������UUUU
Publishing: a
to topic: my/publish/topic len: 16
err=-57
Send reset message
mqtt_input start
[mqtt_evt_handler:166] MQTT client connected!
Subscribing to: my/subscribe/topic len 18
mqtt_input end
mqtt_input start
[mqtt_evt_handler:216] SUBACK packet id: 1234
mqtt_input end
mqtt_input start
mqtt_input end

So this issue should not be related to a broker. 

I'm confused....

[AndreasF]

Hi again.

Can you check that you have the latest modem firmware installed?

Can you also check that you are in the v0.4.0 branch?

Best regards,

Andreas

[Yusuke]

same here.

$ git branch
* (HEAD detached at v0.4.0)
  master

Can you try the same program above with your nRF9160 DK board?

[AndreasF]

Hi again.

It is working for me now, but I moved data_publish() to the connection event in the event handler, MQTT_EVT_CONNACK.

The issue was probably that you tried to publish data without being in the connection state.

Best regards,

Andreas

[Yusuke]

OK. I figured out. mqtt_connect does not deal with CONNACK so that you need to poll after mqtt_connect.

void main(void)
{
	int err;

	printk("The MQTT simple sample started\n");

	modem_configure();

	client_init(&client);

	err = mqtt_connect(&client);
	if (err != 0) {
		printk("ERROR: mqtt_connect %d\n", err);
		return;
	}

	err = fds_init(&client);
	if (err != 0) {
		printk("ERROR: fds_init %d\n", err);
		return;
	}

    err = poll(&fds, 1, K_SECONDS(CONFIG_MQTT_KEEPALIVE)); 
    if (err < 0) {
            printk("ERROR: poll %d\n", errno);
    }

    if ((fds.revents & POLLIN) == POLLIN) {
            err = mqtt_input(&client);
            if (err != 0) {
                    printk("ERROR: mqtt_input %d\n", err);
            }
    }

    while(1){
            err = data_publish(&client, MQTT_QOS_0_AT_MOST_ONCE, "a", strlen("a")); // This works out
            printk("err=%d\n", err);
            printk("Send reset message\n");
            k_sleep(2*1000);
    }
}

[dtquang89]

This helps me. Thank you a lot.