Re: [lwip-users] netconn_write blocking

[Andrew Lukefahr]

Hi,
Ok, first let me describe in a little more detail how my system works...
There are two threads, the first blocks listening for new connections,
and when it gets one, it adds the *netconn to a linked list.  Then a
second thread generates some data, and iterates through the linked list,
sending the same packet to every conn on the list. When any of the
netconn_send API calls return <0, the connection is closed, and deleted
from the linked list.

          { //send
              int ret = 0;
              struct node * i = sockets_list->head;
              while (i != NULL){
                  if ((ret = netconn_write( ( struct netconn *) i->data
, outputBuffer,
                                    (u16_t) strlen(outputBuffer),
NETCONN_COPY)) < 0 ){
                     
                      debug_printk("Closing connection\r\n");
                     
                      netconn_close( (struct netconn*) i->data);
                     
                      netconn_delete( (struct netconn * ) i->data);
                     
                      delete_node( sockets_list, i);
                     
                  } //if
                  i = i->next;
              } //while
          } //send

I realize that this probably isn't the best way to write to sockets, as
if anything blocks, it stops sending data to all of the sockets.  This
is what I'm pretty sure is currently happening with netconn_write

Ok, next, this is what I get for my debug output when i have the
following in my lwipopts.h
...
#define DBG_MIN_LEVEL                     DBG_LEVEL_SERIOUS
#define DBG_TYPES_ON    ( API_LIB_DEBUG |\
                                            API_MSG_DEBUG | \
                                            )
#define API_LIB_DEBUG                   LWIP_DBG_ON
#define API_MSG_DEBUG                   LWIP_DBG_ON

Debug Output:
( I added the LWIP:\t to each line)
...
LWIP:     tcp_write(pcb=0x207e78, data=0x20574c, len=18, copy=1)
LWIP:     tcp_enqueue(pcb=0x207e78, arg=0x20574c, len=18, flags=0, co
LWIP:     tcp_enqueue: queuelen: 32
LWIP:     tcp_enqueue: too long queue 32 (max 32)
LWIP:     tcp_output: snd_wnd 1052, cwnd 128, wnd 128, effwnd 135, se
LWIP:     sys_timeout: 0x20877c msecs=100 h=0x114629 arg=0x0
LWIP:     tcpip_thread: PACKET 0x2085d0
LWIP:     smf calling h=0x114629(0x0)
LWIP:     sys_timeout: 0x20877c msecs=100 h=0x114629 arg=0x0
LWIP:     smf calling h=0x114629(0x0)
LWIP:     tcp_slowtmr: processing active pcb
LWIP:     sys_timeout: 0x20877c msecs=100 h=0x114629 arg=0x0
LWIP:     smf calling h=0x1146bd(0x0)
LWIP:     tcpip: ip_reass_tmr()
LWIP:     sys_timeout: 0x2087ac msecs=1000 h=0x1146bd arg=0x0
LWIP:     smf calling h=0x114629(0x0)
LWIP:     sys_timeout: 0x20877c msecs=100 h=0x114629 arg=0x0
LWIP:     smf calling h=0x114629(0x0)
LWIP:     tcp_slowtmr: processing active pcb
LWIP:     sys_timeout: 0x20877c msecs=100 h=0x114629 arg=0x0
LWIP:     smf calling h=0x114629(0x0)
LWIP:     sys_timeout: 0x20877c msecs=100 h=0x114629 arg=0x0
LWIP:     tcpip_thread: PACKET 0x2085d0
LWIP:     smf calling h=0x114629(0x0)
LWIP:     tcp_slowtmr: processing active pcb
LWIP:     sys_timeout: 0x20877c msecs=100 h=0x114629 arg=0x0
LWIP:     smf calling h=0x114629(0x0)
LWIP:     sys_timeout: 0x20877c msecs=100 h=0x114629 arg=0x0
LWIP:     smf calling h=0x114629(0x0)
LWIP:     tcp_slowtmr: processing active pcb
LWIP:     tcp_slowtmr: polling application
LWIP:     tcp_write(pcb=0x207e78, data=0x20574c, len=18, copy=1)
LWIP:     tcp_enqueue(pcb=0x207e78, arg=0x20574c, len=18, flags=0, co
LWIP:     tcp_enqueue: queuelen: 32
LWIP:     tcp_enqueue: too long queue 32 (max 32)
LWIP:     tcp_output: snd_wnd 1052, cwnd 128, wnd 128, effwnd 135, se
LWIP:     sys_timeout: 0x20877c msecs=100 h=0x114629 arg=0x0
LWIP:     smf calling h=0x114629(0x0)
LWIP:     sys_timeout: 0x20877c msecs=100 h=0x114629 arg=0x0
LWIP:     smf calling h=0x114629(0x0)
LWIP:     tcp_slowtmr: processing active pcb
LWIP:     sys_timeout: 0x20877c msecs=100 h=0x114629 arg=0x0
LWIP:     smf calling h=0x114629(0x0)
LWIP:     sys_timeout: 0x20877c msecs=100 h=0x114629 arg=0x0
LWIP:     smf calling h=0x114629(0x0)
LWIP:     tcp_slowtmr: processing active pcb
LWIP:     sys_timeout: 0x20877c msecs=100 h=0x114629 arg=0x0
LWIP:     smf calling h=0x1146bd(0x0)
LWIP:     tcpip: ip_reass_tmr()
LWIP:     sys_timeout: 0x2087ac msecs=1000 h=0x1146bd arg=0x0
LWIP:     smf calling h=0x114629(0x0)
LWIP:     sys_timeout: 0x20877c msecs=100 h=0x114629 arg=0x0
LWIP:     smf calling h=0x114629(0x0)
LWIP:     tcp_slowtmr: processing active pcb
LWIP:     sys_timeout: 0x20877c msecs=100 h=0x114629 arg=0x0
LWIP:     smf calling h=0x114629(0x0)
LWIP:     sys_timeout: 0x20877c msecs=100 h=0x114629 arg=0x0
LWIP:     smf calling h=0x114629(0x0)
LWIP:     tcp_slowtmr: processing active pcb
LWIP:     tcp_slowtmr: polling application
LWIP:     tcp_write(pcb=0x207e78, data=0x20574c, len=18, copy=1)
LWIP:     tcp_enqueue(pcb=0x207e78, arg=0x20574c, len=18, flags=0, co
LWIP:     tcp_enqueue: queuelen: 32
LWIP:     tcp_enqueue: too long queue 32 (max 32)
... etc...

So, tcp_enqueue is complaining because the queue is too long.  Will
netconn_write block until it can write the next segment in the queue? 

Ok, now the good news....
By setting the following:

#define TCP_MAXRTX              4
#define TCP_SYNMAXRTX           4
#define TCP_TMR_INTERVAL        100

I was able to cut the amount of time for a timeout down to like ~20
seconds.  This isn't great, as all of the other connections will be
without data for that ~20 seconds, and also, it seems like I'm setting
the number of times the packet can be retransmitted pretty low.  But
once the connection timed out, netconn_write returns, and the netconn is
deleted, and everything continues to operate normally. 

This is at best a flimsy fix, so if anyone has better ideas, please feel
free to send them my way. 

Thanks

- 
Andrew Lukefahr
address@hidden

Open Source, Open Minds

signature.asc
Description: OpenPGP digital signature