Date: Sat, 28 Jul 2001 17:48:09 +0200 (CEST) From: Sameh Ghane <sw@anthologeek.net> To: FreeBSD-gnats-submit@freebsd.org Subject: bin/29277: PPPoE weirdness with some DSL providers Message-ID: <200107281548.f6SFm9t10927@core.pourIX.net>
next in thread | raw e-mail | index | archive | help
>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
Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?200107281548.f6SFm9t10927>