ppp failure

[Chris Knipe]

Hi,

Can some ppp guru not by any change tell me why the below session is 
failing?  I never seem to be able to properly read these PPP sessions...

Feb 22 16:31:44 wsmd01 pppoed[7845]: Listening
Feb 22 16:31:44 wsmd01 pppoed[8045]: Offering to .:exec-8045 as access 
concentrator wsmd01
Feb 22 16:31:44 wsmd01 pppoed[8045]: adding to .:exec-8045 as offered 
service wsmd01
Feb 22 16:31:44 wsmd01 pppoed[8045]: Received NGM_PPPOE_SESSIONID (hook "%")
Feb 22 16:31:44 wsmd01 pppoed[8045]: Received NGM_PPPOE_SUCCESS (hook 
"exec-8045")
Feb 22 16:31:44 wsmd01 pppoed[8045]: Executing: exec /usr/sbin/ppp -direct 
PPPoE
Feb 22 16:31:44 wsmd01 ppp[8045]: Phase: Using interface: tun1
Feb 22 16:31:44 wsmd01 ppp[8045]: Phase: deflink: Created in closed state
Feb 22 16:31:44 wsmd01 ppp[8045]: tun1: Command: default: ident user-ppp 
VERSION (built COMPILATIONDATE)
Feb 22 16:31:44 wsmd01 ppp[8045]: tun1: Command: default: set device 
/dev/cuaa1
Feb 22 16:31:44 wsmd01 ppp[8045]: tun1: Command: default: set speed 115200
Feb 22 16:31:44 wsmd01 ppp[8045]: tun1: Command: default: set dial ABORT 
BUSY ABORT NO\sCARRIER TIMEOUT 5            "" AT OK-AT-OK ATE1Q0 OK 
\dATDT\T TIMEOUT 40 CONNECT
Feb 22 16:31:44 wsmd01 ppp[8045]: tun1: Command: PPPoE: enable lqr proxy
Feb 22 16:31:44 wsmd01 ppp[8045]: tun1: Command: PPPoE: enable pap chap 
passwdauth
Feb 22 16:31:44 wsmd01 ppp[8045]: tun1: Command: PPPoE: set ifaddr 
192.168.1.20 192.168.1.200-192.168.1.254
Feb 22 16:31:44 wsmd01 ppp[8045]: tun1: IPCP: Selected IP address 
192.168.1.241
Feb 22 16:31:44 wsmd01 ppp[8045]: tun1: Command: PPPoE: accept dns
Feb 22 16:31:44 wsmd01 ppp[8045]: tun1: Phase: PPP Started (direct mode).
Feb 22 16:31:44 wsmd01 ppp[8045]: tun1: Phase: bundle: Establish
Feb 22 16:31:44 wsmd01 ppp[8045]: tun1: Phase: deflink: closed -> opening
Feb 22 16:31:44 wsmd01 ppp[8045]: tun1: Phase: deflink: Link is a netgraph 
node
Feb 22 16:31:44 wsmd01 ppp[8045]: tun1: Phase: deflink: Connected!
Feb 22 16:31:44 wsmd01 ppp[8045]: tun1: Phase: deflink: opening -> carrier
Feb 22 16:31:44 wsmd01 ppp[8045]: tun1: Phase: deflink: carrier -> lcp
Feb 22 16:31:44 wsmd01 ppp[8045]: tun1: LCP: FSM: Using "deflink" as a 
transport
Feb 22 16:31:44 wsmd01 ppp[8045]: tun1: LCP: deflink: State change 
Initial --> Closed
Feb 22 16:31:44 wsmd01 ppp[8045]: tun1: LCP: deflink: State change 
Closed --> Stopped
Feb 22 16:31:44 wsmd01 ppp[8045]: tun1: LCP: deflink: RecvConfigReq(1) state 
= Stopped
Feb 22 16:31:44 wsmd01 ppp[8045]: tun1: LCP:  MRU[4] 1440
Feb 22 16:31:44 wsmd01 ppp[8045]: tun1: LCP:  MAGICNUM[6] 0x00001771
Feb 22 16:31:44 wsmd01 ppp[8045]: tun1: Warning: deflink: Reducing 
configured MRU from 1500 to 1492
Feb 22 16:31:44 wsmd01 ppp[8045]: tun1: LCP: deflink: SendConfigReq(1) state 
= Stopped
Feb 22 16:31:44 wsmd01 ppp[8045]: tun1: LCP:  ACFCOMP[2]
Feb 22 16:31:44 wsmd01 ppp[8045]: tun1: LCP:  PROTOCOMP[2]
Feb 22 16:31:44 wsmd01 ppp[8045]: tun1: LCP:  ACCMAP[6] 0x00000000
Feb 22 16:31:44 wsmd01 ppp[8045]: tun1: LCP:  MRU[4] 1492
Feb 22 16:31:44 wsmd01 ppp[8045]: tun1: LCP:  MAGICNUM[6] 0xf9d75109
Feb 22 16:31:44 wsmd01 ppp[8045]: tun1: LCP:  QUALPROTO[8] proto c025, 
interval 30000ms
Feb 22 16:31:44 wsmd01 ppp[8045]: tun1: LCP:  AUTHPROTO[5] 0xc223 (CHAP 
0x05)
Feb 22 16:31:44 wsmd01 ppp[8045]: tun1: LCP: deflink: SendConfigAck(1) state 
= Stopped
Feb 22 16:31:44 wsmd01 ppp[8045]: tun1: LCP:  MRU[4] 1440
Feb 22 16:31:44 wsmd01 ppp[8045]: tun1: LCP:  MAGICNUM[6] 0x00001771
Feb 22 16:31:44 wsmd01 ppp[8045]: tun1: LCP: deflink: LayerStart
Feb 22 16:31:44 wsmd01 ppp[8045]: tun1: LCP: deflink: State change 
Stopped --> Ack-Sent
Feb 22 16:31:44 wsmd01 ppp[8045]: tun1: LCP: deflink: RecvConfigRej(1) state 
= Ack-Sent
Feb 22 16:31:44 wsmd01 ppp[8045]: tun1: LCP: deflink: SendIdent(0) state = 
Ack-Sent
Feb 22 16:31:44 wsmd01 ppp[8045]: tun1: LCP:  MAGICNUM f9d75109
Feb 22 16:31:44 wsmd01 ppp[8045]: tun1: LCP:  TEXT user-ppp 3.1 (built Feb 
23 2004)
Feb 22 16:31:44 wsmd01 ppp[8045]: tun1: LCP:  QUALPROTO[8] proto c025, 
interval 30000ms
Feb 22 16:31:44 wsmd01 ppp[8045]: tun1: LCP: deflink: SendConfigReq(2) state 
= Ack-Sent
Feb 22 16:31:44 wsmd01 ppp[8045]: tun1: LCP:  ACFCOMP[2]
Feb 22 16:31:44 wsmd01 ppp[8045]: tun1: LCP:  PROTOCOMP[2]
Feb 22 16:31:44 wsmd01 ppp[8045]: tun1: LCP:  ACCMAP[6] 0x00000000
Feb 22 16:31:44 wsmd01 ppp[8045]: tun1: LCP:  MRU[4] 1492
Feb 22 16:31:44 wsmd01 ppp[8045]: tun1: LCP:  MAGICNUM[6] 0xf9d75109
Feb 22 16:31:44 wsmd01 ppp[8045]: tun1: LCP:  AUTHPROTO[5] 0xc223 (CHAP 
0x05)
Feb 22 16:31:46 wsmd01 ppp[8045]: tun1: LCP: deflink: RecvConfigReq(2) state 
= Ack-Sent
Feb 22 16:31:46 wsmd01 ppp[8045]: tun1: LCP:  MRU[4] 1440
Feb 22 16:31:46 wsmd01 ppp[8045]: tun1: LCP:  MAGICNUM[6] 0x00001771
Feb 22 16:31:46 wsmd01 ppp[8045]: tun1: LCP: deflink: SendConfigAck(2) state 
= Ack-Sent
Feb 22 16:31:46 wsmd01 ppp[8045]: tun1: LCP:  MRU[4] 1440
Feb 22 16:31:46 wsmd01 ppp[8045]: tun1: LCP:  MAGICNUM[6] 0x00001771
Feb 22 16:31:46 wsmd01 ppp[8043]: tun0: LCP: deflink: LayerFinish
Feb 22 16:31:46 wsmd01 ppp[8043]: tun0: LCP: deflink: State change 
Ack-Sent --> Stopped
Feb 22 16:31:46 wsmd01 ppp[8043]: tun0: LCP: deflink: State change 
Stopped --> Closed
Feb 22 16:31:46 wsmd01 ppp[8043]: tun0: LCP: deflink: State change 
Closed --> Initial
Feb 22 16:31:46 wsmd01 ppp[8043]: tun0: Phase: deflink: Disconnected!
Feb 22 16:31:46 wsmd01 ppp[8043]: tun0: Phase: deflink: Connect time: 15 
secs: 126 octets in, 348 octets out
Feb 22 16:31:46 wsmd01 ppp[8043]: tun0: Phase: deflink: 8 packets in, 14 
packets out
Feb 22 16:31:46 wsmd01 ppp[8043]: tun0: Phase:  total 31 bytes/sec, peak 79 
bytes/sec on Tue Feb 22 16:31:32 2005
Feb 22 16:31:46 wsmd01 ppp[8043]: tun0: Phase: deflink: lcp -> closed
Feb 22 16:31:46 wsmd01 ppp[8043]: tun0: Phase: bundle: Dead
Feb 22 16:31:46 wsmd01 ppp[8043]: tun0: Phase: PPP Terminated (normal).


Thanks, much appreciated.

--
Chris.