Date: Thu, 05 Dec 2013 11:49:46 -0500 From: Mike Tancsa <mike@sentex.net> To: Chris <chris@lrckinfo.com> Cc: freebsd-questions <freebsd-questions@freebsd.org> Subject: Re: PPPoE help Message-ID: <52A0AEAA.8030503@sentex.net> In-Reply-To: <E0E413DA-E77D-4CB0-8126-E4624ABF9E9C@lrckinfo.com> References: <529FA253.2000900@sentex.net> <E0E413DA-E77D-4CB0-8126-E4624ABF9E9C@lrckinfo.com>
next in thread | previous in thread | raw e-mail | index | archive | help
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 <mike@sentex.net> 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/
Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?52A0AEAA.8030503>