buglwIP - A Lightweight TCP/IP stack - Bugs: bug #49285, PPP doesn't get connected anymore...

 
 

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

bug #49285: PPP doesn't get connected anymore after a link fail

Submitted by:  Marco <marcoe>
Submitted on:  Thu 06 Oct 2016 02:40:45 PM UTC  
 
Category:  PPP Severity:  3 - Normal
Item Group:  Faulty Behaviour Status:  Fixed
Privacy:  Public Assigned to:  Sylvain Rochet <gradator>
Open/Closed:  Closed Planned Release:  2.0.0
lwIP version:  Other

( Jump to the original submission)

Thu 10 Nov 2016 06:28:40 PM UTC, comment #20: 

Many thanks for the fix!

Marco

Marco <marcoe>
Sat 05 Nov 2016 09:10:29 PM UTC, comment #19: 

Fixed in commit dde55c6c0e.

Thanks for the report! :)

Sylvain

Sylvain Rochet <gradator>
Project MemberIn charge of this item.
Thu 20 Oct 2016 09:54:57 AM UTC, comment #18: 

Great!, thanks you very much for testing, time for the real fix then.

By the way, to answer various Simon's questions:

> That would mean removing the 'memset()' to parts of the ppp_pcb broke it?


Yes.

> Sylvain, in the commit message, you say that 'init' has been moved from 'connect' to first-init because one user wanted to change the default configuration.
> Do all the protocols handle init being called only once correctly?


They should :-)

> I'm lost in checking how the original pppd code does that...


Init is actually called only once.

Resetting is done in the resetci fsm callbacks, which is called when protocol send the first configure request frame, see fsm_sconfreq function.

> On the other hand, the remote side seems to terminate the connection, maybe because of too many IPCP reqs?


Not here.

> Or because the old address is now requested?


Yes!

> How did the retry look with commit "c751802fad4b0eda89965f575035cee318df29e7"?


It worked, because the giant memset cleared the IPCP wanted options struct.

IPCP is special regarding that, I suppose but I am not sure, because of a protocol design flaw on the old ADDRS protocol (which shouldn't be used anymore) wanted options struct need to be changed to improve the chance of converging. That's only a guess and I don't want to change that because it was clearly done on purpose in pppd.

Anyway, I am very well aware that removing the giant memset between retries may reveal bugs that were previously shadowed, but it was worth it to allow user configuration.

Sylvain

Sylvain Rochet <gradator>
Project MemberIn charge of this item.
Wed 19 Oct 2016 08:19:01 AM UTC, comment #17: 

Hi Sylvain, good news!
I've applied your patch to the fd096a5769976935251c2fb19f3e363f7dddb1ca commit and it seems to fix the issue.

Marco

Marco <marcoe>
Tue 18 Oct 2016 09:06:32 PM UTC, comment #16: 

Hello Marco,

Well, this is not as obvious as I previously thought, but I might have a clue of what could happen here, could you try this hotfix?

Sylvain

(file #38754)

Sylvain Rochet <gradator>
Project MemberIn charge of this item.
Tue 18 Oct 2016 07:33:32 AM UTC, comment #15: 

Hello Sylvain,
I've just tried with the fd096a5769976935251c2fb19f3e363f7dddb1ca commit and the case CI_ADDRS is never entered.
Also with the 33955c636d17bee230cde746a92e1cff11a7a177 commit (which for me is working well) this case is never entered.

I've also tried putting a breakpoint on the statement
switch (citype) { /* Check CI type */
and when it is executed the variable citype has always the value CI_ADDR.

Marco

Marco <marcoe>
Mon 17 Oct 2016 11:01:16 PM UTC, comment #14: 

Marco, could you check if you are entering into the "case CI_ADDRS" of the ipcp_reqci() function ?

Then could you check if you are executing the following statement of this "CI_ADDRS" case:
wo->ouraddr = ciaddr2; /* accept peer's idea */

Sylvain

Sylvain Rochet <gradator>
Project MemberIn charge of this item.
Wed 12 Oct 2016 12:51:56 PM UTC, comment #13: 

Hi Sylvain,
nice to here that from you!
Don't hesitate to contact me for any further information.

Thank you all for your support,
Marco

Marco <marcoe>
Wed 12 Oct 2016 12:14:43 PM UTC, comment #12: 

OK, I see the difference but from now on I'm lost but Sylvain should know more ;-)

Simon Goldschmidt <goldsimon>
Project Administrator
Wed 12 Oct 2016 12:14:07 PM UTC, comment #11: 

Marco, don't worry, the first trace you sent is perfectly fine for me to investigate.

The fix is pretty obvious anyway, the problem is not the fix here, it's the investigation to find out which component is wrong here, I have to dig into the IPCP RFC to write the right commit message about the issue :)

Will do that this week-end.

Sylvain

Sylvain Rochet <gradator>
Project MemberIn charge of this item.
Wed 12 Oct 2016 11:24:58 AM UTC, comment #10: 

Simon, here you can find attached the connection and reconnection log using the "c751802fad4b0eda89965f575035cee318df29e7" commit as you requested.

Regards,
Marco

(file #38710)

Marco <marcoe>
Wed 12 Oct 2016 10:49:58 AM UTC, comment #9: 

You are right: from the log it seems that the ESTABLISH phase is not reached when at first attempt the PPP goes up.
But, instead, it's reached after the SIM is removed while the connection is dropping (?) and also in the next faulty retries...

Marco <marcoe>
Wed 12 Oct 2016 10:40:54 AM UTC, comment #8: 

Sorry Simon but I've done tests with different versions to identify the last working commit and this has brought some confusion while reporting the results.
Since I can't remember clearly what version I was using when I wrote the first post, please ignore the phase sequence described here.

Please refer to the uploaded log (https://savannah.nongnu.org/support/download.php?file_id=38692) which is obtained with the RC2 version (fd096a5769976935251c2fb19f3e363f7dddb1ca).
The redefinition of the phase sequences has been done AFTER the RC2 release.

Marco

Marco <marcoe>
Wed 12 Oct 2016 10:33:30 AM UTC, comment #7: 

> I'm not the PPP expert though, just trying to get things clear here...


Reading throught the code, a lot has changed regarding initialization after the commit you mentioned.

Sylvain, in the commit message, you say that 'init' has been moved from 'connect' to first-init because one user wanted to change the default configuration. Do all the protocols handle init being called only once correctly? I'm lost in checking how the original pppd code does that...

On the other hand, the remote side seems to terminate the connection, maybe because of too many IPCP reqs? Or because the old address is now requested? How did the retry look with commit "c751802fad4b0eda89965f575035cee318df29e7"?

Simon Goldschmidt <goldsimon>
Project Administrator
Wed 12 Oct 2016 08:01:17 AM UTC, comment #6: 

As long as you correctly describe the version discrepancy, that's fine by me. So the numbers in your first post are RC2-based but the log is RC1-based? I must say this confuses me!

In this situation, it might be better to use the phase names though, to prevent such confusion: so you say you expect "INITIALIZE, ESTABLISH, NETWORK, RUNNING" but you get "INITIALIZE, ESTABLISH, NETWORK, ESTABLISH, DISCONNECT, DEAD" on reconnect.

I'm still missing phase "ESTABLISH" as 2nd phase in your logs then.

I'm not the PPP expert though, just trying to get things clear here...

Simon Goldschmidt <goldsimon>
Project Administrator
Wed 12 Oct 2016 07:42:26 AM UTC, comment #5: 

Simon, I think that the discrepance you pointed out is due to the fact that at some point the PPP_PHASE definitions have been changed, and probably when I wrote the first post I reported the phase sequence observed during a test with the latest commit version.

For generating the attached log I am sure that I have used the RC2 tagged commit (fd096a5769976935251c2fb19f3e363f7dddb1ca). In this commit the phase definitions are still the oldest so, for example, 8 is PPP_PHASE_RUNNING.

Tell me if it is better for you to have the log obtained with the RC2 version or with some newer commit.

Marco

Marco <marcoe>
Wed 12 Oct 2016 06:59:59 AM UTC, comment #4: 

Reading the log file, I cannot see the phases you mentioned in the initial post.

Instead, I see a "phase=8" line in the log. 8 should be PPP_PHASE_CALLBACK, which is only used in a "#if CBCP_SUPPORT" block and ppp_opts.h says "CURRENTLY NOT SUPPORTED! DO NOT SET!" about that code...

Simon Goldschmidt <goldsimon>
Project Administrator
Mon 10 Oct 2016 08:12:12 AM UTC, comment #3: 

Hello Sylvain,
thank you for your reply.
You can find attached the trace including some comments added in the form:

<<comment>>

Marco

(file #38692)

Marco <marcoe>
Sat 08 Oct 2016 09:41:54 PM UTC, comment #2: 

Marco, could you enable PPP_DEBUG, PRINTPKT_SUPPORT, and PPP_PROTOCOLNAME and provide us PPP traces for both first connect and reconnecting ?

At first sight, this is probably around a protocol which doesn't reset properly at lowerdown stage, the PPP trace might give a clue which one it is, which might reduce where to investigate.

After that, we will have to reset protocols in a clever manner before reconnecting until we found which one (or more) that have a reset issue.

Unfortunately, I can't reproduce the issue, I tested reconnecting scenarios in many cases when I worked on allowing user configuration, and everything worked. So you will have to dig into the issue, with my remote help :-)

Sylvain

Sylvain Rochet <gradator>
Project MemberIn charge of this item.
Fri 07 Oct 2016 05:48:57 AM UTC, comment #1: 

That would mean removing the 'memset()' to parts of the ppp_pcb broke it?

Simon Goldschmidt <goldsimon>
Project Administrator
Thu 06 Oct 2016 02:40:45 PM UTC, original submission:  

The use case is a PPP (PPPoS) connection to a GPRS modem.
We have developed our firmware and tested it using the lwip version STABLE-2_0_0_RC1 and all what we have tested was ok.
Now we have decided to upgrade to the RC2 version but we have found the following problem: if the GPRS link fails (for example, to have a easy reproducible condition, removing and then reinserting the SIM) the PPP can't reconnect.
When it's working the PHASE sequence is 3,6,9,10, while when it's failing the sequence is 3,6,9,6,12,0.

I've identified the last working commit as the one with commit hash = c751802fad4b0eda89965f575035cee318df29e7.

Marco <marcoe>

 

Attached Files
file #38710:  ppp2.log added by marcoe (8KiB - application/octet-stream)
file #38692:  ppp.log added by marcoe (12KiB - 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 gradator (Posted a comment)
  • -email is unavailable- added by goldsimon (Posted a comment)
  • -email is unavailable- added by marcoe (Submitted the item)
  • -email is unavailable- added by marcoe
  •  

    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 8 latest changes.

    Date Changed by Updated Field Previous Value => Replaced by
    2016-11-05 gradator StatusNone => Fixed
        Open/ClosedOpen => Closed
    2016-10-18 gradator Attached File- => Added 0001-ppp-hotfix-for-bug-49285-PPP-doesn-t-get-connected-a.patch, #38754
    2016-10-12 marcoe Attached File- => Added ppp2.log, #38710
    2016-10-11 gradator Planned ReleaseNone => 2.0.0
    2016-10-10 marcoe Attached File- => Added ppp.log, #38692
    2016-10-07 goldsimon Assigned toNone => gradator
    2016-10-06 marcoe Carbon-Copy- => Added mario@viara.eu

    Back to the top


    Powered by Savane 3.5