PPPoE problems with latest -CURRENT
Maxim Maximov
mcsi at mcsi.pp.ru
Sun Aug 1 02:45:27 PDT 2004
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
More information about the freebsd-current
mailing list