From owner-freebsd-questions@FreeBSD.ORG Thu Dec 5 16:49:32 2013 Return-Path: Delivered-To: freebsd-questions@freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2001:1900:2254:206a::19:1]) (using TLSv1 with cipher ADH-AES256-SHA (256/256 bits)) (No client certificate requested) by hub.freebsd.org (Postfix) with ESMTPS id 36E9C74C for ; Thu, 5 Dec 2013 16:49:32 +0000 (UTC) Received: from smarthost1.sentex.ca (smarthost1-6.sentex.ca [IPv6:2607:f3e0:0:1::12]) (using TLSv1 with cipher DHE-RSA-AES256-SHA (256/256 bits)) (No client certificate requested) by mx1.freebsd.org (Postfix) with ESMTPS id C92251A15 for ; Thu, 5 Dec 2013 16:49:31 +0000 (UTC) Received: from [192.168.43.26] (pyroxene.sentex.ca [199.212.134.18]) by smarthost1.sentex.ca (8.14.7/8.14.7) with ESMTP id rB5GnThf095819; Thu, 5 Dec 2013 11:49:30 -0500 (EST) (envelope-from mike@sentex.net) Message-ID: <52A0AEAA.8030503@sentex.net> Date: Thu, 05 Dec 2013 11:49:46 -0500 From: Mike Tancsa Organization: Sentex Communications User-Agent: Mozilla/5.0 (Windows NT 6.1; WOW64; rv:24.0) Gecko/20100101 Thunderbird/24.1.1 MIME-Version: 1.0 To: Chris Subject: Re: PPPoE help References: <529FA253.2000900@sentex.net> In-Reply-To: X-Enigmail-Version: 1.6 Content-Type: text/plain; charset=ISO-8859-1 Content-Transfer-Encoding: 8bit X-Scanned-By: MIMEDefang 2.74 on 64.7.153.18 Cc: freebsd-questions X-BeenThere: freebsd-questions@freebsd.org X-Mailman-Version: 2.1.17 Precedence: list List-Id: User questions List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Thu, 05 Dec 2013 16:49:32 -0000 Thanks Chris, I setup a little script to monitor it out of syslog. But one thing I noticed which is odd, is that I cant start it up from a script that is called from syslog ?! *.* | /usr/local/bin/logwatch.sh read LINE BROKENPPPOE=`echo "$LINE" |grep "IPCP: deflink: Oops, RCR in Initial."` if [ "$BROKENPPPOE" ] then pkill -9 -f pppoe sleep 3 pkill -9 -f pppoe sleep 6 id | /usr/bin/logger /usr/sbin/ppp -ddial pppoe & ppp starts up, but its never actually able to connect when it starts from here for some reason ?! ---Mike On 12/4/2013 6:23 PM, Chris wrote: > I have a workaround that I've been using for a long time which works great for me and some clients who can only connect with PPPoE > > It can be found here; > > http://logicsquad.net/freebsd/pingmonitor-how-to.html > > You don't have to reinvent your own solution. It would be great if ppp would reset when the connection gets "jammed" > > > Chris > chris@lrckinfo.com > --------------------------------------------------------------- > 514.884.8185 > 320, rue de la Fenaison > Varennes, Québec, J3X 2H2 > --------------------------------------------------------------- > http://www.lrckinfo.com > > > > On Dec 4, 2013, at 4:44 PM, Mike Tancsa wrote: > >> Googling around this problem occasionally comes up, but I have yet to >> find a definitive answer. An ISP is changing out their LACs and when >> they are doing a hot cut, this sometimes messes up the pppoe ppp process >> so it gets stuck in a loop and never recovers. Killing off the ppp >> process and restarts it works and all is fixed. >> >> But this still on rare occasion will come up. Does anyone know the >> cause or work around ? I did manage to catch one and up the debug logs. >> >> None debug looks like >> >> Nov 26 15:30:01 s0332 ppp[1620]: tun1: IPCP: deflink: RecvConfigReq(10) >> state = Initial >> Nov 26 15:30:01 s0332 ppp[1620]: tun1: IPCP: IPADDR[6] xx.yy.128.14 >> Nov 26 15:30:01 s0332 ppp[1620]: tun1: IPCP: deflink: Oops, RCR in Initial. >> Nov 26 15:30:03 s0332 ppp[1620]: tun1: IPCP: deflink: RecvConfigReq(11) >> state = Initial >> Nov 26 15:30:03 s0332 ppp[1620]: tun1: IPCP: IPADDR[6] xx.yy.128.14 >> Nov 26 15:30:03 s0332 ppp[1620]: tun1: IPCP: deflink: Oops, RCR in Initial. >> Nov 26 15:30:04 s0332 ppp[1620]: tun1: LCP: deflink: >> RecvEchoRequest(174) state = Opened >> Nov 26 15:30:04 s0332 ppp[1620]: tun1: LCP: deflink: SendEchoReply(174) >> state = Opened >> Nov 26 15:30:05 s0332 ppp[1620]: tun1: IPCP: deflink: RecvConfigReq(12) >> state = Initial >> >> >> Config is simple >> >> >> pppoe: >> add 10.6.153.2 HISADDR >> add default HISADDR >> set device PPPoE:vr0 >> set server /var/run/spdsl-internet "" 0177 >> set speed sync >> enable echo >> disable ipv6cp >> disable vjcomp >> set cd 15 >> set dial >> set login >> set timeout 0 >> set lqrperiod 10 >> set authname s0332@realm >> set authkey xxxxxxxx >> set ifaddr 10.0.0.1/0 10.0.0.2/0 255.255.255.0 255.255.255.0 >> >> With debugging >> >> Nov 26 16:53:20 s0332 ppp[1620]: tun1: Timer: Select returns 1 >> Nov 26 16:53:20 s0332 ppp[1620]: tun1: Physical: read >> Nov 26 16:53:20 s0332 ppp[1620]: tun1: Physical: 80 21 01 97 00 0a 03 >> 06 43 2b 80 0e .!......C+.. >> Nov 26 16:53:20 s0332 ppp[1620]: tun1: Debug: deflink: DescriptorRead: >> read 12/2048 from 1 >> Nov 26 16:53:20 s0332 ppp[1620]: tun1: Sync: Read >> Nov 26 16:53:20 s0332 ppp[1620]: tun1: Sync: 80 21 01 97 00 0a 03 06 43 >> 2b 80 0e .!......C+.. >> Nov 26 16:53:20 s0332 ppp[1620]: tun1: Debug: proto_LayerPull: unknown >> -> 0x8021 >> Nov 26 16:53:20 s0332 ppp[1620]: tun1: Debug: link_PullPacket: Despatch >> proto 0x8021 >> Nov 26 16:53:20 s0332 ppp[1620]: tun1: IPCP: deflink: RecvConfigReq(151) >> state = Initial >> Nov 26 16:53:20 s0332 ppp[1620]: tun1: IPCP: IPADDR[6] xx.yy.128.14 >> Nov 26 16:53:20 s0332 ppp[1620]: tun1: IPCP: deflink: Oops, RCR in Initial. >> Nov 26 16:53:20 s0332 ppp[1620]: tun1: Timer: tun: fdset(r) 6 >> Nov 26 16:53:20 s0332 ppp[1620]: tun1: Timer: deflink(ctrl): fdset(r) 0 >> Nov 26 16:53:20 s0332 ppp[1620]: tun1: Timer: deflink: fdset(r) 1 >> Nov 26 16:53:20 s0332 ppp[1620]: tun1: Timer: deflink: fdset(e) 1 >> Nov 26 16:53:20 s0332 ppp[1620]: tun1: Timer: server: fdset(r) 9 >> Nov 26 16:53:20 s0332 ppp[1620]: tun1: Timer: prompt >> /var/run/spdsl-internet: fdset(r) 2 >> Nov 26 16:53:21 s0332 ppp[1620]: tun1: Timer: Select returns -1 >> Nov 26 16:53:21 s0332 ppp[1620]: tun1: Timer: ---- Begin of Timer >> Service List--- >> Nov 26 16:53:21 s0332 ppp[1620]: tun1: Timer: physical throughput >> timer[0x28411068]: freq = 1.00s, next = 0.00s, state = running >> Nov 26 16:53:21 s0332 ppp[1620]: tun1: Timer: lqm timer[0x28413df4]: >> freq = 10.00s, next = 2.40s, state = running >> Nov 26 16:53:21 s0332 ppp[1620]: tun1: Timer: hdlc timer[0x28413db0]: >> freq = 60.00s, next = 52.40s, state = running >> Nov 26 16:53:21 s0332 ppp[1620]: tun1: Timer: ---- End of Timer Service >> List --- >> Nov 26 16:53:21 s0332 ppp[1620]: tun1: Timer: timer_Start: Inserting >> physical throughput timer[0x28411068] before lqm timer[0x28413df4], >> delta = 10 >> Nov 26 16:53:21 s0332 ppp[1620]: tun1: Timer: tun: fdset(r) 6 >> Nov 26 16:53:21 s0332 ppp[1620]: tun1: Timer: deflink(ctrl): fdset(r) 0 >> Nov 26 16:53:21 s0332 ppp[1620]: tun1: Timer: deflink: fdset(r) 1 >> Nov 26 16:53:21 s0332 ppp[1620]: tun1: Timer: deflink: fdset(e) 1 >> Nov 26 16:53:21 s0332 ppp[1620]: tun1: Timer: server: fdset(r) 9 >> Nov 26 16:53:21 s0332 ppp[1620]: tun1: Timer: prompt >> /var/run/spdsl-internet: fdset(r) 2 >> Nov 26 16:53:22 s0332 ppp[1620]: tun1: Timer: Select returns -1 >> Nov 26 16:53:22 s0332 ppp[1620]: tun1: Timer: ---- Begin of Timer >> Service List--- >> Nov 26 16:53:22 s0332 ppp[1620]: tun1: Timer: physical throughput >> timer[0x28411068]: freq = 1.00s, next = 0.00s, state = running >> Nov 26 16:53:22 s0332 ppp[1620]: tun1: Timer: lqm timer[0x28413df4]: >> freq = 10.00s, next = 1.40s, state = running >> Nov 26 16:53:22 s0332 ppp[1620]: tun1: Timer: hdlc timer[0x28413db0]: >> freq = 60.00s, next = 51.40s, state = running >> Nov 26 16:53:22 s0332 ppp[1620]: tun1: Timer: ---- End of Timer Service >> List --- >> Nov 26 16:53:22 s0332 ppp[1620]: tun1: Timer: timer_Start: Inserting >> physical throughput timer[0x28411068] before lqm timer[0x28413df4], >> delta = 10 >> Nov 26 16:53:22 s0332 ppp[1620]: tun1: Timer: tun: fdset(r) 6 >> Nov 26 16:53:22 s0332 ppp[1620]: tun1: Timer: deflink(ctrl): fdset(r) 0 >> Nov 26 16:53:22 s0332 ppp[1620]: tun1: Timer: deflink: fdset(r) 1 >> Nov 26 16:53:22 s0332 ppp[1620]: tun1: Timer: deflink: fdset(e) 1 >> Nov 26 16:53:22 s0332 ppp[1620]: tun1: Timer: server: fdset(r) 9 >> Nov 26 16:53:22 s0332 ppp[1620]: tun1: Timer: prompt >> /var/run/spdsl-internet: fdset(r) 2 >> Nov 26 16:53:22 s0332 ppp[1620]: tun1: Timer: Select returns 1 >> Nov 26 16:53:22 s0332 ppp[1620]: tun1: Physical: read >> Nov 26 16:53:22 s0332 ppp[1620]: tun1: Physical: 80 21 01 98 00 0a 03 >> 06 43 2b 80 0e .!......C+.. >> Nov 26 16:53:22 s0332 ppp[1620]: tun1: Debug: deflink: DescriptorRead: >> read 12/2048 from 1 >> Nov 26 16:53:22 s0332 ppp[1620]: tun1: Sync: Read >> Nov 26 16:53:22 s0332 ppp[1620]: tun1: Sync: 80 21 01 98 00 0a 03 06 43 >> 2b 80 0e .!......C+.. >> Nov 26 16:53:22 s0332 ppp[1620]: tun1: Debug: proto_LayerPull: unknown >> -> 0x8021 >> Nov 26 16:53:22 s0332 ppp[1620]: tun1: Debug: link_PullPacket: Despatch >> proto 0x8021 >> Nov 26 16:53:22 s0332 ppp[1620]: tun1: IPCP: deflink: RecvConfigReq(152) >> state = Initial >> Nov 26 16:53:22 s0332 ppp[1620]: tun1: IPCP: IPADDR[6] xx.yy.128.14 >> Nov 26 16:53:22 s0332 ppp[1620]: tun1: IPCP: deflink: Oops, RCR in Initial. >> Nov 26 16:53:22 s0332 ppp[1620]: tun1: Timer: tun: fdset(r) 6 >> Nov 26 16:53:22 s0332 ppp[1620]: tun1: Timer: deflink(ctrl): fdset(r) 0 >> >> >> >> >> -- >> ------------------- >> Mike Tancsa, tel +1 519 651 3400 >> Sentex Communications, mike@sentex.net >> Providing Internet services since 1994 www.sentex.net >> Cambridge, Ontario Canada http://www.tancsa.com/ >> _______________________________________________ >> freebsd-questions@freebsd.org mailing list >> http://lists.freebsd.org/mailman/listinfo/freebsd-questions >> To unsubscribe, send any mail to "freebsd-questions-unsubscribe@freebsd.org" > > _______________________________________________ > freebsd-questions@freebsd.org mailing list > http://lists.freebsd.org/mailman/listinfo/freebsd-questions > To unsubscribe, send any mail to "freebsd-questions-unsubscribe@freebsd.org" > > -- ------------------- Mike Tancsa, tel +1 519 651 3400 Sentex Communications, mike@sentex.net Providing Internet services since 1994 www.sentex.net Cambridge, Ontario Canada http://www.tancsa.com/