From owner-freebsd-bugs@FreeBSD.ORG Tue Dec 7 21:10:24 2004 Return-Path: Delivered-To: freebsd-bugs@hub.freebsd.org Received: from mx1.FreeBSD.org (mx1.freebsd.org [216.136.204.125]) by hub.freebsd.org (Postfix) with ESMTP id 219C316A4CF for ; Tue, 7 Dec 2004 21:10:24 +0000 (GMT) Received: from freefall.freebsd.org (freefall.freebsd.org [216.136.204.21]) by mx1.FreeBSD.org (Postfix) with ESMTP id B7D2343D5D for ; Tue, 7 Dec 2004 21:10:23 +0000 (GMT) (envelope-from gnats@FreeBSD.org) Received: from freefall.freebsd.org (gnats@localhost [127.0.0.1]) by freefall.freebsd.org (8.13.1/8.13.1) with ESMTP id iB7LAN7d007960 for ; Tue, 7 Dec 2004 21:10:23 GMT (envelope-from gnats@freefall.freebsd.org) Received: (from gnats@localhost) by freefall.freebsd.org (8.13.1/8.13.1/Submit) id iB7LANE7007956; Tue, 7 Dec 2004 21:10:23 GMT (envelope-from gnats) Resent-Date: Tue, 7 Dec 2004 21:10:23 GMT Resent-Message-Id: <200412072110.iB7LANE7007956@freefall.freebsd.org> Resent-From: FreeBSD-gnats-submit@FreeBSD.org (GNATS Filer) Resent-To: freebsd-bugs@FreeBSD.org Resent-Reply-To: FreeBSD-gnats-submit@FreeBSD.org, Mike Tancsa Received: from mx1.FreeBSD.org (mx1.freebsd.org [216.136.204.125]) by hub.freebsd.org (Postfix) with ESMTP id 5174B16A4CE for ; Tue, 7 Dec 2004 21:06:56 +0000 (GMT) Received: from www.freebsd.org (www.freebsd.org [216.136.204.117]) by mx1.FreeBSD.org (Postfix) with ESMTP id 09D7343D2D for ; Tue, 7 Dec 2004 21:06:56 +0000 (GMT) (envelope-from nobody@FreeBSD.org) Received: from www.freebsd.org (localhost [127.0.0.1]) by www.freebsd.org (8.13.1/8.13.1) with ESMTP id iB7L6tIB039843 for ; Tue, 7 Dec 2004 21:06:55 GMT (envelope-from nobody@www.freebsd.org) Received: (from nobody@localhost) by www.freebsd.org (8.13.1/8.13.1/Submit) id iB7L6tZr039841; Tue, 7 Dec 2004 21:06:55 GMT (envelope-from nobody) Message-Id: <200412072106.iB7L6tZr039841@www.freebsd.org> Date: Tue, 7 Dec 2004 21:06:55 GMT From: Mike Tancsa To: freebsd-gnats-submit@FreeBSD.org X-Send-Pr-Version: www-2.3 Subject: bin/74821: PPPoE with LQR is broken for users connecting to a Juniper ERX X-BeenThere: freebsd-bugs@freebsd.org X-Mailman-Version: 2.1.1 Precedence: list List-Id: Bug reports List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Tue, 07 Dec 2004 21:10:24 -0000 >Number: 74821 >Category: bin >Synopsis: PPPoE with LQR is broken for users connecting to a Juniper ERX >Confidential: no >Severity: non-critical >Priority: medium >Responsible: freebsd-bugs >State: open >Quarter: >Keywords: >Date-Required: >Class: sw-bug >Submitter-Id: current-users >Arrival-Date: Tue Dec 07 21:10:23 GMT 2004 >Closed-Date: >Last-Modified: >Originator: Mike Tancsa >Release: RELENG_5 >Organization: Sentex Communications >Environment: FreeBSD releng5-865.sentex.ca 5.3-STABLE FreeBSD 5.3-STABLE #0: Tue Dec 7 11:29:41 EST 2004 >Description: When enabling LQR on FreeBSD with PPPoE, and when the otherside is a Juniper ERX, LQM_LQR does not seem to work properly... However, LQM_ECHO does seem to work. Here is a sample broken session Dec 7 15:58:39 releng5-865 ppp[4420]: tun0: Phase: deflink: his = PAP, mine = none Dec 7 15:58:39 releng5-865 ppp[4420]: tun0: Phase: Pap Output: testusername@sentex.ca ******** Dec 7 15:58:39 releng5-865 ppp[4420]: tun0: Phase: Pap Input: SUCCESS () Dec 7 15:58:39 releng5-865 ppp[4420]: tun0: IPCP: Using trigger address 0.0.0.0 Dec 7 15:58:39 releng5-865 ppp[4420]: tun0: CCP: FSM: Using "deflink" as a transport Dec 7 15:58:39 releng5-865 ppp[4420]: tun0: CCP: deflink: State change Initial --> Closed Dec 7 15:58:39 releng5-865 ppp[4420]: tun0: CCP: deflink: LayerStart. Dec 7 15:58:39 releng5-865 ppp[4420]: tun0: CCP: MPPE: Not usable without CHAP81 Dec 7 15:58:39 releng5-865 ppp[4420]: tun0: CCP: deflink: SendConfigReq(1) state = Closed Dec 7 15:58:39 releng5-865 ppp[4420]: tun0: CCP: DEFLATE[4] win 15 Dec 7 15:58:39 releng5-865 ppp[4420]: tun0: CCP: PRED1[2] Dec 7 15:58:39 releng5-865 ppp[4420]: tun0: CCP: deflink: State change Closed --> Req-Sent Dec 7 15:58:39 releng5-865 ppp[4420]: tun0: Phase: deflink: lcp -> open Dec 7 15:58:39 releng5-865 ppp[4420]: tun0: Phase: bundle: Network Dec 7 15:58:39 releng5-865 ppp[4420]: tun0: IPCP: FSM: Using "deflink" as a transport Dec 7 15:58:39 releng5-865 ppp[4420]: tun0: IPCP: deflink: State change Initial --> Closed Dec 7 15:58:39 releng5-865 ppp[4420]: tun0: IPCP: deflink: LayerStart. Dec 7 15:58:39 releng5-865 ppp[4420]: tun0: IPCP: deflink: SendConfigReq(9) state = Closed Dec 7 15:58:39 releng5-865 ppp[4420]: tun0: IPCP: IPADDR[6] 0.0.0.0 Dec 7 15:58:39 releng5-865 ppp[4420]: tun0: IPCP: PRIDNS[6] 205.211.164.51 Dec 7 15:58:39 releng5-865 ppp[4420]: tun0: IPCP: SECDNS[6] 64.7.128.99 Dec 7 15:58:39 releng5-865 ppp[4420]: tun0: IPCP: deflink: State change Closed --> Req-Sent Dec 7 15:58:39 releng5-865 ppp[4420]: tun0: IPCP: deflink: RecvConfigReq(1) state = Req-Sent Dec 7 15:58:39 releng5-865 ppp[4420]: tun0: IPCP: IPADDR[6] 67.43.128.6 Dec 7 15:58:39 releng5-865 ppp[4420]: tun0: IPCP: deflink: SendConfigAck(1) state = Req-Sent Dec 7 15:58:39 releng5-865 ppp[4420]: tun0: IPCP: IPADDR[6] 67.43.128.6 Dec 7 15:58:39 releng5-865 ppp[4420]: tun0: IPCP: deflink: State change Req-Sent --> Ack-Sent Dec 7 15:58:39 releng5-865 ppp[4420]: tun0: LCP: deflink: RecvProtocolRej(3) state = Opened Dec 7 15:58:39 releng5-865 ppp[4420]: tun0: LCP: deflink: -- Protocol 0x80fd (Compression Control Protocol) was rejected! Dec 7 15:58:39 releng5-865 ppp[4420]: tun0: CCP: deflink: State change Req-Sent --> Stopped Dec 7 15:58:39 releng5-865 ppp[4420]: tun0: IPCP: deflink: RecvConfigNak(9) state = Ack-Sent Dec 7 15:58:39 releng5-865 ppp[4420]: tun0: IPCP: IPADDR[6] 67.43.133.120 Dec 7 15:58:39 releng5-865 ppp[4420]: tun0: IPCP: IPADDR[6] changing address: 0.0.0.0 --> 67.43.133.120 Dec 7 15:58:39 releng5-865 ppp[4420]: tun0: IPCP: deflink: SendConfigReq(10) state = Ack-Sent Dec 7 15:58:39 releng5-865 ppp[4420]: tun0: IPCP: IPADDR[6] 67.43.133.120 Dec 7 15:58:39 releng5-865 ppp[4420]: tun0: IPCP: PRIDNS[6] 205.211.164.51 Dec 7 15:58:39 releng5-865 ppp[4420]: tun0: IPCP: SECDNS[6] 64.7.128.99 Dec 7 15:58:39 releng5-865 ppp[4420]: tun0: IPCP: deflink: RecvConfigAck(10) state = Ack-Sent Dec 7 15:58:39 releng5-865 ppp[4420]: tun0: IPCP: IPADDR[6] 67.43.133.120 Dec 7 15:58:39 releng5-865 ppp[4420]: tun0: IPCP: PRIDNS[6] 205.211.164.51 Dec 7 15:58:39 releng5-865 ppp[4420]: tun0: IPCP: SECDNS[6] 64.7.128.99 Dec 7 15:58:39 releng5-865 ppp[4420]: tun0: IPCP: deflink: State change Ack-Sent --> Opened Dec 7 15:58:39 releng5-865 ppp[4420]: tun0: IPCP: deflink: LayerUp. Dec 7 15:58:39 releng5-865 ppp[4420]: tun0: IPCP: myaddr 67.43.133.120 hisaddr = 67.43.128.6 Dec 7 15:58:40 releng5-865 ppp[4420]: tun0: LCP: deflink: RecvEchoRequest(1) state = Opened Dec 7 15:58:40 releng5-865 ppp[4420]: tun0: LCP: deflink: SendEchoReply(1) state = Opened Dec 7 15:58:49 releng5-865 ppp[4420]: tun0: LQM: deflink: Output: Dec 7 15:58:49 releng5-865 ppp[4420]: tun0: LQM: Magic: 24f33001 LastOutLQRs: 00000000 Dec 7 15:58:49 releng5-865 ppp[4420]: tun0: LQM: LastOutPackets: 00000000 LastOutOctets: 00000000 Dec 7 15:58:49 releng5-865 ppp[4420]: tun0: LQM: PeerInLQRs: 00000000 PeerInPackets: 00000000 Dec 7 15:58:49 releng5-865 ppp[4420]: tun0: LQM: PeerInDiscards: 00000000 PeerInErrors: 00000000 Dec 7 15:58:49 releng5-865 ppp[4420]: tun0: LQM: PeerInOctets: 00000000 PeerOutLQRs: 00000002 Dec 7 15:58:49 releng5-865 ppp[4420]: tun0: LQM: PeerOutPackets: 0000001a PeerOutOctets: 000002ce Dec 7 15:58:50 releng5-865 ppp[4420]: tun0: LCP: deflink: RecvEchoRequest(2) state = Opened Dec 7 15:58:50 releng5-865 ppp[4420]: tun0: LCP: deflink: SendEchoReply(2) state = Opened Dec 7 15:58:59 releng5-865 ppp[4420]: tun0: LQM: deflink: Output: Dec 7 15:58:59 releng5-865 ppp[4420]: tun0: LQM: Magic: 24f33001 LastOutLQRs: 00000000 Dec 7 15:58:59 releng5-865 ppp[4420]: tun0: LQM: LastOutPackets: 00000000 LastOutOctets: 00000000 Dec 7 15:58:59 releng5-865 ppp[4420]: tun0: LQM: PeerInLQRs: 00000000 PeerInPackets: 00000000 Dec 7 15:58:59 releng5-865 ppp[4420]: tun0: LQM: PeerInDiscards: 00000000 PeerInErrors: 00000000 Dec 7 15:58:59 releng5-865 ppp[4420]: tun0: LQM: PeerInOctets: 00000000 PeerOutLQRs: 00000003 Dec 7 15:58:59 releng5-865 ppp[4420]: tun0: LQM: PeerOutPackets: 0000001c PeerOutOctets: 00000310 Dec 7 15:59:00 releng5-865 ppp[4420]: tun0: LCP: deflink: RecvEchoRequest(3) state = Opened Dec 7 15:59:00 releng5-865 ppp[4420]: tun0: LCP: deflink: SendEchoReply(3) state = Opened Dec 7 15:59:09 releng5-865 ppp[4420]: tun0: LQM: deflink: Output: Dec 7 15:59:09 releng5-865 ppp[4420]: tun0: LQM: Magic: 24f33001 LastOutLQRs: 00000000 Dec 7 15:59:09 releng5-865 ppp[4420]: tun0: LQM: LastOutPackets: 00000000 LastOutOctets: 00000000 Dec 7 15:59:09 releng5-865 ppp[4420]: tun0: LQM: PeerInLQRs: 00000000 PeerInPackets: 00000000 Dec 7 15:59:09 releng5-865 ppp[4420]: tun0: LQM: PeerInDiscards: 00000000 PeerInErrors: 00000000 Dec 7 15:59:09 releng5-865 ppp[4420]: tun0: LQM: PeerInOctets: 00000000 PeerOutLQRs: 00000004 Dec 7 15:59:09 releng5-865 ppp[4420]: tun0: LQM: PeerOutPackets: 0000001e PeerOutOctets: 00000352 Dec 7 15:59:10 releng5-865 ppp[4420]: tun0: LCP: deflink: RecvEchoRequest(4) state = Opened Dec 7 15:59:10 releng5-865 ppp[4420]: tun0: LCP: deflink: SendEchoReply(4) state = Opened Dec 7 15:59:19 releng5-865 ppp[4420]: tun0: LQM: deflink: Output: Dec 7 15:59:19 releng5-865 ppp[4420]: tun0: LQM: Magic: 24f33001 LastOutLQRs: 00000000 Dec 7 15:59:19 releng5-865 ppp[4420]: tun0: LQM: LastOutPackets: 00000000 LastOutOctets: 00000000 Dec 7 15:59:19 releng5-865 ppp[4420]: tun0: LQM: PeerInLQRs: 00000000 PeerInPackets: 00000000 Dec 7 15:59:19 releng5-865 ppp[4420]: tun0: LQM: PeerInDiscards: 00000000 PeerInErrors: 00000000 Dec 7 15:59:19 releng5-865 ppp[4420]: tun0: LQM: PeerInOctets: 00000000 PeerOutLQRs: 00000005 Dec 7 15:59:19 releng5-865 ppp[4420]: tun0: LQM: PeerOutPackets: 00000020 PeerOutOctets: 00000394 Dec 7 15:59:21 releng5-865 ppp[4420]: tun0: LCP: deflink: RecvEchoRequest(5) state = Opened Dec 7 15:59:21 releng5-865 ppp[4420]: tun0: LCP: deflink: SendEchoReply(5) state = Opened Dec 7 15:59:30 releng5-865 ppp[4420]: tun0: LQM: deflink: Output: Dec 7 15:59:30 releng5-865 ppp[4420]: tun0: LQM: Magic: 24f33001 LastOutLQRs: 00000000 Dec 7 15:59:30 releng5-865 ppp[4420]: tun0: LQM: LastOutPackets: 00000000 LastOutOctets: 00000000 Dec 7 15:59:30 releng5-865 ppp[4420]: tun0: LQM: PeerInLQRs: 00000000 PeerInPackets: 00000000 Dec 7 15:59:30 releng5-865 ppp[4420]: tun0: LQM: PeerInDiscards: 00000000 PeerInErrors: 00000000 Dec 7 15:59:30 releng5-865 ppp[4420]: tun0: LQM: PeerInOctets: 00000000 PeerOutLQRs: 00000006 Dec 7 15:59:30 releng5-865 ppp[4420]: tun0: LQM: PeerOutPackets: 00000022 PeerOutOctets: 000003d6 Dec 7 15:59:31 releng5-865 ppp[4420]: tun0: LCP: deflink: RecvEchoRequest(6) state = Opened Dec 7 15:59:31 releng5-865 ppp[4420]: tun0: LCP: deflink: SendEchoReply(6) state = Opened Dec 7 15:59:40 releng5-865 ppp[4420]: tun0: Phase: deflink: ** Too many LQR packets lost ** Dec 7 15:59:40 releng5-865 ppp[4420]: tun0: LQM: deflink: Too many LQR packets lost Dec 7 15:59:40 releng5-865 ppp[4420]: tun0: CCP: deflink: State change Stopped --> Closed Dec 7 15:59:40 releng5-865 ppp[4420]: tun0: CCP: deflink: State change Closed --> Initial Dec 7 15:59:40 releng5-865 ppp[4420]: tun0: LCP: deflink: LayerDown Dec 7 15:59:40 releng5-865 ppp[4420]: tun0: LCP: deflink: State change Opened --> Starting Dec 7 15:59:40 releng5-865 ppp[4420]: tun0: Phase: deflink: open -> lcp Then, forcing LQM_ECHO, it works >How-To-Repeat: In Canada, the incumbant telco (Bell Canada) has mostly ERXes deployed. Enable LQR on the link and you will see it fail. >Fix: I came up with this simple hack that lets the user LQM_ECHO in the ppp.conf releng5-865# diff -u command.c.prev command.c --- command.c.prev Tue Dec 7 15:43:28 2004 +++ command.c Tue Dec 7 15:43:36 2004 @@ -166,6 +166,7 @@ #define NEG_VJCOMP 53 #define NEG_MPPE 54 #define NEG_CHAP81 55 +#define NEG_LCPECHO 56 const char Version[] = "3.2"; @@ -2856,6 +2857,10 @@ cx->physical->link.lcp.cfg.lqr &= keep; cx->physical->link.lcp.cfg.lqr |= add; break; + case NEG_LCPECHO: + cx->physical->link.lcp.cfg.forcelcpecho &= keep; + cx->physical->link.lcp.cfg.forcelcpecho |= add; + break; case NEG_PAP: cx->physical->link.lcp.cfg.pap &= keep; cx->physical->link.lcp.cfg.pap |= add; @@ -2977,6 +2982,9 @@ {"lqr", NULL, NegotiateSet, LOCAL_AUTH | LOCAL_CX, "Link Quality Reports", "accept|deny|disable|enable", (const void *)NEG_LQR}, + {"forcelcpecho", NULL, NegotiateSet, LOCAL_AUTH | LOCAL_CX, + "Link Quality Reports", "accept|deny|disable|enable", + (const void *)NEG_LCPECHO}, {"pap", NULL, NegotiateSet, LOCAL_AUTH | LOCAL_CX, "Password Authentication protocol", "accept|deny|disable|enable", (const void *)NEG_PAP}, releng5-865# releng5-865# diff -u lcp.h.prev lcp.h --- lcp.h.prev Tue Dec 7 15:44:04 2004 +++ lcp.h Tue Dec 7 15:51:21 2004 @@ -98,6 +98,7 @@ unsigned chap81 : 2; /* Microsoft CHAP v2 */ #endif unsigned lqr : 2; /* Link Quality Report */ + unsigned forcelcpecho : 2; /* Some PPPoE concentrators are broken for LQR. Allow users to force LCP ECHOS */ unsigned pap : 2; /* Password Authentication protocol */ unsigned protocomp : 2; /* Protocol field compression */ char ident[DEF_MRU - 7]; /* SendIdentification() data */ releng5-865# releng5-865# diff -u lqr.c.prev lqr.c --- lqr.c.prev Tue Dec 7 15:43:34 2004 +++ lqr.c Tue Dec 7 15:43:36 2004 @@ -276,8 +276,13 @@ sizeof physical->hdlc.lqm.lqr.peer); physical->hdlc.lqm.method = LQM_ECHO; - if (IsEnabled(lcp->cfg.lqr) && !REJECTED(lcp, TY_QUALPROTO)) + log_Printf(LogPHASE, "Enabling LQM_ECHO %s",physical->link.name); + if (IsEnabled(lcp->cfg.lqr) && !REJECTED(lcp, TY_QUALPROTO) && !IsEnabled(lcp->cfg.forcelcpecho) ) + { physical->hdlc.lqm.method |= LQM_LQR; + log_Printf(LogPHASE, "Enabling LQM_LQR, not LQM_ECHO %s",physical->link.name); + + } timer_Stop(&physical->hdlc.lqm.timer); physical->hdlc.lqm.lqr.peer_timeout = lcp->his_lqrperiod; releng5-865# In /etc/ppp/ppp.conf the user just needs to add enable forcelcpecho >Release-Note: >Audit-Trail: >Unformatted: