buglwIP - A Lightweight TCP/IP stack - Bugs: bug #24212, Deadlocked tcp_retransmit due to...

 
 

You are not allowed to post comments on this tracker with your current authentication level.

bug #24212: Deadlocked tcp_retransmit due to exceeded pcb->cwnd

Submitted by:  Simon Goldschmidt <goldsimon>
Submitted on:  Sat 06 Sep 2008 08:44:51 AM UTC  
Votes:  20  
 
Category:  TCP Severity:  4 - Important
Item Group:  None Status:  Fixed
Privacy:  Public Assigned to:  Simon Goldschmidt <goldsimon>
Open/Closed:  Closed Planned Release:  None
lwIP version:  1.3.0

( Jump to the original submission)

Sun 26 Apr 2009 12:28:05 PM UTC, comment #14: 

I've had a quick look over what Oleg suggested in comment #3 and checked it in, since it seems to work.

Simon Goldschmidt <goldsimon>
Project AdministratorIn charge of this item.
Thu 23 Apr 2009 07:27:08 AM UTC, comment #13: 

I've been running Oleg's code since 2008-Nov, and lwip still works well in my device. So it seems it has good (or at least no bad) impact for our scenarios.

Tamas Somogyi <tsomogyi>
Wed 22 Apr 2009 07:26:27 PM UTC, comment #12: 

I'd also prefer sort on insert. The code in comment #3 looks OK to me, the only question is how to test it without completing task #7930... I'm not in a position to really test the impact of this change :-(

Simon Goldschmidt <goldsimon>
Project AdministratorIn charge of this item.
Wed 22 Apr 2009 08:13:19 AM UTC, comment #11: 

I like Oleg's approach of inserting the packet in the right place rather than having to sort the queue later.

Kieran Mansley <kieranm>
Project Member
Tue 21 Apr 2009 08:21:57 PM UTC, comment #10: 

Kieran, what's your opinion on this? In my opinion, sorting the queues is the right thing to do, although it's not me who's the expert on lwIP's TCP code...

Simon Goldschmidt <goldsimon>
Project AdministratorIn charge of this item.
Fri 03 Apr 2009 10:53:39 AM UTC, comment #9: 

Just to recap, this bug is concerning badly order tcp queues, for which Oleg suggests a fix in comment #3

Kieran Mansley <kieranm>
Project Member
Thu 27 Nov 2008 12:06:38 PM UTC, comment #8: 

It seems that my problem is not related to this issue indeed, but to bug #20511, which is about Zero Window Probe. More explanation follow in that bugtrack soon.

Tamas Somogyi <tsomogyi>
Fri 21 Nov 2008 04:15:38 PM UTC, comment #7: 

The person most likely to investigate is probably me, and I'm snowed under with other work at the moment.  If you need a quick solution, you'll have to investigate further yourself, much like the case for the start of this bug report.  I appreciate that this is not ideal, but I think it better that I say that I don't have time, rather than claim I do and then do nothing!

Kieran Mansley <kieranm>
Project Member
Fri 21 Nov 2008 04:11:29 PM UTC, comment #6: 

Perhaps a different bug indeed, but very close to it: must be something with retransmission and acknowledge handling. What to do now: shall I expect somebody among LwIP developers to investigate or I'd rather open a new bug track?

Tamas Somogyi <tsomogyi>
Fri 21 Nov 2008 10:59:18 AM UTC, comment #5: 

If fully sorting the list doesn't solve your problem, this is a different bug.

Kieran Mansley <kieranm>
Project Member
Fri 21 Nov 2008 10:42:16 AM UTC, comment #4: 

Hi,

I have similar problem around the retransmission.

The scenario is the following:
I have a socket wherein my server device sends message to a client in every 200ms and the client acknowledges the received packets. See also the attached log ‘9700-9746.1.3.0.pcap’. But sometimes I get [TCP Previous segment lost] (frame 22), which quickly leads to some [TCP Retransmission], [TCP Dup ACK], and finally the socket shuts down (around frame 43). Note also that there’s always a [TCP Window update] around when the crash occurs.

Symptoms:
Parallel to retransmitting the packages, snd_queuelen of the related pcb goes from the normal level (0-7 in my application) step by step up to 70-80 in 5-6 seconds till the socket closes. I had to increase the default of TCP_SND_QUEUELEN (=64) to double size, otherwise my application together with LwIP wouldn’t survive, but this is just a symptomatic treatment. Moreover lwip_send blocks the calling thread even if I set MSG_DONTWAIT, because tcpip_apimsg is locked until the packet has been sent.

Remarks:
1) Sometimes it survives the [TCP Previous segment lost] event, after 5-10 retransmissions it runs well again, see also the log ‘750-850.1.3.0.pcap’. Perhaps that’s because no TCP window update at that point.
2) I get this error sometimes in 5-10 minutes, sometimes only in 2-3 hours. But in slower 10Mbit/s network it usually comes in 5-10 minutes.
3) My platform is based on Texas Instruments TMS320C6711 DSP and Critical Link’s MityDSP board using LwIP 1.3.0 stable, but the problem comes also with the latest code. It is interesting that using earlier version of LwIP doesn’t crash: after some retransmission it runs again well without closing the socket. So it looks like a regression in LwIP.

Unfortunately applying Hans Jörg’s and/or Oleg’s fixes related to reorganizing pcb->unsent and pcb->unacked lists still producing the same error. I tried with some modifications as well: fully sorting in tcp_reorder_segments not just bringing the smallest seq forward or sorting unacked list in tcp_rexmit – but I get the error even faster.

Questions:
1. What causes [TCP Previous segment lost] event? I can imagine some transient network failure or maybe if packet sniffer misses one or more packets – but would be more interesting if LwIP generated wrong sequence number in TCP header…
2. For me it seems that on retransmission, the “handshake” of acknowledging the retransmitted packages cannot be established with the peer properly. Could you please give me some explanation how should it work and why the order of unsent and unacknowledged packets are important?
3. Can you please give me some advise what to do to fix or to work around this bug? In my application a transient problem or a few delayed or lost packages is not a big problem unlike closing the sockets or freezing the stack for seconds.
4. Can you please let me know whether somebody is working on this bug? If so, can you give an estimated time of fix?
As this is a job stopper issue for my project, I’m going to investigate, but I’m not familiar with internals of TCP, therefore I would appreciate any help or suggestion.

Best regards, Tamas

(file #16889, file #16890)

Tamas Somogyi <tsomogyi>
Mon 22 Sep 2008 04:57:17 PM UTC, comment #3: 

In time I tested fastretransmit I had the same problem with unordered queues.
Instead of tcp_reorder_segments() in my modified implementation
I have used insert fragment in rite place.
1)=================
void
tcp_rexmit(struct tcp_pcb *pcb)
{
  if (pcb->unacked == NULL) {
    return;
  }

  /* Move the first unacked segment to the unsent queue */
  /* keep unsent queue sorted */
  struct tcp_seg* seg_to_move = pcb->unacked;
  pcb->unacked = seg_to_move->next;

  struct tcp_seg** ppCurSeg = &(pcb->unsent);
  while (*ppCurSeg &&
         TCP_SEQ_LT(ntohl((*ppCurSeg)->tcphdr->seqno), ntohl(seg_to_move->tcphdr->seqno))) {
    ppCurSeg = &( (*ppCurSeg)->mpNext );
  }
  seg_to_move->mpNext = (*ppCurSeg);
  (*ppCurSeg) = seg_to_move;

 

  pcb->snd_nxt = ntohl(pcb->unsent->tcphdr->seqno);
....

2)=================
in tcp_output()
............
        /* In the case of fast retransmit, the packet should not go to the tail
         * of the unacked queue, but rather at the head. We need to check for
         * this case. -STJ Jul 27, 2004 */
        if (TCP_SEQ_LT(ntohl(seg->tcphdr->seqno), ntohl(useg->tcphdr->seqno))){
          /* add segment to head of unacked list */
          /* keep unacked queue sorted */
          struct tcp_seg* seg_to_move = seg;
          struct tcp_seg** ppCurSeg = &(pcb->unacked);
          while (*ppCurSeg &&
                 TCP_SEQ_LT(ntohl((*ppCurSeg)->tcphdr->seqno), ntohl(seg_to_move->tcphdr->seqno))) {
            ppCurSeg = &( (*ppCurSeg)->next );
          }
          seg_to_move->next = (*ppCurSeg);
          (*ppCurSeg) = seg_to_move;
        } else {
.........

Oleg Tyshev <olegreen>
Sat 06 Sep 2008 08:57:37 AM UTC, comment #2: 

tcp_output not sending because of (tcp_input_pcb == pcb) is clearly a problem, but could the nagel algorithm (which was introduced in 1.3.0) also be a problem here? Since it wouldn't cause problems without the (tcp_input_pcb == pcb) problem, I think it's not the cause of this bug.

On the other hand, (forgive me for not being too familiar with the tcp code of lwIP), what would happen if fast-retransmit of 10085 succeeded, would the unacked queue become unacked->11453->12818->14183->10085 ??

Finally, to detect other problems in this area, it might be a good idea to include (debug-only-) code to check these lists are sorted. This way, we don't introduce the overhead of Hans-Joerg's quick fix while (for tests) still being able to check the queues to find other bugs.

Simon Goldschmidt <goldsimon>
Project AdministratorIn charge of this item.
Sat 06 Sep 2008 08:48:46 AM UTC, comment #1: 

And a reply from Kieran:

> > Hi there
> >
> > Kieran asked me to do further investigations considering the topic
> > "Deadlocked tcp_retransmit due to exceeded pcb->cwnd" (see
> > http://lists.gnu.org/archive/html/lwip-users/2008-07/msg00098.html).


Thanks for taking the time to produce such a detailed and helpful
analysis.

> > 9. We get the third dupack for 10085. According to RFC2581 we shall
> > start a fast retransmission now
> > 10. For fast retransmission tcp_process() calls tcp_receive() calls
> > tcp_rexmit() calls tcp_output()
> > 11. Cause tcp_output() was invoked by an initial tcp_input() it bailes
> > out on
> >     if (tcp_input_pcb == pcb)
> >     ==> !!! This violates RFC2581 IMHO !!!


Yes, that's a problem.  We'll need to fix that somehow.

> > 12. But tcp_rexmit() already tinkered our queues by placing the first
> > unacked segment to the
> >     unsent queue.
> >     unsent->10085
> >     unacked->11453->12818->14183
> > 13. The next few ouput attempts bail out in tcp_output() due to the
> > nagle algorith
> >     (tcp_do_output_nagle()). Thus nothing more hapens till a
> > retransmission timeout occurs
> > 14. tcp_slowtmr() requires a retransmission (pcb->rtime >= pcb->rto).
> > This shrinks down the
> >     congestion window to the maximum segment size (1390 in my case).
> >     BTW: A retransmission is triggered by segment 14183 and not by
> > 10085 in this case
> >     which is an aftereffect of the underlying bug IMHO.
> > 15. tcp_slowtmr() calls tcp_rexmit_rto(). The rto function moves all
> > unacked segments to the head
> >     of the unsent queue. This is final step causing the deadlock in
> > tcp_output() cause the
> >     smallest sequence number is now at the end of the queue.
> >     Unsent->11453->12818->14183->10085.


And that looks to be the fundamental cause of this bug. 

> > I needed a quick fix for our project and therefore I reordered the
> > queue in tcp_output before the
> > While loop in tcp_output. However this is just a quick fix to fight
> > the symptoms. Therefore I ask
> > for other suggestions or perhaps a patch.


Your solution isn't that bad, other than the amount of CPU required to
sort the queue.  I'll try and find some time to look at this though and
come up with something better.  Other people's suggestions are always
welcome though as time is often in short supply!

If there's a bug open for this, could you add these details to the bug.
If there's no open bug, could you open one!

Thanks

Kieran

Simon Goldschmidt <goldsimon>
Project AdministratorIn charge of this item.
Sat 06 Sep 2008 08:44:51 AM UTC, original submission:  

Hans-Joerg Wagner found this, posted on lwip-users:

Hi there

Kieran asked me to do further investigations considering the topic "Deadlocked tcp_retransmit due to exceeded pcb->cwnd" (see http://lists.gnu.org/archive/html/lwip-users/2008-07/msg00098.html).

With some "segment loss emulation" code I was able to reproduce the deadlock frequently.

My summary first:
It is not a high ACK loss problem. The congestion window test in tcp_output() fails, cause the unacked queue gets misordered in the situation I will further describe. This is a severe bug in my opinion and I have no idea how to solve it (despite I wrote a workaround, but that's not a properly styled solution). I could imagine that some ghost like troubles of other lwip users are caused by this bug too.

The "segment loss emulation"
To gulp only one segment is not sufficient to reproduce the problem frequently. Therefore I decided to gulp the first retransmission of every 10th segment too. And here we are:

/* begin code snippet */

static void
tcp_output_segment(struct tcp_seg seg, struct tcp_pcb pcb)
{

    //... Some statements ...

    packets_sent++;
    if ((packets_sent % 10) == 0)
    {
      //we enter here on every 10th segment and gulp it
        //(we omit to call ip_output()
        //we keep the sequence number of the gulped segment
        kept_seqno = seg->tcphdr->seqno;
    }
    else if (kept_seqno == seg->tcphdr->seqno)
    {
        //if the gulped segment gets retransmitted the first
        //time we gulp it once again.
        kept_seqno = 0;
    }
    else {
      //in every other case we do normal output
      ip_output(seg->p, &(pcb->local_ip), &(pcb->remote_ip), pcb->ttl, pcb->tos,
      IP_PROTO_TCP);
    }

    // ... Some statements ...
}

/* end of code snippet */

And this is whats happening on the "ether". In my queue representation I use the sequence number of the segments (not tcp_seg pointers). The sequence numbers are given from the last traces I made on our GPRS system.

1. Segment 8720:10085 was the last acknowledged segment from our gprs remote peer.
2. Segments 10085 to 14183 get enqueued by the local application the unsent queue is as follows:
   unsent->10085->11453->12818->14183.
3. Segment 10085 should be the next "in-sequence" to be sent, hovever the gulp
   mechanism of our local peer emulates a segment loss. The queues are as follows:
   unsent->11453->12818->14183
   unacked->10085.
4. Due to the available congestion window (cwnd) segment 11453 is sent (not gulped).
   unsent->12818->14183
   unacked->10085->11453
5. Due to the available congestion window (cwnd) segment 12818 is sent (not gulped).
   Unsent->14183
   unacked->10085->11453->12818
6. Due to the available congestion window (cwnd) segment 14183 is sent (not gulped).
   Unsent->empty
   unacked->10085->11453->12818->14183
7. Due to high round trip time in the gprs network we get the first dupack for
   segment 10085 from our remote peer
8. We get the second dupack for 10085
9. We get the third dupack for 10085. According to RFC2581 we shall start a fast retransmission now
10. For fast retransmission tcp_process() calls tcp_receive() calls tcp_rexmit() calls tcp_output()
11. Cause tcp_output() was invoked by an initial tcp_input() it bailes out on
    if (tcp_input_pcb == pcb)
    ==> !!! This violates RFC2581 IMHO !!!
12. But tcp_rexmit() already tinkered our queues by placing the first unacked segment to the
    unsent queue.
    unsent->10085
    unacked->11453->12818->14183
13. The next few ouput attempts bail out in tcp_output() due to the nagle algorith
    (tcp_do_output_nagle()). Thus nothing more hapens till a retransmission timeout occurs
14. tcp_slowtmr() requires a retransmission (pcb->rtime >= pcb->rto). This shrinks down the
    congestion window to the maximum segment size (1390 in my case).
    BTW: A retransmission is triggered by segment 14183 and not by 10085 in this case
    which is an aftereffect of the underlying bug IMHO.
15. tcp_slowtmr() calls tcp_rexmit_rto(). The rto function moves all unacked segments to the head
    of the unsent queue. This is final step causing the deadlock in tcp_output() cause the
    smallest sequence number is now at the end of the queue.
    Unsent->11453->12818->14183->10085.
16. tcp_ouput() is finally called. Instead of retransmitting 10085 it retransmits 11453 but fails
    on (seg->tcphdr->seqno - pcb->lastack + seg->len > wnd) cause
    seg->tcphdr->seqno = 11453
    pcb->lastack = 10085
    seg->len = 12818-11453 = 1365
    wnd = 1390
    11453-10085+1365=2733 which is greater than 1365 and therefor the test fails.
17. from now on we have a deadlock cause the queue stays misordered and tcp_output() always
    fails on this test.

I needed a quick fix for our project and therefore I reordered the queue in tcp_output before the
While loop in tcp_output. However this is just a quick fix to fight the symptoms. Therefore I ask
for other suggestions or perhaps a patch.

Remark: Perhaps this situation is hard to reproduce. Without the "segment loss emulation" the
Deadlock only occured by using very paricular memory (pbuf etc.) configurations and by using the gprs
Network with its high round trip delays and relays.

/* begin of quick fix */
  tcp_reorder_segments(&seg);

  while ((seg != NULL) && (seg->tcphdr->seqno - pcb->lastack + seg->len > wnd))
  {
     //.... Some statements ...//
  }

void tcp_reorder_segments(struct tcp_seg **seg_ptr)
{
    struct tcp_seg* left_seg;
    struct tcp_seg* right_seg;
    struct tcp_seg* head_seg;

    if (*seg_ptr == NULL)
    {
        return;
    }
    if ((*seg_ptr)->next == NULL)
    {
        return;
    }
    left_seg = *seg_ptr;
    head_seg = *seg_ptr;
    right_seg = (*seg_ptr)->next;
    while (right_seg != NULL)
    {
        if (right_seg->tcphdr->seqno < head_seg->tcphdr->seqno)
        {
            left_seg->next = right_seg->next;
            right_seg->next = head_seg;
            head_seg = right_seg;
            if (left_seg->next == NULL)
            {
                break;
            }
        }
        else
        {
            left_seg = right_seg;
        }
        right_seg = left_seg->next;
    }
    *seg_ptr = head_seg;
}

/* end of quick fix */

Kind regs
Hans-Joerg Wagner B.Sc.EE / PGDip. SE

Simon Goldschmidt <goldsimon>
Project AdministratorIn charge of this item.

 

Attached Files
file #16889:  750-850.1.3.0.pcap added by tsomogyi (15KiB - application/octet-stream)
file #16890:  9700-9746.1.3.0.pcap added by tsomogyi (6KiB - application/octet-stream)

 

Depends on the following items: None found

Items that depend on this one: None found

 

Carbon-Copy List
  • -email is unavailable- added by kieranm (Posted a comment)
  • -email is unavailable- added by tsomogyi (Updated the item)
  • -email is unavailable- added by tsomogyi
  • -email is unavailable- added by olegreen (Posted a comment)
  • -email is unavailable- added by goldsimon (Submitted the item)
  •  

    Do you think this task is very important?
    If so, you can add your encouragement to it.
    This task has 20 encouragements so far.

    Only logged-in users can vote.

     

     

     

    Follow 7 latest changes.

    Date Changed by Updated Field Previous Value => Replaced by
    2009-04-26 goldsimon StatusNone => Fixed
        Assigned toNone => goldsimon
        Open/ClosedOpen => Closed
    2009-04-03 kieranm Planned Release => 1.3.1
    2008-11-21 tsomogyi Attached File- => Added 750-850.1.3.0.pcap, #16889
        Attached File- => Added 9700-9746.1.3.0.pcap, #16890
        Carbon-Copy- => Added tsomogyi

    Back to the top


    Powered by Savane 3.5