Subject: Reconnects with in-kernel pppoe
To: None <current-users@netbsd.org>
From: Paul Ripke <stixpjr@ozemail.com.au>
List: current-users
Date: 02/25/2002 23:28:19
I'm running with a kernel from around 2002-01-05, with 
if_pppoe.c 1.15 and if_pppoe.h 1.2. My ADSL link runs fine, 
until I have too many reconnects, then it seems I must destroy 
and re-create the pppoe0 interface before I can regain my 
connection. With debug on, the failed reconnects log the 
following:

Feb 22 17:59:57 stix-pc /netbsd: pppoe0: lcp close(initial)
Feb 22 17:59:57 stix-pc /netbsd: pppoe0: lcp open(initial)
Feb 22 17:59:57 stix-pc /netbsd: pppoe0: phase establish
Feb 22 17:59:57 stix-pc /netbsd: pppoe0: session 0x77e connected
Feb 22 17:59:57 stix-pc /netbsd: pppoe0: lcp up(starting)
Feb 22 17:59:57 stix-pc /netbsd: pppoe0: lcp output <conf-req 
id=0xad len=10 ...>
Feb 22 17:59:57 stix-pc /netbsd: pppoe0: lcp input(req-sent): 
<conf-req id=0x3d len=19 ...>
Feb 22 17:59:57 stix-pc /netbsd: pppoe0: lcp parse opts: magic 
mru auth-proto
Feb 22 17:59:57 stix-pc /netbsd: pppoe0: lcp parse opt values:  
magic 0x46d72cc6 mru 1500 auth-proto send conf-ack
Feb 22 17:59:57 stix-pc /netbsd: pppoe0: lcp output <conf-ack 
id=0x3d len=19 ...>
Feb 22 17:59:57 stix-pc /netbsd: pppoe0: lcp input(ack-sent): 
<conf-ack id=0xad len=10 ...>
Feb 22 17:59:58 stix-pc /netbsd: pppoe0: lcp tlu
Feb 22 17:59:58 stix-pc /netbsd: pppoe0: phase authenticate
Feb 22 17:59:58 stix-pc /netbsd: pppoe0: chap input <challenge 
id=0x1 len=39 name=ppp@shastanets.com value-size=16 value= ...>
Feb 22 17:59:58 stix-pc /netbsd: pppoe0: chap output <response 
id=0x1 len=36 ...>
Feb 22 17:59:58 stix-pc /netbsd: pppoe0: chap success
Feb 22 17:59:58 stix-pc /netbsd: pppoe0: phase network
Feb 22 17:59:58 stix-pc /netbsd: pppoe0: ipcp open(stopped)
Feb 22 17:59:58 stix-pc /netbsd: pppoe0: lcp close(opened)
Feb 22 17:59:58 stix-pc /netbsd: pppoe0: phase terminate
Feb 22 17:59:58 stix-pc /netbsd: pppoe0: lcp output <term-req 
id=0xae len=4>
Feb 22 17:59:58 stix-pc /netbsd: pppoe0: lcp input(closing): 
<term-ack id=0xae len=4 ...>
Feb 22 17:59:58 stix-pc /netbsd: pppoe0: phase dead
Feb 22 17:59:59 stix-pc /netbsd: pppoe0: disconnecting
Feb 22 17:59:59 stix-pc /netbsd: pppoe0: lcp down(closed)
Feb 22 17:59:59 stix-pc /netbsd: pppoe0: Down event (carrier 
loss), taking interface down.

After destroying and re-creating the interface, it works fine:
Feb 22 18:03:09 stix-pc /netbsd: pppoe0: lcp close(initial)
Feb 22 18:03:09 stix-pc /netbsd: pppoe0: lcp open(initial)
Feb 22 18:03:09 stix-pc /netbsd: pppoe0: phase establish
Feb 22 18:03:09 stix-pc /netbsd: pppoe0: session 0x785 connected
Feb 22 18:03:09 stix-pc /netbsd: pppoe0: lcp up(starting)
Feb 22 18:03:09 stix-pc /netbsd: pppoe0: lcp output <conf-req 
id=0x1 len=10 ...>
Feb 22 18:03:09 stix-pc /netbsd: pppoe0: lcp input(req-sent): 
<conf-req id=0x5d len=19 ...>
Feb 22 18:03:09 stix-pc /netbsd: pppoe0: lcp parse opts: magic 
mru auth-proto
Feb 22 18:03:09 stix-pc /netbsd: pppoe0: lcp parse opt values:  
magic 0x6f9ab266 mru 1500 auth-proto send conf-ack
Feb 22 18:03:10 stix-pc /netbsd: pppoe0: lcp output <conf-ack 
id=0x5d len=19 ...>
Feb 22 18:03:10 stix-pc /netbsd: pppoe0: lcp input(ack-sent): 
<conf-ack id=0x1 len=10 ...>
Feb 22 18:03:10 stix-pc /netbsd: pppoe0: lcp tlu
Feb 22 18:03:10 stix-pc /netbsd: pppoe0: phase authenticate
Feb 22 18:03:10 stix-pc /netbsd: pppoe0: chap input <challenge 
id=0x1 len=39 name=ppp@shastanets.com value-size=16 value= ...>
Feb 22 18:03:10 stix-pc /netbsd: pppoe0: chap output <response 
id=0x1 len=36 ...>
Feb 22 18:03:10 stix-pc /netbsd: pppoe0: chap success
Feb 22 18:03:10 stix-pc /netbsd: pppoe0: phase network
Feb 22 18:03:10 stix-pc /netbsd: pppoe0: ipcp open(initial)
Feb 22 18:03:10 stix-pc /netbsd: pppoe0: ipcp up(starting)
Feb 22 18:03:10 stix-pc /netbsd: pppoe0: ipcp output <conf-req 
id=0x1 len=10 ...>

The "ipcp open(stopped)" seems to be where things start going 
bad. Looks like some state somewhere isn't being reset. Has 
anyone else seen this?

Cheers,
--
Paul Ripke
stixpjr @ ozemail.com.au