[Server-devel] pppd restarting mysteriously
Joshua N Pritikin
jpritikin at pobox.com
Thu Jul 23 13:05:14 EDT 2009
On Thu, Jul 23, 2009 at 02:54:20PM +0200, Martin Langhoff wrote:
> On Thu, Jul 23, 2009 at 1:52 PM, Joshua N Pritikin<jpritikin at pobox.com> wrote:
> > I looked at the options for wvdial and turned off anything suspicious. I
> > don't think wvdial is implicated. It looks like something crazy with
> > pppd. If I enable debug in /etc/ppp/options, will I see something extra
> > in /var/log/messages?
>
> /var/log/pppd.log I think.
I am attaching two logs. dell-desktop shows a working ppp session.
schoolserver shows a ppp session which is terminated shortly after
connecting.
Can anyone offer any insight into what is going wrong on the
schoolserver?
-------------- next part --------------
Jul 23 22:25:36 dell-desktop pppd[14482]: pppd 2.4.5 started by root, uid 0
Jul 23 22:25:36 dell-desktop pppd[14482]: using channel 40
Jul 23 22:25:36 dell-desktop pppd[14482]: Using interface ppp0
Jul 23 22:25:36 dell-desktop pppd[14482]: Connect: ppp0 <--> /dev/ttyUSB0
Jul 23 22:25:36 dell-desktop pppd[14482]: sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0xc140ebcc> <pcomp> <accomp>]
Jul 23 22:25:36 dell-desktop pppd[14482]: rcvd [LCP ConfReq id=0x3 <auth chap MD5> <magic 0x8e2304> <pcomp> <accomp>]
Jul 23 22:25:36 dell-desktop pppd[14482]: sent [LCP ConfAck id=0x3 <auth chap MD5> <magic 0x8e2304> <pcomp> <accomp>]
Jul 23 22:25:36 dell-desktop pppd[14482]: rcvd [LCP ConfAck id=0x1 <asyncmap 0x0> <magic 0xc140ebcc> <pcomp> <accomp>]
Jul 23 22:25:36 dell-desktop pppd[14482]: sent [LCP EchoReq id=0x0 magic=0xc140ebcc]
Jul 23 22:25:36 dell-desktop pppd[14482]: rcvd [CHAP Challenge id=0x2 <14e30d98e64016736957963a1136c95a>, name = ""]
Jul 23 22:25:36 dell-desktop pppd[14482]: sent [CHAP Response id=0x2 <93aac1f490ceff13b3e9d8931205b259>, name = "cdma"]
Jul 23 22:25:36 dell-desktop pppd[14482]: rcvd [LCP EchoRep id=0x0 magic=0x8e2304]
Jul 23 22:25:36 dell-desktop pppd[14482]: rcvd [CHAP Success id=0x2 ""]
Jul 23 22:25:36 dell-desktop pppd[14482]: CHAP authentication succeeded
Jul 23 22:25:36 dell-desktop pppd[14482]: CHAP authentication succeeded
Jul 23 22:25:36 dell-desktop pppd[14482]: sent [CCP ConfReq id=0x1 <deflate 15> <deflate(old#) 15> <bsd v1 15>]
Jul 23 22:25:36 dell-desktop pppd[14482]: sent [IPCP ConfReq id=0x1 <compress VJ 0f 01> <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
Jul 23 22:25:36 dell-desktop pppd[14482]: rcvd [IPCP ConfReq id=0x2 <addr 192.168.52.12>]
Jul 23 22:25:36 dell-desktop pppd[14482]: sent [IPCP ConfAck id=0x2 <addr 192.168.52.12>]
Jul 23 22:25:37 dell-desktop pppd[14482]: rcvd [LCP ProtRej id=0x4 80 fd 01 01 00 0f 1a 04 78 00 18 04 78 00 15 03 2f 00 00 00 bf e0 e1 89 ac 01 34 69 12 90 21 04 ...]
Jul 23 22:25:37 dell-desktop pppd[14482]: Protocol-Reject for 'Compression Control Protocol' (0x80fd) received
Jul 23 22:25:37 dell-desktop pppd[14482]: rcvd [IPCP ConfRej id=0x1 <compress VJ 0f 01>]
Jul 23 22:25:37 dell-desktop pppd[14482]: sent [IPCP ConfReq id=0x2 <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
Jul 23 22:25:37 dell-desktop pppd[14482]: rcvd [IPCP ConfNak id=0x2 <addr 117.254.27.38> <ms-dns1 218.248.240.134> <ms-dns2 218.248.240.181>]
Jul 23 22:25:37 dell-desktop pppd[14482]: sent [IPCP ConfReq id=0x3 <addr 117.254.27.38> <ms-dns1 218.248.240.134> <ms-dns2 218.248.240.181>]
Jul 23 22:25:37 dell-desktop pppd[14482]: rcvd [IPCP ConfAck id=0x3 <addr 117.254.27.38> <ms-dns1 218.248.240.134> <ms-dns2 218.248.240.181>]
Jul 23 22:25:37 dell-desktop pppd[14482]: Cannot determine ethernet address for proxy ARP
Jul 23 22:25:37 dell-desktop pppd[14482]: local IP address 117.254.27.38
Jul 23 22:25:37 dell-desktop pppd[14482]: remote IP address 192.168.52.12
Jul 23 22:25:37 dell-desktop pppd[14482]: primary DNS address 218.248.240.134
Jul 23 22:25:37 dell-desktop pppd[14482]: secondary DNS address 218.248.240.181
Jul 23 22:25:37 dell-desktop pppd[14482]: Script /etc/ppp/ip-up started (pid 14487)
Jul 23 22:25:37 dell-desktop pppd[14482]: Script /etc/ppp/ip-up finished (pid 14487), status = 0x0
Jul 23 22:26:06 dell-desktop pppd[14482]: sent [LCP EchoReq id=0x1 magic=0xc140ebcc]
Jul 23 22:26:06 dell-desktop pppd[14482]: rcvd [LCP EchoRep id=0x1 magic=0x8e2304]
Jul 23 22:26:36 dell-desktop pppd[14482]: sent [LCP EchoReq id=0x2 magic=0xc140ebcc]
Jul 23 22:26:36 dell-desktop pppd[14482]: rcvd [LCP EchoRep id=0x2 magic=0x8e2304]
Jul 23 22:27:06 dell-desktop pppd[14482]: sent [LCP EchoReq id=0x3 magic=0xc140ebcc]
Jul 23 22:27:06 dell-desktop pppd[14482]: rcvd [LCP EchoRep id=0x3 magic=0x8e2304]
-------------- next part --------------
Jul 23 22:16:01 schoolserver pppd[6859]: pppd 2.4.4 started by root, uid 0
Jul 23 22:16:01 schoolserver pppd[6859]: using channel 7
Jul 23 22:16:01 schoolserver pppd[6859]: Using interface ppp0
Jul 23 22:16:01 schoolserver pppd[6859]: Connect: ppp0 <--> /dev/ttyUSB0
Jul 23 22:16:01 schoolserver pppd[6859]: sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0x35dde7e1> <pcomp> <accomp>]
Jul 23 22:16:02 schoolserver pppd[6859]: rcvd [LCP ConfAck id=0x1 <asyncmap 0x0> <magic 0x35dde7e1> <pcomp> <accomp>]
Jul 23 22:16:04 schoolserver pppd[6859]: sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0x35dde7e1> <pcomp> <accomp>]
Jul 23 22:16:05 schoolserver pppd[6859]: rcvd [LCP ConfReq id=0x1 <auth chap MD5> <magic 0x8edcb1> <pcomp> <accomp>]
Jul 23 22:16:05 schoolserver pppd[6859]: sent [LCP ConfAck id=0x1 <auth chap MD5> <magic 0x8edcb1> <pcomp> <accomp>]
Jul 23 22:16:05 schoolserver pppd[6859]: rcvd [LCP ConfAck id=0x1 <asyncmap 0x0> <magic 0x35dde7e1> <pcomp> <accomp>]
Jul 23 22:16:05 schoolserver pppd[6859]: rcvd [CHAP Challenge id=0x1 <0f4c6dcb6a9aedb33fa9dc55e5fe20c1>, name = ""]
Jul 23 22:16:05 schoolserver pppd[6859]: sent [CHAP Response id=0x1 <f7cbd06a52225bdd6e8370d23ecb8f6d>, name = "cdma"]
Jul 23 22:16:06 schoolserver pppd[6859]: rcvd [CHAP Success id=0x1 ""]
Jul 23 22:16:06 schoolserver pppd[6859]: CHAP authentication succeeded
Jul 23 22:16:06 schoolserver pppd[6859]: CHAP authentication succeeded
Jul 23 22:16:06 schoolserver pppd[6859]: sent [CCP ConfReq id=0x1 <deflate 15> <deflate(old#) 15>]
Jul 23 22:16:06 schoolserver pppd[6859]: sent [IPCP ConfReq id=0x1 <compress VJ 0f 01> <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns3 0.0.0.0>]
Jul 23 22:16:06 schoolserver pppd[6859]: rcvd [IPCP ConfReq id=0x1 <addr 192.168.52.12>]
Jul 23 22:16:06 schoolserver pppd[6859]: sent [IPCP ConfAck id=0x1 <addr 192.168.52.12>]
Jul 23 22:16:06 schoolserver pppd[6859]: rcvd [LCP ProtRej id=0x2 80 fd 01 01 00 0c 1a 04 78 00 18 04 78 00 00 00 75 fe 0a b0 00 50 04 13 68 e1 f2 ae 7b c2 d1 d7 ...]
Jul 23 22:16:06 schoolserver pppd[6859]: Protocol-Reject for 'Compression Control Protocol' (0x80fd) received
Jul 23 22:16:06 schoolserver pppd[6859]: rcvd [IPCP ConfRej id=0x1 <compress VJ 0f 01>]
Jul 23 22:16:06 schoolserver pppd[6859]: sent [IPCP ConfReq id=0x2 <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns3 0.0.0.0>]
Jul 23 22:16:06 schoolserver pppd[6859]: rcvd [IPCP ConfNak id=0x2 <addr 117.254.7.208> <ms-dns1 218.248.240.134> <ms-dns3 218.248.240.181>]
Jul 23 22:16:06 schoolserver pppd[6859]: sent [IPCP ConfReq id=0x3 <addr 117.254.7.208> <ms-dns1 218.248.240.134> <ms-dns3 218.248.240.181>]
Jul 23 22:16:06 schoolserver pppd[6859]: rcvd [IPCP ConfAck id=0x3 <addr 117.254.7.208> <ms-dns1 218.248.240.134> <ms-dns3 218.248.240.181>]
Jul 23 22:16:06 schoolserver pppd[6859]: local IP address 117.254.7.208
Jul 23 22:16:06 schoolserver pppd[6859]: remote IP address 192.168.52.12
Jul 23 22:16:06 schoolserver pppd[6859]: primary DNS address 218.248.240.134
Jul 23 22:16:06 schoolserver pppd[6859]: secondary DNS address 218.248.240.181
Jul 23 22:16:06 schoolserver pppd[6859]: Script /etc/ppp/ip-up started (pid 6872)
Jul 23 22:16:06 schoolserver pppd[6859]: Script /etc/ppp/ip-up finished (pid 6872), status = 0x0
Jul 23 22:16:08 schoolserver ntpd[2647]: Listening on interface #25 ppp0, 117.254.7.208#123 Enabled
Jul 23 22:16:08 schoolserver ntpd[2647]: new interface(s) found: waking up resolver
Jul 23 22:16:11 schoolserver pppd[6859]: rcvd [LCP ConfReq id=0x1 <auth chap MD5> <magic 0x8efba8> <pcomp> <accomp>]
Jul 23 22:16:11 schoolserver pppd[6859]: Connect time 0.1 minutes.
Jul 23 22:16:11 schoolserver pppd[6859]: Sent 600 bytes, received 0 bytes.
Jul 23 22:16:11 schoolserver pppd[6859]: Script /etc/ppp/ip-down started (pid 6874)
Jul 23 22:16:11 schoolserver pppd[6859]: sent [LCP ConfReq id=0x2 <asyncmap 0x0> <magic 0x7731fcf5> <pcomp> <accomp>]
Jul 23 22:16:11 schoolserver pppd[6859]: sent [LCP ConfAck id=0x1 <auth chap MD5> <magic 0x8efba8> <pcomp> <accomp>]
Jul 23 22:16:11 schoolserver pppd[6859]: Script /etc/ppp/ip-down finished (pid 6874), status = 0x0
More information about the Server-devel
mailing list