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]

I think you can enable a timeout on the recv() function by using the setsockopt() function (See this link). It can be done by setting "level" to SOL_SOCKET and "option name" to SO_RCVTIMEO and set your timeout and size of timeout variable to respectively "optval" and "optlen".

Take a look here, to get an understanding of the arguments used when setting a timeout.

I have not tested this, and I am not sure if I understand it correctly, but it is worth taking a look at.

Best regards,

Simon

[miked531]

Thanks for the suggestion. For my application, I can can use a polling loop with recv(MSG_DONTWAIT). I'd like to use the SO_RCVTIMEO, but I'm not confident it is immune from the same behavior I see with and don't have time to experiment currently.

[Simon]

I tested the suggestion, and it worked fine as far as I could see. I added the lines in the snippet below, and if nothing was received in a second, the function stopped and the program continued.

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

Best regards,

Simon

[miked531]

I tried the code above and strangeness happened as soon at I put it in (setsockopt failed with errno EPERM!?). I'm now convinced there is an issue, and my guess is that it's in nrfxlib. Note that my test was using the AF_LTE socket

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