PPP authorisation over ISDN connection takes a lot of attempts before it succeeds - PPP

This is a discussion on PPP authorisation over ISDN connection takes a lot of attempts before it succeeds - PPP ; Hi, I'm using e-smith (Redhat 7.3) as an email-server and to share a connection to the internet.Unfortunately, creating the connection through ISDN to the ISP is highly unreliable and it often takes a lot (10-20) of dial-in attempts before the ...

+ Reply to Thread
Results 1 to 3 of 3

Thread: PPP authorisation over ISDN connection takes a lot of attempts before it succeeds

  1. PPP authorisation over ISDN connection takes a lot of attempts before it succeeds

    Hi,

    I'm using e-smith (Redhat 7.3) as an email-server and to share a connection
    to the internet.Unfortunately, creating the connection through ISDN to the
    ISP is highly unreliable and it often takes a lot (10-20) of dial-in
    attempts before the PPP authorisation succeeds.

    When I looked in the messages log I noticed that in the cases where the
    connection failed an extra "sent [1][LCP ConfReq" was sent (marked with
    *** below) to the ISP when it takes the ISP a bit longer to reply with a
    'ConfAck'. My guess is that this gets client and server 'out of sync' or
    something.

    I've been reading through howto's and faq's and have been messing with
    "lcp-..." options but didn't find a solution for this problem.
    Hope there's anybody over here who can point me in the right direction...

    Thanks in advance,

    Aart

    Extract of the logfile:

    Succesfull attempt:
    ===================
    Sep 22 12:43:38 csesrv ipppd[1155]: Local number: , Remote number:
    0123456789, Type: outgoing
    Sep 22 12:43:38 csesrv ipppd[1155]: PHASE_WAIT -> PHASE_ESTABLISHED,
    ifunit: 0, linkunit: 1, fd: 8
    Sep 22 12:43:38 csesrv ipppd[1155]: sent [1][LCP ConfReq id=0x1
    ]
    Sep 22 12:43:38 csesrv ipppd[1155]: rcvd [1][LCP ConfReq id=0x2
    ]
    Sep 22 12:43:38 csesrv ipppd[1155]: sent [1][LCP ConfAck id=0x2
    ]
    Sep 22 12:43:38 csesrv ipppd[1155]: rcvd [1][LCP ConfAck id=0x1
    ]
    Sep 22 12:43:38 csesrv ipppd[1155]: lcp layer is UP
    Sep 22 12:43:38 csesrv ipppd[1155]: sent [1][PAP AuthReq id=0x3b
    user="ausername" password not logged for security reasons! Use '+pwlog'
    option to enable full logging.]
    Sep 22 12:43:38 csesrv ipppd[1155]: rcvd [1][PAP AuthAck id=0x3bmsg=""]

    Failed attempt:
    ===============
    Sep 22 10:34:28 csesrv ipppd[1155]: Local number: , Remote number:
    0123456789, Type: outgoing
    Sep 22 10:34:28 csesrv ipppd[1155]: PHASE_WAIT -> PHASE_ESTABLISHED,
    ifunit: 0, linkunit: 1, fd: 8
    Sep 22 10:34:28 csesrv ipppd[1155]: sent [1][LCP ConfReq id=0x1
    ]
    Sep 22 10:34:28 csesrv ipppd[1155]: rcvd [1][LCP ConfReq id=0x3f
    ]
    Sep 22 10:34:28 csesrv ipppd[1155]: sent [1][LCP ConfAck id=0x3f
    ]
    *** Sep 22 10:34:31 csesrv ipppd[1155]: sent [1][LCP ConfReq id=0x1 1500> ]
    Sep 22 10:34:31 csesrv ipppd[1155]: rcvd [1][LCP ConfAck id=0x1
    ]
    Sep 22 10:34:31 csesrv ipppd[1155]: lcp layer is UP
    Sep 22 10:34:31 csesrv ipppd[1155]: sent [1][PAP AuthReq id=0xe1
    user="ausername" password not logged for security reasons! Use '+pwlog'
    option to enable full logging.]
    Sep 22 10:34:31 csesrv ipppd[1155]: rcvd [1][LCP ConfReq id=0x40
    ]
    Sep 22 10:34:31 csesrv ipppd[1155]: sent [1][LCP ConfReq id=0x2
    ]
    Sep 22 10:34:31 csesrv ipppd[1155]: sent [1][LCP ConfAck id=0x40
    ]
    Sep 22 10:34:31 csesrv ipppd[1155]: rcvd [1][LCP ConfAck id=0x1
    ]
    Sep 22 10:34:34 csesrv ipppd[1155]: sent [1][LCP ConfReq id=0x2
    ]
    Sep 22 10:34:34 csesrv ipppd[1155]: rcvd [1][LCP ConfAck id=0x2
    ]
    Sep 22 10:34:34 csesrv ipppd[1155]: lcp layer is UP
    Sep 22 10:34:34 csesrv ipppd[1155]: sent [1][PAP AuthReq id=0xe2
    user="ausername" password not logged for security reasons! Use '+pwlog'
    option to enable full logging.]
    ....
    ....
    Sep 22 10:34:37 csesrv diald[1205]: connector: Timed out

  2. Re: PPP authorisation over ISDN connection takes a lot of attempts before it succeeds

    Aart Molenaar writes:
    > Failed attempt:

    [...]
    > Sep 22 10:34:28 csesrv ipppd[1155]: sent [1][LCP ConfReq id=0x1
    > ]
    > Sep 22 10:34:28 csesrv ipppd[1155]: rcvd [1][LCP ConfReq id=0x3f
    > ]
    > Sep 22 10:34:28 csesrv ipppd[1155]: sent [1][LCP ConfAck id=0x3f
    > ]
    > *** Sep 22 10:34:31 csesrv ipppd[1155]: sent [1][LCP ConfReq id=0x1 > 1500> ]


    There are two possible cases to consider at this point:

    1. The peer didn't see your initial LCP Configure-Request,
    and that's why it didn't ack. In that case, he was stuck
    in AckRcvd state and should respond with a Configure-Ack
    to your new request, and transition to Opened state.

    2. The peer saw your initial LCP Configure-Request, but the
    ack got lost on the way back. In that case, he's now in
    Opened state, and should respond to your new request with
    a brand new Configure-Request followed by Configure-Ack.

    > Sep 22 10:34:31 csesrv ipppd[1155]: rcvd [1][LCP ConfAck id=0x1
    > ]


    This implies that case (1) above was true, otherwise, the first
    message out would be "LCP ConfReq." The peer should now be in Opened
    state.

    > Sep 22 10:34:31 csesrv ipppd[1155]: rcvd [1][LCP ConfReq id=0x40
    > ]


    Oops. That shouldn't have happened. Either:

    a. The peer has decided that he wants to renegotiate
    something about the connection.

    b. Case (2) actually happened but, due to a comedy of errors
    (and a violation of RFCs) the packets were reordered in
    flight.

    c. The peer is a moron.

    I'd vote for (c). Ask the ISP to upgrade that equipment, find a new
    ISP, or just live with the problem. But then things get even worse:

    > Sep 22 10:34:31 csesrv ipppd[1155]: sent [1][LCP ConfReq id=0x2
    > ]
    > Sep 22 10:34:31 csesrv ipppd[1155]: sent [1][LCP ConfAck id=0x40
    > ]


    This part is right. You were in Opened state, and you responded
    correctly to the unexpected LCP Configure-Request from the peer. You
    should now be in AckSent state.

    > Sep 22 10:34:31 csesrv ipppd[1155]: rcvd [1][LCP ConfAck id=0x1
    > ]


    You get back an LCP Configure-Ack. If your side were guilt-free,
    you'd be in Opened state. But then this unexpected thing happens:

    > Sep 22 10:34:34 csesrv ipppd[1155]: sent [1][LCP ConfReq id=0x2
    > ]


    Oops again. You should never have sent that. Your side is also
    broken.

    I don't know much about the 'ipppd' variant. It looks very different
    from normal pppd, though, and (at a guess) seems to violate the RFCs
    with respect to when the restart timer is running. You *might* get
    away with a "silent" option (if it has such a thing) -- forcing the
    ISP to send the first LCP Configure-Request. But that seems really
    wrong.

    --
    James Carlson, Solaris Networking
    Sun Microsystems / 1 Network Drive 71.234W Vox +1 781 442 2084
    MS UBUR02-212 / Burlington MA 01803-2757 42.497N Fax +1 781 442 1677

  3. Re: PPP authorisation over ISDN connection takes a lot of attempts before it succeeds

    I tried the "silent" option but this didn't help. Your comments didn't
    leave me much hope that this problem would be easy to solve so I followed
    your advice and switched to another ISP. Connecting is now trouble-free.
    Thank you very much for your quick reply and for taking the trouble to look
    at my logdetails.

    Aart

+ Reply to Thread