Problems with 8.1, PPPoE server, and Cisco client

[Ian Smith]

On Tue, 19 Oct 2010, Paul Thornton wrote:
 > I'm hoping that someone can point me in the right direction to get
 > enough debug to troubleshoot a very annoying connection problem with
 > PPPoE to a Cisco.
 > 
 > I have a freshly installed 8.1-RELEASE amd64 box with a very simple
 > PPPoE daemon setup on it.  This works fine for a test WinXP and Mac OS X
 > client so I know that fundamentally that side of things should be OK. I
 > have also used a similar setup (under 7.0) with all sorts of consumer
 > routers doing PPPoE and it "just works".  The server I'm testing with
 > has VLANs on top of igb interfaces, and I haven't seen any other network
 > issues.
 > 
 > Using a Cisco 800 series as the client, however, things start off
 > working fine - connects up OK, authenticates, etc. but then it
 > immediately disconnects.
 > There is no clear error as to why the disconnect happens at either end -
 > hence my confusion.  I've tried several routers (some direct Ethernet
 > link, some via VDSL) and have upgraded to the latest IOS in an attempt
 > to make this work, nothing changes.
 > 
 > Have also tried with 7.2-RELEASE in case it was an 8.X issue - again,
 > same problem seen.
 > 
 > Any hints to help debug this (from either end) would be much appreciated.

Just to add to what Julian and Bjoern said .. something about addressing 
/ routing looks maybe odd to me, without knowing your network setup or 
much at all about vlans.

Adding both lcp and ipcp to ppp logging should confirm success (or 
indicate problems) at those levels.

 >  set ifaddr 217.65.168.254/32

 > > Oct 19 20:05:33 vdsl02a ppp[2234]: Command: default: set ifaddr 217.65.168.254/32

 > > Oct 19 20:05:36 vdsl02a ppp[2234]: Phase:  IP 217.65.167.1
 > > Oct 19 20:05:36 vdsl02a ppp[2234]: Phase:  Route: 217.65.167.64/29 217.65.167.1 1

Does that all look right?

 > > Oct 19 20:05:36 vdsl02a ppp[2234]: Warning: iface add: ioctl(SIOCAIFADDR, 217.65.168.254 -> 217.65.167.1): File exists

>From memory, 'File exists' means more like 'route exists'

 > > Oct 19 20:05:36 vdsl02a ppp[2234]: Phase: deflink: open -> lcp
 > > Oct 19 20:05:36 vdsl02a ppp[2234]: Phase: bundle: Terminate

Bang.

 > And every time the router attempts to reconnect, the same thing is seen.
 > 
 > Here is the log from the router's perspective:

Maybe add IPCP logging on the Cisco too?  No addressing info shown here.

 > > *Oct 19 20:19:52.139: Vi2 LCP: State is Open
 > > *Oct 19 20:19:52.147: Vi2 CHAP: I SUCCESS id 1 len 13 msg is "Welcome!!"
 > > *Oct 19 20:19:52.147: Vi2 PPP: Phase is FORWARDING, Attempting Forward
 > > *Oct 19 20:19:52.147: Vi2 PPP: Queue CCP code[1] id[1]
 > > *Oct 19 20:19:52.147: Vi2 PPP: Queue IPCP code[1] id[1]
 > > *Oct 19 20:19:52.151: Vi2 PPP DISC: Lower Layer disconnected
 > > *Oct 19 20:19:52.151: Vi2 LCP: O TERMREQ [Open] id 2 len 4
 > > *Oct 19 20:19:52.151: Vi2 LCP: Event[CLOSE] State[Open to Closing]
 > > *Oct 19 20:19:52.151: Vi2 PPP: Phase is TERMINATING

Definitely looks like LCP, but that could come from IPCP layer .. I've 
been using mpd for so long I hardly remember ppp logging.

Just another stab in the dark,

Ian