On Wed, 09 Jun 2004 14:01:49 -0500, Clifford Kite wrote:
> This is not a disconnection during a working PPP session. It looks
> like the other side abruptly hungup without starting it's PPP. But in
> the case of an abrupt hangup at any stage I don't think there's any
> way other to terminate pppd other than kill -9. Does "for any reason"
> include one that does *not* involve an abrupt hangup? If so then show
> us a log of the debug messages for such a session. And, please, NOT
> hand-copied messages.
Sure, that last connection was a test one only. A demo of a connection
where we did a little traffic etc is here:
Jun 9 14:14:45 natalie pppd[19803]: pppd 2.4.1 started by root, uid 0
Jun 9 14:14:45 natalie pppd[19803]: using channel 81
Jun 9 14:14:45 natalie pppd[19803]: Using interface ppp1
Jun 9 14:14:45 natalie pppd[19803]: Connect: ppp1 <--> /dev/tts/0
Jun 9 14:14:45 natalie pppd[19803]: sent [LCP ConfReq id=0x1 <asyncmap 0x0> <auth pap> <magic 0xde1cf632> <pcomp> <accomp>]
Jun 9 14:14:45 natalie pppd[19803]: rcvd [LCP ConfAck id=0x1 <asyncmap 0x0> <auth pap> <magic 0xde1cf632> <pcomp> <accomp>]
Jun 9 14:14:48 natalie pppd[19803]: rcvd [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0xbc137772> <pcomp> <accomp>]
Jun 9 14:14:48 natalie pppd[19803]: sent [LCP ConfAck id=0x1 <asyncmap 0x0> <magic 0xbc137772> <pcomp> <accomp>]
Jun 9 14:14:48 natalie pppd[19803]: rcvd [PAP AuthReq id=0x1 user="vert" password=<hidden>]
Jun 9 14:14:48 natalie pppd[19803]: sent [PAP AuthAck id=0x1 "Login ok"]
Jun 9 14:14:48 natalie pppd[19803]: sent [IPCP ConfReq id=0x1 <addr 172.16.0.1> <compress VJ 0f 01> <ms-dns1 0.0.0.0> <ms-dns3 0.0.0.0>]
Jun 9 14:14:48 natalie pppd[19803]: sent [IPCP ConfReq id=0x1 <addr 172.16.0.1> <compress VJ 0f 01> <ms-dns1 0.0.0.0> <ms-dns3 0.0.0.0>]
Jun 9 14:14:48 natalie pppd[19803]: sent [CCP ConfReq id=0x1 <deflate 15> <deflate(old#) 15> <bsd v1 15>]
Jun 9 14:14:48 natalie pppd[19803]: rcvd [IPCP ConfReq id=0x1 <addr 0.0.0.0> <compress VJ 0f 01> <ms-dns1 0.0.0.0> <ms-dns3 0.0.0.0>]
Jun 9 14:14:48 natalie pppd[19803]: sent [IPCP ConfRej id=0x1 <ms-dns1 0.0.0.0> <ms-dns3 0.0.0.0>]
Jun 9 14:14:48 natalie pppd[19803]: rcvd [CCP ConfReq id=0x1 <deflate 15> <deflate(old#) 15> <bsd v1 15>]
Jun 9 14:14:48 natalie pppd[19803]: sent [CCP ConfAck id=0x1 <deflate 15> <deflate(old#) 15> <bsd v1 15>]
Jun 9 14:14:48 natalie pppd[19803]: rcvd [IPCP ConfRej id=0x1 <ms-dns1 0.0.0.0> <ms-dns3 0.0.0.0>]
Jun 9 14:14:48 natalie pppd[19803]: sent [IPCP ConfReq id=0x2 <addr 172.16.0.1> <compress VJ 0f 01>]
Jun 9 14:14:48 natalie pppd[19803]: rcvd [CCP ConfAck id=0x1 <deflate 15> <deflate(old#) 15> <bsd v1 15>]
Jun 9 14:14:48 natalie pppd[19803]: Deflate (15) compression enabled
Jun 9 14:14:48 natalie pppd[19803]: rcvd [IPCP ConfReq id=0x2 <addr 0.0.0.0> <compress VJ 0f 01>]
Jun 9 14:14:48 natalie pppd[19803]: sent [IPCP ConfNak id=0x2 <addr 172.16.0.2>]
Jun 9 14:14:48 natalie pppd[19803]: rcvd [IPCP ConfAck id=0x2 <addr 172.16.0.1> <compress VJ 0f 01>]
Jun 9 14:14:48 natalie pppd[19803]: rcvd [IPCP ConfReq id=0x3 <addr 172.16.0.2> <compress VJ 0f 01>]
Jun 9 14:14:48 natalie pppd[19803]: sent [IPCP ConfAck id=0x3 <addr 172.16.0.2> <compress VJ 0f 01>]
Jun 9 14:14:48 natalie pppd[19803]: local IP address 172.16.0.1
Jun 9 14:14:48 natalie pppd[19803]: remote IP address 172.16.0.2
Jun 9 14:14:48 natalie pppd[19803]: Script /etc/ppp/ip-up started (pid 20406)
Jun 9 14:14:50 natalie pppd[19803]: Script /etc/ppp/ip-up finished (pid 20406), status = 0x0
Jun 9 17:40:16 natalie pppd[19803]: rcvd [LCP TermReq id=0x2 "User request"]
Jun 9 17:40:16 natalie pppd[19803]: LCP terminated by peer (User request)
Jun 9 17:40:16 natalie pppd[19803]: Script /etc/ppp/ip-down started (pid 23969)Jun 9 17:40:16 natalie pppd[19803]: sent [LCP TermAck id=0x2]
Jun 9 17:40:16 natalie pppd[19803]: Script /etc/ppp/ip-down finished (pid 23969), status = 0x0
Jun 9 17:40:19 natalie pppd[19803]: Connection terminated.
Jun 9 17:40:19 natalie pppd[19803]: Connect time 205.6 minutes.
Jun 9 17:40:19 natalie pppd[19803]: Sent 1825263 bytes, received 578076 bytes.
Jun 9 17:40:19 natalie pppd[19803]: using channel 82
Jun 9 17:40:19 natalie pppd[19803]: Using interface ppp1
Jun 9 17:40:19 natalie pppd[19803]: Connect: ppp1 <--> /dev/tts/0
Jun 9 17:40:19 natalie pppd[19803]: sent [LCP ConfReq id=0x2 <asyncmap 0x0> <auth pap> <magic 0xc52c931f> <pcomp> <accomp>]
Jun 9 17:40:46 natalie last message repeated 9 times
Jun 9 18:17:45 natalie pppd[19803]: Hangup (SIGHUP)
Jun 9 18:17:45 natalie pppd[19803]: Modem hangup
Jun 9 18:17:45 natalie pppd[19803]: Connection terminated.
Just noticed the end of that log, pretty strange stuff. Maybe its related to the
passive option? I will remove it and observe the next connection's hanup.
I've also just created a script that will kill -9 pppd's PID at the point
where it runs the ip-down script. That should help me out
> What bothers me is the /dev/tts/0 that appears in the output above. That
> should read /dev/pts/0, or /dev/pts/<some integer> . I suppose Mandrake
> could have mangled things and created /dev/tts but it's very doubtful
> that it would be used by pppd. But if "looks like" means you
> hand-copied the messages then that might explain it. In fact, comparing
> this with my own logs strongly implies that it *is* a hand-copy. I'd
> expect a line with "Using interface ppp1" before the "Connect" line and
> a 1-second delay between the "Connect" and the first LCP request.
It wasn't hand copied, straight from the logs
> That's surprising; I'd expect the PID file to be around after an abrupt
> hangup. Or does "it hangs up" mean that it is pppd that actually hangs
> up, after closing the PPP session?
I think its a case where it hangs up but maybe crashes on terminating? I really
don't know though. Perhaps its something to do with Mandrake's PPP. On a couple
of times only when it hung, there was also an ip-down <defunct> process but I
couldn't kill this directly, had to kill pppd.
Thanks for your help thus far. I will let you know how I go with the disconnect
script I made.
Michael Collard