nrf_poll may be consuming data when not supposed to on nrf9160

[miked531]

I'm using the socket(AF_LTE) to talk directly to the modem on the nrf9160 and wanted to add a timeout to my recv() call. I added a call to poll() before recv() and am seeing strange results now. It looks like the poll is consuming some of the data. I'm only sending the plain "AT" command. When the poll is removed, it works as expected, when it's there I lose some data. Specifically, I am calling recv(), which ends up calling nrf_poll() at some point, if it matters.

I'm confident enough in my code (aren't we all?) to suggest this may be a bug, but I'm not sure. There's too much code to post, but the gist of it is: send("AT\r\n"), poll(for_single_socket), recv() is missing some data in the read and by removing the poll() it works fine.

Mike

[Simon]

Test out the sample below, and check if you are able to get that to work.

recv_timeout.zip

Best regards,

Simon

[miked531]

The sample did work. I modified it to add concurrency with multiple AF_LTE sockets open and it starts to fail after just a few thousand iterations, mostly with EINVAL

#include <zephyr.h>

#include <stdio.h>
#include <string.h>

//functions like send() and rev() is declared here
#include <net/socket.h>

static const u8_t at_buf[256] = "AT+CGMI\r\n";
static const u8_t at_cfun[256] = "AT+CFUN=4\r\n";
#define SENDME at_buf

void runner(void *a, void *b, void *c)
{
int counter = 0;
int id = (int)a;
char buf[256];
int sockfd, bytes_sent, bytes_read;

sockfd = socket(AF_LTE, 0, NPROTO_AT);

if (sockfd == -1) {
printk("[%d] Could not open socket\n", id);
k_sleep(86400 * 1000);
} else {
printk("[%d] sockfd %d\n", id, sockfd);
}

struct timeval tv;
tv.tv_sec = 1;
tv.tv_usec = 0;
setsockopt(sockfd, SOL_SOCKET, SO_RCVTIMEO, (const char*)&tv, sizeof tv);

int bytes_to_send = strlen(SENDME);

while(1) {
if( (++counter % 1000) == 0 ) printk("[%d] count %d\n", id, counter);
bytes_sent = send(sockfd, SENDME, bytes_to_send, 0);
if (bytes_sent != bytes_to_send) {
printk("[%d] send failed, returned %d, errno %d\n", id, bytes_sent, errno);
} else{
//printk("[%d] sent %d bytes\n", id, bytes_sent);
}
bytes_read = recv(sockfd, buf, sizeof(buf), 0);
if( bytes_read > 0 ) {
//printk("[%d] recv %d bytes: %s\n", id, bytes_read, buf);
} else {
printk("[%d] recv failed, errno %d\n", id, errno);
}
//k_sleep(100);
}
}

K_THREAD_DEFINE(zero, 1024, runner, 0, 0, 0, 5, 0, 0);
K_THREAD_DEFINE(one, 1024, runner, 1, 0, 0, 5, 0, 0);
K_THREAD_DEFINE(two, 1024, runner, 2, 0, 0, 5, 0, 0);
K_THREAD_DEFINE(three, 1024, runner, 3, 0, 0, 5, 0, 0);
K_THREAD_DEFINE(four, 1024, runner, 4, 0, 0, 5, 0, 0);
K_THREAD_DEFINE(five, 1024, runner, 5, 0, 0, 5, 0, 0);

void main(void)
{
k_sleep(86400 * 1000);
}

[Simon]

I tested your code, and I got the same error message as you (EINVAL=22). However, I noticed something interesting, the EINVAL error is not the initial cause of the problem. I saw that the send function in three of the five threads failed with the errno NRF_ENOMEM=12 (Cannot allocate memory) initially. Then, following that, the send() functions in the respective threads failed with EINVAL.

I am not sure what specifically is happening internally, but will look into it. By the way, I tried changing the stack size of all the threads to 512, then it didn't fail until 63000 iterations was passed by.

Best regards,

Simon

[Simon]

Hello miked!

Have you made any progress on this, or should I take a deeper look at your problem?

Best regards,

Simon

[miked531]

I was having the issue with nrf v1.0.0. I came across a similar issue and v1.1.0 resolved it with the updated nrfxlib. I'll give this another shot once the new modem firmware comes out