buglwIP - A Lightweight TCP/IP stack - Bugs: bug #30561, Failed assert in...


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

bug #30561: Failed assert in tcp_in.c:tcp_receive()

Submitted by:  Iordan Neshev <iordan_neshev>
Submitted on:  Tue 27 Jul 2010 10:27:06 AM UTC  
Category:  None Severity:  3 - Normal
Item Group:  Faulty Behaviour Status:  Fixed
Privacy:  Public Assigned to:  Simon Goldschmidt <goldsimon>
Open/Closed:  Closed Planned Release:  None
lwIP version:  CVS Head

( Jump to the original submission)

Sun 03 Oct 2010 05:11:07 PM UTC, comment #8: 

Great to hear it works!

Simon Goldschmidt <goldsimon>
Project AdministratorIn charge of this item.
Sat 02 Oct 2010 11:08:49 PM UTC, comment #7: 

I finally found the time to check this issue. I did the same test again and tried the proposed solution - to remove the call to tcp_pcb_purge(). And this time it worked! The assertion does not fire any more. Probably in the last two months there was some change in the lwip's source which solves the problem. Unfortunately I can not tell exactly which one.
Anyway, I think this bug can be closed now.

Simon, thank you very much for the help!

Iordan Neshev <iordan_neshev>
Wed 11 Aug 2010 07:11:14 AM UTC, comment #6: 

>What does 'did not help' mean? Do you still get the failing
>assert or is it just the data not coming through like you
>expect it to?

The assert failed. Unfortunately I still can't find the time to investigate this. It's highly unlike to find it till the end of the month. If there are no other bugs left, close this one. I did not see any harmful consequences anyway. I don't want an invalid bug entry to stop the release of lwip 1.4.

Iordan Neshev <iordan_neshev>
Tue 10 Aug 2010 08:19:01 PM UTC, comment #5: 

What does 'did not help' mean? Do you still get the failing assert or is it just the data not coming through like you expect it to?

To me, the assertion:
if (pcb->snd_queuelen != 0) {
LWIP_ASSERT("tcp_receive: valid queue length", pcb->unacked != NULL ||pcb->unsent != NULL);

is very much likely to be provoked by calling tcp_pcb_purge as that functions sets unacked and unsent to NULL without even touching snd_queuelen.

Simon Goldschmidt <goldsimon>
Project AdministratorIn charge of this item.
Tue 03 Aug 2010 10:00:40 AM UTC, comment #4: 

I removed the call of tcp_pcb_purge() from the application but unfortunately it did not help. I made just a quick test because right now I can not concentrate on this issue. I had to switch to another task. Probably till the end of the next week I will be able to dig more. If till then this is the only bug entry left, (probably) you'd better close it and release lwip 1.4.

I took a quick look at bug #30577. There is something that I don't understand, I need more than (the available at this moment) 5 minutes. I'll test the proposed patch too and report.

Thank you for the support.

Iordan Neshev <iordan_neshev>
Sat 31 Jul 2010 06:03:14 AM UTC, comment #3: 

Any more input on this? If not, I'll mark this as invalid (because user code calls tcp_pcb_purge()).

Simon Goldschmidt <goldsimon>
Project AdministratorIn charge of this item.
Wed 28 Jul 2010 04:56:10 PM UTC, comment #2: 

I've added a new bug entry (bug #30577) for the 'refused_data' issue, hoping that the rest of this bug resolves as 'invalid' once you tried to not call 'tcp_pcb_purge' from your application code.

Simon Goldschmidt <goldsimon>
Project AdministratorIn charge of this item.
Tue 27 Jul 2010 12:09:49 PM UTC, comment #1: 

I might be wrong, but I guess your problem is the (invalid!) call to tcp_pcb_purge(): this is an internal function, which is neither documented for applications (or is it?) nor supported that way.

This is reflected in 1.4.0 RC1 by moving its declaration to tcp_impl.h, which should not be included by applications. I know that this wasn't quite optimal up to 1.3.2 (since the tcp.h file was quite large and didn't really differ between API and internal delcarations).

Could you check if the assert still fires when removing that call?

As to the 'refused_data' part, this is a different bug, but I guess you are right: when refusing 'refused_data' again, the input packet should only be dropped if it contains data.

Simon Goldschmidt <goldsimon>
Project AdministratorIn charge of this item.
Tue 27 Jul 2010 10:27:06 AM UTC, original submission:  

This assertion failed while I was closing a connection:

if (pcb->snd_queuelen != 0) {
LWIP_ASSERT("tcp_receive: valid queue length", pcb->unacked != NULL ||pcb->unsent != NULL);

This is what I do:
1. I send the HEADER of a short POST request to a HTTP server.

2. I got TCP_EVENT_SENT for this request.

3. I put the application in Idle state for 5 sec.

4. While the application is idle (these 5 seconds) the server sends back a long answer (the HTTP HEADER with Error 404), which I was constantly refusing just for the test (by returning ERR_MEM in the receive callback).

5. Because the application is simple at this stage, it does not bother to check if the server rejects the POST request. It assumes that it can send the BODY because step 2 was successful.

6. I send the BODY (which is 20 bytes long) and wait for the server's TCP/IP stack to ACK it.

7. I would expect to get this ACK (TCP_EVENT_SENT to fire) in a short time, but I don't. Instead lwip is still calling the recv callback, desperately trying to deliver the HEADER. The application keeps refusing it.

8. After e certain timeout the application gives up waiting for the BODY to be ACKed. (During all this time the input data is refused)

9. Now I clear the flag that forces the recv callback to refuse the data. Then I put the application in idle state for 5 seconds. Now the application "consumes" the HEADER which lwip was trying to deliver so many times.

10. Now the application is idle again for a couple of seconds. Nothing happens. I would expect to get the ACK for the BODY of the request.

11. I try to close the connection (from within the poll handler if it matters) using the following code:

err = tcp_close();
//tcp_close returned ERR_OK

12. Now the application waits for the recv callback to be called with (p==NULL), which would indicate that the peer has closed the connection from its side.

13. At this moment the assertion fired. Later I split it in two ASSERTs to check which condition was not satisfied. It turned out that they both fail. Both unacked and unsent were NULL.

14. Now I finally got the ACK for the BODY I sent at step 6.

15. I keep waiting for the recv callback to fire with p==NULL, but this did not happen. The temporary flag for refusing is already cleared, so I am not skipping this code, as someone may suspect.

16. After a certain timeout I give up waiting for p==NULL and the connection is aborted.

I know that such stupid application must not be released in the final product (and it will not be), but this showed that lwip is not behaving properly:

 - At step 7 TCP_EVENT_SENT (probably) should be called. The presence of refused data in the input direction should not keep the application away from the fact that the peer has ACKed  the output data.

 - Even if the upper statement is not correct, at step 10, when there is no more refused data, TCP_EVENT_SENT should fire. There is something that does not allow lwip to do this. After calling tcp_pcb_purge() and tcp_close() lwip is able to do what it had to do.

 - As a consequence (?) of what happened till now, the recv callback with p==NULL is not called.

I will be able to investigate this further after a couple of days. I really hope that the fault is mine. Otherwise this problem will delay a bit the release of lwip 1.4.

If the cost for fixing this (as code size) is too high, I'm OK to live with such limitation, as long as we are aware of it.

Iordan Neshev <iordan_neshev>


No files currently attached


Depends on the following items: None found

Items that depend on this one: None found


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

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

    Only logged-in users can vote.




    Follow 5 latest changes.

    Date Changed by Updated Field Previous Value => Replaced by
    2010-10-03 goldsimon StatusNone => Fixed
        Assigned toNone => goldsimon
        Open/ClosedOpen => Closed
    2010-09-16 kieranm StatusNeed Info => None
    2010-07-28 goldsimon StatusNone => Need Info

    Back to the top

    Powered by Savane 3.5