Re: PPPoE problems with latest -CURRENT

From: Maxim Maximov <mcsi_at_mcsi.pp.ru>
Date: Sun, 01 Aug 2004 13:45:13 +0400
Gleb Smirnoff wrote:
>   Maxim,
> 
> On Sun, Aug 01, 2004 at 01:03:32PM +0400, Maxim Maximov wrote:
> M> I can confirm that the problems are still there. ppp.log and tcpdump 
> M> output follow:
> 
>   This is a different problem. You either can't negotiate MRU with your
> peer, are you are suppling incorrect CHAP secret.
> 
> What operating system/hardware is in remote side?
> 
> Please check your password, too.
> 

Gleb,

	My ppp.conf haven't been changed from the time this machine have 
FreeBSD installed. Password configured is the same that I'm successfuly 
using now with rp-pppoe.
	Please look at this successful rp-pppoe session log. I see MRU is 
really changed to 1500. Why ng_pppoe can't do this anymore?
	OS/hardware on the remote side is beyond my knowledge. I could try to 
find it out, but it may take some time.

Aug  1 13:03:10 ultra ppp[723]: Phase: Using interface: tun0
Aug  1 13:03:10 ultra ppp[723]: Phase: deflink: Created in closed state
Aug  1 13:03:10 ultra ppp[723]: tun0: Command: default: ident user-ppp 
VERSION (built COMPILATIONDATE)
Aug  1 13:03:10 ultra ppp[723]: tun0: Command: default: set device 
/dev/cuaa1
Aug  1 13:03:10 ultra ppp[723]: tun0: Command: default: enable dns
Aug  1 13:03:10 ultra ppp[723]: tun0: Command: mtu-rp: set device 
!/usr/local/sbin/pppoe -U -I sk0
Aug  1 13:03:10 ultra ppp[723]: tun0: Command: mtu-rp: set ifaddr 
172.16.0.1/0 172.16.0.2/0 255.255.255.0 0.0.0.0
Aug  1 13:03:10 ultra ppp[723]: tun0: Command: mtu-rp: add default HISADDR
Aug  1 13:03:10 ultra ppp[723]: tun0: Command: mtu-rp: set authname xxxxxxxx
Aug  1 13:03:10 ultra ppp[723]: tun0: Command: mtu-rp: set authkey ********
Aug  1 13:03:10 ultra ppp[724]: tun0: Phase: PPP Started (auto mode).
Aug  1 13:03:12 ultra ppp[724]: tun0: Phase: bundle: Establish
Aug  1 13:03:12 ultra ppp[724]: tun0: Phase: deflink: closed -> opening
Aug  1 13:03:12 ultra ppp[724]: tun0: Phase: deflink: Connected!
Aug  1 13:03:12 ultra ppp[724]: tun0: Phase: deflink: opening -> dial
Aug  1 13:03:12 ultra ppp[724]: tun0: Chat: deflink: Dial attempt 1 of 1
Aug  1 13:03:12 ultra ppp[724]: tun0: Phase: deflink: dial -> carrier
Aug  1 13:03:12 ultra ppp[724]: tun0: Phase: deflink: carrier -> login
Aug  1 13:03:12 ultra ppp[724]: tun0: Phase: deflink: login -> lcp
Aug  1 13:03:12 ultra ppp[724]: tun0: LCP: FSM: Using "deflink" as a 
transport
Aug  1 13:03:12 ultra ppp[724]: tun0: LCP: deflink: State change Initial 
--> Closed
Aug  1 13:03:12 ultra ppp[724]: tun0: LCP: deflink: State change Closed 
--> Stopped
Aug  1 13:03:12 ultra ppp[724]: tun0: LCP: deflink: RecvConfigReq(1) 
state = Stopped
Aug  1 13:03:12 ultra ppp[724]: tun0: LCP:  MRU[4] 1492
Aug  1 13:03:12 ultra ppp[724]: tun0: LCP:  AUTHPROTO[5] 0xc223 (CHAP 0x05)
Aug  1 13:03:12 ultra ppp[724]: tun0: LCP:  MAGICNUM[6] 0x592003fa
Aug  1 13:03:12 ultra ppp[724]: tun0: LCP: deflink: SendConfigReq(1) 
state = Stopped
Aug  1 13:03:12 ultra ppp[724]: tun0: LCP:  ACFCOMP[2]
Aug  1 13:03:12 ultra ppp[724]: tun0: LCP:  PROTOCOMP[2]
Aug  1 13:03:12 ultra ppp[724]: tun0: LCP:  ACCMAP[6] 0x00000000
Aug  1 13:03:12 ultra ppp[724]: tun0: LCP:  MRU[4] 1500
Aug  1 13:03:12 ultra ppp[724]: tun0: LCP:  MAGICNUM[6] 0xbc956200
Aug  1 13:03:12 ultra ppp[724]: tun0: LCP: deflink: SendConfigAck(1) 
state = Stopped
Aug  1 13:03:12 ultra ppp[724]: tun0: LCP:  MRU[4] 1492
Aug  1 13:03:12 ultra ppp[724]: tun0: LCP:  AUTHPROTO[5] 0xc223 (CHAP 0x05)
Aug  1 13:03:12 ultra ppp[724]: tun0: LCP:  MAGICNUM[6] 0x592003fa
Aug  1 13:03:12 ultra ppp[724]: tun0: LCP: deflink: LayerStart
Aug  1 13:03:12 ultra ppp[724]: tun0: LCP: deflink: State change Stopped 
--> Ack-Sent
Aug  1 13:03:12 ultra ppp[724]: tun0: LCP: deflink: RecvConfigAck(1) 
state = Ack-Sent
Aug  1 13:03:12 ultra ppp[724]: tun0: LCP:  ACFCOMP[2]
Aug  1 13:03:12 ultra ppp[724]: tun0: LCP:  PROTOCOMP[2]
Aug  1 13:03:12 ultra ppp[724]: tun0: LCP:  ACCMAP[6] 0x00000000
Aug  1 13:03:12 ultra ppp[724]: tun0: LCP:  MRU[4] 1500
Aug  1 13:03:12 ultra ppp[724]: tun0: LCP:  MAGICNUM[6] 0xbc956200
Aug  1 13:03:12 ultra ppp[724]: tun0: LCP: deflink: State change 
Ack-Sent --> Opened
Aug  1 13:03:12 ultra ppp[724]: tun0: LCP: deflink: LayerUp
Aug  1 13:03:12 ultra ppp[724]: tun0: LCP: deflink: SendIdent(0) state = 
Opened
Aug  1 13:03:12 ultra ppp[724]: tun0: LCP:  MAGICNUM bc956200
Aug  1 13:03:12 ultra ppp[724]: tun0: LCP:  TEXT user-ppp 3.2 (built Jul 
30 2004)
Aug  1 13:03:12 ultra ppp[724]: tun0: Phase: bundle: Authenticate
Aug  1 13:03:12 ultra ppp[724]: tun0: Phase: deflink: his = CHAP 0x05, 
mine = none
Aug  1 13:03:12 ultra ppp[724]: tun0: Phase: Chap Input: CHALLENGE (16 
bytes from A947-agr01)
Aug  1 13:03:12 ultra ppp[724]: tun0: Phase: Chap Output: RESPONSE 
(xxxxxxxxxxxxxx)
Aug  1 13:03:13 ultra ppp[724]: tun0: Phase: Chap Input: SUCCESS
Aug  1 13:03:13 ultra ppp[724]: tun0: IPCP: Using trigger address 0.0.0.0
Aug  1 13:03:13 ultra ppp[724]: tun0: CCP: FSM: Using "deflink" as a 
transport
Aug  1 13:03:13 ultra ppp[724]: tun0: CCP: deflink: State change Initial 
--> Closed
Aug  1 13:03:13 ultra ppp[724]: tun0: CCP: deflink: LayerStart.
Aug  1 13:03:13 ultra ppp[724]: tun0: CCP: MPPE: Not usable without CHAP81
Aug  1 13:03:13 ultra ppp[724]: tun0: CCP: deflink: SendConfigReq(1) 
state = Closed
Aug  1 13:03:13 ultra ppp[724]: tun0: CCP:  DEFLATE[4] win 15
Aug  1 13:03:13 ultra ppp[724]: tun0: CCP:  PRED1[2]
Aug  1 13:03:13 ultra ppp[724]: tun0: CCP: deflink: State change Closed 
--> Req-Sent
Aug  1 13:03:13 ultra ppp[724]: tun0: Phase: deflink: lcp -> open
Aug  1 13:03:13 ultra ppp[724]: tun0: Phase: bundle: Network
Aug  1 13:03:13 ultra ppp[724]: tun0: IPCP: FSM: Using "deflink" as a 
transport
Aug  1 13:03:13 ultra ppp[724]: tun0: IPCP: deflink: State change 
Initial --> Closed
Aug  1 13:03:13 ultra ppp[724]: tun0: IPCP: deflink: LayerStart.
Aug  1 13:03:13 ultra ppp[724]: tun0: IPCP: deflink: SendConfigReq(1) 
state = Closed
Aug  1 13:03:13 ultra ppp[724]: tun0: IPCP:  IPADDR[6] 0.0.0.0
Aug  1 13:03:13 ultra ppp[724]: tun0: IPCP:  COMPPROTO[6] 16 VJ slots 
with slot compression
Aug  1 13:03:13 ultra ppp[724]: tun0: IPCP:  PRIDNS[6] 212.188.4.10
Aug  1 13:03:13 ultra ppp[724]: tun0: IPCP:  SECDNS[6] 255.255.255.255
Aug  1 13:03:13 ultra ppp[724]: tun0: IPCP: deflink: State change Closed 
--> Req-Sent
Aug  1 13:03:13 ultra ppp[724]: tun0: IPCP: deflink: RecvConfigReq(1) 
state = Req-Sent
Aug  1 13:03:13 ultra ppp[724]: tun0: IPCP:  IPADDR[6] 10.2.255.2
Aug  1 13:03:13 ultra ppp[724]: tun0: IPCP: deflink: SendConfigAck(1) 
state = Req-Sent
Aug  1 13:03:13 ultra ppp[724]: tun0: IPCP:  IPADDR[6] 10.2.255.2
Aug  1 13:03:13 ultra ppp[724]: tun0: IPCP: deflink: State change 
Req-Sent --> Ack-Sent
Aug  1 13:03:13 ultra ppp[724]: tun0: LCP: deflink: RecvProtocolRej(2) 
state = Opened
Aug  1 13:03:13 ultra ppp[724]: tun0: LCP: deflink: -- Protocol 0x80fd 
(Compression Control Protocol) was rejected!
Aug  1 13:03:13 ultra ppp[724]: tun0: CCP: deflink: State change 
Req-Sent --> Stopped
Aug  1 13:03:13 ultra ppp[724]: tun0: IPCP: deflink: RecvConfigRej(1) 
state = Ack-Sent
Aug  1 13:03:13 ultra ppp[724]: tun0: LCP: deflink: SendIdent(1) state = 
Opened
Aug  1 13:03:13 ultra ppp[724]: tun0: LCP:  MAGICNUM bc956200
Aug  1 13:03:13 ultra ppp[724]: tun0: LCP:  TEXT user-ppp 3.2 (built Jul 
30 2004)
Aug  1 13:03:13 ultra ppp[724]: tun0: IPCP:  COMPPROTO[6] 16 VJ slots 
with slot compression
Aug  1 13:03:13 ultra ppp[724]: tun0: IPCP: deflink: SendConfigReq(2) 
state = Ack-Sent
Aug  1 13:03:13 ultra ppp[724]: tun0: IPCP:  IPADDR[6] 0.0.0.0
Aug  1 13:03:13 ultra ppp[724]: tun0: IPCP:  PRIDNS[6] 212.188.4.10
Aug  1 13:03:13 ultra ppp[724]: tun0: IPCP:  SECDNS[6] 255.255.255.255
Aug  1 13:03:13 ultra ppp[724]: tun0: IPCP: deflink: RecvConfigNak(2) 
state = Ack-Sent
Aug  1 13:03:13 ultra ppp[724]: tun0: IPCP:  IPADDR[6] 81.195.16.111
Aug  1 13:03:13 ultra ppp[724]: tun0: IPCP:  IPADDR[6] changing address: 
0.0.0.0  --> 81.195.16.111
Aug  1 13:03:13 ultra ppp[724]: tun0: IPCP:  PRIDNS[6] 195.34.32.10
Aug  1 13:03:13 ultra ppp[724]: tun0: IPCP:  SECDNS[6] 212.188.4.10
Aug  1 13:03:13 ultra ppp[724]: tun0: IPCP: Primary nameserver set to 
195.34.32.10
Aug  1 13:03:13 ultra ppp[724]: tun0: IPCP: Secondary nameserver set to 
212.188.4.10
Aug  1 13:03:13 ultra ppp[724]: tun0: IPCP: deflink: SendConfigReq(3) 
state = Ack-Sent
Aug  1 13:03:13 ultra ppp[724]: tun0: IPCP:  IPADDR[6] 81.195.16.111
Aug  1 13:03:13 ultra ppp[724]: tun0: IPCP:  PRIDNS[6] 195.34.32.10
Aug  1 13:03:13 ultra ppp[724]: tun0: IPCP:  SECDNS[6] 212.188.4.10
Aug  1 13:03:13 ultra ppp[724]: tun0: IPCP: deflink: RecvConfigAck(3) 
state = Ack-Sent
Aug  1 13:03:13 ultra ppp[724]: tun0: IPCP:  IPADDR[6] 81.195.16.111
Aug  1 13:03:13 ultra ppp[724]: tun0: IPCP:  PRIDNS[6] 195.34.32.10
Aug  1 13:03:13 ultra ppp[724]: tun0: IPCP:  SECDNS[6] 212.188.4.10
Aug  1 13:03:13 ultra ppp[724]: tun0: IPCP: deflink: State change 
Ack-Sent --> Opened
Aug  1 13:03:13 ultra ppp[724]: tun0: IPCP: deflink: LayerUp.
Aug  1 13:03:13 ultra ppp[724]: tun0: IPCP: myaddr 81.195.16.111 hisaddr 
= 10.2.255.2
Aug  1 13:03:14 ultra ppp[724]: tun0: LCP: deflink: RecvEchoRequest(1) 
state = Opened
Aug  1 13:03:14 ultra ppp[724]: tun0: LCP: deflink: SendEchoReply(1) 
state = Opened
Aug  1 13:04:56 ultra ppp[724]: tun0: LCP: deflink: RecvEchoRequest(2) 
state = Opened
Aug  1 13:04:56 ultra ppp[724]: tun0: LCP: deflink: SendEchoReply(2) 
state = Opened
Aug  1 13:05:17 ultra ppp[724]: tun0: LCP: deflink: RecvEchoRequest(3) 
state = Opened

-- 
Maxim Maximov
Received on Sun Aug 01 2004 - 07:45:27 UTC

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