Date: Sun, 01 Aug 2004 13:03:32 +0400 From: Maxim Maximov <mcsi@mcsi.pp.ru> To: Gleb Smirnoff <glebius@freebsd.org> Cc: freebsd-current@freebsd.org Subject: Re: PPPoE problems with latest -CURRENT Message-ID: <410CB1E4.2030103@mcsi.pp.ru> In-Reply-To: <20040731213854.GB38076@cell.sick.ru> References: <20040730091525.U484@pukruppa.net> <20040731213854.GB38076@cell.sick.ru>
next in thread | previous in thread | raw e-mail | index | archive | help
Gleb Smirnoff wrote: > On Fri, Jul 30, 2004 at 09:28:05AM +0000, Peter Ulrich Kruppa wrote: > P> I use my -CURRENT machine to connect with /usr/sbin/ppp to the > P> internet via a DSL modem (or bridge as some people say). > P> Since my cvsup yesterday this doesn't work anymore - and what is > P> even worse I can't see any errror messages: > P> neither in my ppp.logs nor when I run ppp manually; it just > P> doen't connect. > > That was my stupid error, shame on me. Already fixed. > I can confirm that the problems are still there. ppp.log and tcpdump output follow: Aug 1 12:49:44 ultra ppp[221]: tun0: Phase: bundle: Establish Aug 1 12:49:44 ultra ppp[221]: tun0: Phase: deflink: closed -> opening Aug 1 12:49:44 ultra ppp[221]: tun0: Phase: deflink: Connected! Aug 1 12:49:44 ultra ppp[221]: tun0: Phase: deflink: opening -> dial Aug 1 12:49:44 ultra ppp[221]: tun0: Chat: deflink: Dial attempt 1 of 1 Aug 1 12:49:44 ultra ppp[221]: tun0: Phase: deflink: dial -> carrier Aug 1 12:49:45 ultra ppp[221]: tun0: Phase: Received NGM_PPPOE_ACNAME (hook "MGTS") Aug 1 12:49:45 ultra ppp[221]: tun0: Phase: Received NGM_PPPOE_SESSIONID Aug 1 12:49:45 ultra ppp[221]: tun0: Phase: Received NGM_PPPOE_SUCCESS Aug 1 12:49:45 ultra ppp[221]: tun0: Phase: deflink: carrier -> login Aug 1 12:49:45 ultra ppp[221]: tun0: Phase: deflink: login -> lcp Aug 1 12:49:45 ultra ppp[221]: tun0: LCP: FSM: Using "deflink" as a transport Aug 1 12:49:45 ultra ppp[221]: tun0: LCP: deflink: State change Initial --> Closed Aug 1 12:49:45 ultra ppp[221]: tun0: LCP: deflink: State change Closed --> Stopped Aug 1 12:49:45 ultra ppp[221]: tun0: LCP: deflink: RecvConfigReq(1) state = Stopped Aug 1 12:49:45 ultra ppp[221]: tun0: LCP: MRU[4] 1492 Aug 1 12:49:45 ultra ppp[221]: tun0: LCP: AUTHPROTO[5] 0xc223 (CHAP 0x05) Aug 1 12:49:45 ultra ppp[221]: tun0: LCP: MAGICNUM[6] 0x5913af2d Aug 1 12:49:45 ultra ppp[221]: tun0: Warning: deflink: Reducing configured MRU from 1500 to 1492 Aug 1 12:49:45 ultra ppp[221]: tun0: LCP: deflink: SendConfigReq(1) state = Stopped Aug 1 12:49:45 ultra ppp[221]: tun0: LCP: ACFCOMP[2] Aug 1 12:49:45 ultra ppp[221]: tun0: LCP: PROTOCOMP[2] Aug 1 12:49:45 ultra ppp[221]: tun0: LCP: ACCMAP[6] 0x00000000 Aug 1 12:49:45 ultra ppp[221]: tun0: LCP: MRU[4] 1492 Aug 1 12:49:45 ultra ppp[221]: tun0: LCP: MAGICNUM[6] 0xb3747467 Aug 1 12:49:45 ultra ppp[221]: tun0: LCP: deflink: SendConfigAck(1) state = Stopped Aug 1 12:49:45 ultra ppp[221]: tun0: LCP: MRU[4] 1492 Aug 1 12:49:45 ultra ppp[221]: tun0: LCP: AUTHPROTO[5] 0xc223 (CHAP 0x05) Aug 1 12:49:45 ultra ppp[221]: tun0: LCP: MAGICNUM[6] 0x5913af2d Aug 1 12:49:45 ultra ppp[221]: tun0: LCP: deflink: LayerStart Aug 1 12:49:45 ultra ppp[221]: tun0: LCP: deflink: State change Stopped --> Ack-Sent Aug 1 12:49:46 ultra ppp[221]: tun0: LCP: deflink: RecvConfigReq(2) state = Ack-Sent Aug 1 12:49:46 ultra ppp[221]: tun0: LCP: MRU[4] 1492 Aug 1 12:49:46 ultra ppp[221]: tun0: LCP: AUTHPROTO[5] 0xc223 (CHAP 0x05) Aug 1 12:49:46 ultra ppp[221]: tun0: LCP: MAGICNUM[6] 0x5913af2d Aug 1 12:49:46 ultra ppp[221]: tun0: LCP: deflink: SendConfigAck(2) state = Ack-Sent Aug 1 12:49:46 ultra ppp[221]: tun0: LCP: MRU[4] 1492 Aug 1 12:49:46 ultra ppp[221]: tun0: LCP: AUTHPROTO[5] 0xc223 (CHAP 0x05) Aug 1 12:49:46 ultra ppp[221]: tun0: LCP: MAGICNUM[6] 0x5913af2d Aug 1 12:49:48 ultra ppp[221]: tun0: LCP: deflink: SendConfigReq(1) state = Ack-Sent Aug 1 12:49:48 ultra ppp[221]: tun0: LCP: ACFCOMP[2] Aug 1 12:49:48 ultra ppp[221]: tun0: LCP: PROTOCOMP[2] Aug 1 12:49:48 ultra ppp[221]: tun0: LCP: ACCMAP[6] 0x00000000 Aug 1 12:49:48 ultra ppp[221]: tun0: LCP: MRU[4] 1492 Aug 1 12:49:48 ultra ppp[221]: tun0: LCP: MAGICNUM[6] 0xb3747467 Aug 1 12:49:48 ultra ppp[221]: tun0: LCP: deflink: RecvConfigReq(3) state = Ack-Sent Aug 1 12:49:48 ultra ppp[221]: tun0: LCP: MRU[4] 1492 Aug 1 12:49:48 ultra ppp[221]: tun0: LCP: AUTHPROTO[5] 0xc223 (CHAP 0x05) Aug 1 12:49:48 ultra ppp[221]: tun0: LCP: MAGICNUM[6] 0x5913af2d Aug 1 12:49:48 ultra ppp[221]: tun0: LCP: deflink: SendConfigAck(3) state = Ack-Sent Aug 1 12:49:48 ultra ppp[221]: tun0: LCP: MRU[4] 1492 Aug 1 12:49:48 ultra ppp[221]: tun0: LCP: AUTHPROTO[5] 0xc223 (CHAP 0x05) Aug 1 12:49:48 ultra ppp[221]: tun0: LCP: MAGICNUM[6] 0x5913af2d Aug 1 12:49:50 ultra ppp[221]: tun0: LCP: deflink: RecvConfigReq(4) state = Ack-Sent Aug 1 12:49:50 ultra ppp[221]: tun0: LCP: MRU[4] 1492 Aug 1 12:49:50 ultra ppp[221]: tun0: LCP: AUTHPROTO[5] 0xc223 (CHAP 0x05) Aug 1 12:49:50 ultra ppp[221]: tun0: LCP: MAGICNUM[6] 0x5913af2d Aug 1 12:49:50 ultra ppp[221]: tun0: LCP: deflink: SendConfigAck(4) state = Ack-Sent Aug 1 12:49:50 ultra ppp[221]: tun0: LCP: MRU[4] 1492 Aug 1 12:49:50 ultra ppp[221]: tun0: LCP: AUTHPROTO[5] 0xc223 (CHAP 0x05) Aug 1 12:49:50 ultra ppp[221]: tun0: LCP: MAGICNUM[6] 0x5913af2d Aug 1 12:49:51 ultra ppp[221]: tun0: LCP: deflink: SendConfigReq(1) state = Ack-Sent Aug 1 12:49:51 ultra ppp[221]: tun0: LCP: ACFCOMP[2] Aug 1 12:49:51 ultra ppp[221]: tun0: LCP: PROTOCOMP[2] Aug 1 12:49:51 ultra ppp[221]: tun0: LCP: ACCMAP[6] 0x00000000 Aug 1 12:49:51 ultra ppp[221]: tun0: LCP: MRU[4] 1492 Aug 1 12:49:51 ultra ppp[221]: tun0: LCP: MAGICNUM[6] 0xb3747467 Aug 1 12:49:52 ultra ppp[221]: tun0: LCP: deflink: RecvConfigReq(5) state = Ack-Sent Aug 1 12:49:52 ultra ppp[221]: tun0: LCP: MRU[4] 1492 Aug 1 12:49:52 ultra ppp[221]: tun0: LCP: AUTHPROTO[5] 0xc223 (CHAP 0x05) Aug 1 12:49:52 ultra ppp[221]: tun0: LCP: MAGICNUM[6] 0x5913af2d Aug 1 12:49:52 ultra ppp[221]: tun0: LCP: deflink: SendConfigAck(5) state = Ack-Sent Aug 1 12:49:52 ultra ppp[221]: tun0: LCP: MRU[4] 1492 Aug 1 12:49:52 ultra ppp[221]: tun0: LCP: AUTHPROTO[5] 0xc223 (CHAP 0x05) Aug 1 12:49:52 ultra ppp[221]: tun0: LCP: MAGICNUM[6] 0x5913af2d Aug 1 12:49:54 ultra ppp[221]: tun0: LCP: deflink: SendConfigReq(1) state = Ack-Sent Aug 1 12:49:54 ultra ppp[221]: tun0: LCP: ACFCOMP[2] Aug 1 12:49:54 ultra ppp[221]: tun0: LCP: PROTOCOMP[2] Aug 1 12:49:54 ultra ppp[221]: tun0: LCP: ACCMAP[6] 0x00000000 Aug 1 12:49:54 ultra ppp[221]: tun0: LCP: MRU[4] 1492 Aug 1 12:49:54 ultra ppp[221]: tun0: LCP: MAGICNUM[6] 0xb3747467 Aug 1 12:49:54 ultra ppp[221]: tun0: LCP: deflink: RecvConfigReq(6) state = Ack-Sent Aug 1 12:49:54 ultra ppp[221]: tun0: LCP: MRU[4] 1492 Aug 1 12:49:54 ultra ppp[221]: tun0: LCP: AUTHPROTO[5] 0xc223 (CHAP 0x05) Aug 1 12:49:54 ultra ppp[221]: tun0: LCP: MAGICNUM[6] 0x5913af2d Aug 1 12:49:54 ultra ppp[221]: tun0: LCP: deflink: SendConfigAck(6) state = Ack-Sent Aug 1 12:49:54 ultra ppp[221]: tun0: LCP: MRU[4] 1492 Aug 1 12:49:54 ultra ppp[221]: tun0: LCP: AUTHPROTO[5] 0xc223 (CHAP 0x05) Aug 1 12:49:54 ultra ppp[221]: tun0: LCP: MAGICNUM[6] 0x5913af2d Aug 1 12:49:56 ultra ppp[221]: tun0: LCP: deflink: RecvConfigReq(7) state = Ack-Sent Aug 1 12:49:56 ultra ppp[221]: tun0: LCP: MRU[4] 1492 Aug 1 12:49:56 ultra ppp[221]: tun0: LCP: AUTHPROTO[5] 0xc223 (CHAP 0x05) Aug 1 12:49:56 ultra ppp[221]: tun0: LCP: MAGICNUM[6] 0x5913af2d Aug 1 12:49:56 ultra ppp[221]: tun0: LCP: deflink: SendConfigAck(7) state = Ack-Sent Aug 1 12:49:56 ultra ppp[221]: tun0: LCP: MRU[4] 1492 Aug 1 12:49:56 ultra ppp[221]: tun0: LCP: AUTHPROTO[5] 0xc223 (CHAP 0x05) Aug 1 12:49:56 ultra ppp[221]: tun0: LCP: MAGICNUM[6] 0x5913af2d Aug 1 12:49:57 ultra ppp[221]: tun0: LCP: deflink: SendConfigReq(1) state = Ack-Sent Aug 1 12:49:57 ultra ppp[221]: tun0: LCP: ACFCOMP[2] Aug 1 12:49:57 ultra ppp[221]: tun0: LCP: PROTOCOMP[2] Aug 1 12:49:57 ultra ppp[221]: tun0: LCP: ACCMAP[6] 0x00000000 Aug 1 12:49:57 ultra ppp[221]: tun0: LCP: MRU[4] 1492 Aug 1 12:49:57 ultra ppp[221]: tun0: LCP: MAGICNUM[6] 0xb3747467 Aug 1 12:49:58 ultra ppp[221]: tun0: LCP: deflink: RecvConfigReq(8) state = Ack-Sent Aug 1 12:49:58 ultra ppp[221]: tun0: LCP: MRU[4] 1492 Aug 1 12:49:58 ultra ppp[221]: tun0: LCP: AUTHPROTO[5] 0xc223 (CHAP 0x05) Aug 1 12:49:58 ultra ppp[221]: tun0: LCP: MAGICNUM[6] 0x5913af2d Aug 1 12:49:58 ultra ppp[221]: tun0: LCP: deflink: SendConfigAck(8) state = Ack-Sent Aug 1 12:49:58 ultra ppp[221]: tun0: LCP: MRU[4] 1492 Aug 1 12:49:58 ultra ppp[221]: tun0: LCP: AUTHPROTO[5] 0xc223 (CHAP 0x05) Aug 1 12:49:58 ultra ppp[221]: tun0: LCP: MAGICNUM[6] 0x5913af2d Aug 1 12:50:00 ultra ppp[221]: tun0: LCP: deflink: RecvConfigReq(9) state = Ack-Sent Aug 1 12:50:00 ultra ppp[221]: tun0: LCP: MRU[4] 1492 Aug 1 12:50:00 ultra ppp[221]: tun0: LCP: AUTHPROTO[5] 0xc223 (CHAP 0x05) Aug 1 12:50:00 ultra ppp[221]: tun0: LCP: MAGICNUM[6] 0x5913af2d Aug 1 12:50:00 ultra ppp[221]: tun0: LCP: deflink: SendConfigAck(9) state = Ack-Sent Aug 1 12:50:00 ultra ppp[221]: tun0: LCP: MRU[4] 1492 Aug 1 12:50:00 ultra ppp[221]: tun0: LCP: AUTHPROTO[5] 0xc223 (CHAP 0x05) Aug 1 12:50:00 ultra ppp[221]: tun0: LCP: MAGICNUM[6] 0x5913af2d Aug 1 12:50:00 ultra ppp[221]: tun0: LCP: deflink: LayerFinish Aug 1 12:50:00 ultra ppp[221]: tun0: LCP: deflink: State change Ack-Sent --> Stopped Aug 1 12:50:00 ultra ppp[221]: tun0: LCP: deflink: State change Stopped --> Closed Aug 1 12:50:00 ultra ppp[221]: tun0: LCP: deflink: State change Closed --> Initial Aug 1 12:50:00 ultra ppp[221]: tun0: Phase: deflink: Disconnected! Aug 1 12:50:00 ultra ppp[221]: tun0: Phase: deflink: lcp -> logout Aug 1 12:50:00 ultra ppp[221]: tun0: Phase: deflink: logout -> hangup Aug 1 12:50:00 ultra ppp[221]: tun0: Phase: deflink: Disconnected! Aug 1 12:50:00 ultra ppp[221]: tun0: Phase: deflink: Connect time: 16 secs: 189 octets in, 319 octets out Aug 1 12:50:00 ultra ppp[221]: tun0: Phase: deflink: 9 packets in, 14 packets out Aug 1 12:50:00 ultra ppp[221]: tun0: Phase: total 31 bytes/sec, peak 35 bytes/sec on Sun Aug 1 12:49:49 2004 Aug 1 12:50:00 ultra ppp[221]: tun0: Phase: deflink: hangup -> closed Aug 1 12:50:00 ultra ppp[221]: tun0: Phase: bundle: Dead mcsi@ultra(ttyp1) [114] ~# tcpdump -i sk0 -v tcpdump: listening on sk0, link-type EN10MB (Ethernet), capture size 96 bytes 13:01:40.424159 PPPoE PADI [Host-Uniq "@0N."] 13:01:40.446730 PPPoE PADO [Host-Uniq "@0N."] [Service-Name] [AC-Name "MGTS"] [AC-Cookie 0xF342EBA050A9C9414C23C834EFB69BD7] 13:01:40.689709 PPPoE PADI [Host-Uniq 0x00B02CC2] 13:01:40.710923 PPPoE PADO [Host-Uniq 0x00B02CC2] [Service-Name] [AC-Name "MGTS"] [AC-Cookie 0xF342EBA050A9C9414C23C834EFB69BD7] 13:01:40.711018 PPPoE PADR [Host-Uniq 0x00B02CC2] [AC-Cookie 0xF342EBA050A9C9414C23C834EFB69BD7] [AC-Name "MGTS"] 13:01:40.734840 PPPoE PADS [ses 0x3ad6] [Host-Uniq 0x00B02CC2] [AC-Cookie 0xF342EBA050A9C9414C23C834EFB69BD7] [AC-Name "MGTS"] 13:01:40.736769 PPPoE [ses 0x3ad6] LCP, Conf-Request (0x01), id 1, MRU 1492, Auth-Prot CHAP, MD5, Magic-Num 0x591e9c1f, length 19 13:01:40.741625 PPPoE [ses 0x3ad6] LCP, Conf-Request (0x01), id 1, ACFC , PFC , ACCM 00000000, MRU 1492, Magic-Num 0x512de9cc, length 24 13:01:40.741977 PPPoE [ses 0x3ad6] LCP, Conf-Ack (0x02), id 1, MRU 1492, Auth-Prot CHAP, MD5, Magic-Num 0x591e9c1f, length 19 13:01:42.736133 PPPoE [ses 0x3ad6] LCP, Conf-Request (0x01), id 2, MRU 1492, Auth-Prot CHAP, MD5, Magic-Num 0x591e9c1f, length 19 13:01:42.737387 PPPoE [ses 0x3ad6] LCP, Conf-Ack (0x02), id 2, MRU 1492, Auth-Prot CHAP, MD5, Magic-Num 0x591e9c1f, length 19 13:01:43.838600 PPPoE [ses 0x3ad6] LCP, Conf-Request (0x01), id 1, ACFC , PFC , ACCM 00000000, MRU 1492, Magic-Num 0x512de9cc, length 24 13:01:44.755120 PPPoE [ses 0x3ad6] LCP, Conf-Request (0x01), id 3, MRU 1492, Auth-Prot CHAP, MD5, Magic-Num 0x591e9c1f, length 19 13:01:44.756305 PPPoE [ses 0x3ad6] LCP, Conf-Ack (0x02), id 3, MRU 1492, Auth-Prot CHAP, MD5, Magic-Num 0x591e9c1f, length 19 13:01:46.772310 PPPoE [ses 0x3ad6] LCP, Conf-Request (0x01), id 4, MRU 1492, Auth-Prot CHAP, MD5, Magic-Num 0x591e9c1f, length 19 13:01:46.772976 PPPoE [ses 0x3ad6] LCP, Conf-Ack (0x02), id 4, MRU 1492, Auth-Prot CHAP, MD5, Magic-Num 0x591e9c1f, length 19 13:01:46.878655 PPPoE [ses 0x3ad6] LCP, Conf-Request (0x01), id 1, ACFC , PFC , ACCM 00000000, MRU 1492, Magic-Num 0x512de9cc, length 24 13:01:48.789497 PPPoE [ses 0x3ad6] LCP, Conf-Request (0x01), id 5, MRU 1492, Auth-Prot CHAP, MD5, Magic-Num 0x591e9c1f, length 19 13:01:48.790178 PPPoE [ses 0x3ad6] LCP, Conf-Ack (0x02), id 5, MRU 1492, Auth-Prot CHAP, MD5, Magic-Num 0x591e9c1f, length 19 13:01:49.919138 PPPoE [ses 0x3ad6] LCP, Conf-Request (0x01), id 1, ACFC , PFC , ACCM 00000000, MRU 1492, Magic-Num 0x512de9cc, length 24 13:01:50.804753 PPPoE [ses 0x3ad6] LCP, Conf-Request (0x01), id 6, MRU 1492, Auth-Prot CHAP, MD5, Magic-Num 0x591e9c1f, length 19 13:01:50.805429 PPPoE [ses 0x3ad6] LCP, Conf-Ack (0x02), id 6, MRU 1492, Auth-Prot CHAP, MD5, Magic-Num 0x591e9c1f, length 19 13:01:52.823878 PPPoE [ses 0x3ad6] LCP, Conf-Request (0x01), id 7, MRU 1492, Auth-Prot CHAP, MD5, Magic-Num 0x591e9c1f, length 19 13:01:52.824570 PPPoE [ses 0x3ad6] LCP, Conf-Ack (0x02), id 7, MRU 1492, Auth-Prot CHAP, MD5, Magic-Num 0x591e9c1f, length 19 13:01:52.958776 PPPoE [ses 0x3ad6] LCP, Conf-Request (0x01), id 1, ACFC , PFC , ACCM 00000000, MRU 1492, Magic-Num 0x512de9cc, length 24 13:01:54.841068 PPPoE [ses 0x3ad6] LCP, Conf-Request (0x01), id 8, MRU 1492, Auth-Prot CHAP, MD5, Magic-Num 0x591e9c1f, length 19 13:01:54.841745 PPPoE [ses 0x3ad6] LCP, Conf-Ack (0x02), id 8, MRU 1492, Auth-Prot CHAP, MD5, Magic-Num 0x591e9c1f, length 19 13:01:56.108986 PPPoE PADT [ses 0x3ad6] [Generic-Error "session closed"] 13:01:56.856322 PPPoE [ses 0x3ad6] LCP, Conf-Request (0x01), id 9, MRU 1492, Auth-Prot CHAP, MD5, Magic-Num 0x591e9c1f, length 19 13:01:58.873373 PPPoE [ses 0x3ad6] LCP, Conf-Request (0x01), id 10, MRU 1492, Auth-Prot CHAP, MD5, Magic-Num 0x591e9c1f, length 19 13:02:00.892636 PPPoE PADT [ses 0x3ad6] [EOL] -- Maxim Maximov
Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?410CB1E4.2030103>