Re: Strange Pipex ADSL Problem

This sounds much like the problem I've seen again today. I watch the router
get sync and start to negotiate PPP.
It gets its IP address, goes active and then returns to the negotiating
state. I spent half a day trying to get some help from Pipex a
week back on this, but ended up moving back to my Modem and ICS instead of
the router. This works fine, but as Pete pointed out the PPP negotiation is
with the PC this time and is going to be different in the exchange sequence.
I asked Pipex if they had been making authentication
changes but they did not reply. The help they were able to give was limited,
and ended up blaming my US Robotics Router.
Next step to find out how to dump trace from my router. I suspect they are
breaking the PPP negotiation in a way that doesnt effect
Windows but does the router.

(E-Mail Removed) wrote:

> This sounds much like the problem I've seen again today. I watch the
> router get sync and start to negotiate PPP.
> It gets its IP address, goes active and then returns to the negotiating
> state. I spent half a day trying to get some help from Pipex a
> week back on this, but ended up moving back to my Modem and ICS instead of
> the router. This works fine, but as Pete pointed out the PPP negotiation
> is with the PC this time and is going to be different in the exchange
> sequence. I asked Pipex if they had been making authentication
> changes but they did not reply. The help they were able to give was
> limited, and ended up blaming my US Robotics Router.
> Next step to find out how to dump trace from my router. I suspect they are
> breaking the PPP negotiation in a way that doesnt effect
> Windows but does the router.

They have been changing the ppp for me.

Sometimes - recently and today I get a different remote IP - a 62 rather
than my usual 81.

When this happens it sets a mru of 32725 - it doesn't break things for me
but comes close.

Andy.

Managed to locate the trace command in the US Robotics 9003 router ('sndcp
ppptrace on' from a telnet session).

From a working session....
ADSL Link ESTABLISHED !
pppatalink : ppp0: Created in Dead state
ppp: FSM: Using "ppp0" as a transport
ppp: FSM: ppp0: State change Initial --> Closed

ppp: FSM: ppp0: State change Closed --> Req-Sent

ppp: FSM: ppp0: RecvConfigReq(116) state = Req-Sent
ppp: LCP : ppp0 : MRU[4] 1500
ppp: LCP : ppp0 : AUTHPROTO[5] 0xc223 (CHAP 0x05)
ppp: MAGICNUM[6] 0x47df38f6
ppp: FSM: ppp0: State change Req-Sent --> Ack-Sent

ppp: FSM: ppp0: RecvConfigAck(1) state = Ack-Sent
ppp: FSM: ppp0: State change Ack-Sent --> Opened

ppp: LCP : ppp0: LayerUp
pppatalink : link name ppp0, Authentication phase: mine = none
Chap Input: CHALLENGE (16 bytes from sms2.dsl.pipex.net)
ppp: Chap Output: RESPONSE ((E-Mail Removed))
Chap Input: SUCCESS (CHAP authentication success, unit 747)
ppp: FSM: Using "ppp0" as a transport
ppp: FSM: ppp0: State change Initial --> Closed

ppp: FSM: ppp0: State change Closed --> Req-Sent

ppp: FSM: ppp0: RecvConfigReq(138) state = Req-Sent
ppp: IPADDR[6]
ppp: FSM: ppp0: State change Req-Sent --> Ack-Sent

ppp: FSM: ppp0: RecvConfigNak(1) state = Ack-Sent
ppp: IPADDR[6]
ppp: <129>[6]
ppp: <131>[6]

PPP: FSM: Sending Lcp Echo Req. restart = 5
ppp: FSM: ppp0: RecvConfigAck(2) state = Ack-Sent
ppp: FSM: ppp0: State change Ack-Sent --> Opened

ppp: IPCP : ppp0: LayerUp. Myaddr = 81.86.224.XX

PPP: IPCP: timer was running so stopping it ...

PPP: IPCP: Starting the LCP Echo Request timer.
ppp: FSM: ppp0: RecvEchoReply(2) state = Opened

PPP: FSM: Lcp Echo Reply recvd from server....

PPP: FSM: Sending Lcp Echo Req. restart = 5
ppp: FSM: ppp0: RecvEchoReply(2) state = Opened

PPP: FSM: Lcp Echo Reply recvd from server....

All is fine.

However with a bust attempt.....
ADSL Link ESTABLISHED !
pppatalink : ppp0: Created in Dead state
ppp: FSM: Using "ppp0" as a transport
ppp: FSM: ppp0: State change Initial --> Closed

ppp: FSM: ppp0: State change Closed --> Req-Sent

ppp: FSM: ppp0: RecvConfigReq(16) state = Req-Sent
ppp: LCP : ppp0 : MRU[4] 32725
ppp: LCP : ppp0 : AUTHPROTO[5] 0xc223 (CHAP 0x05)
ppp: MAGICNUM[6] 0x209dd2f2
ppp: FSM: ppp0: State change Req-Sent --> Ack-Sent

ppp: FSM: ppp0: RecvConfigAck(1) state = Ack-Sent
ppp: FSM: ppp0: State change Ack-Sent --> Opened

ppp: LCP : ppp0: LayerUp
pppatalink : link name ppp0, Authentication phase: mine = none
ppp: FSM: ppp0: RecvTerminateReq(17) state = Opened
ppp: LCP : ppp0: LayerDown

FsmRecvTermReq: TermReq recieved setting the pppoa flag
ppp: FSM: ppp0: State change Opened --> Stopping


Term Req recvd, closing session 0
ppp: FSM: ppp0: State change Stopping --> Closing


Now restarting the session 0
pppatalink : ppp0: Created in Dead state
ppp: FSM: Using "ppp0" as a transport
ppp: FSM: ppp0: State change Initial --> Closed

ppp: FSM: ppp0: State change Closed --> Req-Sent


pppoa Reconnect, Adding default route......
ppp: FSM: ppp0: RecvConfigReq(21) state = Req-Sent
ppp: LCP : ppp0 : AUTHPROTO[5] 0xc223 (CHAP 0x05)
ppp: MAGICNUM[6] 0x524593f6
ppp: FSM: ppp0: State change Req-Sent --> Ack-Sent

ppp: FSM: ppp0: RecvConfigAck(1) state = Ack-Sent
ppp: FSM: ppp0: State change Ack-Sent --> Opened

ppp: LCP : ppp0: LayerUp
pppatalink : link name ppp0, Authentication phase: mine = none
Chap Input: CHALLENGE (16 bytes from RASB2NRP6.Birmingham)
ppp: Chap Output: RESPONSE ((E-Mail Removed))
ppp: FSM: ppp0: RecvConfigReq(227) state = Opened
ppp: LCP : ppp0: LayerDown
ppp: LCP : ppp0 : MRU[4] 32725
ppp: LCP : ppp0 : AUTHPROTO[5] 0xc223 (CHAP 0x05)
ppp: MAGICNUM[6] 0x23dd0997
ppp: FSM: ppp0: State change Opened --> Ack-Sent

ppp: FSM: ppp0: RecvConfigAck(2) state = Ack-Sent
ppp: FSM: ppp0: State change Ack-Sent --> Opened

ppp: LCP : ppp0: LayerUp
pppatalink : link name ppp0, Authentication phase: mine = none
Chap Input: CHALLENGE (18 bytes from ERX1.GS1)
ppp: Chap Output: RESPONSE ((E-Mail Removed))
Chap Input: SUCCESS
ppp: FSM: Using "ppp0" as a transport
ppp: FSM: ppp0: State change Initial --> Closed

ppp: FSM: ppp0: State change Closed --> Req-Sent

ppp: FSM: ppp0: RecvConfigNak(1) state = Req-Sent
ppp: IPADDR[6]
ppp: <129>[6]
ppp: <131>[6]
ppp: FSM: ppp0: RecvConfigAck(2) state = Req-Sent
ppp: FSM: ppp0: State change Req-Sent --> Ack-Rcvd

ppp: FSM: ppp0: RecvConfigReq(111) state = Ack-Rcvd
ppp: IPADDR[6]
ppp: FSM: ppp0: State change Ack-Rcvd --> Opened

ppp: IPCP : ppp0: LayerUp. Myaddr = 81.178.242.156

PPP: IPCP: Starting the LCP Echo Request timer.
ppp: Chap Output: RESPONSE ((E-Mail Removed))
Chap Input: SUCCESS
ppp: FSM ppp0: Oops, Up at Opened
pppoaTransmitData: PPP negotiation not complete, packet dropped

PPP: FSM: Sending Lcp Echo Req. restart = 5
ppp: FSM: ppp0: RecvEchoReply(1) state = Opened

PPP: FSM: Lcp Echo Reply recvd from server....
pppoaDataReceived: Unexpected IP packet, PPP negotiation not complete
pppoaTransmitData: PPP negotiation not complete, packet dropped

Looks like in the fail condition they are not sending the CHAP challenge.

Trying to resolve this with Pipex.

Dave

nospam-(E-Mail Removed) wrote:

<snip>

> Looks like in the fail condition they are not sending the CHAP challenge.
>
> Trying to resolve this with Pipex.

Looking at my logs again - and your output, it seems to me the problem is
they send two challanges in the fail case.

Andy.

You might be right, PPP negotiation was never my strong point :-)

As I remember the Windows PPP code is far less compliant with the RFC, but
in this case seems to connect more often.
The problem is still intermittent and seems OK today.

I wonder if its symptomatic of Blaster saturating whatever I'm
authenticating against. It would be good to get raw packets out of the
router to see what the unexpected ones are at the end of the trace.
Unfortunatly my router doesnt seem willing to do that.

Dave

nospam-(E-Mail Removed) wrote:

> You might be right, PPP negotiation was never my strong point :-)
>
> As I remember the Windows PPP code is far less compliant with the RFC, but
> in this case seems to connect more often.
> The problem is still intermittent and seems OK today.

Seems like it's pot luck as to which remote kit you talk to - I am starting
to see other posts of a similar nature.

It also looks like you need to take down/power down so you resync, if you
want to have a shout at talking to the working kit - retrying just ppp gets
the same remote.

Luckily for me linux pppoatm also survives.

>
> I wonder if its symptomatic of Blaster saturating whatever I'm
> authenticating against. It would be good to get raw packets out of the
> router to see what the unexpected ones are at the end of the trace.
> Unfortunatly my router doesnt seem willing to do that.

I doubt it's anything to do with blaster - just some client ppp code can
handle being sent a chap request to which replies are ignored, then getting
another different one which lets you authenticate, even though you haven't
given up trying on the first.

Andy.