I don't see anything really wrong with your configuration.  When I used
userland PPP, I had the mtu and mru set to 1492 but you took a known working
configuration from a previous setup.  Is there a good reason why you couldn't
use kernel PPP?  It is really easy:

cat /etc/hostname.pppoe0:
inet 0.0.0.0
255.255.255.255 NONE pppoedev <interface> authproto pap authname
<isp_username> authkey <isp_password>
dest 0.0.0.1
!/sbin/route add default
-ifp pppoe0 0.0.0.1

cat /etc/hostname.<interface>:
up

add a rule to your
pf.conf:
match on pppoe0 scrub (max-mss 1440)

I have found performance to be
much better using OpenBSD's implementation of kernel PPPoE
________________________________


I originally sent this message to misc@ on
April 17/2011, but I never got a response and I can't find it in the
archives.  (I found this copy in my sent mail).

I guess it never went
through.  Since I never heard anything back, I figured I'd wait a while and
see if the problem got corrected after the kernel hackathon finished.  (It
didn't.)

I gave the most recent snapshot (June 29) a try, and the problem
remains, so I'll try sending this "again".  I haven't seen anything about this
on the list since; surely I can't be the only person who has run into this.
My original message:


After some experimenting, I've discovered that userland
ppp stopped working normally at some point between the March 24th and April
8th snapshots.

I've been using the same ppp.{conf,linkup,linkdown} files for
6 months now with 4.8-stable without any problems.  This weekend I decided to
change firewall hardware and use -current, and the same configuration fails.
It's not the hardware: 4.8-stable and snapshots up to Mar. 24th work just
fine.  The next snap I have in my collection is Apr. 8th, and everything since
then including Apr. 17th, fails.

Replication is simple:

- clean install, not
an upgrade.  No customizing/tweaking anything.
- copy my known-good ppp.*
files over
- "up" the interface my DSL modem is on
- adjust syslog.conf to
allow ppp logging to /var/log/ppp.log
# ppp -ddial mlppp (config file below;
normally this done from rc.local)

- with anything <= Mar 24th, the connection
works straight away
- with anything >= Apr. 8th, the ppp process loops
continuously trying to establish the connection

Looking at the log, the old
version shows "LCP: 2: RecvConfigReq", after which my MRU drops from 1500 to
1492, and the connection ultimately succeeds.  The new version only shows
"LCP: 2: SendConfigReq" and the redial process loops until manually stopped.
Does anyone have any idea if my config needs adjusting, or have I found a
bug?  The only variable is the version of -current I use, and the ppp(8) man
page is the same.  Nothing to indicate that my config needs adjusting.

I'm
not sure if the following log snippets show the proper information, so I'll
wait for requests for full logs instead of spamming the list with a hugely
long post.

Thanks,

- Scott


Log snippet from successful connection:
Apr 17
21:09:22 fw0 ppp[30518]: tun0: Chat: 2: Reconnect try 2 of 3
Apr 17 21:09:25
fw0 ppp[30518]: tun0: Chat: 2: Redial timer expired.
Apr 17 21:09:25 fw0
ppp[30518]: tun0: Warning: Carrier settings ignored
Apr 17 21:09:25 fw0
ppp[30518]: tun0: Phase: 2: Connected!
Apr 17 21:09:25 fw0 ppp[30518]: tun0:
Phase: 2: opening -> dial
Apr 17 21:09:25 fw0 ppp[30518]: tun0: Phase: 2: dial
-> carrier
Apr 17 21:09:25 fw0 ppp[30518]: tun0: Phase: 2: carrier -> login
Apr 17 21:09:25 fw0 ppp[30518]: tun0: Phase: 2: login -> lcp
Apr 17 21:09:25
fw0 ppp[30518]: tun0: LCP: FSM: Using "2" as a transport
Apr 17 21:09:25 fw0
ppp[30518]: tun0: LCP: 2: State change Initial --> Closed
Apr 17 21:09:25 fw0
ppp[30518]: tun0: LCP: 2: State change Closed --> Stopped
Apr 17 21:09:26 fw0
ppp[30518]: tun0: LCP: 2: LayerStart
Apr 17 21:09:26 fw0 ppp[30518]: tun0:
LCP: 2: SendConfigReq(6) state = Stopped
Apr 17 21:09:26 fw0 ppp[30518]: tun0:
LCP:  MRU[4] 1500
Apr 17 21:09:26 fw0 ppp[30518]: tun0: LCP:  MAGICNUM[6]
0x48a3693d
Apr 17 21:09:26 fw0 ppp[30518]: tun0: LCP:  MRRU[4] 1485
Apr 17
21:09:26 fw0 ppp[30518]: tun0: LCP:  SHORTSEQ[2]
Apr 17 21:09:26 fw0
ppp[30518]: tun0: LCP: 2: State change Stopped --> Req-Sent
Apr 17 21:09:26
fw0 ppp[30518]: tun0: LCP: 2: RecvConfigReq(138) state = Req-Sent
Apr 17
21:09:26 fw0 ppp[30518]: tun0: LCP:  MRU[4] 1492
Apr 17 21:09:26 fw0
ppp[30518]: tun0: LCP:  AUTHPROTO[4] 0xc023 (PAP)
Apr 17 21:09:26 fw0
ppp[30518]: tun0: LCP:  MAGICNUM[6] 0x4a64ebd8
Apr 17 21:09:26 fw0 ppp[30518]:
tun0: LCP: 2: SendConfigAck(138) state = Req-Sent
Apr 17 21:09:26 fw0
ppp[30518]: tun0: LCP:  MRU[4] 1492
Apr 17 21:09:26 fw0 ppp[30518]: tun0:
LCP:  AUTHPROTO[4] 0xc023 (PAP)
Apr 17 21:09:26 fw0 ppp[30518]: tun0: LCP: 
MAGICNUM[6] 0x4a64ebd8
Apr 17 21:09:26 fw0 ppp[30518]: tun0: LCP: 2: State
change Req-Sent --> Ack-Sent
Apr 17 21:09:26 fw0 ppp[30518]: tun0: LCP: 2:
RecvConfigRej(6) state = Ack-Sent
Apr 17 21:09:26 fw0 ppp[30518]: tun0: LCP: 
MRRU[4] 1485
Apr 17 21:09:26 fw0 ppp[30518]: tun0: LCP:  SHORTSEQ[2]
Apr 17
21:09:26 fw0 ppp[30518]: tun0: LCP: 2: SendConfigReq(7) state = Ack-Sent

Log
snippet from unsuccessful connection:
Apr 17 21:07:29 hellgate ppp[30239]:
tun0: Chat: 2: Reconnect try 2 of 3
Apr 17 21:07:32 hellgate ppp[30239]: tun0:
Chat: 1: Redial timer expired.
Apr 17 21:07:32 hellgate ppp[30239]: tun0:
Chat: 2: Redial timer expired.
Apr 17 21:07:32 hellgate ppp[30239]: tun0:
Warning: Carrier settings ignored
Apr 17 21:07:32 hellgate ppp[30239]: tun0:
Phase: 1: Connected!
Apr 17 21:07:32 hellgate ppp[30239]: tun0: Phase: 1:
opening -> dial
Apr 17 21:07:32 hellgate ppp[30239]: tun0: Phase: 1: dial ->
carrier
Apr 17 21:07:32 hellgate ppp[30239]: tun0: Phase: 1: carrier -> login
Apr 17 21:07:32 hellgate ppp[30239]: tun0: Phase: 1: login -> lcp
Apr 17
21:07:32 hellgate ppp[30239]: tun0: LCP: FSM: Using "1" as a transport
Apr 17
21:07:32 hellgate ppp[30239]: tun0: LCP: 1: State change Initial --> Closed
Apr 17 21:07:32 hellgate ppp[30239]: tun0: LCP: 1: State change Closed -->
Stopped
Apr 17 21:07:32 hellgate ppp[30239]: tun0: Warning: Carrier settings
ignored
Apr 17 21:07:32 hellgate ppp[30239]: tun0: Phase: 2: Connected!
Apr 17
21:07:32 hellgate ppp[30239]: tun0: Phase: 2: opening -> dial
Apr 17 21:07:32
hellgate ppp[30239]: tun0: Phase: 2: dial -> carrier
Apr 17 21:07:32 hellgate
ppp[30239]: tun0: Phase: 2: carrier -> login
Apr 17 21:07:32 hellgate
ppp[30239]: tun0: Phase: 2: login -> lcp
Apr 17 21:07:32 hellgate ppp[30239]:
tun0: LCP: FSM: Using "2" as a transport
Apr 17 21:07:32 hellgate ppp[30239]:
tun0: LCP: 2: State change Initial --> Closed
Apr 17 21:07:32 hellgate
ppp[30239]: tun0: LCP: 2: State change Closed --> Stopped
Apr 17 21:07:33
hellgate ppp[30239]: tun0: LCP: 1: LayerStart
Apr 17 21:07:33 hellgate
ppp[30239]: tun0: LCP: 1: SendConfigReq(1) state = Stopped
Apr 17 21:07:33
hellgate ppp[30239]: tun0: LCP:  MRU[4] 1500
Apr 17 21:07:33 hellgate
ppp[30239]: tun0: LCP:  MAGICNUM[6] 0x19df081a
Apr 17 21:07:33 hellgate
ppp[30239]: tun0: LCP:  MRRU[4] 1485
Apr 17 21:07:33 hellgate ppp[30239]:
tun0: LCP:  SHORTSEQ[2]
Apr 17 21:07:33 hellgate ppp[30239]: tun0: LCP: 1:
State change Stopped --> Req-Sent
Apr 17 21:07:33 hellgate ppp[30239]: tun0:
LCP: 2: LayerStart
Apr 17 21:07:33 hellgate ppp[30239]: tun0: LCP: 2:
SendConfigReq(1) state = Stopped
Apr 17 21:07:33 hellgate ppp[30239]: tun0:
LCP:  MRU[4] 1500
Apr 17 21:07:33 hellgate ppp[30239]: tun0: LCP:  MAGICNUM[6]
0x58de90cd
Apr 17 21:07:33 hellgate ppp[30239]: tun0: LCP:  MRRU[4] 1485
Apr
17 21:07:33 hellgate ppp[30239]: tun0: LCP:  SHORTSEQ[2]
Apr 17 21:07:33
hellgate ppp[30239]: tun0: LCP: 2: State change Stopped --> Req-Sent
Apr 17
21:07:36 hellgate ppp[30239]: tun0: LCP: 1: SendConfigReq(1) state = Req-Sent
Apr 17 21:07:36 hellgate ppp[30239]: tun0: LCP:  MRU[4] 1500
Apr 17 21:07:36
hellgate ppp[30239]: tun0: LCP:  MAGICNUM[6] 0x19df081a
Apr 17 21:07:36
hellgate ppp[30239]: tun0: LCP:  MRRU[4] 1485
Apr 17 21:07:36 hellgate
ppp[30239]: tun0: LCP:  SHORTSEQ[2]
Apr 17 21:07:36 hellgate ppp[30239]: tun0:
LCP: 2: SendConfigReq(1) state = Req-Sent
Apr 17 21:07:36 hellgate ppp[30239]:
tun0: LCP:  MRU[4] 1500
Apr 17 21:07:36 hellgate ppp[30239]: tun0: LCP: 
MAGICNUM[6] 0x58de90cd
Apr 17 21:07:36 hellgate ppp[30239]: tun0: LCP: 
MRRU[4] 1485
Apr 17 21:07:36 hellgate ppp[30239]: tun0: LCP:  SHORTSEQ[2]
Apr
17 21:07:37 hellgate ppp[30239]: tun0: Phase: 1: read (0): Connection reset by
peer
Apr 17 21:07:37 hellgate ppp[30239]: tun0: LCP: 1: State change Req-Sent
--> Starting
Apr 17 21:07:37 hellgate ppp[30239]: tun0: LCP: 1: LayerFinish
Apr 17 21:07:37 hellgate ppp[30239]: tun0: LCP: 1: State change Starting -->
Initial
Apr 17 21:07:37 hellgate ppp[30239]: tun0: Phase: 1: Disconnected!
Apr
17 21:07:37 hellgate ppp[30239]: tun0: Phase: 1: lcp -> logout

The ppp.conf
file:
default:
set log Phase Chat LCP IPCP CCP tun command
set reconnect 3 3
enable mssfixup
disable ipv6cp

mlppp:
set log Phase Chat LCP IPCP CCP tun
command
set mtu 1486
set mrru 1485
set speed sync
set cd 5
set dial
set hangup
set login
set timeout 0
set authname xxxxx
set authkey xxxxx
set server
/var/run/ppp=tun%d 0177
set mode ddial
clone 1,2
link deflink remove
link 1,2
set mode ddial
link 1 set device "!/usr/sbin/pppoe -i xl0"
link 2 set device
"!/usr/sbin/pppoe -i xl0"
add! default HISADDR

Reply via email to