PPPoE Problems

[ Available lists | Index of freebsd-questions | Month of Jan 2000 | Week of 17 Jan 2000 | Raw email | View thread | Wrap long lines | Reply | Tag ]
From
Dany Cayouette <danyc@playground.net>
Date
17 Jan 2000 17:17:29
Subject
PPPoE Problems
Message-ID
3883BFE2.AE260F84@playground.net


[ Hide this part ]
Greetings,
I recently got my hands on an old DEC pentium 133 PC. I just got
FreeBSD 3.4-RELEASE installed. I am interested in getting PPPoE
running. I recompile a kernel with all the NETGRAPH options. The first
problem I noticed is a 50% success rate on getting a successful
connection. I start my session with the command "ppp -dedicated". I
stop the session with "kill <PPP PID>". When the process terminates,
I get the following 2 messages:

/var/log/messages:
Jan 12 16:48:19 freebsd ppp[265]: tun0: Warning: deflink: Oops: Got 8
bytes but 4 byte payload
Jan 12 16:48:20 freebsd ppp[265]: tun0: Warning: deflink: Oops: Got 8
bytes but 4 byte payload

When I try to restart "ppp -dedicated" I don't get any special error
messages but a tcpdump suggests that nothing goes out on the Ethernet
interface. I kill the ppp process and re-issue the command "ppp
-dedicated" and everything works! I wanted to do more debugging today
but now nothing works. I am getting a write error on the tun
interface. Any idea on what extra debugging I could turn on...

Here is my configuration, the output on /var/log/ppp.log for the write
failure and finally output from a successful session:
/etc/ppp/ppp.conf

default:
set device PPPoE:de0
set MRU 1490
set MTU 1490
set authname user@domain.com
set authkey password
set log Phase Chat LCP IPCP CCP tun command
# set log Phase IPCP CCP tun LCP
set dial
set login "TIMEOUT 1.5 name:\\r-login:\\U:\\P ocol:PPP HELLO"
set ifaddr 10.0.0.1/0 10.0.0.2/0
add default HISADDR
# enable dns
set cd off
set crtscts off

/var/log/ppp.log
--------
Failing Session
--------
Jan 17 13:31:30 freebsd ppp[6886]: Phase: Using interface: tun0
Jan 17 13:31:30 freebsd ppp[6886]: Phase: deflink: Created in closed
state
Jan 17 13:31:30 freebsd ppp[6887]: tun0: Phase: PPP Started (dedicated
mode).
Jan 17 13:31:30 freebsd ppp[6887]: tun0: Phase: bundle: Establish
Jan 17 13:31:30 freebsd ppp[6887]: tun0: Phase: deflink: closed ->
opening
Jan 17 13:31:30 freebsd ppp[6887]: tun0: Phase: deflink: Connected!
Jan 17 13:31:30 freebsd ppp[6887]: tun0: Phase: deflink: opening ->
carrier
Jan 17 13:31:31 freebsd ppp[6887]: tun0: Phase: deflink: Disconnected!
Jan 17 13:31:31 freebsd ppp[6887]: tun0: Phase: deflink: carrier -> lcp
Jan 17 13:31:31 freebsd ppp[6887]: tun0: LCP: FSM: Using "deflink" as a
transport
Jan 17 13:31:31 freebsd ppp[6887]: tun0: LCP: deflink: State change
Initial --> Closed
Jan 17 13:31:31 freebsd ppp[6887]: tun0: LCP: deflink: State change
Closed --> Stopped
Jan 17 13:31:32 freebsd ppp[6887]: tun0: LCP: deflink: LayerStart
Jan 17 13:31:32 freebsd ppp[6887]: tun0: LCP: deflink: SendConfigReq(1)
state = Stopped
Jan 17 13:31:32 freebsd ppp[6887]: tun0: LCP: ACFCOMP[2]
Jan 17 13:31:32 freebsd ppp[6887]: tun0: LCP: PROTOCOMP[2]
Jan 17 13:31:32 freebsd ppp[6887]: tun0: LCP: ACCMAP[6] 0x00000000
Jan 17 13:31:32 freebsd ppp[6887]: tun0: LCP: MRU[4] 1490
Jan 17 13:31:32 freebsd ppp[6887]: tun0: LCP: MAGICNUM[6] 0x744e7a6d
Jan 17 13:31:32 freebsd ppp[6887]: tun0: LCP: deflink: State change
Stopped --> Req-Sent
Jan 17 13:31:32 freebsd ppp[6887]: tun0: Phase: deflink: write (1):
Network is unreachable
Jan 17 13:31:32 freebsd ppp[6887]: tun0: LCP: deflink: State change
Req-Sent --> Starting
Jan 17 13:31:32 freebsd ppp[6887]: tun0: LCP: deflink: LayerFinish
Jan 17 13:31:32 freebsd ppp[6887]: tun0: LCP: deflink: State change
Starting --> Initial
Jan 17 13:31:32 freebsd ppp[6887]: tun0: Phase: deflink: Disconnected!
Jan 17 13:31:32 freebsd ppp[6887]: tun0: LCP: FSM: Using "deflink" as a
transport
Jan 17 13:31:32 freebsd ppp[6887]: tun0: LCP: deflink: State change
Initial --> Closed
Jan 17 13:31:32 freebsd ppp[6887]: tun0: LCP: deflink: State change
Closed --> Stopped
Jan 17 13:31:32 freebsd ppp[6887]: tun0: Phase: deflink: Disconnected!
..........................

------
Successful session
------

Jan 12 16:41:40 freebsd ppp[264]: Phase: Using interface: tun0
Jan 12 16:41:40 freebsd ppp[264]: Phase: deflink: Created in closed
state
Jan 12 16:41:41 freebsd ppp[265]: tun0: LCP: FSM: Using "deflink" as a
transport
Jan 12 16:41:41 freebsd ppp[265]: tun0: LCP: deflink: State change
Initial --> Closed
Jan 12 16:41:41 freebsd ppp[265]: tun0: LCP: deflink: State change
Closed --> Stopped
Jan 12 16:41:42 freebsd ppp[265]: tun0: LCP: deflink: LayerStart
Jan 12 16:41:42 freebsd ppp[265]: tun0: LCP: deflink: SendConfigReq(1)
state = Stopped
Jan 12 16:41:42 freebsd ppp[265]: tun0: LCP: ACFCOMP[2]
Jan 12 16:41:42 freebsd ppp[265]: tun0: LCP: PROTOCOMP[2]
Jan 12 16:41:42 freebsd ppp[265]: tun0: LCP: ACCMAP[6] 0x00000000
Jan 12 16:41:42 freebsd ppp[265]: tun0: LCP: MRU[4] 1490
Jan 12 16:41:42 freebsd ppp[265]: tun0: LCP: MAGICNUM[6] 0x52516508
Jan 12 16:41:42 freebsd ppp[265]: tun0: LCP: deflink: State change
Stopped --> Req-Sent
Jan 12 16:41:42 freebsd ppp[265]: tun0: LCP: deflink: RecvConfigReq(249)
state = Req-Sent
Jan 12 16:41:42 freebsd ppp[265]: tun0: LCP: MAGICNUM[6] 0x5b6ecd20
Jan 12 16:41:42 freebsd ppp[265]: tun0: LCP: MRU[4] 1492
Jan 12 16:41:42 freebsd ppp[265]: tun0: LCP: AUTHPROTO[5] 0xc223 (CHAP
0x05)
Jan 12 16:41:42 freebsd ppp[265]: tun0: LCP: deflink: SendConfigAck(249)
state = Req-Sent
Jan 12 16:41:42 freebsd ppp[265]: tun0: LCP: MAGICNUM[6] 0x5b6ecd20
Jan 12 16:41:42 freebsd ppp[265]: tun0: LCP: MRU[4] 1492
Jan 12 16:41:42 freebsd ppp[265]: tun0: LCP: AUTHPROTO[5] 0xc223 (CHAP
0x05)
Jan 12 16:41:42 freebsd ppp[265]: tun0: LCP: deflink: State change
Req-Sent --> Ack-Sent
Jan 12 16:41:42 freebsd ppp[265]: tun0: LCP: deflink: RecvConfigRej(1)
state = Ack-Sent
Jan 12 16:41:42 freebsd ppp[265]: tun0: LCP: ACFCOMP[2]
Jan 12 16:41:42 freebsd ppp[265]: tun0: LCP: PROTOCOMP[2]
Jan 12 16:41:42 freebsd ppp[265]: tun0: LCP: ACCMAP[6] 0x00000000
Jan 12 16:41:42 freebsd ppp[265]: tun0: LCP: deflink: SendConfigReq(2)
state = Ack-Sent
Jan 12 16:41:42 freebsd ppp[265]: tun0: LCP: MRU[4] 1490
Jan 12 16:41:42 freebsd ppp[265]: tun0: LCP: MAGICNUM[6] 0x52516508
Jan 12 16:41:42 freebsd ppp[265]: tun0: LCP: deflink: RecvConfigAck(2)
state = Ack-Sent
Jan 12 16:41:42 freebsd ppp[265]: tun0: LCP: deflink: State change
Ack-Sent --> Opened
Jan 12 16:41:42 freebsd ppp[265]: tun0: LCP: deflink: LayerUp
Jan 12 16:41:42 freebsd ppp[265]: tun0: CCP: FSM: Using "deflink" as a
transport
Jan 12 16:41:42 freebsd ppp[265]: tun0: CCP: deflink: State change
Initial --> Closed
Jan 12 16:41:42 freebsd ppp[265]: tun0: CCP: deflink: LayerStart.
Jan 12 16:41:42 freebsd ppp[265]: tun0: CCP: deflink: SendConfigReq(1)
state = Closed
Jan 12 16:41:42 freebsd ppp[265]: tun0: CCP: DEFLATE[4] win 15
Jan 12 16:41:42 freebsd ppp[265]: tun0: CCP: PRED1[2]
Jan 12 16:41:42 freebsd ppp[265]: tun0: CCP: deflink: State change
Closed --> Req-Sent
Jan 12 16:41:42 freebsd ppp[265]: tun0: IPCP: FSM: Using "deflink" as a
transport
Jan 12 16:41:42 freebsd ppp[265]: tun0: IPCP: deflink: State change
Initial --> Closed
Jan 12 16:41:42 freebsd ppp[265]: tun0: IPCP: deflink: LayerStart.
Jan 12 16:41:42 freebsd ppp[265]: tun0: IPCP: deflink: SendConfigReq(1)
state = Closed
Jan 12 16:41:42 freebsd ppp[265]: tun0: IPCP: IPADDR[6] 10.0.0.1
Jan 12 16:41:42 freebsd ppp[265]: tun0: IPCP: COMPPROTO[6] 16 VJ slots
with slot compression
Jan 12 16:41:42 freebsd ppp[265]: tun0: IPCP: PRIDNS[6] 10.10.10.10
Jan 12 16:41:42 freebsd ppp[265]: tun0: IPCP: SECDNS[6] 20.20.20.20
Jan 12 16:41:42 freebsd ppp[265]: tun0: IPCP: deflink: State change
Closed --> Req-Sent
Jan 12 16:41:42 freebsd ppp[265]: tun0: IPCP: deflink:
RecvConfigReq(220) state = Req-Sent
Jan 12 16:41:42 freebsd ppp[265]: tun0: IPCP: IPADDR[6] 10.64.178.94
Jan 12 16:41:42 freebsd ppp[265]: tun0: IPCP: deflink:
SendConfigAck(220) state = Req-Sent
Jan 12 16:41:42 freebsd ppp[265]: tun0: IPCP: IPADDR[6] 10.64.178.94
Jan 12 16:41:42 freebsd ppp[265]: tun0: IPCP: deflink: State change
Req-Sent --> Ack-Sent
Jan 12 16:41:42 freebsd ppp[265]: tun0: LCP: deflink:
RecvProtocolRej(250) state = Opened
Jan 12 16:41:42 freebsd ppp[265]: tun0: LCP: deflink: -- Protocol 0x80fd
(Compression Control Protocol) was rejected!
Jan 12 16:41:42 freebsd ppp[265]: tun0: CCP: deflink: State change
Req-Sent --> Stopped
Jan 12 16:41:42 freebsd ppp[265]: tun0: IPCP: deflink: RecvConfigRej(1)
state = Ack-Sent
Jan 12 16:41:42 freebsd ppp[265]: tun0: IPCP: COMPPROTO[6] 16 VJ slots
with slot compression
Jan 12 16:41:42 freebsd ppp[265]: tun0: IPCP: deflink: SendConfigReq(2)
state = Ack-Sent
Jan 12 16:41:42 freebsd ppp[265]: tun0: IPCP: IPADDR[6] 10.0.0.1
Jan 12 16:41:42 freebsd ppp[265]: tun0: IPCP: PRIDNS[6] 10.10.10.10
Jan 12 16:41:42 freebsd ppp[265]: tun0: IPCP: SECDNS[6] 20.20.20.20
Jan 12 16:41:42 freebsd ppp[265]: tun0: IPCP: deflink: RecvConfigNak(2)
state = Ack-Sent
Jan 12 16:41:42 freebsd ppp[265]: tun0: IPCP: IPADDR[6] 10.200.0.6
Jan 12 16:41:42 freebsd ppp[265]: tun0: IPCP: IPADDR[6] changing
address: 10.0.0.1 --> 10.200.0.6
Jan 12 16:41:42 freebsd ppp[265]: tun0: IPCP: deflink: SendConfigReq(3)
state = Ack-Sent
Jan 12 16:41:42 freebsd ppp[265]: tun0: IPCP: IPADDR[6] 10.200.0.6
Jan 12 16:41:42 freebsd ppp[265]: tun0: IPCP: PRIDNS[6] 10.10.10.10
Jan 12 16:41:42 freebsd ppp[265]: tun0: IPCP: SECDNS[6] 20.20.20.20
Jan 12 16:41:42 freebsd ppp[265]: tun0: IPCP: deflink: RecvConfigAck(3)
state = Ack-Sent
Jan 12 16:41:42 freebsd ppp[265]: tun0: IPCP: deflink: State change
Ack-Sent --> Opened
Jan 12 16:41:42 freebsd ppp[265]: tun0: IPCP: deflink: LayerUp.
Jan 12 16:41:42 freebsd ppp[265]: tun0: IPCP: myaddr 10.200.0.6 hisaddr
= 10.64.178.94
Jan 12 16:41:53 freebsd ppp[265]: tun0: LCP: deflink: RecvEchoRequest(0)
state = Opened
Jan 12 16:41:53 freebsd ppp[265]: tun0: LCP: deflink: SendEchoReply(0)
state = Opened
Jan 12 16:42:04 freebsd ppp[265]: tun0: LCP: deflink: RecvEchoRequest(1)
state = Opened
Jan 12 16:42:04 freebsd ppp[265]: tun0: LCP: deflink: SendEchoReply(1)
state = Opened
Jan 12 16:42:14 freebsd ppp[265]: tun0: LCP: deflink: RecvEchoRequest(2)
state = Opened
Jan 12 16:42:14 freebsd ppp[265]: tun0: LCP: deflink: SendEchoReply(2)
state = Opened
Jan 12 16:42:25 freebsd ppp[265]: tun0: LCP: deflink: RecvEchoRequest(3)
state = Opened
--- repeating lines deleted
Jan 12 16:48:03 freebsd ppp[265]: tun0: LCP: deflink:
RecvEchoRequest(34) state = Opened
Jan 12 16:48:03 freebsd ppp[265]: tun0: LCP: deflink: SendEchoReply(34)
state = Opened
Jan 12 16:48:13 freebsd ppp[265]: tun0: LCP: deflink:
RecvEchoRequest(35) state = Opened
Jan 12 16:48:14 freebsd ppp[265]: tun0: LCP: deflink: SendEchoReply(35)
state = Opened
Jan 12 16:48:19 freebsd ppp[265]: tun0: IPCP: deflink: LayerDown:
10.200.0.6
Jan 12 16:48:19 freebsd ppp[265]: tun0: IPCP: deflink:
SendTerminateReq(4) state = Opened
Jan 12 16:48:19 freebsd ppp[265]: tun0: IPCP: deflink: State change
Opened --> Closing
Jan 12 16:48:19 freebsd ppp[265]: tun0: Warning: deflink: Oops: Got 8
bytes but 4 byte payload
Jan 12 16:48:19 freebsd ppp[265]: tun0: IPCP: deflink:
RecvTerminateAck(4) state = Closing
Jan 12 16:48:19 freebsd ppp[265]: tun0: IPCP: deflink: LayerFinish.
Jan 12 16:48:19 freebsd ppp[265]: tun0: IPCP: Connect time: 397 secs: 0
octets in, 0 octets out
Jan 12 16:48:19 freebsd ppp[265]: tun0: IPCP: total 0 bytes/sec, peak 0
bytes/sec on Wed Jan 12 16:48:19 2000
Jan 12 16:48:19 freebsd ppp[265]: tun0: IPCP: deflink: State change
Closing --> Closed
Jan 12 16:48:19 freebsd ppp[265]: tun0: CCP: deflink: State change
Stopped --> Closed
Jan 12 16:48:19 freebsd ppp[265]: tun0: CCP: deflink: State change
Closed --> Initial
Jan 12 16:48:19 freebsd ppp[265]: tun0: LCP: deflink: LayerDown
Jan 12 16:48:19 freebsd ppp[265]: tun0: LCP: deflink:
SendTerminateReq(3) state = Opened
Jan 12 16:48:19 freebsd ppp[265]: tun0: LCP: deflink: State change
Opened --> Closing
Jan 12 16:48:19 freebsd ppp[265]: tun0: IPCP: deflink: State change
Closed --> Initial
Jan 12 16:48:19 freebsd ppp[265]: tun0: Warning: deflink: Oops: Got 8
bytes but 4 byte payload
Jan 12 16:48:19 freebsd ppp[265]: tun0: LCP: deflink:
RecvTerminateAck(3) state = Closing
Jan 12 16:48:19 freebsd ppp[265]: tun0: LCP: deflink: LayerFinish
Jan 12 16:48:19 freebsd ppp[265]: tun0: LCP: deflink: State change
Closing --> Closed
Jan 12 16:48:19 freebsd ppp[265]: tun0: LCP: deflink: State change
Closed --> Initial


Regards,
Dany Cayouette




To Unsubscribe: send mail to majordomo@FreeBSD.org
with "unsubscribe freebsd-questions" in the body of the message



Elapsed time: 0.372 seconds