Re: PPPoE problems with latest -CURRENT

From: Maxim Maximov <mcsi_at_mcsi.pp.ru>
Date: Sun, 01 Aug 2004 13:03:32 +0400
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_at_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 "_at_0N."]
13:01:40.446730 PPPoE PADO [Host-Uniq "_at_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
Received on Sun Aug 01 2004 - 07:03:48 UTC

This archive was generated by hypermail 2.4.0 : Wed May 19 2021 - 11:38:04 UTC