From owner-freebsd-net@FreeBSD.ORG Fri Jan 16 06:21:24 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 A84F316A4CE for ; Fri, 16 Jan 2004 06:21:24 -0800 (PST) Received: from einet.bg (sonata3.bginter.net [217.79.32.3]) by mx1.FreeBSD.org (Postfix) with ESMTP id C4ACF43D5D for ; Fri, 16 Jan 2004 06:21:18 -0800 (PST) (envelope-from tie@einet.bg) Received: from root by einet.bg with scanned-ok (Exim 4.21) id 1AhUqz-0000F5-E4 for freebsd-net@freebsd.org; Fri, 16 Jan 2004 16:21:41 +0200 Received: from [217.79.34.250] (helo=filipov) by einet.bg with smtp (Exim 4.21) id 1AhUqi-0000DR-GI; Fri, 16 Jan 2004 16:21:24 +0200 Message-ID: <009401c3dc3c$1fa680e0$6e00a8c0@filipov> From: "Emil Filipov" To: Date: Fri, 16 Jan 2004 16:22:05 +0200 MIME-Version: 1.0 X-Priority: 3 X-MSMail-Priority: Normal X-Mailer: Microsoft Outlook Express 6.00.2800.1158 X-MimeOLE: Produced By Microsoft MimeOLE V6.00.2800.1165 Content-Type: text/plain; charset="koi8-r" Content-Transfer-Encoding: quoted-printable X-Content-Filtered-By: Mailman/MimeDel 2.1.1 Subject: Re: PPPOE server with pppoed and mppe 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: Fri, 16 Jan 2004 14:21:24 -0000 OK guys, according to your advice I'm now trying with mpd (v.3.16). Works like magic with a SMC Router, but when I try to connect from a = Win2k box with RASPPPOE installed, the LCP negotiation fails. Here is a logged example of one such failure: Jan 16 15:46:28 opera mpd: Incoming PPPoE connection request via = vlan107: for service "EuroIntegra" from 00:00:e2:6e:d0:d9 Jan 16 15:46:28 opera mpd: [pppoe1] Accepting PPPoE connection Jan 16 15:46:28 opera mpd: [pppoe1] PPPoE response sent Jan 16 15:46:28 opera mpd: [bun_pppoe1] IPCP: Open event Jan 16 15:46:28 opera mpd: [bun_pppoe1] IPCP: state change Initial --> = Starting Jan 16 15:46:28 opera mpd: [bun_pppoe1] IPCP: LayerStart Jan 16 15:46:28 opera mpd: [bun_pppoe1] bundle: OPEN event in state = CLOSED Jan 16 15:46:28 opera mpd: [bun_pppoe1] opening link "pppoe1"... Jan 16 15:46:28 opera mpd: [pppoe1] link: OPEN event Jan 16 15:46:28 opera mpd: [pppoe1] LCP: Open event Jan 16 15:46:28 opera mpd: [pppoe1] LCP: state change Initial --> = Starting Jan 16 15:46:28 opera mpd: [pppoe1] LCP: LayerStart Jan 16 15:46:28 opera mpd: [pppoe1] device: OPEN event in state DOWN Jan 16 15:46:28 opera mpd: [pppoe1] PppoeOpen() on incoming call Jan 16 15:46:28 opera mpd: [pppoe1] device is now in state OPENING Jan 16 15:46:28 opera mpd: [pppoe1] PPPoE connection successful Jan 16 15:46:28 opera mpd: [pppoe1] device: UP event in state OPENING Jan 16 15:46:28 opera mpd: [pppoe1] device is now in state UP Jan 16 15:46:28 opera mpd: [pppoe1] link: UP event Jan 16 15:46:28 opera mpd: [pppoe1] link: origination is remote Jan 16 15:46:28 opera mpd: [pppoe1] LCP: Up event Jan 16 15:46:28 opera mpd: [pppoe1] LCP: state change Starting --> = Req-Sent Jan 16 15:46:28 opera mpd: [pppoe1] LCP: phase shift DEAD --> ESTABLISH Jan 16 15:46:28 opera mpd: [pppoe1] LCP: SendConfigReq #1 Jan 16 15:46:28 opera mpd: MRU 1492 Jan 16 15:46:28 opera mpd: MAGICNUM 1c5e3cf8 Jan 16 15:46:28 opera mpd: AUTHPROTO CHAP MSOFTv2 Jan 16 15:46:28 opera mpd: [pppoe1] LCP: rec'd Configure Request #0 link = 0 (Req-Sent) Jan 16 15:46:28 opera mpd: MAGICNUM 7f0f0305 Jan 16 15:46:28 opera mpd: MP MRRU 1614 Jan 16 15:46:28 opera mpd: ENDPOINTDISC [LOCAL] 7e e7 eb 44 29 cc 46 7d = 97 6a c8 8f 33 00 9d 2a 00 00 00 00 Jan 16 15:46:28 opera mpd: [pppoe1] LCP: SendConfigRej #0 Jan 16 15:46:28 opera mpd: MP MRRU 1614 Jan 16 15:46:28 opera mpd: [pppoe1] LCP: rec'd Configure Nak #1 link 0 = (Req-Sent) Jan 16 15:46:28 opera mpd: MRU 1488 Jan 16 15:46:28 opera mpd: [pppoe1] LCP: SendConfigReq #2 Jan 16 15:46:28 opera mpd: MRU 1488 Jan 16 15:46:28 opera mpd: MAGICNUM 1c5e3cf8 Jan 16 15:46:28 opera mpd: AUTHPROTO CHAP MSOFTv2 Jan 16 15:46:28 opera mpd: [pppoe1] LCP: rec'd Configure Request #1 link = 0 (Req-Sent) Jan 16 15:46:28 opera mpd: MAGICNUM 7f0f0305 Jan 16 15:46:28 opera mpd: ENDPOINTDISC [LOCAL] 7e e7 eb 44 29 cc 46 7d = 97 6a c8 8f 33 00 9d 2a 00 00 00 00 Jan 16 15:46:28 opera mpd: [pppoe1] LCP: SendConfigAck #1 Jan 16 15:46:28 opera mpd: MAGICNUM 7f0f0305 Jan 16 15:46:28 opera mpd: ENDPOINTDISC [LOCAL] 7e e7 eb 44 29 cc 46 7d = 97 6a c8 8f 33 00 9d 2a 00 00 00 00 Jan 16 15:46:28 opera mpd: [pppoe1] LCP: state change Req-Sent --> = Ack-Sent Jan 16 15:46:28 opera mpd: [pppoe1] LCP: rec'd Configure Nak #2 link 0 = (Ack-Sent) Jan 16 15:46:28 opera mpd: MRU 1488 Jan 16 15:46:28 opera mpd: [pppoe1] LCP: SendConfigReq #3 Jan 16 15:46:28 opera mpd: MRU 1488 Jan 16 15:46:28 opera mpd: MAGICNUM 1c5e3cf8 Jan 16 15:46:28 opera mpd: AUTHPROTO CHAP MSOFTv2 Jan 16 15:46:30 opera mpd: [pppoe1] LCP: SendConfigReq #4 Jan 16 15:46:30 opera mpd: MRU 1488 Jan 16 15:46:30 opera mpd: MAGICNUM 1c5e3cf8 Jan 16 15:46:30 opera mpd: AUTHPROTO CHAP MSOFTv2 Jan 16 15:46:30 opera mpd: [pppoe1] LCP: rec'd Configure Nak #4 link 0 = (Ack-Sent) Jan 16 15:46:30 opera mpd: MRU 1488 Jan 16 15:46:30 opera mpd: [pppoe1] LCP: SendConfigReq #5 Jan 16 15:46:30 opera mpd: MRU 1488 Jan 16 15:46:30 opera mpd: MAGICNUM 1c5e3cf8 Jan 16 15:46:30 opera mpd: AUTHPROTO CHAP MSOFTv2 Jan 16 15:46:30 opera mpd: [pppoe1] LCP: rec'd Configure Nak #5 link 0 = (Ack-Sent) Jan 16 15:46:30 opera mpd: MRU 1488 Jan 16 15:46:30 opera mpd: [pppoe1] LCP: SendConfigReq #6 Jan 16 15:46:30 opera mpd: MRU 1488 Jan 16 15:46:30 opera mpd: MAGICNUM 1c5e3cf8 Jan 16 15:46:30 opera mpd: AUTHPROTO CHAP MSOFTv2 Jan 16 15:46:30 opera mpd: [pppoe1] LCP: rec'd Configure Nak #6 link 0 = (Ack-Sent) Jan 16 15:46:30 opera mpd: MRU 1488 Jan 16 15:46:30 opera mpd: [pppoe1] LCP: SendConfigReq #7 Jan 16 15:46:30 opera mpd: MRU 1488 Jan 16 15:46:30 opera mpd: MAGICNUM 1c5e3cf8 Jan 16 15:46:30 opera mpd: AUTHPROTO CHAP MSOFTv2 Jan 16 15:46:30 opera mpd: [pppoe1] LCP: rec'd Configure Nak #7 link 0 = (Ack-Sent) Jan 16 15:46:30 opera mpd: MRU 1488 Jan 16 15:46:30 opera mpd: [pppoe1] LCP: SendConfigReq #8 Jan 16 15:46:30 opera mpd: MRU 1488 Jan 16 15:46:30 opera mpd: MAGICNUM 1c5e3cf8 Jan 16 15:46:30 opera mpd: AUTHPROTO CHAP MSOFTv2 Jan 16 15:46:30 opera mpd: [pppoe1] LCP: rec'd Configure Nak #8 link 0 = (Ack-Sent) Jan 16 15:46:30 opera mpd: MRU 1488 Jan 16 15:46:30 opera mpd: [pppoe1] LCP: SendConfigReq #9 Jan 16 15:46:30 opera mpd: MRU 1488 Jan 16 15:46:30 opera mpd: MAGICNUM 1c5e3cf8 Jan 16 15:46:30 opera mpd: AUTHPROTO CHAP MSOFTv2 Jan 16 15:46:30 opera mpd: [pppoe1] LCP: rec'd Configure Nak #9 link 0 = (Ack-Sent) Jan 16 15:46:30 opera mpd: MRU 1488 Jan 16 15:46:30 opera mpd: [pppoe1] LCP: SendConfigReq #10 Jan 16 15:46:30 opera mpd: MRU 1488 Jan 16 15:46:30 opera mpd: MAGICNUM 1c5e3cf8 Jan 16 15:46:30 opera mpd: AUTHPROTO CHAP MSOFTv2 Jan 16 15:46:30 opera mpd: [pppoe1] LCP: rec'd Configure Nak #10 link 0 = (Ack-Sent) Jan 16 15:46:30 opera mpd: MRU 1488 Jan 16 15:46:30 opera mpd: [pppoe1] LCP: not converging Jan 16 15:46:30 opera mpd: [pppoe1] LCP: parameter negotiation failed Jan 16 15:46:30 opera mpd: [pppoe1] LCP: state change Ack-Sent --> = Stopped Jan 16 15:46:30 opera mpd: [pppoe1] LCP: LayerFinish Jan 16 15:46:30 opera mpd: [pppoe1] device: CLOSE event in state UP Jan 16 15:46:30 opera mpd: [pppoe1] device is now in state CLOSING Jan 16 15:46:30 opera mpd: [pppoe1] device: DOWN event in state CLOSING Jan 16 15:46:30 opera mpd: [pppoe1] device is now in state DOWN Jan 16 15:46:30 opera mpd: [pppoe1] link: DOWN event Jan 16 15:46:30 opera mpd: [pppoe1] LCP: Down event Jan 16 15:46:30 opera mpd: [pppoe1] LCP: state change Stopped --> = Starting Jan 16 15:46:30 opera mpd: [pppoe1] LCP: phase shift ESTABLISH --> DEAD Jan 16 15:46:30 opera mpd: [pppoe1] LCP: LayerStart Jan 16 15:46:30 opera mpd: [pppoe1] LCP: Close event Jan 16 15:46:30 opera mpd: [pppoe1] LCP: state change Starting --> = Initial Jan 16 15:46:30 opera mpd: [pppoe1] LCP: LayerFinish Jan 16 15:46:30 opera mpd: [bun_pppoe1] closing link "pppoe1"... Jan 16 15:46:30 opera mpd: [bun_pppoe1] IPCP: Close event Jan 16 15:46:30 opera mpd: [bun_pppoe1] IPCP: state change Starting --> = Initial Jan 16 15:46:30 opera mpd: [bun_pppoe1] IPCP: LayerFinish Jan 16 15:46:30 opera mpd: [bun_pppoe1] bundle: CLOSE event in state = OPENED Jan 16 15:46:30 opera mpd: [pppoe1] link: CLOSE event Jan 16 15:46:30 opera mpd: [pppoe1] LCP: Close event Jan 16 15:46:30 opera mpd: [pppoe1] device: OPEN event in state DOWN Jan 16 15:46:30 opera mpd: [pppoe1] pausing 4 seconds before open Jan 16 15:46:30 opera mpd: [pppoe1] device is now in state DOWN Jan 16 15:46:30 opera mpd: [pppoe1] device: CLOSE event in state DOWN Jan 16 15:46:30 opera mpd: [pppoe1] device is now in state DOWN As you can see the client does not agree with MRU of 1488 (I tried = initially with the default of 1492). Bug in RASPPOE implementation? Here is the relevant part of my mpd.conf: pppoe_standart: set bundle no multilink set bundle enable compression set bundle accept encryption set bundle max-logins 1 set iface idle 0 set iface disable on-demand set iface disable proxy-arp set iface enable tcpmssfix set ipcp no vjcomp set link no pap chap acfcomp protocomp callback set link yes chap-msv2 chap-msv1 set link max-redial -1 set ccp yes mpp-e40 set ccp yes mpp-e128 set ccp yes mpp-stateless set pppoe iface vlan107 set pppoe service MyService set pppoe disable originate set pppoe enable incoming Regards, Emil Filipov