Date: Thu, 5 Oct 2006 00:06:06 +0200 From: cpghost <cpghost@cordula.ws> To: Ulrich Spoerlein <uspoerlein@gmail.com>, stable@freebsd.org Subject: Re: ppp redial unsuccessful Message-ID: <20061004220606.GA95202@epia2.farid-hajji.net> In-Reply-To: <20061004213909.GC1848@roadrunner.q.local> References: <20061004185148.GA1848@roadrunner.q.local> <20061004185911.GA94703@epia2.farid-hajji.net> <20061004190611.GB1848@roadrunner.q.local> <45240D81.2080506@mail.txf.com> <20061004212417.GA95104@epia2.farid-hajji.net> <20061004213909.GC1848@roadrunner.q.local>
next in thread | previous in thread | raw e-mail | index | archive | help
On Wed, Oct 04, 2006 at 11:39:09PM +0200, Ulrich Spoerlein wrote: > I maintain three FreeBSD boxes from 4.11 to 6.1-RELEASE and 6-STABLE. > They have been showing this for at least 1 or 2 years. So it is/was also > present in the 5.x line. > > I usually work around this by having a cron job that restarts ppp every > day at 04:00 or somewhere around that. > > So either I'm just unlucky or I'm doing something fundamentally wrong. > > Could someone paste me the snippet from ppp.log of a successful 24h > disconnect + redial? Here we go (sorry, it's a bit lengthy): Oct 4 03:07:03 fw ppp[219]: LCP: deflink: RecvEchoReply(58) state = Opened Oct 4 03:07:14 fw ppp[219]: LCP: deflink: RecvEchoRequest(0) state = Opened Oct 4 03:07:14 fw ppp[219]: LCP: deflink: SendEchoReply(0) state = Opened Oct 4 03:07:17 fw ppp[219]: Phase: Received NGM_PPPOE_CLOSE Oct 4 03:07:17 fw ppp[219]: Phase: deflink: Device disconnected Oct 4 03:07:17 fw ppp[219]: CCP: deflink: State change Stopped --> Closed Oct 4 03:07:17 fw ppp[219]: CCP: deflink: State change Closed --> Initial Oct 4 03:07:17 fw ppp[219]: LCP: deflink: LayerDown Oct 4 03:07:17 fw ppp[219]: LCP: deflink: State change Opened --> Starting Oct 4 03:07:17 fw ppp[219]: Phase: deflink: open -> lcp Oct 4 03:07:17 fw ppp[219]: IPCP: deflink: LayerDown: 111.222.111.222 Oct 4 03:07:17 fw ppp[219]: IPCP: Using trigger address 0.0.0.0 Oct 4 03:07:17 fw ppp[219]: IPCP: deflink: State change Opened --> Starting Oct 4 03:07:17 fw ppp[219]: IPCP: deflink: LayerFinish. Oct 4 03:07:17 fw ppp[219]: IPCP: Connect time: 86399 secs: 1659445914 octets in, 662415224 octets out Oct 4 03:07:17 fw ppp[219]: IPCP: 167362746 packets in, 154080745 packets out Oct 4 03:07:17 fw ppp[219]: IPCP: total 26873 bytes/sec, peak 123304 bytes/sec on Tue Oct 3 23:11:04 2006 Oct 4 03:07:17 fw ppp[219]: IPCP: deflink: State change Starting --> Initial Oct 4 03:07:17 fw ppp[219]: Phase: bundle: Terminate Oct 4 03:07:17 fw ppp[219]: LCP: deflink: LayerFinish Oct 4 03:07:17 fw ppp[219]: LCP: deflink: State change Starting --> Initial Oct 4 03:07:17 fw ppp[219]: Phase: deflink: Disconnected! Oct 4 03:07:17 fw ppp[219]: Phase: deflink: lcp -> logout Oct 4 03:07:17 fw ppp[219]: Phase: deflink: Disconnected! Oct 4 03:07:17 fw ppp[219]: Phase: deflink: logout -> hangup Oct 4 03:07:17 fw ppp[219]: Phase: deflink: Connect time: 86403 secs: 1655294933 octets in, 666526906 octets out Oct 4 03:07:17 fw ppp[219]: Phase: deflink: 167928154 packets in, 154647096 packets out Oct 4 03:07:17 fw ppp[219]: Phase: total 26872 bytes/sec, peak 125048 bytes/sec on Tue Oct 3 23:11:29 2006 Oct 4 03:07:17 fw ppp[219]: Phase: deflink: hangup -> opening Oct 4 03:07:17 fw ppp[219]: Phase: bundle: Establish Oct 4 03:07:17 fw ppp[219]: Phase: deflink: Enter pause (3) for redialing. Oct 4 03:07:20 fw ppp[219]: Phase: deflink: Connected! Oct 4 03:07:20 fw ppp[219]: Phase: deflink: opening -> dial Oct 4 03:07:20 fw ppp[219]: Phase: deflink: dial -> carrier Oct 4 03:07:22 fw ppp[219]: Phase: Received NGM_PPPOE_ACNAME (hook "DSSX43-erx") Oct 4 03:07:22 fw ppp[219]: Phase: Received NGM_PPPOE_SESSIONID Oct 4 03:07:22 fw ppp[219]: Phase: Received NGM_PPPOE_SUCCESS Oct 4 03:07:22 fw ppp[219]: Phase: deflink: carrier -> login Oct 4 03:07:22 fw ppp[219]: Phase: deflink: login -> lcp Oct 4 03:07:22 fw ppp[219]: LCP: FSM: Using "deflink" as a transport Oct 4 03:07:22 fw ppp[219]: LCP: deflink: State change Initial --> Closed Oct 4 03:07:22 fw ppp[219]: LCP: deflink: State change Closed --> Stopped Oct 4 03:07:23 fw ppp[219]: LCP: deflink: LayerStart Oct 4 03:07:23 fw ppp[219]: LCP: deflink: SendConfigReq(58) state = Stopped Oct 4 03:07:23 fw ppp[219]: LCP: MRU[4] 1460 Oct 4 03:07:23 fw ppp[219]: LCP: MAGICNUM[6] 0xff621829 Oct 4 03:07:23 fw ppp[219]: LCP: deflink: State change Stopped --> Req-Sent Oct 4 03:07:23 fw ppp[219]: LCP: deflink: RecvConfigReq(209) state = Req-Sent Oct 4 03:07:23 fw ppp[219]: LCP: MRU[4] 1492 Oct 4 03:07:23 fw ppp[219]: LCP: AUTHPROTO[4] 0xc023 (PAP) Oct 4 03:07:23 fw ppp[219]: LCP: MAGICNUM[6] 0x60a9a23e Oct 4 03:07:23 fw ppp[219]: LCP: deflink: SendConfigAck(209) state = Req-Sent Oct 4 03:07:23 fw ppp[219]: LCP: MRU[4] 1492 Oct 4 03:07:23 fw ppp[219]: LCP: AUTHPROTO[4] 0xc023 (PAP) Oct 4 03:07:23 fw ppp[219]: LCP: MAGICNUM[6] 0x60a9a23e Oct 4 03:07:23 fw ppp[219]: LCP: deflink: State change Req-Sent --> Ack-Sent Oct 4 03:07:23 fw ppp[219]: LCP: deflink: RecvConfigAck(58) state = Ack-Sent Oct 4 03:07:23 fw ppp[219]: LCP: MRU[4] 1460 Oct 4 03:07:23 fw ppp[219]: LCP: MAGICNUM[6] 0xff621829 Oct 4 03:07:23 fw ppp[219]: LCP: deflink: State change Ack-Sent --> Opened Oct 4 03:07:23 fw ppp[219]: LCP: deflink: LayerUp Oct 4 03:07:23 fw ppp[219]: LCP: deflink: SendEchoRequest(0) state = Opened Oct 4 03:07:23 fw ppp[219]: LCP: deflink: SendIdent(102) state = Opened Oct 4 03:07:23 fw ppp[219]: LCP: MAGICNUM ff621829 Oct 4 03:07:23 fw ppp[219]: LCP: TEXT user-ppp 3.4.2 (built Jul 22 2006) Oct 4 03:07:23 fw ppp[219]: Phase: bundle: Authenticate Oct 4 03:07:23 fw ppp[219]: Phase: deflink: his = PAP, mine = none Oct 4 03:07:23 fw ppp[219]: Phase: Pap Output: XXXXXXXXXXXXXXXXXXXXX ******** Oct 4 03:07:23 fw ppp[219]: LCP: deflink: RecvEchoReply(0) state = Opened Oct 4 03:07:24 fw ppp[219]: LCP: deflink: RecvConfigReq(1) state = Opened Oct 4 03:07:24 fw ppp[219]: LCP: deflink: LayerDown Oct 4 03:07:24 fw ppp[219]: LCP: MRU[4] 1492 Oct 4 03:07:24 fw ppp[219]: LCP: AUTHPROTO[4] 0xc023 (PAP) Oct 4 03:07:24 fw ppp[219]: LCP: MAGICNUM[6] 0xf354c39a Oct 4 03:07:24 fw ppp[219]: LCP: deflink: SendConfigReq(59) state = Opened Oct 4 03:07:24 fw ppp[219]: LCP: MRU[4] 1460 Oct 4 03:07:24 fw ppp[219]: LCP: MAGICNUM[6] 0xa01edec4 Oct 4 03:07:24 fw ppp[219]: LCP: deflink: SendConfigAck(1) state = Opened Oct 4 03:07:24 fw ppp[219]: LCP: MRU[4] 1492 Oct 4 03:07:24 fw ppp[219]: LCP: AUTHPROTO[4] 0xc023 (PAP) Oct 4 03:07:24 fw ppp[219]: LCP: MAGICNUM[6] 0xf354c39a Oct 4 03:07:24 fw ppp[219]: LCP: deflink: State change Opened --> Ack-Sent Oct 4 03:07:24 fw ppp[219]: LCP: deflink: RecvConfigNak(59) state = Ack-Sent Oct 4 03:07:24 fw ppp[219]: LCP: MRU[4] 1492 Oct 4 03:07:24 fw ppp[219]: LCP: deflink: SendConfigReq(60) state = Ack-Sent Oct 4 03:07:24 fw ppp[219]: LCP: MRU[4] 1460 Oct 4 03:07:24 fw ppp[219]: LCP: MAGICNUM[6] 0xa01edec4 Oct 4 03:07:24 fw ppp[219]: LCP: deflink: RecvConfigNak(60) state = Ack-Sent Oct 4 03:07:24 fw ppp[219]: LCP: MRU[4] 1492 Oct 4 03:07:24 fw ppp[219]: LCP: deflink: SendConfigReq(61) state = Ack-Sent Oct 4 03:07:24 fw ppp[219]: LCP: MRU[4] 1460 Oct 4 03:07:24 fw ppp[219]: LCP: MAGICNUM[6] 0xa01edec4 Oct 4 03:07:24 fw ppp[219]: LCP: deflink: RecvConfigNak(61) state = Ack-Sent Oct 4 03:07:24 fw ppp[219]: LCP: MRU[4] 1492 Oct 4 03:07:24 fw ppp[219]: LCP: deflink: SendConfigReq(62) state = Ack-Sent Oct 4 03:07:24 fw ppp[219]: LCP: MRU[4] 1460 Oct 4 03:07:24 fw ppp[219]: LCP: MAGICNUM[6] 0xa01edec4 Oct 4 03:07:24 fw ppp[219]: LCP: deflink: RecvConfigNak(62) state = Ack-Sent Oct 4 03:07:24 fw ppp[219]: LCP: MRU[4] 1492 Oct 4 03:07:24 fw ppp[219]: LCP: deflink: SendConfigReq(63) state = Ack-Sent Oct 4 03:07:24 fw ppp[219]: LCP: MRU[4] 1460 Oct 4 03:07:24 fw ppp[219]: LCP: MAGICNUM[6] 0xa01edec4 Oct 4 03:07:24 fw ppp[219]: LCP: deflink: RecvConfigNak(63) state = Ack-Sent Oct 4 03:07:24 fw ppp[219]: LCP: MRU[4] 1492 Oct 4 03:07:24 fw ppp[219]: LCP: deflink: SendConfigReq(64) state = Ack-Sent Oct 4 03:07:24 fw ppp[219]: LCP: MRU[4] 1460 Oct 4 03:07:24 fw ppp[219]: LCP: MAGICNUM[6] 0xa01edec4 Oct 4 03:07:24 fw ppp[219]: LCP: deflink: RecvConfigRej(64) state = Ack-Sent Oct 4 03:07:24 fw ppp[219]: LCP: deflink: SendIdent(103) state = Ack-Sent Oct 4 03:07:24 fw ppp[219]: LCP: MAGICNUM a01edec4 Oct 4 03:07:24 fw ppp[219]: LCP: TEXT user-ppp 3.4.2 (built Jul 22 2006) Oct 4 03:07:24 fw ppp[219]: LCP: MRU[4] 1460 Oct 4 03:07:24 fw ppp[219]: LCP: deflink: SendConfigReq(65) state = Ack-Sent Oct 4 03:07:24 fw ppp[219]: LCP: MAGICNUM[6] 0xa01edec4 Oct 4 03:07:24 fw ppp[219]: LCP: deflink: RecvConfigAck(65) state = Ack-Sent Oct 4 03:07:24 fw ppp[219]: LCP: MAGICNUM[6] 0xa01edec4 Oct 4 03:07:24 fw ppp[219]: LCP: deflink: State change Ack-Sent --> Opened Oct 4 03:07:24 fw ppp[219]: LCP: deflink: LayerUp Oct 4 03:07:24 fw ppp[219]: LCP: deflink: SendEchoRequest(0) state = Opened Oct 4 03:07:24 fw ppp[219]: LCP: deflink: SendIdent(104) state = Opened Oct 4 03:07:24 fw ppp[219]: LCP: MAGICNUM a01edec4 Oct 4 03:07:24 fw ppp[219]: LCP: TEXT user-ppp 3.4.2 (built Jul 22 2006) Oct 4 03:07:24 fw ppp[219]: Phase: deflink: his = PAP, mine = none Oct 4 03:07:24 fw ppp[219]: Phase: Pap Output: XXXXXXXXXXXXXXXXXXXXX ******** Oct 4 03:07:24 fw ppp[219]: LCP: deflink: RecvEchoReply(0) state = Opened Oct 4 03:07:24 fw ppp[219]: LCP: deflink: RecvConfigReq(1) state = Opened Oct 4 03:07:24 fw ppp[219]: LCP: deflink: LayerDown Oct 4 03:07:24 fw ppp[219]: LCP: MRU[4] 1460 Oct 4 03:07:24 fw ppp[219]: LCP: AUTHPROTO[4] 0xc023 (PAP) Oct 4 03:07:24 fw ppp[219]: LCP: MAGICNUM[6] 0x3d11736a Oct 4 03:07:24 fw ppp[219]: LCP: deflink: SendConfigReq(66) state = Opened Oct 4 03:07:24 fw ppp[219]: LCP: MRU[4] 1460 Oct 4 03:07:24 fw ppp[219]: LCP: MAGICNUM[6] 0x6607d07b Oct 4 03:07:24 fw ppp[219]: LCP: deflink: SendConfigAck(1) state = Opened Oct 4 03:07:24 fw ppp[219]: LCP: MRU[4] 1460 Oct 4 03:07:24 fw ppp[219]: LCP: AUTHPROTO[4] 0xc023 (PAP) Oct 4 03:07:24 fw ppp[219]: LCP: MAGICNUM[6] 0x3d11736a Oct 4 03:07:24 fw ppp[219]: LCP: deflink: State change Opened --> Ack-Sent Oct 4 03:07:24 fw ppp[219]: LCP: deflink: RecvConfigAck(66) state = Ack-Sent Oct 4 03:07:24 fw ppp[219]: LCP: MRU[4] 1460 Oct 4 03:07:24 fw ppp[219]: LCP: MAGICNUM[6] 0x6607d07b Oct 4 03:07:24 fw ppp[219]: LCP: deflink: State change Ack-Sent --> Opened Oct 4 03:07:24 fw ppp[219]: LCP: deflink: LayerUp Oct 4 03:07:24 fw ppp[219]: LCP: deflink: SendEchoRequest(0) state = Opened Oct 4 03:07:24 fw ppp[219]: LCP: deflink: SendIdent(105) state = Opened Oct 4 03:07:24 fw ppp[219]: LCP: MAGICNUM 6607d07b Oct 4 03:07:24 fw ppp[219]: LCP: TEXT user-ppp 3.4.2 (built Jul 22 2006) Oct 4 03:07:24 fw ppp[219]: Phase: deflink: his = PAP, mine = none Oct 4 03:07:24 fw ppp[219]: Phase: Pap Output: XXXXXXXXXXXXXXXXXXXXX ******** Oct 4 03:07:24 fw ppp[219]: LCP: deflink: RecvEchoReply(0) state = Opened Oct 4 03:07:24 fw ppp[219]: Phase: Pap Input: SUCCESS () Oct 4 03:07:24 fw ppp[219]: IPCP: Using trigger address 0.0.0.0 Oct 4 03:07:24 fw ppp[219]: CCP: FSM: Using "deflink" as a transport Oct 4 03:07:24 fw ppp[219]: CCP: deflink: State change Initial --> Closed Oct 4 03:07:24 fw ppp[219]: CCP: deflink: LayerStart. Oct 4 03:07:24 fw ppp[219]: CCP: MPPE: Not usable without CHAP81 Oct 4 03:07:24 fw ppp[219]: CCP: deflink: SendConfigReq(1) state = Closed Oct 4 03:07:24 fw ppp[219]: CCP: [EMPTY] Oct 4 03:07:24 fw ppp[219]: CCP: deflink: State change Closed --> Req-Sent Oct 4 03:07:24 fw ppp[219]: Phase: deflink: lcp -> open Oct 4 03:07:24 fw ppp[219]: Phase: bundle: Network Oct 4 03:07:24 fw ppp[219]: IPCP: FSM: Using "deflink" as a transport Oct 4 03:07:24 fw ppp[219]: IPCP: deflink: State change Initial --> Closed Oct 4 03:07:24 fw ppp[219]: IPCP: deflink: LayerStart. Oct 4 03:07:24 fw ppp[219]: IPCP: deflink: SendConfigReq(151) state = Closed Oct 4 03:07:24 fw ppp[219]: IPCP: IPADDR[6] 0.0.0.0 Oct 4 03:07:24 fw ppp[219]: IPCP: deflink: State change Closed --> Req-Sent Oct 4 03:07:24 fw ppp[219]: IPCP: deflink: RecvConfigReq(1) state = Req-Sent Oct 4 03:07:24 fw ppp[219]: IPCP: IPADDR[6] 222.222.222.222 Oct 4 03:07:24 fw ppp[219]: IPCP: deflink: SendConfigAck(1) state = Req-Sent Oct 4 03:07:24 fw ppp[219]: IPCP: IPADDR[6] 222.222.222.222 Oct 4 03:07:24 fw ppp[219]: IPCP: deflink: State change Req-Sent --> Ack-Sent Oct 4 03:07:24 fw ppp[219]: LCP: deflink: RecvProtocolRej(2) state = Opened Oct 4 03:07:24 fw ppp[219]: LCP: deflink: -- Protocol 0x80fd (Compression Control Protocol) was rejected! Oct 4 03:07:24 fw ppp[219]: CCP: deflink: State change Req-Sent --> Stopped Oct 4 03:07:24 fw ppp[219]: IPCP: deflink: RecvConfigNak(151) state = Ack-Sent Oct 4 03:07:24 fw ppp[219]: IPCP: IPADDR[6] 111.222.111.222 Oct 4 03:07:24 fw ppp[219]: IPCP: IPADDR[6] changing address: 0.0.0.0 --> 111.222.111.222 Oct 4 03:07:24 fw ppp[219]: IPCP: deflink: SendConfigReq(152) state = Ack-Sent Oct 4 03:07:24 fw ppp[219]: IPCP: IPADDR[6] 111.222.111.222 Oct 4 03:07:24 fw ppp[219]: LCP: deflink: RecvProtocolRej(3) state = Opened Oct 4 03:07:24 fw ppp[219]: LCP: deflink: -- Protocol 0x8057 (Internet Protocol V6 Control Protocol) was rejected! Oct 4 03:07:24 fw ppp[219]: Phase: deflink: IPV6CP protocol reject closes IPV6CP ! Oct 4 03:07:24 fw ppp[219]: IPCP: deflink: RecvConfigAck(152) state = Ack-Sent Oct 4 03:07:24 fw ppp[219]: IPCP: IPADDR[6] 111.222.111.222 Oct 4 03:07:24 fw ppp[219]: IPCP: deflink: State change Ack-Sent --> Opened Oct 4 03:07:24 fw ppp[219]: IPCP: deflink: LayerUp. Oct 4 03:07:24 fw ppp[219]: IPCP: myaddr 111.222.111.222 hisaddr = 222.222.222.222 Oct 4 03:07:25 fw ppp[219]: LCP: deflink: RecvEchoRequest(1) state = Opened Oct 4 03:07:25 fw ppp[219]: LCP: deflink: SendEchoReply(1) state = Opened Oct 4 03:07:54 fw ppp[219]: LCP: deflink: SendEchoRequest(1) state = Opened Oct 4 03:07:54 fw ppp[219]: LCP: deflink: RecvEchoReply(1) state = Opened Here's /etc/ppp/ppp.conf: default: set log Phase Chat LCP IPCP CCP tun command ident user-ppp VERSION (built COMPILATIONDATE) isp-dsl: set device PPPoE:sis0 #set MTU 1492 #set MRU 1492 set MTU 1460 set MRU 1460 set dial set crtscts off set speed sync #accept lqr #enable lqr #enable lqr echo disable lqr set echoperiod 30 enable echo disable deflate disable pred1 disable vjcomp disable acfcomp disable protocomp set log Phase LCP IPCP CCP Warning Error Alert set ifaddr 10.0.0.1/0 10.0.0.2/0 0.0.0.0 0.0.0.0 set login set authname XXXXXXXXXXXXXXXXXXXXX set authkey XXXXXXXXXXXX set timeout 0 add default HISADDR set server /var/run/internet "" 0177 > Ulrich Spoerlein Good luck! -cpghost. -- Cordula's Web. http://www.cordula.ws/
Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?20061004220606.GA95202>