From owner-freebsd-bugs Sat Jul 28 8:50:21 2001 Delivered-To: freebsd-bugs@hub.freebsd.org Received: from freefall.freebsd.org (freefall.freebsd.org [216.136.204.21]) by hub.freebsd.org (Postfix) with ESMTP id A0E4637B406 for ; Sat, 28 Jul 2001 08:50:02 -0700 (PDT) (envelope-from gnats@FreeBSD.org) Received: (from gnats@localhost) by freefall.freebsd.org (8.11.4/8.11.4) id f6SFo2h19219; Sat, 28 Jul 2001 08:50:02 -0700 (PDT) (envelope-from gnats) Received: from core.pourIX.net (unknown [195.36.237.135]) by hub.freebsd.org (Postfix) with ESMTP id 9278337B405 for ; Sat, 28 Jul 2001 08:48:29 -0700 (PDT) (envelope-from sw@core.pourIX.net) Received: (from sw@localhost) by core.pourIX.net (8.11.4/8.11.4) id f6SFm9t10927; Sat, 28 Jul 2001 17:48:09 +0200 (CEST) (envelope-from sw) Message-Id: <200107281548.f6SFm9t10927@core.pourIX.net> Date: Sat, 28 Jul 2001 17:48:09 +0200 (CEST) From: Sameh Ghane Reply-To: Sameh Ghane To: FreeBSD-gnats-submit@freebsd.org X-Send-Pr-Version: 3.113 Subject: bin/29277: PPPoE weirdness with some DSL providers Sender: owner-freebsd-bugs@FreeBSD.ORG Precedence: bulk List-ID: List-Archive: (Web Archive) List-Help: (List Instructions) List-Subscribe: List-Unsubscribe: X-Loop: FreeBSD.org >Number: 29277 >Category: bin >Synopsis: PPPoE weirdness with some DSL providers >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: Sat Jul 28 08:50:01 PDT 2001 >Closed-Date: >Last-Modified: >Originator: Sameh Ghane >Release: FreeBSD 5.0-CURRENT i386 >Organization: dummy >Environment: System: FreeBSD core.pourIX.net 5.0-CURRENT FreeBSD 5.0-CURRENT #2: Fri Jul 20 15:36:38 CEST 2001 root@core.pourIX.net:/var/obj/var/src/sys/CORE i386 This problem appears with 4.3-STABLE too. -CURRENT was working fine until sources of 20th July at last. ECI Ethernet ADSL modem + 3Com 3c905C. >Description: PPPoE ADSL connection with PPP loops, and finally gives up: Jul 22 18:27:15 core ppp[7855]: tun0: LCP: FSM: Using "deflink" as a transport Jul 22 18:27:15 core ppp[7855]: tun0: LCP: deflink: State change Initial --> Closed Jul 22 18:27:15 core ppp[7855]: tun0: LCP: deflink: State change Closed --> Stopped Jul 22 18:27:15 core ppp[7855]: tun0: LCP: deflink: RecvConfigReq(160) state = Stopped Jul 22 18:27:15 core ppp[7855]: tun0: LCP: MRU[4] 1492 Jul 22 18:27:15 core ppp[7855]: tun0: LCP: AUTHPROTO[5] 0xc223 (CHAP 0x05) Jul 22 18:27:15 core ppp[7855]: tun0: LCP: MAGICNUM[6] 0x0a29f23b Jul 22 18:27:15 core ppp[7855]: tun0: LCP: deflink: SendConfigReq(1) state = Stopped Jul 22 18:27:15 core ppp[7855]: tun0: LCP: MRU[4] 1492 Jul 22 18:27:15 core ppp[7855]: tun0: LCP: MAGICNUM[6] 0x42d536c0 Jul 22 18:27:15 core ppp[7855]: tun0: LCP: QUALPROTO[8] proto c025, interval 30000ms Jul 22 18:27:15 core ppp[7855]: tun0: LCP: deflink: SendConfigAck(160) state = Stopped Jul 22 18:27:15 core ppp[7855]: tun0: LCP: MRU[4] 1492 Jul 22 18:27:15 core ppp[7855]: tun0: LCP: AUTHPROTO[5] 0xc223 (CHAP 0x05) Jul 22 18:27:15 core ppp[7855]: tun0: LCP: MAGICNUM[6] 0x0a29f23b Jul 22 18:27:15 core ppp[7855]: tun0: LCP: deflink: LayerStart Jul 22 18:27:15 core ppp[7855]: tun0: LCP: deflink: State change Stopped --> Ack-Sent Jul 22 18:27:15 core ppp[7855]: tun0: LCP: deflink: RecvConfigRej(1) state = Ack-Sent Jul 22 18:27:15 core ppp[7855]: tun0: LCP: QUALPROTO[8] proto c025, interval 30000ms Jul 22 18:27:15 core ppp[7855]: tun0: LCP: deflink: SendConfigReq(2) state = Ack-Sent Jul 22 18:27:15 core ppp[7855]: tun0: LCP: MRU[4] 1492 Jul 22 18:27:15 core ppp[7855]: tun0: LCP: MAGICNUM[6] 0x42d536c0 Jul 22 18:27:16 core ppp[7855]: tun0: LCP: deflink: RecvConfigAck(2) state = Ack-Sent Jul 22 18:27:16 core ppp[7855]: tun0: LCP: deflink: State change Ack-Sent --> Opened Jul 22 18:27:16 core ppp[7855]: tun0: LCP: deflink: LayerUp Jul 22 18:27:16 core ppp[7855]: tun0: LCP: deflink: SendEchoRequest(0) state = Opened Jul 22 18:27:16 core ppp[7855]: tun0: Phase: bundle: Authenticate Jul 22 18:27:16 core ppp[7855]: tun0: Phase: deflink: his = CHAP 0x05, mine = none Jul 22 18:27:16 core ppp[7855]: tun0: Phase: Chap Input: CHALLENGE (16 bytes from BSBGN103) Jul 22 18:27:16 core ppp[7855]: tun0: Phase: Chap Output: RESPONSE (sameh@net1.nerim.fsa) Jul 22 18:27:16 core ppp[7855]: tun0: LCP: deflink: RecvEchoReply(0) state = Opened Jul 22 18:27:18 core ppp[7855]: tun0: LCP: deflink: RecvConfigReq(1) state = Opened Jul 22 18:27:18 core ppp[7855]: tun0: LCP: deflink: LayerDown Jul 22 18:27:18 core ppp[7855]: tun0: LCP: AUTHPROTO[5] 0xc223 (CHAP 0x05) Jul 22 18:27:18 core ppp[7855]: tun0: LCP: MAGICNUM[6] 0x0ecf65f1 Jul 22 18:27:18 core ppp[7855]: tun0: LCP: deflink: SendConfigReq(3) state = Opened Jul 22 18:27:18 core ppp[7855]: tun0: LCP: MRU[4] 1492 Jul 22 18:27:18 core ppp[7855]: tun0: LCP: MAGICNUM[6] 0x9429fe39 Jul 22 18:27:18 core ppp[7855]: tun0: LCP: QUALPROTO[8] proto c025, interval 30000ms Jul 22 18:27:18 core ppp[7855]: tun0: LCP: deflink: SendConfigNak(1) state = Opened Jul 22 18:27:18 core ppp[7855]: tun0: LCP: MRU[4] 1492 Jul 22 18:27:18 core ppp[7855]: tun0: LCP: deflink: State change Opened --> Req-Sent Jul 22 18:27:18 core ppp[7855]: tun0: LCP: deflink: RecvConfigNak(3) state = Req-Sent Jul 22 18:27:18 core ppp[7855]: tun0: LCP: MRU[4] 1500 Jul 22 18:27:18 core ppp[7855]: tun0: LCP: deflink: SendConfigReq(4) state = Req-Sent Jul 22 18:27:18 core ppp[7855]: tun0: LCP: MRU[4] 1492 Jul 22 18:27:18 core ppp[7855]: tun0: LCP: MAGICNUM[6] 0x9429fe39 Jul 22 18:27:18 core ppp[7855]: tun0: LCP: QUALPROTO[8] proto c025, interval 30000ms Jul 22 18:27:18 core ppp[7855]: tun0: LCP: deflink: RecvConfigReq(2) state = Req-Sent Jul 22 18:27:18 core ppp[7855]: tun0: LCP: MRU[4] 1492 Jul 22 18:27:18 core ppp[7855]: tun0: LCP: AUTHPROTO[5] 0xc223 (CHAP 0x05) Jul 22 18:27:18 core ppp[7855]: tun0: LCP: MAGICNUM[6] 0x0ecf65f1 Jul 22 18:27:18 core ppp[7855]: tun0: LCP: deflink: SendConfigAck(2) state = Req-Sent Jul 22 18:27:18 core ppp[7855]: tun0: LCP: MRU[4] 1492 Jul 22 18:27:18 core ppp[7855]: tun0: LCP: AUTHPROTO[5] 0xc223 (CHAP 0x05) Jul 22 18:27:18 core ppp[7855]: tun0: LCP: MAGICNUM[6] 0x0ecf65f1 Jul 22 18:27:18 core ppp[7855]: tun0: LCP: deflink: State change Req-Sent --> Ack-Sent Jul 22 18:27:18 core ppp[7855]: tun0: LCP: deflink: RecvConfigNak(4) state = Ack-Sent Jul 22 18:27:18 core ppp[7855]: tun0: LCP: MRU[4] 1500 Jul 22 18:27:18 core ppp[7855]: tun0: LCP: deflink: SendConfigReq(5) state = Ack-Sent Jul 22 18:27:18 core ppp[7855]: tun0: LCP: MRU[4] 1492 Jul 22 18:27:18 core ppp[7855]: tun0: LCP: MAGICNUM[6] 0x9429fe39 Jul 22 18:27:18 core ppp[7855]: tun0: LCP: QUALPROTO[8] proto c025, interval 30000ms Jul 22 18:27:18 core ppp[7855]: tun0: LCP: deflink: RecvConfigNak(5) state = Ack-Sent Jul 22 18:27:18 core ppp[7855]: tun0: LCP: MRU[4] 1500 Jul 22 18:27:18 core ppp[7855]: tun0: LCP: deflink: SendConfigReq(6) state = Ack-Sent Jul 22 18:27:18 core ppp[7855]: tun0: LCP: MRU[4] 1492 Jul 22 18:27:18 core ppp[7855]: tun0: LCP: MAGICNUM[6] 0x9429fe39 Jul 22 18:27:18 core ppp[7855]: tun0: LCP: QUALPROTO[8] proto c025, interval 30000ms Jul 22 18:27:18 core ppp[7855]: tun0: LCP: deflink: RecvConfigNak(6) state = Ack-Sent Jul 22 18:27:18 core ppp[7855]: tun0: LCP: MRU[4] 1500 Jul 22 18:27:18 core ppp[7855]: tun0: LCP: deflink: SendConfigReq(7) state = Ack-Sent Jul 22 18:27:18 core ppp[7855]: tun0: LCP: MRU[4] 1492 Jul 22 18:27:18 core ppp[7855]: tun0: LCP: MAGICNUM[6] 0x9429fe39 Jul 22 18:27:18 core ppp[7855]: tun0: LCP: QUALPROTO[8] proto c025, interval 30000ms Jul 22 18:27:18 core ppp[7855]: tun0: LCP: deflink: RecvConfigNak(7) state = Ack-Sent Jul 22 18:27:18 core ppp[7855]: tun0: LCP: MRU[4] 1500 Jul 22 18:27:18 core ppp[7855]: tun0: LCP: deflink: SendConfigReq(8) state = Ack-Sent Jul 22 18:27:18 core ppp[7855]: tun0: LCP: MRU[4] 1492 Jul 22 18:27:18 core ppp[7855]: tun0: LCP: MAGICNUM[6] 0x9429fe39 Jul 22 18:27:18 core ppp[7855]: tun0: LCP: QUALPROTO[8] proto c025, interval 30000ms Jul 22 18:27:18 core ppp[7855]: tun0: LCP: deflink: RecvConfigRej(8) state = Ack-Sent Jul 22 18:27:18 core ppp[7855]: tun0: LCP: MRU[4] 1492 Jul 22 18:27:18 core ppp[7855]: tun0: LCP: deflink: SendConfigReq(9) state = Ack-Sent Jul 22 18:27:18 core ppp[7855]: tun0: LCP: MRU[4] 1492 Jul 22 18:27:18 core ppp[7855]: tun0: LCP: MAGICNUM[6] 0x9429fe39 Jul 22 18:27:18 core ppp[7855]: tun0: LCP: QUALPROTO[8] proto c025, interval 30000ms Jul 22 18:27:18 core ppp[7855]: tun0: LCP: deflink: RecvConfigRej(9) state = Ack-Sent Jul 22 18:27:18 core ppp[7855]: tun0: LCP: MRU[4] 1492 Jul 22 18:27:18 core ppp[7855]: tun0: LCP: deflink: SendConfigReq(10) state = Ack-Sent Jul 22 18:27:18 core ppp[7855]: tun0: LCP: MRU[4] 1492 Jul 22 18:27:18 core ppp[7855]: tun0: LCP: MAGICNUM[6] 0x9429fe39 Jul 22 18:27:18 core ppp[7855]: tun0: LCP: QUALPROTO[8] proto c025, interval 30000ms Jul 22 18:27:18 core ppp[7855]: tun0: LCP: deflink: RecvConfigRej(10) state = Ack-Sent Jul 22 18:27:18 core ppp[7855]: tun0: LCP: MRU[4] 1492 Jul 22 18:27:18 core ppp[7855]: tun0: LCP: deflink: SendConfigReq(11) state = Ack-Sent Jul 22 18:27:18 core ppp[7855]: tun0: LCP: MRU[4] 1492 Jul 22 18:27:18 core ppp[7855]: tun0: LCP: MAGICNUM[6] 0x9429fe39 Jul 22 18:27:18 core ppp[7855]: tun0: LCP: QUALPROTO[8] proto c025, interval 30000ms Jul 22 18:27:19 core ppp[7855]: tun0: LCP: deflink: RecvConfigRej(11) state = Ack-Sent Jul 22 18:27:19 core ppp[7855]: tun0: LCP: MRU[4] 1492 Jul 22 18:27:19 core ppp[7855]: tun0: LCP: deflink: SendConfigReq(12) state = Ack-Sent Jul 22 18:27:19 core ppp[7855]: tun0: LCP: MRU[4] 1492 Jul 22 18:27:19 core ppp[7855]: tun0: LCP: MAGICNUM[6] 0x9429fe39 Jul 22 18:27:19 core ppp[7855]: tun0: LCP: QUALPROTO[8] proto c025, interval 30000ms Jul 22 18:27:19 core ppp[7855]: tun0: LCP: deflink: RecvConfigRej(12) state = Ack-Sent Jul 22 18:27:19 core ppp[7855]: tun0: LCP: MRU[4] 1492 Jul 22 18:27:19 core ppp[7855]: tun0: LCP: deflink: SendConfigReq(13) state = Ack-Sent Jul 22 18:27:19 core ppp[7855]: tun0: LCP: MRU[4] 1492 Jul 22 18:27:19 core ppp[7855]: tun0: LCP: MAGICNUM[6] 0x9429fe39 Jul 22 18:27:19 core ppp[7855]: tun0: LCP: QUALPROTO[8] proto c025, interval 30000ms Jul 22 18:27:19 core ppp[7855]: tun0: LCP: deflink: RecvConfigRej(13) state = Ack-Sent Jul 22 18:27:19 core ppp[7855]: tun0: LCP: MRU[4] 1492 Jul 22 18:27:19 core ppp[7855]: tun0: LCP: deflink: SendConfigReq(14) state = Ack-Sent Jul 22 18:27:19 core ppp[7855]: tun0: LCP: MRU[4] 1492 Jul 22 18:27:19 core ppp[7855]: tun0: LCP: MAGICNUM[6] 0x9429fe39 Jul 22 18:27:19 core ppp[7855]: tun0: LCP: QUALPROTO[8] proto c025, interval 30000ms Jul 22 18:27:19 core ppp[7855]: tun0: LCP: deflink: RecvConfigRej(14) state = Ack-Sent Jul 22 18:27:19 core ppp[7855]: tun0: LCP: MRU[4] 1492 Jul 22 18:27:19 core ppp[7855]: tun0: LCP: deflink: SendConfigReq(15) state = Ack-Sent Jul 22 18:27:19 core ppp[7855]: tun0: LCP: MRU[4] 1492 Jul 22 18:27:19 core ppp[7855]: tun0: LCP: MAGICNUM[6] 0x9429fe39 Jul 22 18:27:19 core ppp[7855]: tun0: LCP: QUALPROTO[8] proto c025, interval 30000ms Jul 22 18:27:19 core ppp[7855]: tun0: LCP: deflink: RecvConfigRej(15) state = Ack-Sent Jul 22 18:27:19 core ppp[7855]: tun0: LCP: MRU[4] 1492 Jul 22 18:27:19 core ppp[7855]: tun0: LCP: deflink: SendConfigReq(16) state = Ack-Sent Jul 22 18:27:19 core ppp[7855]: tun0: LCP: MRU[4] 1492 Jul 22 18:27:19 core ppp[7855]: tun0: LCP: MAGICNUM[6] 0x9429fe39 Jul 22 18:27:19 core ppp[7855]: tun0: LCP: QUALPROTO[8] proto c025, interval 30000ms Jul 22 18:27:19 core ppp[7855]: tun0: LCP: deflink: RecvConfigRej(16) state = Ack-Sent Jul 22 18:27:19 core ppp[7855]: tun0: LCP: MRU[4] 1492 Jul 22 18:27:19 core ppp[7855]: tun0: LCP: deflink: SendConfigReq(17) state = Ack-Sent Jul 22 18:27:19 core ppp[7855]: tun0: LCP: MRU[4] 1492 Jul 22 18:27:19 core ppp[7855]: tun0: LCP: MAGICNUM[6] 0x9429fe39 Jul 22 18:27:19 core ppp[7855]: tun0: LCP: QUALPROTO[8] proto c025, interval 30000ms Jul 22 18:27:19 core ppp[7855]: tun0: LCP: deflink: RecvConfigRej(17) state = Ack-Sent Jul 22 18:27:19 core ppp[7855]: tun0: LCP: MRU[4] 1492 Jul 22 18:27:19 core ppp[7855]: tun0: Phase: deflink: Too many LCP REQs sent - abandoning negotiation The problem does not happen with an old release PPP. It also happens only with *some* DSL providers. It has been seen with Nerim, by two others french -STABLE users, after a PPP upgrade. A PPP downgrade fixes the problem. Removing set mru/mtu from ppp.conf doesn't resolve the problem. >How-To-Repeat: Try connecting with a fresh -current or -stable to some DSL providers, using PPPoE. >Fix: Must have something with the ether.c/lcp.c commits around 18th-20th July. Please contact me to test patches if you have some. >Release-Note: >Audit-Trail: >Unformatted: To Unsubscribe: send mail to majordomo@FreeBSD.org with "unsubscribe freebsd-bugs" in the body of the message