leemoore1966
Posts: 25
Joined: Sat Aug 29, 2015 2:39 pm

UDP Unicast Tx Buffer not flushing

Fri Dec 15, 2017 6:12 pm

Hi All

I am seeing some very strange behavior, and very difficult to reproduce.

on an RPi3 I have a UDP client which is sending data to a number of servers over wlan0
The RPi3 is configured as a hotspot running hostapd, with 5 clients.

UDP data is sent from the RPi3 using unicast, the bandwidth is quite low approx 5kbytes/Second to each client, when data is sent the UDP tx buffer is monitored to ensure it is not growing 'abnormally'

Code: Select all

            int txqPre, txqPost;
            ioctl(sock, TIOCOUTQ, &txqPre);
            int sent = sendto(sock, buf, buflen, MSG_DONTWAIT, siP, slen);
            ioctl(sock, TIOCOUTQ, &txqPost);
occasionally the buffer starts to grow, and it appears to block the flushing of the packets to the network.
This stall can last many seconds, as this is streaming data, this is really bad, but I can find no way to determine what is going wrong.
Nothing is logged in the syslogs, but at the Receive end, I see data just stops, whilst the Buffers grow at the Transmit end, here is an extract of the logging reporting the growing buffers
As you can see below I effectively get a stall for 30 seconds, as the buffer continually fills but the kernel is not sending out

Could this be a kernel bug, I cannot see anything in the application that would cause this and I have investigated very thoroughly, it happens infrequently and with no apparent symptom. The sends occur at 1second intervals, but as can be seen the Buffer continues growing and no output UDP packets are observed at the Receivers
Current kernel is
Linux raspberrypi 4.9.35-v7+ #1014 SMP Fri Jun 30 14:47:43 BST 2017 armv7l GNU/Linux

Code: Select all

(17:01:10) COMMON    : sendUdpMessageSock UDP sendto(192.168.1.20) Send-Q=35584 traffictable=9
(17:01:11) COMMON    : sendUdpMessageSock UDP sendto(192.168.1.20) Send-Q=39616 traffictable=9
(17:01:11) COMMON    : sendUdpMessageSock UDP sendto(192.168.1.20) Send-Q=45184 traffictable=9
(17:01:12) COMMON    : sendUdpMessageSock UDP sendto(192.168.1.20) Send-Q=49216 traffictable=9
(17:01:12) COMMON    : sendUdpMessageSock UDP sendto(192.168.1.20) Send-Q=54784 traffictable=9
(17:01:13) COMMON    : sendUdpMessageSock UDP sendto(192.168.1.20) Send-Q=58816 traffictable=9
(17:01:13) COMMON    : sendUdpMessageSock UDP sendto(192.168.1.20) Send-Q=64384 traffictable=9
(17:01:14) COMMON    : sendUdpMessageSock UDP sendto(192.168.1.20) Send-Q=68416 traffictable=9
(17:01:14) COMMON    : sendUdpMessageSock UDP sendto(192.168.1.20) Send-Q=73984 traffictable=9
(17:01:15) COMMON    : sendUdpMessageSock UDP sendto(192.168.1.20) Send-Q=78016 traffictable=9
(17:01:15) COMMON    : sendUdpMessageSock UDP sendto(192.168.1.20) Send-Q=83584 traffictable=9
(17:01:16) COMMON    : sendUdpMessageSock UDP sendto(192.168.1.20) Send-Q=87616 traffictable=9
(17:01:16) COMMON    : sendUdpMessageSock UDP sendto(192.168.1.20) Send-Q=93184 traffictable=9
(17:01:36) COMMON    : sendUdpMessageSock UDP sendto(192.168.1.20) Send-Q=97216 traffictable=12
(17:01:36) COMMON    : sendUdpMessageSock UDP sendto(192.168.1.20) Send-Q=102784 traffictable=12
(17:01:37) COMMON    : sendUdpMessageSock UDP sendto(192.168.1.20) Send-Q=106816 traffictable=12
(17:01:37) COMMON    : sendUdpMessageSock UDP sendto(192.168.1.20) Send-Q=112384 traffictable=12
(17:01:38) COMMON    : sendUdpMessageSock UDP sendto(192.168.1.20) Send-Q=114304 traffictable=12
(17:01:39) COMMON    : sendUdpMessageSock UDP sendto(192.168.1.20) Send-Q=118336 traffictable=12
(17:01:39) COMMON    : sendUdpMessageSock UDP sendto(192.168.1.20) Send-Q=123904 traffictable=12
(17:01:40) COMMON    : sendUdpMessageSock UDP sendto(192.168.1.20) Send-Q=127936 traffictable=11
(17:01:40) COMMON    : sendUdpMessageSock UDP sendto(192.168.1.20) Send-Q=133504 traffictable=11
(17:01:41) COMMON    : sendUdpMessageSock UDP sendto(192.168.1.20) Send-Q=137536 traffictable=11
(17:01:41) COMMON    : sendUdpMessageSock UDP sendto(192.168.1.20) Send-Q=143104 traffictable=11
(17:01:42) COMMON    : sendUdpMessageSock UDP sendto(192.168.1.20) Send-Q=145024 traffictable=11
(17:01:43) COMMON    : sendUdpMessageSock UDP sendto(192.168.1.20) Send-Q=149056 traffictable=12
(17:01:43) COMMON    : sendUdpMessageSock UDP sendto(192.168.1.20) Send-Q=154624 traffictable=12
(17:01:44) COMMON    : sendUdpMessageSock UDP sendto(192.168.1.20) Send-Q=158656 traffictable=12
(17:01:44) COMMON    : sendUdpMessageSock UDP sendto(192.168.1.20) Send-Q=164224 traffictable=12
(17:01:45) COMMON    : sendUdpMessageSock UDP sendto(192.168.1.20) Send-Q=168256 traffictable=12
(17:01:45) COMMON    : sendUdpMessageSock UDP sendto(192.168.1.20) Send-Q=173824 traffictable=12
(17:01:46) COMMON    : sendUdpMessageSock UDP sendto(192.168.1.20) Send-Q=175744 traffictable=12
...

leemoore1966
Posts: 25
Joined: Sat Aug 29, 2015 2:39 pm

Re: UDP Unicast Tx Buffer not flushing

Sat Dec 16, 2017 12:55 pm

A further update on this

Something is happening periodically which I can observe easily.
it would appear that at every 120 second interval - the RPI stops sending UDP packets for about 3-4 seconds

I have a test setup, whereby I am sending UDP messages from RPi and listening on a WiFi connected ubuntu PC
I am guessing something is possibly going on in the kernel every 120 seconds which is interfering ?

Impossible to know really, any ideas welcome
Thx
Lee

User avatar
allfox
Posts: 452
Joined: Sat Jun 22, 2013 1:36 pm
Location: Guang Dong, China

Re: UDP Unicast Tx Buffer not flushing

Sat Dec 16, 2017 2:08 pm

Are you using the Pi 3 on-board WiFi?

Maybe half a year ago, I used it for samba and hostapd. And an Amazon Kindle Fire to connect. The samba TCP connection would stall soon. I remember it's very reproducible, just open a JPEG preview via samba and it's dead. WiFi signal is full, no error message on both ends, just no data coming through, end with timeout.

I'm now using an USB dongle, which has AR7010+AR9280 chipset. I know the AR9271 would work either.

Don't know if it's the same thing. Maybe you could try another WiFi device. A real WiFi AP device connected to Pi Ethernet port should work too.

leemoore1966
Posts: 25
Joined: Sat Aug 29, 2015 2:39 pm

Re: UDP Unicast Tx Buffer not flushing

Sat Dec 16, 2017 2:20 pm

Are you using the Pi 3 on-board WiFi?
Yes that is correct.
I am not totally convinced it is connected to the on-board WiFi, because if I recall correctly, I had the same behavior with an RT5370

Although I will try a test going through eth0 to see if it is reproducible on that interface

Thx
Lee

Return to “General discussion”