From owner-freebsd-questions Mon Jan 17 17:17:29 2000 Delivered-To: freebsd-questions@freebsd.org Received: from mail.rdc3.on.home.com (ha1.rdc3.on.home.com [24.2.9.68]) by hub.freebsd.org (Postfix) with ESMTP id C6CA414A1E for ; Mon, 17 Jan 2000 17:17:22 -0800 (PST) (envelope-from danyc@playground.net) Received: from playground.net ([24.114.192.235]) by mail.rdc3.on.home.com (InterMail v4.01.01.02 201-229-111-106) with ESMTP id <20000118011508.SHIV15357.mail.rdc3.on.home.com@playground.net> for ; Mon, 17 Jan 2000 17:15:08 -0800 Message-ID: <3883BFE2.AE260F84@playground.net> Date: Mon, 17 Jan 2000 20:20:35 -0500 From: Dany Cayouette X-Mailer: Mozilla 4.7 [en] (X11; U; FreeBSD 3.4-RELEASE i386) X-Accept-Language: en MIME-Version: 1.0 To: freebsd-questions@FreeBSD.ORG Subject: PPPoE Problems Content-Type: text/plain; charset=us-ascii Content-Transfer-Encoding: 7bit Sender: owner-freebsd-questions@FreeBSD.ORG Precedence: bulk X-Loop: FreeBSD.ORG Greetings, I recently got my hands on an old DEC pentium 133 PC. I just got FreeBSD 3.4-RELEASE installed. I am interested in getting PPPoE running. I recompile a kernel with all the NETGRAPH options. The first problem I noticed is a 50% success rate on getting a successful connection. I start my session with the command "ppp -dedicated". I stop the session with "kill ". When the process terminates, I get the following 2 messages: /var/log/messages: Jan 12 16:48:19 freebsd ppp[265]: tun0: Warning: deflink: Oops: Got 8 bytes but 4 byte payload Jan 12 16:48:20 freebsd ppp[265]: tun0: Warning: deflink: Oops: Got 8 bytes but 4 byte payload When I try to restart "ppp -dedicated" I don't get any special error messages but a tcpdump suggests that nothing goes out on the Ethernet interface. I kill the ppp process and re-issue the command "ppp -dedicated" and everything works! I wanted to do more debugging today but now nothing works. I am getting a write error on the tun interface. Any idea on what extra debugging I could turn on... Here is my configuration, the output on /var/log/ppp.log for the write failure and finally output from a successful session: /etc/ppp/ppp.conf default: set device PPPoE:de0 set MRU 1490 set MTU 1490 set authname user@domain.com set authkey password set log Phase Chat LCP IPCP CCP tun command # set log Phase IPCP CCP tun LCP set dial set login "TIMEOUT 1.5 name:\\r-login:\\U:\\P ocol:PPP HELLO" set ifaddr 10.0.0.1/0 10.0.0.2/0 add default HISADDR # enable dns set cd off set crtscts off /var/log/ppp.log -------- Failing Session -------- Jan 17 13:31:30 freebsd ppp[6886]: Phase: Using interface: tun0 Jan 17 13:31:30 freebsd ppp[6886]: Phase: deflink: Created in closed state Jan 17 13:31:30 freebsd ppp[6887]: tun0: Phase: PPP Started (dedicated mode). Jan 17 13:31:30 freebsd ppp[6887]: tun0: Phase: bundle: Establish Jan 17 13:31:30 freebsd ppp[6887]: tun0: Phase: deflink: closed -> opening Jan 17 13:31:30 freebsd ppp[6887]: tun0: Phase: deflink: Connected! Jan 17 13:31:30 freebsd ppp[6887]: tun0: Phase: deflink: opening -> carrier Jan 17 13:31:31 freebsd ppp[6887]: tun0: Phase: deflink: Disconnected! Jan 17 13:31:31 freebsd ppp[6887]: tun0: Phase: deflink: carrier -> lcp Jan 17 13:31:31 freebsd ppp[6887]: tun0: LCP: FSM: Using "deflink" as a transport Jan 17 13:31:31 freebsd ppp[6887]: tun0: LCP: deflink: State change Initial --> Closed Jan 17 13:31:31 freebsd ppp[6887]: tun0: LCP: deflink: State change Closed --> Stopped Jan 17 13:31:32 freebsd ppp[6887]: tun0: LCP: deflink: LayerStart Jan 17 13:31:32 freebsd ppp[6887]: tun0: LCP: deflink: SendConfigReq(1) state = Stopped Jan 17 13:31:32 freebsd ppp[6887]: tun0: LCP: ACFCOMP[2] Jan 17 13:31:32 freebsd ppp[6887]: tun0: LCP: PROTOCOMP[2] Jan 17 13:31:32 freebsd ppp[6887]: tun0: LCP: ACCMAP[6] 0x00000000 Jan 17 13:31:32 freebsd ppp[6887]: tun0: LCP: MRU[4] 1490 Jan 17 13:31:32 freebsd ppp[6887]: tun0: LCP: MAGICNUM[6] 0x744e7a6d Jan 17 13:31:32 freebsd ppp[6887]: tun0: LCP: deflink: State change Stopped --> Req-Sent Jan 17 13:31:32 freebsd ppp[6887]: tun0: Phase: deflink: write (1): Network is unreachable Jan 17 13:31:32 freebsd ppp[6887]: tun0: LCP: deflink: State change Req-Sent --> Starting Jan 17 13:31:32 freebsd ppp[6887]: tun0: LCP: deflink: LayerFinish Jan 17 13:31:32 freebsd ppp[6887]: tun0: LCP: deflink: State change Starting --> Initial Jan 17 13:31:32 freebsd ppp[6887]: tun0: Phase: deflink: Disconnected! Jan 17 13:31:32 freebsd ppp[6887]: tun0: LCP: FSM: Using "deflink" as a transport Jan 17 13:31:32 freebsd ppp[6887]: tun0: LCP: deflink: State change Initial --> Closed Jan 17 13:31:32 freebsd ppp[6887]: tun0: LCP: deflink: State change Closed --> Stopped Jan 17 13:31:32 freebsd ppp[6887]: tun0: Phase: deflink: Disconnected! .......................... ------ Successful session ------ Jan 12 16:41:40 freebsd ppp[264]: Phase: Using interface: tun0 Jan 12 16:41:40 freebsd ppp[264]: Phase: deflink: Created in closed state Jan 12 16:41:41 freebsd ppp[265]: tun0: LCP: FSM: Using "deflink" as a transport Jan 12 16:41:41 freebsd ppp[265]: tun0: LCP: deflink: State change Initial --> Closed Jan 12 16:41:41 freebsd ppp[265]: tun0: LCP: deflink: State change Closed --> Stopped Jan 12 16:41:42 freebsd ppp[265]: tun0: LCP: deflink: LayerStart Jan 12 16:41:42 freebsd ppp[265]: tun0: LCP: deflink: SendConfigReq(1) state = Stopped Jan 12 16:41:42 freebsd ppp[265]: tun0: LCP: ACFCOMP[2] Jan 12 16:41:42 freebsd ppp[265]: tun0: LCP: PROTOCOMP[2] Jan 12 16:41:42 freebsd ppp[265]: tun0: LCP: ACCMAP[6] 0x00000000 Jan 12 16:41:42 freebsd ppp[265]: tun0: LCP: MRU[4] 1490 Jan 12 16:41:42 freebsd ppp[265]: tun0: LCP: MAGICNUM[6] 0x52516508 Jan 12 16:41:42 freebsd ppp[265]: tun0: LCP: deflink: State change Stopped --> Req-Sent Jan 12 16:41:42 freebsd ppp[265]: tun0: LCP: deflink: RecvConfigReq(249) state = Req-Sent Jan 12 16:41:42 freebsd ppp[265]: tun0: LCP: MAGICNUM[6] 0x5b6ecd20 Jan 12 16:41:42 freebsd ppp[265]: tun0: LCP: MRU[4] 1492 Jan 12 16:41:42 freebsd ppp[265]: tun0: LCP: AUTHPROTO[5] 0xc223 (CHAP 0x05) Jan 12 16:41:42 freebsd ppp[265]: tun0: LCP: deflink: SendConfigAck(249) state = Req-Sent Jan 12 16:41:42 freebsd ppp[265]: tun0: LCP: MAGICNUM[6] 0x5b6ecd20 Jan 12 16:41:42 freebsd ppp[265]: tun0: LCP: MRU[4] 1492 Jan 12 16:41:42 freebsd ppp[265]: tun0: LCP: AUTHPROTO[5] 0xc223 (CHAP 0x05) Jan 12 16:41:42 freebsd ppp[265]: tun0: LCP: deflink: State change Req-Sent --> Ack-Sent Jan 12 16:41:42 freebsd ppp[265]: tun0: LCP: deflink: RecvConfigRej(1) state = Ack-Sent Jan 12 16:41:42 freebsd ppp[265]: tun0: LCP: ACFCOMP[2] Jan 12 16:41:42 freebsd ppp[265]: tun0: LCP: PROTOCOMP[2] Jan 12 16:41:42 freebsd ppp[265]: tun0: LCP: ACCMAP[6] 0x00000000 Jan 12 16:41:42 freebsd ppp[265]: tun0: LCP: deflink: SendConfigReq(2) state = Ack-Sent Jan 12 16:41:42 freebsd ppp[265]: tun0: LCP: MRU[4] 1490 Jan 12 16:41:42 freebsd ppp[265]: tun0: LCP: MAGICNUM[6] 0x52516508 Jan 12 16:41:42 freebsd ppp[265]: tun0: LCP: deflink: RecvConfigAck(2) state = Ack-Sent Jan 12 16:41:42 freebsd ppp[265]: tun0: LCP: deflink: State change Ack-Sent --> Opened Jan 12 16:41:42 freebsd ppp[265]: tun0: LCP: deflink: LayerUp Jan 12 16:41:42 freebsd ppp[265]: tun0: CCP: FSM: Using "deflink" as a transport Jan 12 16:41:42 freebsd ppp[265]: tun0: CCP: deflink: State change Initial --> Closed Jan 12 16:41:42 freebsd ppp[265]: tun0: CCP: deflink: LayerStart. Jan 12 16:41:42 freebsd ppp[265]: tun0: CCP: deflink: SendConfigReq(1) state = Closed Jan 12 16:41:42 freebsd ppp[265]: tun0: CCP: DEFLATE[4] win 15 Jan 12 16:41:42 freebsd ppp[265]: tun0: CCP: PRED1[2] Jan 12 16:41:42 freebsd ppp[265]: tun0: CCP: deflink: State change Closed --> Req-Sent Jan 12 16:41:42 freebsd ppp[265]: tun0: IPCP: FSM: Using "deflink" as a transport Jan 12 16:41:42 freebsd ppp[265]: tun0: IPCP: deflink: State change Initial --> Closed Jan 12 16:41:42 freebsd ppp[265]: tun0: IPCP: deflink: LayerStart. Jan 12 16:41:42 freebsd ppp[265]: tun0: IPCP: deflink: SendConfigReq(1) state = Closed Jan 12 16:41:42 freebsd ppp[265]: tun0: IPCP: IPADDR[6] 10.0.0.1 Jan 12 16:41:42 freebsd ppp[265]: tun0: IPCP: COMPPROTO[6] 16 VJ slots with slot compression Jan 12 16:41:42 freebsd ppp[265]: tun0: IPCP: PRIDNS[6] 10.10.10.10 Jan 12 16:41:42 freebsd ppp[265]: tun0: IPCP: SECDNS[6] 20.20.20.20 Jan 12 16:41:42 freebsd ppp[265]: tun0: IPCP: deflink: State change Closed --> Req-Sent Jan 12 16:41:42 freebsd ppp[265]: tun0: IPCP: deflink: RecvConfigReq(220) state = Req-Sent Jan 12 16:41:42 freebsd ppp[265]: tun0: IPCP: IPADDR[6] 10.64.178.94 Jan 12 16:41:42 freebsd ppp[265]: tun0: IPCP: deflink: SendConfigAck(220) state = Req-Sent Jan 12 16:41:42 freebsd ppp[265]: tun0: IPCP: IPADDR[6] 10.64.178.94 Jan 12 16:41:42 freebsd ppp[265]: tun0: IPCP: deflink: State change Req-Sent --> Ack-Sent Jan 12 16:41:42 freebsd ppp[265]: tun0: LCP: deflink: RecvProtocolRej(250) state = Opened Jan 12 16:41:42 freebsd ppp[265]: tun0: LCP: deflink: -- Protocol 0x80fd (Compression Control Protocol) was rejected! Jan 12 16:41:42 freebsd ppp[265]: tun0: CCP: deflink: State change Req-Sent --> Stopped Jan 12 16:41:42 freebsd ppp[265]: tun0: IPCP: deflink: RecvConfigRej(1) state = Ack-Sent Jan 12 16:41:42 freebsd ppp[265]: tun0: IPCP: COMPPROTO[6] 16 VJ slots with slot compression Jan 12 16:41:42 freebsd ppp[265]: tun0: IPCP: deflink: SendConfigReq(2) state = Ack-Sent Jan 12 16:41:42 freebsd ppp[265]: tun0: IPCP: IPADDR[6] 10.0.0.1 Jan 12 16:41:42 freebsd ppp[265]: tun0: IPCP: PRIDNS[6] 10.10.10.10 Jan 12 16:41:42 freebsd ppp[265]: tun0: IPCP: SECDNS[6] 20.20.20.20 Jan 12 16:41:42 freebsd ppp[265]: tun0: IPCP: deflink: RecvConfigNak(2) state = Ack-Sent Jan 12 16:41:42 freebsd ppp[265]: tun0: IPCP: IPADDR[6] 10.200.0.6 Jan 12 16:41:42 freebsd ppp[265]: tun0: IPCP: IPADDR[6] changing address: 10.0.0.1 --> 10.200.0.6 Jan 12 16:41:42 freebsd ppp[265]: tun0: IPCP: deflink: SendConfigReq(3) state = Ack-Sent Jan 12 16:41:42 freebsd ppp[265]: tun0: IPCP: IPADDR[6] 10.200.0.6 Jan 12 16:41:42 freebsd ppp[265]: tun0: IPCP: PRIDNS[6] 10.10.10.10 Jan 12 16:41:42 freebsd ppp[265]: tun0: IPCP: SECDNS[6] 20.20.20.20 Jan 12 16:41:42 freebsd ppp[265]: tun0: IPCP: deflink: RecvConfigAck(3) state = Ack-Sent Jan 12 16:41:42 freebsd ppp[265]: tun0: IPCP: deflink: State change Ack-Sent --> Opened Jan 12 16:41:42 freebsd ppp[265]: tun0: IPCP: deflink: LayerUp. Jan 12 16:41:42 freebsd ppp[265]: tun0: IPCP: myaddr 10.200.0.6 hisaddr = 10.64.178.94 Jan 12 16:41:53 freebsd ppp[265]: tun0: LCP: deflink: RecvEchoRequest(0) state = Opened Jan 12 16:41:53 freebsd ppp[265]: tun0: LCP: deflink: SendEchoReply(0) state = Opened Jan 12 16:42:04 freebsd ppp[265]: tun0: LCP: deflink: RecvEchoRequest(1) state = Opened Jan 12 16:42:04 freebsd ppp[265]: tun0: LCP: deflink: SendEchoReply(1) state = Opened Jan 12 16:42:14 freebsd ppp[265]: tun0: LCP: deflink: RecvEchoRequest(2) state = Opened Jan 12 16:42:14 freebsd ppp[265]: tun0: LCP: deflink: SendEchoReply(2) state = Opened Jan 12 16:42:25 freebsd ppp[265]: tun0: LCP: deflink: RecvEchoRequest(3) state = Opened --- repeating lines deleted Jan 12 16:48:03 freebsd ppp[265]: tun0: LCP: deflink: RecvEchoRequest(34) state = Opened Jan 12 16:48:03 freebsd ppp[265]: tun0: LCP: deflink: SendEchoReply(34) state = Opened Jan 12 16:48:13 freebsd ppp[265]: tun0: LCP: deflink: RecvEchoRequest(35) state = Opened Jan 12 16:48:14 freebsd ppp[265]: tun0: LCP: deflink: SendEchoReply(35) state = Opened Jan 12 16:48:19 freebsd ppp[265]: tun0: IPCP: deflink: LayerDown: 10.200.0.6 Jan 12 16:48:19 freebsd ppp[265]: tun0: IPCP: deflink: SendTerminateReq(4) state = Opened Jan 12 16:48:19 freebsd ppp[265]: tun0: IPCP: deflink: State change Opened --> Closing Jan 12 16:48:19 freebsd ppp[265]: tun0: Warning: deflink: Oops: Got 8 bytes but 4 byte payload Jan 12 16:48:19 freebsd ppp[265]: tun0: IPCP: deflink: RecvTerminateAck(4) state = Closing Jan 12 16:48:19 freebsd ppp[265]: tun0: IPCP: deflink: LayerFinish. Jan 12 16:48:19 freebsd ppp[265]: tun0: IPCP: Connect time: 397 secs: 0 octets in, 0 octets out Jan 12 16:48:19 freebsd ppp[265]: tun0: IPCP: total 0 bytes/sec, peak 0 bytes/sec on Wed Jan 12 16:48:19 2000 Jan 12 16:48:19 freebsd ppp[265]: tun0: IPCP: deflink: State change Closing --> Closed Jan 12 16:48:19 freebsd ppp[265]: tun0: CCP: deflink: State change Stopped --> Closed Jan 12 16:48:19 freebsd ppp[265]: tun0: CCP: deflink: State change Closed --> Initial Jan 12 16:48:19 freebsd ppp[265]: tun0: LCP: deflink: LayerDown Jan 12 16:48:19 freebsd ppp[265]: tun0: LCP: deflink: SendTerminateReq(3) state = Opened Jan 12 16:48:19 freebsd ppp[265]: tun0: LCP: deflink: State change Opened --> Closing Jan 12 16:48:19 freebsd ppp[265]: tun0: IPCP: deflink: State change Closed --> Initial Jan 12 16:48:19 freebsd ppp[265]: tun0: Warning: deflink: Oops: Got 8 bytes but 4 byte payload Jan 12 16:48:19 freebsd ppp[265]: tun0: LCP: deflink: RecvTerminateAck(3) state = Closing Jan 12 16:48:19 freebsd ppp[265]: tun0: LCP: deflink: LayerFinish Jan 12 16:48:19 freebsd ppp[265]: tun0: LCP: deflink: State change Closing --> Closed Jan 12 16:48:19 freebsd ppp[265]: tun0: LCP: deflink: State change Closed --> Initial Regards, Dany Cayouette To Unsubscribe: send mail to majordomo@FreeBSD.org with "unsubscribe freebsd-questions" in the body of the message