Puzzling PPP Problem
I have a problem that I have started getting recently with
one of my ppp connections.
I have two dialup connections at home, one via my place of
work, and another that I pay for myself. Both use the ISDN
modem that I share between two computers, via a switch box
in the serial cable.
One computer is running OS/2, and that can use both of the
ISP's without problem. The other machine is running debian
potato, and has trouble with my private ISP, which used to
work fine. One problem is that it has been a while since I
usd that ISP on the Linux machine, so I don't know exactly
when it stopped working.
The symptom is that the handshaking seems to get stuck for
the ISP that doesn't work. I attach a slightly edited log,
obtained by removing the commenting out of the #debug line
in /etc/ppp/peers/provider which I hope will make sense to
someone.
I need to get this fixed, as I am planning to finally move
my wife's machine over from OS/2 to debian. I do not think
she would be so happy if she loses her internet connection
as a result ;-).
Cheers!
--
.~.
/V\
// \\
/( )\
^`~'^
< hugge >
Edited /etc/ppp/peers/provider to allow debugging.
Here is the (slightly edited) debug log.
I.P. addresses have been munged for safety.
Using pppd version 2.4.0
Oct 9 09:38:43 pehupc pppd[468]: sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0x80d265ff> <pcomp> <accomp>]
Oct 9 09:38:43 pehupc pppd[468]: rcvd [LCP ConfRej id=0x1 <pcomp> <accomp>]
Oct 9 09:38:43 pehupc pppd[468]: sent [LCP ConfReq id=0x2 <asyncmap 0x0> <magic 0x80d265ff>]
Oct 9 09:38:44 pehupc pppd[468]: rcvd [LCP ConfAck id=0x2 <asyncmap 0x0> <magic 0x80d265ff>]
Oct 9 09:38:44 pehupc pppd[468]: rcvd [LCP ConfReq id=0x2 <mru 1564> <asyncmap 0x0> <auth pap> <magic 0xf218d0e6>]
Oct 9 09:38:44 pehupc pppd[468]: sent [LCP ConfAck id=0x2 <mru 1564> <asyncmap 0x0> <auth pap> <magic 0xf218d0e6>]
Oct 9 09:38:44 pehupc pppd[468]: sent [LCP EchoReq id=0x0 magic=0x80d265ff]
Oct 9 09:38:44 pehupc pppd[468]: sent [PAP AuthReq id=0x1 user="hugge" password=<hidden>]
Oct 9 09:38:44 pehupc pppd[468]: rcvd [LCP EchoRep id=0x0 magic=0xf218d0e6]
Oct 9 09:38:44 pehupc pppd[468]: rcvd [PAP AuthAck id=0x1 "Login Succeeded"]
Oct 9 09:38:44 pehupc pppd[468]: sent [IPCP ConfReq id=0x1 <addr 0.0.0.0> <compress VJ 0f 01>]
Oct 9 09:38:44 pehupc pppd[468]: sent [CCP ConfReq id=0x1 <deflate 15> <deflate(old#) 15> <bsd v1 15>]
Oct 9 09:38:44 pehupc pppd[468]: rcvd [IPCP ConfReq id=0x1 <compress VJ 0f 00> <addr 212.xx.xx.xx>]
Oct 9 09:38:44 pehupc pppd[468]: sent [IPCP ConfAck id=0x1 <compress VJ 0f 00> <addr 212.xx.xx.xx>]
Oct 9 09:38:44 pehupc pppd[468]: rcvd [IPCP ConfNak id=0x1 <addr 195.xx.xx.xx>]
Oct 9 09:38:44 pehupc pppd[468]: sent [IPCP ConfReq id=0x2 <addr 195.xx.xx.xx> <compress VJ 0f 01>]
Oct 9 09:38:44 pehupc pppd[468]: rcvd [CCP ConfRej id=0x1 <deflate 15> <deflate(old#) 15> <bsd v1 15>]
Oct 9 09:38:44 pehupc pppd[468]: sent [CCP ConfReq id=0x2]
Oct 9 09:38:44 pehupc pppd[468]: rcvd [CCP ConfReq id=0x1 < 11 05 00 01 03>]
Oct 9 09:38:44 pehupc pppd[468]: sent [CCP ConfRej id=0x1 < 11 05 00 01 03>]
Oct 9 09:38:44 pehupc pppd[468]: rcvd [IPCP ConfAck id=0x2 <addr 195.xx.xx.xx> <compress VJ 0f 01>]
Oct 9 09:38:44 pehupc pppd[468]: Script /etc/ppp/ip-up started (pid 470)
Oct 9 09:38:44 pehupc pppd[468]: rcvd [CCP ConfNak id=0x2 < 11 05 00 01 03>]
Oct 9 09:38:44 pehupc pppd[468]: sent [CCP ConfReq id=0x3]
Oct 9 09:38:44 pehupc pppd[468]: rcvd [CCP ConfNak id=0x3 < 11 05 00 01 03>]
Oct 9 09:38:44 pehupc pppd[468]: sent [CCP ConfReq id=0x4]
Oct 9 09:38:44 pehupc pppd[468]: rcvd [CCP ConfReq id=0x1 < 11 05 00 01 03>]
Oct 9 09:38:44 pehupc pppd[468]: sent [CCP ConfRej id=0x1 < 11 05 00 01 03>]
Oct 9 09:38:44 pehupc pppd[468]: rcvd [CCP ConfNak id=0x4 < 11 05 00 01 03>]
Oct 9 09:38:44 pehupc pppd[468]: sent [CCP ConfReq id=0x5]
Oct 9 09:38:44 pehupc pppd[468]: Script /etc/ppp/ip-up finished (pid 470), status = 0x100
Oct 9 09:38:44 pehupc pppd[468]: rcvd [CCP ConfNak id=0x5 < 11 05 00 01 03>]
Oct 9 09:38:44 pehupc pppd[468]: sent [CCP ConfReq id=0x6]
Oct 9 09:38:44 pehupc pppd[468]: rcvd [CCP ConfReq id=0x1 < 11 05 00 01 03>]
Oct 9 09:38:44 pehupc pppd[468]: sent [CCP ConfRej id=0x1 < 11 05 00 01 03>]
Oct 9 09:38:44 pehupc pppd[468]: rcvd [CCP ConfNak id=0x6 < 11 05 00 01 03>]
Oct 9 09:38:44 pehupc pppd[468]: sent [CCP ConfReq id=0x7]
Oct 9 09:38:44 pehupc pppd[468]: rcvd [CCP ConfNak id=0x7 < 11 05 00 01 03>]
Oct 9 09:38:44 pehupc pppd[468]: sent [CCP ConfReq id=0x8]
Oct 9 09:38:44 pehupc pppd[468]: rcvd [CCP ConfReq id=0x1 < 11 05 00 01 03>]
Oct 9 09:38:44 pehupc pppd[468]: sent [CCP ConfRej id=0x1 < 11 05 00 01 03>]
Oct 9 09:38:44 pehupc pppd[468]: rcvd [CCP ConfNak id=0x8 < 11 05 00 01 03>]
Oct 9 09:38:44 pehupc pppd[468]: sent [CCP ConfReq id=0x9]
Oct 9 09:38:44 pehupc pppd[468]: rcvd [CCP ConfNak id=0x9 < 11 05 00 01 03>]
Oct 9 09:38:44 pehupc pppd[468]: sent [CCP ConfReq id=0xa]
Oct 9 09:38:44 pehupc pppd[468]: rcvd [CCP ConfReq id=0x1 < 11 05 00 01 03>]
Oct 9 09:38:44 pehupc pppd[468]: sent [CCP ConfRej id=0x1 < 11 05 00 01 03>]
Oct 9 09:38:44 pehupc pppd[468]: rcvd [CCP ConfNak id=0xa < 11 05 00 01 03>]
Oct 9 09:38:44 pehupc pppd[468]: sent [CCP ConfReq id=0xb]
Oct 9 09:38:44 pehupc pppd[468]: rcvd [CCP ConfNak id=0xb < 11 05 00 01 03>]
Oct 9 09:38:44 pehupc pppd[468]: sent [CCP ConfReq id=0xc]
Oct 9 09:38:44 pehupc pppd[468]: rcvd [CCP ConfReq id=0x1 < 11 05 00 01 03>]
Oct 9 09:38:44 pehupc pppd[468]: sent [CCP ConfRej id=0x1 < 11 05 00 01 03>]
Oct 9 09:38:44 pehupc pppd[468]: rcvd [CCP ConfNak id=0xc < 11 05 00 01 03>]
Oct 9 09:38:44 pehupc pppd[468]: sent [CCP ConfReq id=0xd]
Oct 9 09:38:44 pehupc pppd[468]: rcvd [CCP ConfNak id=0xd < 11 05 00 01 03>]
# This same pattern repeats for 14 seconds, (output deleted).
# Then terminated by poff at 09:38:59, resulting in the following:
Oct 9 09:38:58 pehupc pppd[468]: sent [CCP ConfReq id=0xda]
Oct 9 09:38:58 pehupc pppd[468]: rcvd [CCP ConfReq id=0x1 < 11 05 00 01 03>]
Oct 9 09:38:58 pehupc pppd[468]: sent [CCP ConfRej id=0x1 < 11 05 00 01 03>]
Oct 9 09:38:58 pehupc pppd[468]: rcvd [CCP ConfNak id=0xda < 11 05 00 01 03>]
Oct 9 09:38:58 pehupc pppd[468]: sent [CCP ConfReq id=0xdb]
Oct 9 09:38:58 pehupc pppd[468]: rcvd [CCP ConfNak id=0xdb < 11 05 00 01 03>]
Oct 9 09:38:58 pehupc pppd[468]: sent [CCP ConfReq id=0xdc]
Oct 9 09:38:58 pehupc pppd[468]: rcvd [CCP ConfReq id=0x1 < 11 05 00 01 03>]
Oct 9 09:38:58 pehupc pppd[468]: sent [CCP ConfRej id=0x1 < 11 05 00 01 03>]
Oct 9 09:38:58 pehupc pppd[468]: rcvd [CCP ConfNak id=0xdc < 11 05 00 01 03>]
Oct 9 09:38:58 pehupc pppd[468]: sent [CCP ConfReq id=0xdd]
Oct 9 09:38:58 pehupc pppd[468]: rcvd [CCP ConfNak id=0xdd < 11 05 00 01 03>]
Oct 9 09:38:58 pehupc pppd[468]: sent [CCP ConfReq id=0xde]
Oct 9 09:38:58 pehupc pppd[468]: rcvd [CCP ConfReq id=0x1 < 11 05 00 01 03>]
Oct 9 09:38:58 pehupc pppd[468]: sent [CCP ConfRej id=0x1 < 11 05 00 01 03>]
Oct 9 09:38:58 pehupc pppd[468]: rcvd [CCP ConfNak id=0xde < 11 05 00 01 03>]
Oct 9 09:38:58 pehupc pppd[468]: sent [CCP ConfReq id=0xdf]
Oct 9 09:38:58 pehupc pppd[468]: rcvd [CCP ConfNak id=0xdf < 11 05 00 01 03>]
Oct 9 09:38:58 pehupc pppd[468]: sent [CCP ConfReq id=0xe0]
Oct 9 09:38:58 pehupc pppd[468]: rcvd [CCP ConfReq id=0x1 < 11 05 00 01 03>]
Oct 9 09:38:58 pehupc pppd[468]: sent [CCP ConfRej id=0x1 < 11 05 00 01 03>]
Oct 9 09:38:58 pehupc pppd[468]: rcvd [CCP ConfNak id=0xe0 < 11 05 00 01 03>]
Oct 9 09:38:58 pehupc pppd[468]: sent [CCP ConfReq id=0xe1]
Oct 9 09:38:59 pehupc pppd[468]: rcvd [CCP ConfNak id=0xe1 < 11 05 00 01 03>]
Oct 9 09:38:59 pehupc pppd[468]: sent [CCP ConfReq id=0xe2]
Oct 9 09:38:59 pehupc pppd[468]: rcvd [CCP ConfReq id=0x1 < 11 05 00 01 03>]
Oct 9 09:38:59 pehupc pppd[468]: sent [CCP ConfRej id=0x1 < 11 05 00 01 03>]
Oct 9 09:38:59 pehupc pppd[468]: Script /etc/ppp/ip-down started (pid 487)
Oct 9 09:38:59 pehupc pppd[468]: sent [LCP TermReq id=0x3 "User request"]
Oct 9 09:38:59 pehupc pppd[468]: rcvd [CCP ConfNak id=0xe2 < 11 05 00 01 03>]
Oct 9 09:38:59 pehupc pppd[468]: rcvd [LCP TermAck id=0x3]
Oct 9 09:38:59 pehupc pppd[468]: Waiting for 1 child processes...
Oct 9 09:38:59 pehupc pppd[468]: script /etc/ppp/ip-down, pid 487
Oct 9 09:38:59 pehupc pppd[468]: Script /etc/ppp/ip-down finished (pid 487), status = 0x0
What's going on?
How do I fix it?
Reply to: