Date: Fri, 26 Jan 2001 12:22:30 -0800 From: "Timothy L. Robertson" <timothyr@timothyr.com> To: <freebsd-questions@freebsd.org>, <freebsd-net@freebsd.org> Subject: PPPoE Connection Hangs Sometimes Message-ID: <NEBBIFIGLFNBHJFLLOKKCEKACFAA.timothyr@timothyr.com>
next in thread | raw e-mail | index | archive | help
Hi Everyone,
I use PPPoE to connect to Mindspring over ADSL. Sometimes Mindspring drops
the connection for whatever reason, so I have a script in ppp.linkup that
pings several sites periodically, and if they all go down kills my ppp
process and starts a new one. This works great most of the time, but
sometimes when ppp tries to connect again it gets stuck. Here's what the
log looks like:
Jan 25 21:15:29 scarlet ppp[18006]: Phase: Using interface: tun0
Jan 25 21:15:29 scarlet ppp[18006]: Phase: deflink: Created in closed state
Jan 25 21:15:29 scarlet ppp[18006]: tun0: Command: pppoe: set device
PPPoE:xl0
Jan 25 21:15:29 scarlet ppp[18006]: tun0: Command: pppoe: set mru 2048
Jan 25 21:15:29 scarlet ppp[18006]: tun0: Command: pppoe: set mtu 1492
Jan 25 21:15:29 scarlet ppp[18006]: tun0: Command: pppoe: set speed sync
Jan 25 21:15:29 scarlet ppp[18006]: tun0: Command: pppoe: set cd 5
Jan 25 21:15:29 scarlet ppp[18006]: tun0: Command: pppoe: set redial 0 0
Jan 25 21:15:29 scarlet ppp[18006]: tun0: Command: pppoe: set reconnect 10
99
Jan 25 21:15:29 scarlet ppp[18006]: tun0: Command: pppoe: set dial
Jan 25 21:15:29 scarlet ppp[18006]: tun0: Command: pppoe: set login
Jan 25 21:15:29 scarlet ppp[18006]: tun0: Command: pppoe: set authname
tlrobertson@mindspring.com
Jan 25 21:15:29 scarlet ppp[18006]: tun0: Command: pppoe: set authkey
********
Jan 25 21:15:29 scarlet ppp[18006]: tun0: Command: pppoe: set timeout 0
Jan 25 21:15:29 scarlet ppp[18006]: tun0: Command: pppoe: set ifaddr 0 0
255.255.255.255 255.255.255.255
Jan 25 21:15:29 scarlet ppp[18006]: tun0: Command: pppoe: delete ALL
Jan 25 21:15:29 scarlet ppp[18006]: tun0: Command: pppoe: add 0 0 HISADDR
Jan 25 21:15:29 scarlet ppp[18007]: tun0: Phase: PPP Started (ddial mode).
Jan 25 21:15:29 scarlet ppp[18007]: tun0: Phase: bundle: Establish
Jan 25 21:15:29 scarlet ppp[18007]: tun0: Phase: deflink: closed -> opening
Jan 25 21:15:29 scarlet ppp[18007]: tun0: Warning: deflink: Reducing MRU to
1492
Jan 25 21:15:29 scarlet ppp[18007]: tun0: Phase: deflink: Connected!
Jan 25 21:15:29 scarlet ppp[18007]: tun0: Phase: deflink: opening -> dial
Jan 25 21:15:29 scarlet ppp[18007]: tun0: Phase: deflink: dial -> carrier
Jan 25 21:15:34 scarlet ppp[18007]: tun0: Phase: deflink: Disconnected!
Jan 25 21:15:34 scarlet ppp[18007]: tun0: Phase: deflink: carrier -> hangup
Jan 25 21:15:34 scarlet ppp[18007]: tun0: Phase: deflink: Connect time: 5
secs: 0 octets in, 0 octets out
Jan 25 21:15:34 scarlet ppp[18007]: tun0: Phase: deflink: : 0 packets in, 0
packets out
Jan 25 21:15:34 scarlet ppp[18007]: tun0: Phase: total 0 bytes/sec, peak 0
bytes/sec on Thu Jan 25 21:15:34 2001
Jan 25 21:15:34 scarlet ppp[18007]: tun0: Phase: deflink: hangup -> opening
and then nothing more. This usually happens when I'm away from my machiine,
I come home, reconnect and everything works fine for a few days, until it
happens again. How can i check for this condition and have ppp start over
when it occurs, or even better avoid it all together? Any help appriciated.
TIA,
-Tim
timothyr@timothyr.com
Here are some other relevant files:
scarlet:/etc/ppp 521$ more ppp.linkup
MYADDR:
!bg /etc/ppp/ppp.linkup.sh
scarlet:/etc/ppp 522$ more ppp.linkup.sh
#!/bin/sh
ddup --host timothyr.dyndns.org
/bin/sh /etc/snortstart.sh
/usr/local/bin/fetchmail -f /etc/mail/fetchmail.rc -d 60
/etc/ppp/nettest.sh &
scarlet:/etc/ppp 523$ more nettest.sh
#! /usr/local/bin/bash
count=1
while [ $count -ne 0 ];
do {
sleep 30
count=0
[ -n "$(ping -c 1 -q mindspring.com | grep ", 0% packet loss")" ] && let
count=$count+1
[ -n "$(ping -c 1 -q yahoo.com | grep ", 0% packet loss")" ] && let
count=$count+1
[ -n "$(ping -c 1 -q salon.com | grep ", 0% packet loss")" ] && let
count=$count+1
[ -n "$(ping -c 1 -q socrates.berkeley.edu | grep ", 0% packet loss")" ] &&
let count=$count+1
[ -n "$(ping -c 1 -q sgi.com | grep ", 0% packet loss")" ] && let
count=$count+1
#echo $count
};
done;
/etc/ppp/reconnect.sh
scarlet:/etc/ppp 524$ more reconnect.sh
#!/usr/local/bin/bash
kill -9 `cat /var/run/tun0.pid`
/usr/sbin/ppp -quiet -ddial pppoe
and here's a successful connection for reference:
Jan 26 11:02:07 scarlet ppp[19109]: Phase: Using interface: tun0
Jan 26 11:02:07 scarlet ppp[19109]: Phase: deflink: Created in closed state
Jan 26 11:02:07 scarlet ppp[19109]: tun0: Command: pppoe: set device
PPPoE:xl0
Jan 26 11:02:07 scarlet ppp[19109]: tun0: Command: pppoe: set mru 2048
Jan 26 11:02:07 scarlet ppp[19109]: tun0: Command: pppoe: set mtu 1492
Jan 26 11:02:07 scarlet ppp[19109]: tun0: Command: pppoe: set speed sync
Jan 26 11:02:07 scarlet ppp[19109]: tun0: Command: pppoe: set cd 5
Jan 26 11:02:07 scarlet ppp[19109]: tun0: Command: pppoe: set redial 0 0
Jan 26 11:02:07 scarlet ppp[19109]: tun0: Command: pppoe: set reconnect 10
99
Jan 26 11:02:07 scarlet ppp[19109]: tun0: Command: pppoe: set dial
Jan 26 11:02:07 scarlet ppp[19109]: tun0: Command: pppoe: set login
Jan 26 11:02:07 scarlet ppp[19109]: tun0: Command: pppoe: set authname
tlrobertson@mindspring.com
Jan 26 11:02:07 scarlet ppp[19109]: tun0: Command: pppoe: set authkey
********
Jan 26 11:02:07 scarlet ppp[19109]: tun0: Command: pppoe: set timeout 0
Jan 26 11:02:07 scarlet ppp[19109]: tun0: Command: pppoe: set ifaddr 0 0
255.255.255.255 255.255.255.255
Jan 26 11:02:07 scarlet ppp[19109]: tun0: Command: pppoe: delete ALL
Jan 26 11:02:07 scarlet ppp[19109]: tun0: Command: pppoe: add 0 0 HISADDR
Jan 26 11:02:07 scarlet ppp[19110]: tun0: Phase: PPP Started (ddial mode).
Jan 26 11:02:07 scarlet ppp[19110]: tun0: Phase: bundle: Establish
Jan 26 11:02:07 scarlet ppp[19110]: tun0: Phase: deflink: closed -> opening
Jan 26 11:02:07 scarlet ppp[19110]: tun0: Warning: deflink: Reducing MRU to
1492
Jan 26 11:02:07 scarlet ppp[19110]: tun0: Phase: deflink: Connected!
Jan 26 11:02:07 scarlet ppp[19110]: tun0: Phase: deflink: opening -> dial
Jan 26 11:02:07 scarlet ppp[19110]: tun0: Phase: deflink: dial -> carrier
Jan 26 11:02:09 scarlet ppp[19110]: tun0: Phase: Received NGM_PPPOE_SUCCESS
(hook "tun0")
Jan 26 11:02:09 scarlet ppp[19110]: tun0: Phase: deflink: carrier -> login
Jan 26 11:02:09 scarlet ppp[19110]: tun0: Phase: deflink: login -> lcp
Jan 26 11:02:09 scarlet ppp[19110]: tun0: LCP: FSM: Using "deflink" as a
transport
Jan 26 11:02:09 scarlet ppp[19110]: tun0: LCP: deflink: State change
Initial --> Closed
Jan 26 11:02:09 scarlet ppp[19110]: tun0: LCP: deflink: State change
Closed --> Stopped
Jan 26 11:02:09 scarlet ppp[19110]: tun0: LCP: deflink: RecvConfigReq(220)
state = Stopped
Jan 26 11:02:09 scarlet ppp[19110]: tun0: LCP: MRU[4] 1492
Jan 26 11:02:09 scarlet ppp[19110]: tun0: LCP: AUTHPROTO[4] 0xc023 (PAP)
Jan 26 11:02:09 scarlet ppp[19110]: tun0: LCP: MAGICNUM[6] 0x0027c326
Jan 26 11:02:09 scarlet ppp[19110]: tun0: LCP: deflink: SendConfigReq(1)
state = Stopped
Jan 26 11:02:09 scarlet ppp[19110]: tun0: LCP: MRU[4] 1492
Jan 26 11:02:09 scarlet ppp[19110]: tun0: LCP: MAGICNUM[6] 0x895630a7
Jan 26 11:02:09 scarlet ppp[19110]: tun0: LCP: deflink: SendConfigAck(220)
state = Stopped
Jan 26 11:02:09 scarlet ppp[19110]: tun0: LCP: MRU[4] 1492
Jan 26 11:02:09 scarlet ppp[19110]: tun0: LCP: AUTHPROTO[4] 0xc023 (PAP)
Jan 26 11:02:09 scarlet ppp[19110]: tun0: LCP: MAGICNUM[6] 0x0027c326
Jan 26 11:02:09 scarlet ppp[19110]: tun0: LCP: deflink: LayerStart
Jan 26 11:02:09 scarlet ppp[19110]: tun0: LCP: deflink: State change
Stopped --> Ack-Sent
Jan 26 11:02:09 scarlet ppp[19110]: tun0: LCP: deflink: RecvConfigAck(1)
state = Ack-Sent
Jan 26 11:02:09 scarlet ppp[19110]: tun0: LCP: deflink: State change
Ack-Sent --> Opened
Jan 26 11:02:09 scarlet ppp[19110]: tun0: LCP: deflink: LayerUp
Jan 26 11:02:09 scarlet ppp[19110]: tun0: Phase: bundle: Authenticate
Jan 26 11:02:09 scarlet ppp[19110]: tun0: Phase: deflink: his = PAP, mine =
none
Jan 26 11:02:09 scarlet ppp[19110]: tun0: Phase: Pap Output:
tlrobertson@mindspring.com ********
Jan 26 11:02:11 scarlet ppp[19110]: tun0: Phase: Pap Input: SUCCESS ()
Jan 26 11:02:11 scarlet ppp[19110]: tun0: IPCP: Using trigger address
255.255.255.255
Jan 26 11:02:11 scarlet ppp[19110]: tun0: CCP: FSM: Using "deflink" as a
transport
Jan 26 11:02:11 scarlet ppp[19110]: tun0: CCP: deflink: State change
Initial --> Closed
Jan 26 11:02:11 scarlet ppp[19110]: tun0: CCP: deflink: LayerStart.
Jan 26 11:02:11 scarlet ppp[19110]: tun0: CCP: MPPE: InitOptsOutput
Jan 26 11:02:11 scarlet ppp[19110]: tun0: CCP: MPPE: MasterKey is invalid,
MPPE is capable only with CHAP81 authentication
Jan 26 11:02:11 scarlet ppp[19110]: tun0: CCP: deflink: SendConfigReq(1)
state = Closed
Jan 26 11:02:11 scarlet ppp[19110]: tun0: CCP: DEFLATE[4] win 15
Jan 26 11:02:11 scarlet ppp[19110]: tun0: CCP: PRED1[2]
Jan 26 11:02:11 scarlet ppp[19110]: tun0: CCP: MPPE[6] value 0x00000000
Jan 26 11:02:11 scarlet ppp[19110]: tun0: CCP: deflink: State change
Closed --> Req-Sent
Jan 26 11:02:11 scarlet ppp[19110]: tun0: Phase: deflink: lcp -> open
Jan 26 11:02:11 scarlet ppp[19110]: tun0: Phase: bundle: Network
Jan 26 11:02:11 scarlet ppp[19110]: tun0: IPCP: FSM: Using "deflink" as a
transport
Jan 26 11:02:11 scarlet ppp[19110]: tun0: IPCP: deflink: State change
Initial --> Closed
Jan 26 11:02:11 scarlet ppp[19110]: tun0: IPCP: deflink: LayerStart.
Jan 26 11:02:11 scarlet ppp[19110]: tun0: IPCP: deflink: SendConfigReq(1)
state = Closed
Jan 26 11:02:11 scarlet ppp[19110]: tun0: IPCP: IPADDR[6] 255.255.255.255
Jan 26 11:02:11 scarlet ppp[19110]: tun0: IPCP: COMPPROTO[6] 16 VJ slots
with slot compression
Jan 26 11:02:11 scarlet ppp[19110]: tun0: IPCP: deflink: State change
Closed --> Req-Sent
Jan 26 11:02:11 scarlet ppp[19110]: tun0: LCP: deflink: RecvEchoRequest(0)
state = Opened
Jan 26 11:02:11 scarlet ppp[19110]: tun0: LCP: deflink: SendEchoReply(0)
state = Opened
Jan 26 11:02:11 scarlet ppp[19110]: tun0: IPCP: deflink: RecvConfigReq(24)
state = Req-Sent
Jan 26 11:02:11 scarlet ppp[19110]: tun0: IPCP: IPADDR[6] 216.175.101.1
Jan 26 11:02:11 scarlet ppp[19110]: tun0: IPCP: deflink: SendConfigAck(24)
state = Req-Sent
Jan 26 11:02:11 scarlet ppp[19110]: tun0: IPCP: IPADDR[6] 216.175.101.1
Jan 26 11:02:11 scarlet ppp[19110]: tun0: IPCP: deflink: State change
Req-Sent --> Ack-Sent
Jan 26 11:02:11 scarlet ppp[19110]: tun0: LCP: deflink: RecvProtocolRej(221)
state = Opened
Jan 26 11:02:11 scarlet ppp[19110]: tun0: LCP: deflink: -- Protocol 0x80fd
(Compression Control Protocol) was rejected!
Jan 26 11:02:11 scarlet ppp[19110]: tun0: CCP: deflink: State change
Req-Sent --> Stopped
Jan 26 11:02:11 scarlet ppp[19110]: tun0: IPCP: deflink: RecvConfigRej(1)
state = Ack-Sent
Jan 26 11:02:11 scarlet ppp[19110]: tun0: IPCP: COMPPROTO[6] 16 VJ slots
with slot compression
Jan 26 11:02:11 scarlet ppp[19110]: tun0: IPCP: deflink: SendConfigReq(2)
state = Ack-Sent
Jan 26 11:02:11 scarlet ppp[19110]: tun0: IPCP: IPADDR[6] 255.255.255.255
Jan 26 11:02:12 scarlet ppp[19110]: tun0: IPCP: deflink: RecvConfigNak(2)
state = Ack-Sent
Jan 26 11:02:12 scarlet ppp[19110]: tun0: IPCP: IPADDR[6] 216.175.101.156
Jan 26 11:02:12 scarlet ppp[19110]: tun0: IPCP: IPADDR[6] changing
address: 255.255.255.255 --> 216.175.101.156
Jan 26 11:02:12 scarlet ppp[19110]: tun0: IPCP: deflink: SendConfigReq(3)
state = Ack-Sent
Jan 26 11:02:12 scarlet ppp[19110]: tun0: IPCP: IPADDR[6] 216.175.101.156
Jan 26 11:02:12 scarlet ppp[19110]: tun0: IPCP: deflink: RecvConfigAck(3)
state = Ack-Sent
Jan 26 11:02:12 scarlet ppp[19110]: tun0: IPCP: deflink: State change
Ack-Sent --> Opened
Jan 26 11:02:12 scarlet ppp[19110]: tun0: IPCP: deflink: LayerUp.
Jan 26 11:02:12 scarlet ppp[19110]: tun0: IPCP: myaddr 216.175.101.156
hisaddr = 216.175.101.1
Jan 26 11:02:12 scarlet ppp[19110]: tun0: Command: MYADDR: !bg
/etc/ppp/ppp.linkup.sh
Jan 26 11:02:12 scarlet ppp[19110]: tun0: LCP: deflink: RecvEchoRequest(0)
state = Opened
Jan 26 11:02:12 scarlet ppp[19110]: tun0: LCP: deflink: SendEchoReply(0)
state = Opened
To Unsubscribe: send mail to majordomo@FreeBSD.org
with "unsubscribe freebsd-net" in the body of the message
Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?NEBBIFIGLFNBHJFLLOKKCEKACFAA.timothyr>