PPTP client not working on 4.10-R

Brett Glass brett at lariat.org
Tue Nov 16 17:42:53 PST 2004 

I've just built and configured a 4.10-R machine for use with a VPN.
It needs to connect to a VPN server using PPTP. I've installed the PPTP
client from the Ports Collection, but it gives odd error messages and
fails to connect. Other clients are connecting properly to the PPTP
server -- and some of them are similarly configured FreeBSD machines.
(None of them is running 4.10-R, though; one is running 5.2 and others
are running 4.9.) The server is running the PoPToP PPTP server, and 
the client is running pptpclient-1.3.1.

The client isn't running IPFW at all (just the GENERIC kernel).

I'm posting the error messages I'm receiving below. (Note the
"Magic is same" messages on the server.) Note that this is PPTP,
not a modem connection, so the problem can't simply be 
characters echoed by a modem. I am wondering if the problem is
FreeBSD 4.10-R and if I need to regress to 4.9-R. Any help 
diagnosing this would be MUCH appreciated!

--Brett Glass

Client ppp.conf:

pptp:
 set authname "username"
 set authkey "password"
 set timeout 0
 set login
 set dial
 set ifaddr 0.0.0.0/0 0.0.0.0/0
 enable lqr
 set lqrperiod 12
 deny chap pap deflate pred1
 disable chap pap passwdauth deflate pred1 ipv6cp
 accept mschapv2 mppe
 enable mppe
 set mppe * stateless
 enable dns
 add! default HISADDR

Server ppp.conf:

pptp:
 set timeout 0
 set dial
 set login
 set ifaddr 172.18.0.1/32
 set server /var/run/pptp_ppp_%d "" 0700
 enable lqr
 set lqrperiod 12
 disable chap
 deny chap
 disable pap
 disable passwdauth
 disable deflate pred1
 deny deflate pred1
 enable utmp
 enable mschapv2 mppe
 set mppe * stateless
 disable proxy
 accept dns
 set dns dns1 dns2


Excerpt from /var/log/messages on the client:

Nov 16 18:12:09 client pptp[200]: anon log[main:pptp.c:219]: The synchronous pptp option is NOT activated
Nov 16 18:12:09 client pptp[203]: anon log[pptp_dispatch_ctrl_packet:pptp_ctrl.c:630]: Client connection established.
Nov 16 18:12:11 client pptp[203]: anon log[pptp_dispatch_ctrl_packet:pptp_ctrl.c:759]: Outgoing call established (call ID 0, peer's call ID 256).
Nov 16 18:12:13 client pptp[204]: anon log[decaps_hdlc:pptp_gre.c:217]: PPP mode seems to be Asynchronous.
Nov 16 18:12:18 client pptp[204]: anon warn[decaps_hdlc:pptp_gre.c:259]: Bad Frame Check Sequence during PPP to GRE decapsulation
Nov 16 18:13:11 client pptp[203]: anon log[pptp_read_some:pptp_ctrl.c:455]: read error: Connection reset by peer
Nov 16 18:13:11 client pptp[203]: anon log[call_callback:pptp_callmgr.c:76]: Closing connection
Nov 16 18:13:11 client pptp[204]: anon warn[decaps_hdlc:pptp_gre.c:209]: short read (0): Invalid argument
Nov 16 18:13:11 client pptp[203]: anon log[pptp_conn_close:pptp_ctrl.c:357]: Closing PPTP connection
Nov 16 18:13:11 client pptp[203]: anon log[pptp_write_some:pptp_ctrl.c:426]: write error: Bad file descriptor

Excerpt from /var/log/ppp.log on the server:

Nov 16 18:14:18 server ppp[224]: Phase: Using interface: tun3
Nov 16 18:14:18 server ppp[224]: Phase: deflink: Created in closed state
Nov 16 18:14:18 server ppp[224]: tun3: Command: default: ident user-ppp VERSION (built COMPILATIONDATE)
Nov 16 18:14:18 server ppp[224]: tun3: Command: pptpoutward: set timeout 0
Nov 16 18:14:18 server ppp[224]: tun3: Command: pptpoutward: set dial
Nov 16 18:14:18 server ppp[224]: tun3: Command: pptpoutward: set login
Nov 16 18:14:18 server ppp[224]: tun3: Command: pptpoutward: set ifaddr 172.18.0.1/32
Nov 16 18:14:18 server ppp[224]: tun3: Command: pptpoutward: set server /var/run/pptp_ppp_%d ******** 0700
Nov 16 18:14:18 server ppp[224]: tun3: Phase: Listening at local socket /var/run/pptp_ppp_3.
Nov 16 18:14:18 server ppp[224]: tun3: Command: pptpoutward: enable lqr
Nov 16 18:14:18 server ppp[224]: tun3: Command: pptpoutward: set lqrperiod 12
Nov 16 18:14:18 server ppp[224]: tun3: Command: pptpoutward: disable chap
Nov 16 18:14:18 server ppp[224]: tun3: Command: pptpoutward: deny chap
Nov 16 18:14:18 server ppp[224]: tun3: Command: pptpoutward: disable pap
Nov 16 18:14:18 server ppp[224]: tun3: Command: pptpoutward: disable passwdauth
Nov 16 18:14:18 server ppp[224]: tun3: Command: pptpoutward: disable deflate pred1
Nov 16 18:14:18 server ppp[224]: tun3: Command: pptpoutward: deny deflate pred1
Nov 16 18:14:18 server ppp[224]: tun3: Command: pptpoutward: enable utmp
Nov 16 18:14:18 server ppp[224]: tun3: Command: pptpoutward: enable mschapv2 mppe
Nov 16 18:14:18 server ppp[224]: tun3: Command: pptpoutward: set mppe * stateless
Nov 16 18:14:18 server ppp[224]: tun3: Command: pptpoutward: disable proxy
Nov 16 18:14:18 server ppp[224]: tun3: Command: pptpoutward: accept dns
Nov 16 18:14:18 server ppp[224]: tun3: Command: pptpoutward: set dns dns1 dns2
Nov 16 18:14:18 server ppp[224]: tun3: Phase: PPP Started (direct mode).
Nov 16 18:14:18 server ppp[224]: tun3: Phase: bundle: Establish
Nov 16 18:14:18 server ppp[224]: tun3: Phase: deflink: closed -> opening
Nov 16 18:14:18 server ppp[224]: tun3: Phase: deflink: Connected!
Nov 16 18:14:18 server ppp[224]: tun3: Phase: deflink: opening -> carrier
Nov 16 18:14:18 server ppp[224]: tun3: Phase: deflink: carrier -> lcp
Nov 16 18:14:18 server ppp[224]: tun3: LCP: FSM: Using "deflink" as a transport
Nov 16 18:14:18 server ppp[224]: tun3: LCP: deflink: State change Initial --> Closed
Nov 16 18:14:18 server ppp[224]: tun3: LCP: deflink: State change Closed --> Stopped
Nov 16 18:14:19 server ppp[224]: tun3: LCP: deflink: LayerStart
Nov 16 18:14:19 server ppp[224]: tun3: LCP: deflink: SendConfigReq(1) state = Stopped
Nov 16 18:14:19 server ppp[224]: tun3: LCP:  ACFCOMP[2]
Nov 16 18:14:19 server ppp[224]: tun3: LCP:  PROTOCOMP[2]
Nov 16 18:14:19 server ppp[224]: tun3: LCP:  ACCMAP[6] 0x00000000
Nov 16 18:14:19 server ppp[224]: tun3: LCP:  MRU[4] 1500
Nov 16 18:14:19 server ppp[224]: tun3: LCP:  MAGICNUM[6] 0x925d4b32
Nov 16 18:14:19 server ppp[224]: tun3: LCP:  QUALPROTO[8] proto c025, interval 12000ms
Nov 16 18:14:19 server ppp[224]: tun3: LCP:  AUTHPROTO[5] 0xc223 (CHAP 0x81)
Nov 16 18:14:19 server ppp[224]: tun3: LCP: deflink: State change Stopped --> Req-Sent
Nov 16 18:14:20 server ppp[224]: tun3: LCP: deflink: RecvConfigReq(1) state = Req-Sent
Nov 16 18:14:20 server ppp[224]: tun3: LCP:  ACFCOMP[2]
Nov 16 18:14:20 server ppp[224]: tun3: LCP:  PROTOCOMP[2]
Nov 16 18:14:20 server ppp[224]: tun3: LCP:  ACCMAP[6] 0x00000000
Nov 16 18:14:20 server ppp[224]: tun3: LCP:  MRU[4] 1500
Nov 16 18:14:20 server ppp[224]: tun3: LCP:  MAGICNUM[6] 0x925d4b32
Nov 16 18:14:20 server ppp[224]: tun3: LCP: Magic is same (925d4b32) - 1 times
Nov 16 18:14:21 server ppp[224]: tun3: LCP:  QUALPROTO[8] proto c025, interval 12000ms
Nov 16 18:14:21 server ppp[224]: tun3: LCP:  AUTHPROTO[5] 0xc223 (CHAP 0x81)
Nov 16 18:14:21 server ppp[224]: tun3: LCP: deflink: SendConfigNak(1) state = Req-Sent
Nov 16 18:14:21 server ppp[224]: tun3: LCP:  MAGICNUM[6] 0x925d4b32
Nov 16 18:14:21 server ppp[224]: tun3: LCP: deflink: RecvConfigNak(1) state = Req-Sent
Nov 16 18:14:21 server ppp[224]: tun3: LCP:  MAGICNUM[6] 0x925d4b32
Nov 16 18:14:21 server ppp[224]: tun3: LCP:  Magic 0x925d4b32 is NAKed!
Nov 16 18:14:21 server ppp[224]: tun3: LCP: deflink: SendConfigReq(2) state = Req-Sent
Nov 16 18:14:21 server ppp[224]: tun3: LCP:  ACFCOMP[2]
Nov 16 18:14:21 server ppp[224]: tun3: LCP:  PROTOCOMP[2]
Nov 16 18:14:21 server ppp[224]: tun3: LCP:  ACCMAP[6] 0x00000000
Nov 16 18:14:21 server ppp[224]: tun3: LCP:  MRU[4] 1500
Nov 16 18:14:21 server ppp[224]: tun3: LCP:  MAGICNUM[6] 0x16cc6628
Nov 16 18:14:21 server ppp[224]: tun3: LCP:  QUALPROTO[8] proto c025, interval 12000ms
Nov 16 18:14:21 server ppp[224]: tun3: LCP:  AUTHPROTO[5] 0xc223 (CHAP 0x81)
Nov 16 18:14:21 server ppp[224]: tun3: LCP: deflink: RecvConfigReq(2) state = Req-Sent
Nov 16 18:14:21 server ppp[224]: tun3: LCP:  ACFCOMP[2]
Nov 16 18:14:21 server ppp[224]: tun3: LCP:  PROTOCOMP[2]
Nov 16 18:14:21 server ppp[224]: tun3: LCP:  ACCMAP[6] 0x00000000
Nov 16 18:14:21 server ppp[224]: tun3: LCP:  MRU[4] 1500
Nov 16 18:14:21 server ppp[224]: tun3: LCP:  MAGICNUM[6] 0x16cc6628
Nov 16 18:14:21 server ppp[224]: tun3: LCP: Magic is same (16cc6628) - 2 times
Nov 16 18:14:22 server ppp[224]: tun3: LCP:  QUALPROTO[8] proto c025, interval 12000ms
Nov 16 18:14:22 server ppp[224]: tun3: LCP:  AUTHPROTO[5] 0xc223 (CHAP 0x81)
Nov 16 18:14:22 server ppp[224]: tun3: LCP: deflink: SendConfigNak(2) state = Req-Sent
Nov 16 18:14:22 server ppp[224]: tun3: LCP:  MAGICNUM[6] 0x16cc6628
Nov 16 18:14:22 server ppp[224]: tun3: LCP: deflink: RecvConfigNak(2) state = Req-Sent
Nov 16 18:14:22 server ppp[224]: tun3: LCP:  MAGICNUM[6] 0x16cc6628
Nov 16 18:14:22 server ppp[224]: tun3: LCP:  Magic 0x16cc6628 is NAKed!
Nov 16 18:14:22 server ppp[224]: tun3: LCP: deflink: SendConfigReq(3) state = Req-Sent
Nov 16 18:14:22 server ppp[224]: tun3: LCP:  ACFCOMP[2]
Nov 16 18:14:22 server ppp[224]: tun3: LCP:  PROTOCOMP[2]
Nov 16 18:14:22 server ppp[224]: tun3: LCP:  ACCMAP[6] 0x00000000
Nov 16 18:14:22 server ppp[224]: tun3: LCP:  MRU[4] 1500
Nov 16 18:14:22 server ppp[224]: tun3: LCP:  MAGICNUM[6] 0x523f4b30
Nov 16 18:14:22 server ppp[224]: tun3: LCP:  QUALPROTO[8] proto c025, interval 12000ms
Nov 16 18:14:22 server ppp[224]: tun3: LCP:  AUTHPROTO[5] 0xc223 (CHAP 0x81)
Nov 16 18:14:22 server ppp[224]: tun3: LCP: deflink: RecvConfigReq(3) state = Req-Sent
Nov 16 18:14:22 server ppp[224]: tun3: LCP:  ACFCOMP[2]
Nov 16 18:14:22 server ppp[224]: tun3: LCP:  PROTOCOMP[2]
Nov 16 18:14:22 server ppp[224]: tun3: LCP:  ACCMAP[6] 0x00000000
Nov 16 18:14:22 server ppp[224]: tun3: LCP:  MRU[4] 1500
Nov 16 18:14:22 server ppp[224]: tun3: LCP:  MAGICNUM[6] 0x523f4b30
Nov 16 18:14:22 server ppp[224]: tun3: LCP: Magic is same (523f4b30) - 3 times
Nov 16 18:14:23 server ppp[224]: tun3: LCP:  QUALPROTO[8] proto c025, interval 12000ms
Nov 16 18:14:23 server ppp[224]: tun3: LCP:  AUTHPROTO[5] 0xc223 (CHAP 0x81)
Nov 16 18:14:23 server ppp[224]: tun3: LCP: deflink: SendConfigNak(3) state = Req-Sent
Nov 16 18:14:23 server ppp[224]: tun3: LCP:  MAGICNUM[6] 0x523f4b30
Nov 16 18:14:23 server ppp[224]: tun3: LCP: deflink: RecvConfigNak(3) state = Req-Sent
Nov 16 18:14:23 server ppp[224]: tun3: LCP:  MAGICNUM[6] 0x523f4b30
Nov 16 18:14:23 server ppp[224]: tun3: LCP:  Magic 0x523f4b30 is NAKed!
Nov 16 18:14:23 server ppp[224]: tun3: LCP: deflink: SendConfigReq(4) state = Req-Sent
Nov 16 18:14:23 server ppp[224]: tun3: LCP:  ACFCOMP[2]
Nov 16 18:14:23 server ppp[224]: tun3: LCP:  PROTOCOMP[2]
Nov 16 18:14:23 server ppp[224]: tun3: LCP:  ACCMAP[6] 0x00000000
Nov 16 18:14:23 server ppp[224]: tun3: LCP:  MRU[4] 1500
Nov 16 18:14:23 server ppp[224]: tun3: LCP:  MAGICNUM[6] 0xb89eaca8
Nov 16 18:14:23 server ppp[224]: tun3: LCP:  QUALPROTO[8] proto c025, interval 12000ms
Nov 16 18:14:23 server ppp[224]: tun3: LCP:  AUTHPROTO[5] 0xc223 (CHAP 0x81)
Nov 16 18:14:23 server ppp[224]: tun3: LCP: deflink: RecvConfigReq(4) state = Req-Sent
Nov 16 18:14:23 server ppp[224]: tun3: LCP:  ACFCOMP[2]
Nov 16 18:14:23 server ppp[224]: tun3: LCP:  PROTOCOMP[2]
Nov 16 18:14:23 server ppp[224]: tun3: LCP:  ACCMAP[6] 0x00000000
Nov 16 18:14:23 server ppp[224]: tun3: LCP:  MRU[4] 1500
Nov 16 18:14:23 server ppp[224]: tun3: LCP:  MAGICNUM[6] 0xb89eaca8
Nov 16 18:14:23 server ppp[224]: tun3: LCP: Magic is same (b89eaca8) - 4 times
Nov 16 18:14:25 server ppp[224]: tun3: LCP:  QUALPROTO[8] proto c025, interval 12000ms
Nov 16 18:14:25 server ppp[224]: tun3: LCP:  AUTHPROTO[5] 0xc223 (CHAP 0x81)
Nov 16 18:14:25 server ppp[224]: tun3: LCP: deflink: SendConfigNak(4) state = Req-Sent
Nov 16 18:14:25 server ppp[224]: tun3: LCP:  MAGICNUM[6] 0xb89eaca8
Nov 16 18:14:25 server ppp[224]: tun3: LCP: deflink: RecvConfigNak(4) state = Req-Sent
Nov 16 18:14:25 server ppp[224]: tun3: LCP:  MAGICNUM[6] 0xb89eaca8
Nov 16 18:14:25 server ppp[224]: tun3: LCP:  Magic 0xb89eaca8 is NAKed!
Nov 16 18:14:25 server ppp[224]: tun3: LCP: deflink: SendConfigReq(5) state = Req-Sent
Nov 16 18:14:25 server ppp[224]: tun3: LCP:  ACFCOMP[2]
Nov 16 18:14:25 server ppp[224]: tun3: LCP:  PROTOCOMP[2]
Nov 16 18:14:25 server ppp[224]: tun3: LCP:  ACCMAP[6] 0x00000000
Nov 16 18:14:25 server ppp[224]: tun3: LCP:  MRU[4] 1500
Nov 16 18:14:25 server ppp[224]: tun3: LCP:  MAGICNUM[6] 0x4ec268e7
Nov 16 18:14:25 server ppp[224]: tun3: LCP:  QUALPROTO[8] proto c025, interval 12000ms
Nov 16 18:14:25 server ppp[224]: tun3: LCP:  AUTHPROTO[5] 0xc223 (CHAP 0x81)
Nov 16 18:14:25 server ppp[224]: tun3: LCP: deflink: RecvConfigReq(5) state = Req-Sent
Nov 16 18:14:26 server ppp[224]: tun3: LCP:  ACFCOMP[2]
Nov 16 18:14:26 server ppp[224]: tun3: LCP:  PROTOCOMP[2]
Nov 16 18:14:26 server ppp[224]: tun3: LCP:  ACCMAP[6] 0x00000000
Nov 16 18:14:26 server ppp[224]: tun3: LCP:  MRU[4] 1500
Nov 16 18:14:26 server ppp[224]: tun3: LCP:  MAGICNUM[6] 0x4ec268e7
Nov 16 18:14:26 server ppp[224]: tun3: LCP: Magic is same (4ec268e7) - 5 times
Nov 16 18:14:28 server ppp[224]: tun3: LCP:  QUALPROTO[8] proto c025, interval 12000ms
Nov 16 18:14:28 server ppp[224]: tun3: LCP:  AUTHPROTO[5] 0xc223 (CHAP 0x81)
Nov 16 18:14:28 server ppp[224]: tun3: LCP: deflink: SendConfigNak(5) state = Req-Sent
Nov 16 18:14:28 server ppp[224]: tun3: LCP:  MAGICNUM[6] 0x4ec268e7
Nov 16 18:14:28 server ppp[224]: tun3: LCP: deflink: RecvConfigNak(5) state = Req-Sent
Nov 16 18:14:28 server ppp[224]: tun3: LCP:  MAGICNUM[6] 0x4ec268e7
Nov 16 18:14:28 server ppp[224]: tun3: LCP:  Magic 0x4ec268e7 is NAKed!
Nov 16 18:14:28 server ppp[224]: tun3: LCP: deflink: SendConfigReq(6) state = Req-Sent
Nov 16 18:14:28 server ppp[224]: tun3: LCP:  ACFCOMP[2]
Nov 16 18:14:28 server ppp[224]: tun3: LCP:  PROTOCOMP[2]
Nov 16 18:14:28 server ppp[224]: tun3: LCP:  ACCMAP[6] 0x00000000
Nov 16 18:14:28 server ppp[224]: tun3: LCP:  MRU[4] 1500
Nov 16 18:14:28 server ppp[224]: tun3: LCP:  MAGICNUM[6] 0x79678116
Nov 16 18:14:28 server ppp[224]: tun3: LCP:  QUALPROTO[8] proto c025, interval 12000ms
Nov 16 18:14:28 server ppp[224]: tun3: LCP:  AUTHPROTO[5] 0xc223 (CHAP 0x81)
Nov 16 18:14:28 server ppp[224]: tun3: LCP: deflink: RecvConfigReq(6) state = Req-Sent
Nov 16 18:14:28 server ppp[224]: tun3: LCP:  ACFCOMP[2]
Nov 16 18:14:28 server ppp[224]: tun3: LCP:  PROTOCOMP[2]
Nov 16 18:14:28 server ppp[224]: tun3: LCP:  ACCMAP[6] 0x00000000
Nov 16 18:14:28 server ppp[224]: tun3: LCP:  MRU[4] 1500
Nov 16 18:14:28 server ppp[224]: tun3: LCP:  MAGICNUM[6] 0x79678116
Nov 16 18:14:28 server ppp[224]: tun3: LCP: Magic is same (79678116) - 6 times
Nov 16 18:14:31 server ppp[224]: tun3: LCP:  QUALPROTO[8] proto c025, interval 12000ms
Nov 16 18:14:31 server ppp[224]: tun3: LCP:  AUTHPROTO[5] 0xc223 (CHAP 0x81)
Nov 16 18:14:31 server ppp[224]: tun3: LCP: deflink: SendConfigNak(6) state = Req-Sent
Nov 16 18:14:31 server ppp[224]: tun3: LCP:  MAGICNUM[6] 0x79678116
Nov 16 18:14:31 server ppp[224]: tun3: LCP: deflink: RecvConfigNak(6) state = Req-Sent
Nov 16 18:14:31 server ppp[224]: tun3: LCP:  MAGICNUM[6] 0x79678116
Nov 16 18:14:31 server ppp[224]: tun3: LCP:  Magic 0x79678116 is NAKed!
Nov 16 18:14:31 server ppp[224]: tun3: LCP: deflink: SendConfigReq(7) state = Req-Sent
Nov 16 18:14:31 server ppp[224]: tun3: LCP:  ACFCOMP[2]
Nov 16 18:14:31 server ppp[224]: tun3: LCP:  PROTOCOMP[2]
Nov 16 18:14:31 server ppp[224]: tun3: LCP:  ACCMAP[6] 0x00000000
Nov 16 18:14:31 server ppp[224]: tun3: LCP:  MRU[4] 1500
Nov 16 18:14:31 server ppp[224]: tun3: LCP:  MAGICNUM[6] 0xc83b3921
Nov 16 18:14:31 server ppp[224]: tun3: LCP:  QUALPROTO[8] proto c025, interval 12000ms
Nov 16 18:14:31 server ppp[224]: tun3: LCP:  AUTHPROTO[5] 0xc223 (CHAP 0x81)
Nov 16 18:14:31 server ppp[224]: tun3: LCP: deflink: RecvConfigReq(7) state = Req-Sent
Nov 16 18:14:31 server ppp[224]: tun3: LCP:  ACFCOMP[2]
Nov 16 18:14:31 server ppp[224]: tun3: LCP:  PROTOCOMP[2]
Nov 16 18:14:31 server ppp[224]: tun3: LCP:  ACCMAP[6] 0x00000000
Nov 16 18:14:31 server ppp[224]: tun3: LCP:  MRU[4] 1500
Nov 16 18:14:31 server ppp[224]: tun3: LCP:  MAGICNUM[6] 0xc83b3921
Nov 16 18:14:31 server ppp[224]: tun3: LCP: Magic is same (c83b3921) - 7 times
Nov 16 18:14:34 server ppp[224]: tun3: LCP:  QUALPROTO[8] proto c025, interval 12000ms
Nov 16 18:14:34 server ppp[224]: tun3: LCP:  AUTHPROTO[5] 0xc223 (CHAP 0x81)
Nov 16 18:14:34 server ppp[224]: tun3: LCP: deflink: SendConfigNak(7) state = Req-Sent
Nov 16 18:14:34 server ppp[224]: tun3: LCP:  MAGICNUM[6] 0xc83b3921
Nov 16 18:14:34 server ppp[224]: tun3: LCP: deflink: RecvConfigNak(7) state = Req-Sent
Nov 16 18:14:34 server ppp[224]: tun3: LCP:  MAGICNUM[6] 0xc83b3921
Nov 16 18:14:34 server ppp[224]: tun3: LCP:  Magic 0xc83b3921 is NAKed!
Nov 16 18:14:34 server ppp[224]: tun3: LCP: deflink: SendConfigReq(8) state = Req-Sent
Nov 16 18:14:34 server ppp[224]: tun3: LCP:  ACFCOMP[2]
Nov 16 18:14:34 server ppp[224]: tun3: LCP:  PROTOCOMP[2]
Nov 16 18:14:34 server ppp[224]: tun3: LCP:  ACCMAP[6] 0x00000000
Nov 16 18:14:34 server ppp[224]: tun3: LCP:  MRU[4] 1500
Nov 16 18:14:34 server ppp[224]: tun3: LCP:  MAGICNUM[6] 0xd4e792b8
Nov 16 18:14:34 server ppp[224]: tun3: LCP:  QUALPROTO[8] proto c025, interval 12000ms
Nov 16 18:14:34 server ppp[224]: tun3: LCP:  AUTHPROTO[5] 0xc223 (CHAP 0x81)
Nov 16 18:14:34 server ppp[224]: tun3: LCP: deflink: RecvConfigReq(8) state = Req-Sent
Nov 16 18:14:34 server ppp[224]: tun3: LCP:  ACFCOMP[2]
Nov 16 18:14:34 server ppp[224]: tun3: LCP:  PROTOCOMP[2]
Nov 16 18:14:34 server ppp[224]: tun3: LCP:  ACCMAP[6] 0x00000000
Nov 16 18:14:34 server ppp[224]: tun3: LCP:  MRU[4] 1500
Nov 16 18:14:34 server ppp[224]: tun3: LCP:  MAGICNUM[6] 0xd4e792b8
Nov 16 18:14:34 server ppp[224]: tun3: LCP: Magic is same (d4e792b8) - 8 times
Nov 16 18:14:38 server ppp[224]: tun3: LCP:  QUALPROTO[8] proto c025, interval 12000ms
Nov 16 18:14:38 server ppp[224]: tun3: LCP:  AUTHPROTO[5] 0xc223 (CHAP 0x81)
Nov 16 18:14:38 server ppp[224]: tun3: LCP: deflink: SendConfigNak(8) state = Req-Sent
Nov 16 18:14:38 server ppp[224]: tun3: LCP:  MAGICNUM[6] 0xd4e792b8
Nov 16 18:14:38 server ppp[224]: tun3: LCP: deflink: RecvConfigNak(8) state = Req-Sent
Nov 16 18:14:38 server ppp[224]: tun3: LCP:  MAGICNUM[6] 0xd4e792b8
Nov 16 18:14:38 server ppp[224]: tun3: LCP:  Magic 0xd4e792b8 is NAKed!
Nov 16 18:14:38 server ppp[224]: tun3: LCP: deflink: SendConfigReq(9) state = Req-Sent
Nov 16 18:14:38 server ppp[224]: tun3: LCP:  ACFCOMP[2]
Nov 16 18:14:38 server ppp[224]: tun3: LCP:  PROTOCOMP[2]
Nov 16 18:14:38 server ppp[224]: tun3: LCP:  ACCMAP[6] 0x00000000
Nov 16 18:14:38 server ppp[224]: tun3: LCP:  MRU[4] 1500
Nov 16 18:14:38 server ppp[224]: tun3: LCP:  MAGICNUM[6] 0xebb0bf24
Nov 16 18:14:38 server ppp[224]: tun3: LCP:  QUALPROTO[8] proto c025, interval 12000ms
Nov 16 18:14:38 server ppp[224]: tun3: LCP:  AUTHPROTO[5] 0xc223 (CHAP 0x81)
Nov 16 18:14:38 server ppp[224]: tun3: LCP: deflink: RecvConfigReq(9) state = Req-Sent
Nov 16 18:14:38 server ppp[224]: tun3: LCP:  ACFCOMP[2]
Nov 16 18:14:38 server ppp[224]: tun3: LCP:  PROTOCOMP[2]
Nov 16 18:14:38 server ppp[224]: tun3: LCP:  ACCMAP[6] 0x00000000
Nov 16 18:14:38 server ppp[224]: tun3: LCP:  MRU[4] 1500
Nov 16 18:14:38 server ppp[224]: tun3: LCP:  MAGICNUM[6] 0xebb0bf24
Nov 16 18:14:38 server ppp[224]: tun3: LCP: Magic is same (ebb0bf24) - 9 times
Nov 16 18:14:42 server ppp[224]: tun3: LCP:  QUALPROTO[8] proto c025, interval 12000ms
Nov 16 18:14:42 server ppp[224]: tun3: LCP:  AUTHPROTO[5] 0xc223 (CHAP 0x81)
Nov 16 18:14:42 server ppp[224]: tun3: LCP: deflink: SendConfigNak(9) state = Req-Sent
Nov 16 18:14:42 server ppp[224]: tun3: LCP:  MAGICNUM[6] 0xebb0bf24
Nov 16 18:14:42 server ppp[224]: tun3: LCP: deflink: RecvConfigNak(9) state = Req-Sent
Nov 16 18:14:42 server ppp[224]: tun3: LCP:  MAGICNUM[6] 0xebb0bf24
Nov 16 18:14:42 server ppp[224]: tun3: LCP:  Magic 0xebb0bf24 is NAKed!
Nov 16 18:14:42 server ppp[224]: tun3: LCP: deflink: SendConfigReq(10) state = Req-Sent
Nov 16 18:14:42 server ppp[224]: tun3: LCP:  ACFCOMP[2]
Nov 16 18:14:42 server ppp[224]: tun3: LCP:  PROTOCOMP[2]
Nov 16 18:14:42 server ppp[224]: tun3: LCP:  ACCMAP[6] 0x00000000
Nov 16 18:14:42 server ppp[224]: tun3: LCP:  MRU[4] 1500
Nov 16 18:14:42 server ppp[224]: tun3: LCP:  MAGICNUM[6] 0xe20a8881
Nov 16 18:14:42 server ppp[224]: tun3: LCP:  QUALPROTO[8] proto c025, interval 12000ms
Nov 16 18:14:42 server ppp[224]: tun3: LCP:  AUTHPROTO[5] 0xc223 (CHAP 0x81)
Nov 16 18:14:42 server ppp[224]: tun3: LCP: deflink: RecvConfigReq(10) state = Req-Sent
Nov 16 18:14:42 server ppp[224]: tun3: LCP:  ACFCOMP[2]
Nov 16 18:14:42 server ppp[224]: tun3: LCP:  PROTOCOMP[2]
Nov 16 18:14:42 server ppp[224]: tun3: LCP:  ACCMAP[6] 0x00000000
Nov 16 18:14:42 server ppp[224]: tun3: LCP:  MRU[4] 1500
Nov 16 18:14:42 server ppp[224]: tun3: LCP:  MAGICNUM[6] 0xe20a8881
Nov 16 18:14:42 server ppp[224]: tun3: LCP: Magic is same (e20a8881) - 10 times
Nov 16 18:14:46 server ppp[224]: tun3: LCP:  QUALPROTO[8] proto c025, interval 12000ms
Nov 16 18:14:46 server ppp[224]: tun3: LCP:  AUTHPROTO[5] 0xc223 (CHAP 0x81)
Nov 16 18:14:46 server ppp[224]: tun3: LCP: deflink: SendConfigNak(10) state = Req-Sent
Nov 16 18:14:46 server ppp[224]: tun3: LCP:  MAGICNUM[6] 0xe20a8881
Nov 16 18:14:46 server ppp[224]: tun3: LCP: deflink: RecvConfigNak(10) state = Req-Sent
Nov 16 18:14:46 server ppp[224]: tun3: LCP:  MAGICNUM[6] 0xe20a8881
Nov 16 18:14:46 server ppp[224]: tun3: LCP:  Magic 0xe20a8881 is NAKed!
Nov 16 18:14:46 server ppp[224]: tun3: LCP: deflink: SendConfigReq(11) state = Req-Sent
Nov 16 18:14:46 server ppp[224]: tun3: LCP:  ACFCOMP[2]
Nov 16 18:14:46 server ppp[224]: tun3: LCP:  PROTOCOMP[2]
Nov 16 18:14:46 server ppp[224]: tun3: LCP:  ACCMAP[6] 0x00000000
Nov 16 18:14:46 server ppp[224]: tun3: LCP:  MRU[4] 1500
Nov 16 18:14:46 server ppp[224]: tun3: LCP:  MAGICNUM[6] 0x56a892ae
Nov 16 18:14:46 server ppp[224]: tun3: LCP:  QUALPROTO[8] proto c025, interval 12000ms
Nov 16 18:14:46 server ppp[224]: tun3: LCP:  AUTHPROTO[5] 0xc223 (CHAP 0x81)
Nov 16 18:14:49 server ppp[224]: tun3: LCP: deflink: SendConfigReq(11) state = Req-Sent
Nov 16 18:14:49 server ppp[224]: tun3: LCP:  ACFCOMP[2]
Nov 16 18:14:49 server ppp[224]: tun3: LCP:  PROTOCOMP[2]
Nov 16 18:14:49 server ppp[224]: tun3: LCP:  ACCMAP[6] 0x00000000
Nov 16 18:14:49 server ppp[224]: tun3: LCP:  MRU[4] 1500
Nov 16 18:14:49 server ppp[224]: tun3: LCP:  MAGICNUM[6] 0x56a892ae
Nov 16 18:14:49 server ppp[224]: tun3: LCP:  QUALPROTO[8] proto c025, interval 12000ms
Nov 16 18:14:49 server ppp[224]: tun3: LCP:  AUTHPROTO[5] 0xc223 (CHAP 0x81)
Nov 16 18:14:52 server ppp[224]: tun3: LCP: deflink: SendConfigReq(11) state = Req-Sent
Nov 16 18:14:52 server ppp[224]: tun3: LCP:  ACFCOMP[2]
Nov 16 18:14:52 server ppp[224]: tun3: LCP:  PROTOCOMP[2]
Nov 16 18:14:52 server ppp[224]: tun3: LCP:  ACCMAP[6] 0x00000000
Nov 16 18:14:52 server ppp[224]: tun3: LCP:  MRU[4] 1500
Nov 16 18:14:52 server ppp[224]: tun3: LCP:  MAGICNUM[6] 0x56a892ae
Nov 16 18:14:52 server ppp[224]: tun3: LCP:  QUALPROTO[8] proto c025, interval 12000ms
Nov 16 18:14:52 server ppp[224]: tun3: LCP:  AUTHPROTO[5] 0xc223 (CHAP 0x81)
Nov 16 18:14:55 server ppp[224]: tun3: LCP: deflink: SendConfigReq(11) state = Req-Sent
Nov 16 18:14:55 server ppp[224]: tun3: LCP:  ACFCOMP[2]
Nov 16 18:14:55 server ppp[224]: tun3: LCP:  PROTOCOMP[2]
Nov 16 18:14:55 server ppp[224]: tun3: LCP:  ACCMAP[6] 0x00000000
Nov 16 18:14:55 server ppp[224]: tun3: LCP:  MRU[4] 1500
Nov 16 18:14:55 server ppp[224]: tun3: LCP:  MAGICNUM[6] 0x56a892ae
Nov 16 18:14:55 server ppp[224]: tun3: LCP:  QUALPROTO[8] proto c025, interval 12000ms
Nov 16 18:14:55 server ppp[224]: tun3: LCP:  AUTHPROTO[5] 0xc223 (CHAP 0x81)
Nov 16 18:14:58 server ppp[224]: tun3: LCP: deflink: SendConfigReq(11) state = Req-Sent
Nov 16 18:14:58 server ppp[224]: tun3: LCP:  ACFCOMP[2]
Nov 16 18:14:58 server ppp[224]: tun3: LCP:  PROTOCOMP[2]
Nov 16 18:14:58 server ppp[224]: tun3: LCP:  ACCMAP[6] 0x00000000
Nov 16 18:14:58 server ppp[224]: tun3: LCP:  MRU[4] 1500
Nov 16 18:14:58 server ppp[224]: tun3: LCP:  MAGICNUM[6] 0x56a892ae
Nov 16 18:14:58 server ppp[224]: tun3: LCP:  QUALPROTO[8] proto c025, interval 12000ms
Nov 16 18:14:58 server ppp[224]: tun3: LCP:  AUTHPROTO[5] 0xc223 (CHAP 0x81)
Nov 16 18:15:01 server ppp[224]: tun3: LCP: deflink: LayerFinish
Nov 16 18:15:01 server ppp[224]: tun3: LCP: deflink: State change Req-Sent --> Stopped
Nov 16 18:15:01 server ppp[224]: tun3: LCP: deflink: State change Stopped --> Closed
Nov 16 18:15:01 server ppp[224]: tun3: LCP: deflink: State change Closed --> Initial
Nov 16 18:15:01 server ppp[224]: tun3: Phase: deflink: Disconnected!
Nov 16 18:15:01 server ppp[224]: tun3: Phase: deflink: Connect time: 43 secs: 975 octets in, 1331 octets out
Nov 16 18:15:01 server ppp[224]: tun3: Phase: deflink: : 20 packets in, 25 packets out
Nov 16 18:15:01 server ppp[224]: tun3: Phase:  total 53 bytes/sec, peak 194 bytes/sec on Tue Nov 16 18:14:31 2004
Nov 16 18:15:01 server ppp[224]: tun3: Phase: deflink: lcp -> closed
Nov 16 18:15:01 server ppp[224]: tun3: Phase: bundle: Dead
Nov 16 18:15:01 server ppp[224]: tun3: Phase: Caught signal 2, abort connection(s)
Nov 16 18:15:01 server ppp[224]: tun3: Phase: PPP Terminated (normal).

More information about the freebsd-questions mailing list