From owner-freebsd-net@FreeBSD.ORG Sun Jan 18 10:52:35 2004 Return-Path: Delivered-To: freebsd-net@freebsd.org Received: from mx1.FreeBSD.org (mx1.freebsd.org [216.136.204.125]) by hub.freebsd.org (Postfix) with ESMTP id B680316A4CE for ; Sun, 18 Jan 2004 10:52:35 -0800 (PST) Received: from server34.totalchoicehosting.com (server34.totalchoicehosting.com [69.50.194.230]) by mx1.FreeBSD.org (Postfix) with ESMTP id 3A6A843D39 for ; Sun, 18 Jan 2004 10:52:28 -0800 (PST) (envelope-from niranjan@monsoonrain.net) Received: from cpanel by server34.totalchoicehosting.com with local (Exim 4.24) id 1AiI24-0003ZM-LG; Sun, 18 Jan 2004 11:52:24 -0700 Received: from localhost (localhost [127.0.0.1]) by www.monsoonrain.net (IMP) with HTTP for ; Sun, 18 Jan 2004 13:52:24 -0500 Message-ID: <1074451944.400ad5e888ba4@www.monsoonrain.net> Date: Sun, 18 Jan 2004 13:52:24 -0500 From: niranjan@monsoonrain.net To: nil000@cse.unsw.edu.au References: <4009C0D5.2070209@cse.unsw.edu.au> In-Reply-To: <4009C0D5.2070209@cse.unsw.edu.au> MIME-Version: 1.0 Content-Type: text/plain; charset=ISO-8859-1 Content-Transfer-Encoding: 8bit User-Agent: Internet Messaging Program (IMP) 3.2.1 X-Originating-IP: 127.0.0.1 X-AntiAbuse: This header was added to track abuse, please include it with any abuse report X-AntiAbuse: Primary Hostname - server34.totalchoicehosting.com X-AntiAbuse: Original Domain - freebsd.org X-AntiAbuse: Originator/Caller UID/GID - [32001 32001] / [47 12] X-AntiAbuse: Sender Address Domain - monsoonrain.net cc: freebsd-net@freebsd.org Subject: Re: PPPoE problem: "Too many LQR packets lost" X-BeenThere: freebsd-net@freebsd.org X-Mailman-Version: 2.1.1 Precedence: list List-Id: Networking and TCP/IP with FreeBSD List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Sun, 18 Jan 2004 18:52:35 -0000 Quoting nil000@cse.unsw.edu.au: > Since my ADSL connection was moved at my ISP's end from one set of > equipment (norte shasta?) to another (unisphere?), I've been having > problems with my PPPoE sessions. > > With "enable lqr" in my ppp.conf, the connection terminates after a few > mintues with "Too many LQR packets lost". I've included log output > below. According to these posts, > Yes, despite the original intent of the RFC, LQM is not commonly used for link state detection and most implementations rely on LCP echoes with knobs for setting the deadcount and loopcount parameters. (counters that dictate when the lcp echo fsm should declare link as dead or link as looped) > Short of actually fixing this LQR negotiation issue (?), might the > suggestion of a ppp.conf option to force LCP echo usage be good? > Yes. I am surprized it doesn't already have that option since thats a more common scenario. Alternately you could use another pppoe implementation, perhaps the one based on pppd/netgraph. BTW, the lcp.c patch suggested by someone else is not the correct approach. There also seems to be a problem with the way the FreeBSD kernel PPP implementation handles LQR and you can see it in the log below. (The unisphere at the other end isn't perfect either and has its own issues!) regards, niranjan [log start] > Jan 3 21:28:11 nn ppp[69401]: Phase: Using interface: tun0 > Jan 3 21:28:11 nn ppp[69401]: Phase: deflink: Created in closed state > Jan 3 21:28:11 nn ppp[69401]: tun0: Command: default: set device > PPPoE:ed0:internode > Jan 3 21:28:11 nn ppp[69401]: tun0: Command: default: set speed sync > Jan 3 21:28:11 nn ppp[69401]: tun0: Command: default: set mru 1492 > Jan 3 21:28:11 nn ppp[69401]: tun0: Command: default: set mtu 1492 > Jan 3 21:28:11 nn ppp[69401]: tun0: Command: default: set ctsrts off > Jan 3 21:28:11 nn ppp[69401]: tun0: Command: default: enable lqr (1) FreeBSD config enables LQR... > Jan 3 21:28:11 nn ppp[69401]: tun0: Command: default: add default HISADDR > Jan 3 21:28:11 nn ppp[69401]: tun0: Command: default: set timeout 0 > Jan 3 21:28:11 nn ppp[69401]: tun0: Command: default: set redial 0 0 > Jan 3 21:28:11 nn ppp[69401]: tun0: Command: internode: set authname > nil000@bogus.internode.on.net > Jan 3 21:28:11 nn ppp[69401]: tun0: Command: internode: set authkey > ******** > Jan 3 21:28:11 nn ppp[69401]: tun0: Command: internode: enable dns > Jan 3 21:28:11 nn ppp[69401]: tun0: Command: internode: nat enable yes > Jan 3 21:28:11 nn ppp[69401]: tun0: Command: internode: nat log yes > Jan 3 21:28:11 nn ppp[69401]: tun0: Command: internode: nat same_ports yes > Jan 3 21:28:11 nn ppp[69401]: tun0: Command: internode: nat > unregistered_only yes > Jan 3 21:28:12 nn ppp[69402]: tun0: LCP: FSM: Using "deflink" as a > transport > Jan 3 21:28:12 nn ppp[69402]: tun0: LCP: deflink: State change Initial > --> Closed > Jan 3 21:28:12 nn ppp[69402]: tun0: LCP: deflink: State change Closed > --> Stopped > Jan 3 21:28:13 nn ppp[69402]: tun0: LCP: deflink: RecvConfigReq(137) > state = Stopped > Jan 3 21:28:13 nn ppp[69402]: tun0: LCP: MRU[4] 1492 > Jan 3 21:28:13 nn ppp[69402]: tun0: LCP: AUTHPROTO[5] 0xc223 (CHAP 0x05) > Jan 3 21:28:13 nn ppp[69402]: tun0: LCP: MAGICNUM[6] 0x3d9db2a2 > Jan 3 21:28:13 nn ppp[69402]: tun0: LCP: deflink: SendConfigReq(1) > state = Stopped > Jan 3 21:28:13 nn ppp[69402]: tun0: LCP: MRU[4] 1492 > Jan 3 21:28:13 nn ppp[69402]: tun0: LCP: MAGICNUM[6] 0xbdf7d851 > Jan 3 21:28:13 nn ppp[69402]: tun0: LCP: QUALPROTO[8] proto c025, > interval 30000ms (2) FreeBSD requests LQR in the config request > Jan 3 21:28:13 nn ppp[69402]: tun0: LCP: deflink: SendConfigAck(137) > state = Stopped > Jan 3 21:28:13 nn ppp[69402]: tun0: LCP: MRU[4] 1492 > Jan 3 21:28:13 nn ppp[69402]: tun0: LCP: AUTHPROTO[5] 0xc223 (CHAP 0x05) > Jan 3 21:28:13 nn ppp[69402]: tun0: LCP: MAGICNUM[6] 0x3d9db2a2 > Jan 3 21:28:13 nn ppp[69402]: tun0: LCP: deflink: LayerStart > Jan 3 21:28:13 nn ppp[69402]: tun0: LCP: deflink: State change Stopped > --> Ack-Sent > Jan 3 21:28:13 nn ppp[69402]: tun0: LCP: deflink: RecvConfigRej(1) > state = Ack-Sent > Jan 3 21:28:13 nn ppp[69402]: tun0: LCP: QUALPROTO[8] proto c025, > interval 30000ms (3) Other end did not like LQR and rejected it > Jan 3 21:28:13 nn ppp[69402]: tun0: LCP: deflink: SendConfigReq(2) > state = Ack-Sent > Jan 3 21:28:13 nn ppp[69402]: tun0: LCP: MRU[4] 1492 > Jan 3 21:28:13 nn ppp[69402]: tun0: LCP: MAGICNUM[6] 0xbdf7d851 > Jan 3 21:28:13 nn ppp[69402]: tun0: LCP: deflink: RecvConfigAck(2) > state = Ack-Sent > Jan 3 21:28:13 nn ppp[69402]: tun0: LCP: MRU[4] 1492 > Jan 3 21:28:13 nn ppp[69402]: tun0: LCP: MAGICNUM[6] 0xbdf7d851 > Jan 3 21:28:13 nn ppp[69402]: tun0: LCP: deflink: State change Ack-Sent > --> Opened (4) FreeBSD now sends a config without LQR > Jan 3 21:28:13 nn ppp[69402]: tun0: LCP: deflink: LayerUp > Jan 3 21:28:13 nn ppp[69402]: tun0: LQM: deflink: Will send ECHO LQR > every 30.00 secs (5) and then decides that it still wants to use LQR... > Jan 3 21:28:13 nn ppp[69402]: tun0: LCP: deflink: SendEchoRequest(0) > state = Opened > Jan 3 21:28:13 nn ppp[69402]: tun0: LCP: deflink: RecvEchoReply(0) > state = Opened > Jan 3 21:28:15 nn ppp[69402]: tun0: LCP: deflink: RecvConfigReq(2) > state = Opened > Jan 3 21:28:15 nn ppp[69402]: tun0: LCP: deflink: LayerDown > Jan 3 21:28:15 nn ppp[69402]: tun0: LCP: AUTHPROTO[5] 0xc223 (CHAP 0x05) > Jan 3 21:28:15 nn ppp[69402]: tun0: LCP: MAGICNUM[6] 0x82a38e1b > Jan 3 21:28:15 nn ppp[69402]: tun0: LCP: deflink: SendConfigReq(3) > state = Opened > Jan 3 21:28:15 nn ppp[69402]: tun0: LCP: MRU[4] 1492 > Jan 3 21:28:15 nn ppp[69402]: tun0: LCP: MAGICNUM[6] 0x2f84cfe2 > Jan 3 21:28:15 nn ppp[69402]: tun0: LCP: QUALPROTO[8] proto c025, > interval 30000ms (6) and tells the other end again that it wants to use LQR... > Jan 3 21:28:15 nn ppp[69402]: tun0: LCP: deflink: SendConfigNak(2) > state = Opened > Jan 3 21:28:15 nn ppp[69402]: tun0: LCP: MRU[4] 1492 > Jan 3 21:28:15 nn ppp[69402]: tun0: LCP: deflink: State change Opened > --> Req-Sent > Jan 3 21:28:15 nn ppp[69402]: tun0: LCP: deflink: RecvConfigAck(3) > state = Req-Sent > Jan 3 21:28:15 nn ppp[69402]: tun0: LCP: MRU[4] 1492 > Jan 3 21:28:15 nn ppp[69402]: tun0: LCP: MAGICNUM[6] 0x2f84cfe2 > Jan 3 21:28:15 nn ppp[69402]: tun0: LCP: QUALPROTO[8] proto c025, > interval 30000ms > Jan 3 21:28:15 nn ppp[69402]: tun0: LCP: deflink: State change Req-Sent > --> Ack-Rcvd (7) other end has no intention of supporting LQR but still acks it.. obviously, at a later time LQR is going to yell "Link Down".. > Jan 3 21:28:15 nn ppp[69402]: tun0: LCP: deflink: RecvConfigReq(3) > state = Ack-Rcvd > Jan 3 21:28:15 nn ppp[69402]: tun0: LCP: MRU[4] 1492 > Jan 3 21:28:15 nn ppp[69402]: tun0: LCP: AUTHPROTO[5] 0xc223 (CHAP 0x05) > Jan 3 21:28:15 nn ppp[69402]: tun0: LCP: MAGICNUM[6] 0x82a38e1b > Jan 3 21:28:15 nn ppp[69402]: tun0: LCP: deflink: SendConfigAck(3) > state = Ack-Rcvd > Jan 3 21:28:15 nn ppp[69402]: tun0: LCP: MRU[4] 1492 > Jan 3 21:28:15 nn ppp[69402]: tun0: LCP: AUTHPROTO[5] 0xc223 (CHAP 0x05) > Jan 3 21:28:15 nn ppp[69402]: tun0: LCP: MAGICNUM[6] 0x82a38e1b > Jan 3 21:28:15 nn ppp[69402]: tun0: LCP: deflink: State change Ack-Rcvd > --> Opened > Jan 3 21:28:15 nn ppp[69402]: tun0: LCP: deflink: LayerUp > Jan 3 21:28:15 nn ppp[69402]: tun0: LQM: deflink: Will send LQR every > 30.00 secs > Jan 3 21:28:15 nn ppp[69402]: tun0: LQM: deflink: Output: > Jan 3 21:28:15 nn ppp[69402]: tun0: LQM: Magic: 2f84cfe2 > LastOutLQRs: 00000000 > Jan 3 21:28:15 nn ppp[69402]: tun0: LQM: LastOutPackets: 00000000 > LastOutOctets: 00000000 > Jan 3 21:28:15 nn ppp[69402]: tun0: LQM: PeerInLQRs: 00000000 > PeerInPackets: 00000008 > Jan 3 21:28:15 nn ppp[69402]: tun0: LQM: PeerInDiscards: 00000000 > PeerInErrors: 00000000 > Jan 3 21:28:15 nn ppp[69402]: tun0: LQM: PeerInOctets: 000000b0 > PeerOutLQRs: 00000001 > Jan 3 21:28:15 nn ppp[69402]: tun0: LQM: PeerOutPackets: 00000009 > PeerOutOctets: 000000fe > Jan 3 21:28:15 nn ppp[69402]: tun0: IPCP: FSM: Using "deflink" as a > transport > Jan 3 21:28:15 nn ppp[69402]: tun0: IPCP: deflink: State change Initial > --> Closed > Jan 3 21:28:15 nn ppp[69402]: tun0: IPCP: deflink: LayerStart. > Jan 3 21:28:15 nn ppp[69402]: tun0: IPCP: deflink: SendConfigReq(1) > state = Closed > Jan 3 21:28:15 nn ppp[69402]: tun0: IPCP: IPADDR[6] 192.168.234.239 > Jan 3 21:28:15 nn ppp[69402]: tun0: IPCP: COMPPROTO[6] 16 VJ slots > with slot compression > Jan 3 21:28:15 nn ppp[69402]: tun0: IPCP: PRIDNS[6] 192.231.203.3 > Jan 3 21:28:15 nn ppp[69402]: tun0: IPCP: SECDNS[6] 255.255.255.255 > Jan 3 21:28:15 nn ppp[69402]: tun0: IPCP: deflink: State change Closed > --> Req-Sent > Jan 3 21:28:15 nn ppp[69402]: tun0: IPCP: deflink: RecvConfigReq(1) > state = Req-Sent > Jan 3 21:28:15 nn ppp[69402]: tun0: IPCP: IPADDR[6] 150.101.197.97 > Jan 3 21:28:15 nn ppp[69402]: tun0: IPCP: deflink: SendConfigAck(1) > state = Req-Sent > Jan 3 21:28:15 nn ppp[69402]: tun0: IPCP: IPADDR[6] 150.101.197.97 > Jan 3 21:28:15 nn ppp[69402]: tun0: IPCP: deflink: State change > Req-Sent --> Ack-Sent > Jan 3 21:28:15 nn ppp[69402]: tun0: LCP: deflink: RecvProtocolRej(4) > state = Opened > Jan 3 21:28:15 nn ppp[69402]: tun0: LCP: deflink: -- Protocol 0x80fd > (Compression Control Protocol) was rejected! > Jan 3 21:28:15 nn ppp[69402]: tun0: IPCP: deflink: RecvConfigRej(1) > state = Ack-Sent > Jan 3 21:28:15 nn ppp[69402]: tun0: IPCP: COMPPROTO[6] 16 VJ slots > with slot compression > Jan 3 21:28:15 nn ppp[69402]: tun0: IPCP: deflink: SendConfigReq(2) > state = Ack-Sent > Jan 3 21:28:15 nn ppp[69402]: tun0: IPCP: IPADDR[6] 192.168.234.239 > Jan 3 21:28:15 nn ppp[69402]: tun0: IPCP: PRIDNS[6] 192.231.203.3 > Jan 3 21:28:15 nn ppp[69402]: tun0: IPCP: SECDNS[6] 255.255.255.255 > Jan 3 21:28:15 nn ppp[69402]: tun0: IPCP: deflink: RecvConfigNak(2) > state = Ack-Sent > Jan 3 21:28:15 nn ppp[69402]: tun0: IPCP: IPADDR[6] 150.101.195.224 > Jan 3 21:28:15 nn ppp[69402]: tun0: IPCP: IPADDR[6] changing address: > 192.168.234.239 --> 150.101.195.224 > Jan 3 21:28:15 nn ppp[69402]: tun0: IPCP: PRIDNS[6] 192.231.203.132 > Jan 3 21:28:15 nn ppp[69402]: tun0: IPCP: SECDNS[6] 192.231.203.3 > Jan 3 21:28:15 nn ppp[69402]: tun0: IPCP: Primary nameserver set to > 192.231.203.132 > Jan 3 21:28:15 nn ppp[69402]: tun0: IPCP: Secondary nameserver set to > 192.231.203.3 > Jan 3 21:28:15 nn ppp[69402]: tun0: IPCP: deflink: SendConfigReq(3) > state = Ack-Sent > Jan 3 21:28:15 nn ppp[69402]: tun0: IPCP: IPADDR[6] 150.101.195.224 > Jan 3 21:28:15 nn ppp[69402]: tun0: IPCP: PRIDNS[6] 192.231.203.132 > Jan 3 21:28:15 nn ppp[69402]: tun0: IPCP: SECDNS[6] 192.231.203.3 > Jan 3 21:28:15 nn ppp[69402]: tun0: IPCP: deflink: RecvConfigAck(3) > state = Ack-Sent > Jan 3 21:28:15 nn ppp[69402]: tun0: IPCP: IPADDR[6] 150.101.195.224 > Jan 3 21:28:15 nn ppp[69402]: tun0: IPCP: PRIDNS[6] 192.231.203.132 > Jan 3 21:28:15 nn ppp[69402]: tun0: IPCP: SECDNS[6] 192.231.203.3 > Jan 3 21:28:15 nn ppp[69402]: tun0: IPCP: deflink: State change > Ack-Sent --> Opened > Jan 3 21:28:15 nn ppp[69402]: tun0: IPCP: deflink: LayerUp. > Jan 3 21:28:15 nn ppp[69402]: tun0: IPCP: myaddr 150.101.195.224 > hisaddr = 150.101.197.97 > Jan 3 21:28:16 nn ppp[69402]: tun0: LCP: deflink: RecvEchoRequest(1) > state = Opened > Jan 3 21:28:16 nn ppp[69402]: tun0: LCP: deflink: SendEchoReply(1) > state = Opened > Jan 3 21:28:26 nn ppp[69402]: tun0: LCP: deflink: RecvEchoRequest(2) > state = Opened > Jan 3 21:28:26 nn ppp[69402]: tun0: LCP: deflink: SendEchoReply(2) > state = Opened > Jan 3 21:28:37 nn ppp[69402]: tun0: LCP: deflink: RecvEchoRequest(3) > state = Opened > Jan 3 21:28:37 nn ppp[69402]: tun0: LCP: deflink: SendEchoReply(3) > state = Opened > Jan 3 21:28:46 nn ppp[69402]: tun0: LQM: deflink: Output (again): > Jan 3 21:28:46 nn ppp[69402]: tun0: LQM: Magic: 2f84cfe2 > LastOutLQRs: 00000000 > Jan 3 21:28:46 nn ppp[69402]: tun0: LQM: LastOutPackets: 00000000 > LastOutOctets: 00000000 > Jan 3 21:28:46 nn ppp[69402]: tun0: LQM: PeerInLQRs: 00000000 > PeerInPackets: 00000013 > Jan 3 21:28:46 nn ppp[69402]: tun0: LQM: PeerInDiscards: 00000000 > PeerInErrors: 00000000 > Jan 3 21:28:46 nn ppp[69402]: tun0: LQM: PeerInOctets: 000001b5 > PeerOutLQRs: 00000001 > Jan 3 21:28:46 nn ppp[69402]: tun0: LQM: PeerOutPackets: 00000013 > PeerOutOctets: 00000209 > Jan 3 21:28:47 nn ppp[69402]: tun0: LCP: deflink: RecvEchoRequest(4) > state = Opened > Jan 3 21:28:47 nn ppp[69402]: tun0: LCP: deflink: SendEchoReply(4) > state = Opened > Jan 3 21:28:57 nn ppp[69402]: tun0: LCP: deflink: RecvEchoRequest(5) > state = Opened > Jan 3 21:28:57 nn ppp[69402]: tun0: LCP: deflink: SendEchoReply(5) > state = Opened > Jan 3 21:29:07 nn ppp[69402]: tun0: LCP: deflink: RecvEchoRequest(6) > state = Opened > Jan 3 21:29:07 nn ppp[69402]: tun0: LCP: deflink: SendEchoReply(6) > state = Opened > Jan 3 21:29:16 nn ppp[69402]: tun0: LQM: deflink: Output (again): > Jan 3 21:29:16 nn ppp[69402]: tun0: LQM: Magic: 2f84cfe2 > LastOutLQRs: 00000000 > Jan 3 21:29:16 nn ppp[69402]: tun0: LQM: LastOutPackets: 00000000 > LastOutOctets: 00000000 > Jan 3 21:29:16 nn ppp[69402]: tun0: LQM: PeerInLQRs: 00000000 > PeerInPackets: 00000016 > Jan 3 21:29:16 nn ppp[69402]: tun0: LQM: PeerInDiscards: 00000000 > PeerInErrors: 00000000 > Jan 3 21:29:16 nn ppp[69402]: tun0: LQM: PeerInOctets: 000001e2 > PeerOutLQRs: 00000001 > Jan 3 21:29:16 nn ppp[69402]: tun0: LQM: PeerOutPackets: 00000017 > PeerOutOctets: 00000271 > Jan 3 21:29:18 nn ppp[69402]: tun0: LCP: deflink: RecvEchoRequest(7) > state = Opened > Jan 3 21:29:18 nn ppp[69402]: tun0: LCP: deflink: SendEchoReply(7) > state = Opened > Jan 3 21:29:28 nn ppp[69402]: tun0: LCP: deflink: RecvEchoRequest(8) > state = Opened > Jan 3 21:29:28 nn ppp[69402]: tun0: LCP: deflink: SendEchoReply(8) > state = Opened > Jan 3 21:29:38 nn ppp[69402]: tun0: LCP: deflink: RecvEchoRequest(9) > state = Opened > Jan 3 21:29:38 nn ppp[69402]: tun0: LCP: deflink: SendEchoReply(9) > state = Opened > Jan 3 21:29:47 nn ppp[69402]: tun0: LQM: deflink: Output (again): > Jan 3 21:29:47 nn ppp[69402]: tun0: LQM: Magic: 2f84cfe2 > LastOutLQRs: 00000000 > Jan 3 21:29:47 nn ppp[69402]: tun0: LQM: LastOutPackets: 00000000 > LastOutOctets: 00000000 > Jan 3 21:29:47 nn ppp[69402]: tun0: LQM: PeerInLQRs: 00000000 > PeerInPackets: 00000019 > Jan 3 21:29:47 nn ppp[69402]: tun0: LQM: PeerInDiscards: 00000000 > PeerInErrors: 00000000 > Jan 3 21:29:47 nn ppp[69402]: tun0: LQM: PeerInOctets: 0000020f > PeerOutLQRs: 00000001 > Jan 3 21:29:47 nn ppp[69402]: tun0: LQM: PeerOutPackets: 0000001b > PeerOutOctets: 000002d9 > Jan 3 21:29:48 nn ppp[69402]: tun0: LCP: deflink: RecvEchoRequest(10) > state = Opened > Jan 3 21:29:48 nn ppp[69402]: tun0: LCP: deflink: SendEchoReply(10) > state = Opened > Jan 3 21:29:59 nn ppp[69402]: tun0: LCP: deflink: RecvEchoRequest(11) > state = Opened > Jan 3 21:29:59 nn ppp[69402]: tun0: LCP: deflink: SendEchoReply(11) > state = Opened > Jan 3 21:30:09 nn ppp[69402]: tun0: LCP: deflink: RecvEchoRequest(12) > state = Opened > Jan 3 21:30:09 nn ppp[69402]: tun0: LCP: deflink: SendEchoReply(12) > state = Opened > Jan 3 21:30:17 nn ppp[69402]: tun0: LQM: deflink: Output (again): > Jan 3 21:30:17 nn ppp[69402]: tun0: LQM: Magic: 2f84cfe2 > LastOutLQRs: 00000000 > Jan 3 21:30:17 nn ppp[69402]: tun0: LQM: LastOutPackets: 00000000 > LastOutOctets: 00000000 > Jan 3 21:30:17 nn ppp[69402]: tun0: LQM: PeerInLQRs: 00000000 > PeerInPackets: 0000001c > Jan 3 21:30:17 nn ppp[69402]: tun0: LQM: PeerInDiscards: 00000000 > PeerInErrors: 00000000 > Jan 3 21:30:17 nn ppp[69402]: tun0: LQM: PeerInOctets: 0000023c > PeerOutLQRs: 00000001 > Jan 3 21:30:17 nn ppp[69402]: tun0: LQM: PeerOutPackets: 0000001f > PeerOutOctets: 00000341 > Jan 3 21:30:19 nn ppp[69402]: tun0: LCP: deflink: RecvEchoRequest(13) > state = Opened > Jan 3 21:30:19 nn ppp[69402]: tun0: LCP: deflink: SendEchoReply(13) > state = Opened > Jan 3 21:30:29 nn ppp[69402]: tun0: LCP: deflink: RecvEchoRequest(14) > state = Opened > Jan 3 21:30:29 nn ppp[69402]: tun0: LCP: deflink: SendEchoReply(14) > state = Opened > Jan 3 21:30:48 nn ppp[69402]: tun0: LQM: deflink: Output (again): > Jan 3 21:30:48 nn ppp[69402]: tun0: LQM: Magic: 2f84cfe2 > LastOutLQRs: 00000000 > Jan 3 21:30:48 nn ppp[69402]: tun0: LQM: LastOutPackets: 00000000 > LastOutOctets: 00000000 > Jan 3 21:30:48 nn ppp[69402]: tun0: LQM: PeerInLQRs: 00000000 > PeerInPackets: 00000022 > Jan 3 21:30:48 nn ppp[69402]: tun0: LQM: PeerInDiscards: 00000000 > PeerInErrors: 00000000 > Jan 3 21:30:48 nn ppp[69402]: tun0: LQM: PeerInOctets: 00000352 > PeerOutLQRs: 00000001 > Jan 3 21:30:48 nn ppp[69402]: tun0: LQM: PeerOutPackets: 00000023 > PeerOutOctets: 000003f9 > Jan 3 21:30:50 nn ppp[69402]: tun0: LCP: deflink: RecvEchoRequest(15) > state = Opened > Jan 3 21:30:50 nn ppp[69402]: tun0: LCP: deflink: SendEchoReply(15) > state = Opened > Jan 3 21:31:00 nn ppp[69402]: tun0: LCP: deflink: RecvEchoRequest(16) > state = Opened > Jan 3 21:31:00 nn ppp[69402]: tun0: LCP: deflink: SendEchoReply(16) > state = Opened > Jan 3 21:31:10 nn ppp[69402]: tun0: LCP: deflink: RecvEchoRequest(17) > state = Opened > Jan 3 21:31:10 nn ppp[69402]: tun0: LCP: deflink: SendEchoReply(17) > state = Opened > Jan 3 21:31:19 nn ppp[69402]: tun0: LQM: deflink: Too many LQR packets > lost > Jan 3 21:31:19 nn ppp[69402]: tun0: LCP: deflink: LayerDown > Jan 3 21:31:19 nn ppp[69402]: tun0: LCP: deflink: State change Opened > --> Starting (8) end of link.... > Jan 3 21:31:19 nn ppp[69402]: tun0: IPCP: deflink: LayerDown: > 150.101.195.224 > Jan 3 21:31:19 nn ppp[69402]: tun0: IPCP: deflink: State change Opened > --> Starting > Jan 3 21:31:19 nn ppp[69402]: tun0: IPCP: deflink: LayerFinish. > Jan 3 21:31:19 nn ppp[69402]: tun0: IPCP: Connect time: 184 secs: 334 > octets in, 92 octets out > Jan 3 21:31:19 nn ppp[69402]: tun0: IPCP: 5 packets in, 1 packets out > Jan 3 21:31:19 nn ppp[69402]: tun0: IPCP: total 2 bytes/sec, peak 58 > bytes/sec on Sat Jan 3 21:30:35 2004 > Jan 3 21:31:19 nn ppp[69402]: tun0: IPCP: deflink: State change > Starting --> Initial > Jan 3 21:31:19 nn ppp[69402]: tun0: LCP: deflink: LayerFinish > Jan 3 21:31:19 nn ppp[69402]: tun0: LCP: deflink: State change Starting > --> Initial > Jan 3 21:31:19 nn ppp[69402]: tun0: Chat: deflink: Reconnect try 1 of 0 > [end]