PPTP not working in 2.0

eri--

Give the error of failure during authentication?

AhnHEL

Authentication works, it signs on fine. Just cant connect to anything after that, times out. Same firewall rules in place as in 1.2.3. Thank you for your help by the way. :)

Dec 28 19:47:24 mpd: [pt0] rec'd unexpected protocol IPV6CP, rejecting
Dec 28 19:47:23 kernel: lla_rt_output: RTM_ADD publish (proxy only) is invalid

Full log:
Dec 28 19:51:18 kernel: lla_rt_output: RTM_ADD publish (proxy only) is invalid
Dec 28 19:51:18 mpd: [pt0] IFACE: Up event
Dec 28 19:51:18 mpd: XXX.XXX.XXX.XXX -> 192.168.1.32
Dec 28 19:51:18 mpd: [pt0] IPCP: LayerUp
Dec 28 19:51:18 mpd: [pt0] IPCP: state change Ack-Sent –> Opened
Dec 28 19:51:18 mpd: IPADDR XXX.XXX.XXX.XXX
Dec 28 19:51:18 mpd: [pt0] IPCP: rec'd Configure Ack #23 (Ack-Sent)
Dec 28 19:51:18 mpd: IPADDR XXX.XXX.XXX.XXX
Dec 28 19:51:18 mpd: [pt0] IPCP: SendConfigReq #23
Dec 28 19:51:18 mpd: COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
Dec 28 19:51:18 mpd: [pt0] IPCP: rec'd Configure Reject #22 (Ack-Sent)
Dec 28 19:51:18 mpd: COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
Dec 28 19:51:18 mpd: IPADDR XXX.XXX.XXX.XXX
Dec 28 19:51:18 mpd: [pt0] IPCP: SendConfigReq #22
Dec 28 19:51:18 mpd: [pt0] IPCP: state change Req-Sent –> Ack-Sent
Dec 28 19:51:18 mpd: SECDNS 208.67.220.220
Dec 28 19:51:18 mpd: PRIDNS 192.168.1.1
Dec 28 19:51:18 mpd: IPADDR 192.168.1.32
Dec 28 19:51:18 mpd: [pt0] IPCP: SendConfigAck #2
Dec 28 19:51:18 mpd: SECDNS 208.67.220.220
Dec 28 19:51:18 mpd: PRIDNS 192.168.1.1
Dec 28 19:51:18 mpd: 192.168.1.32 is OK
Dec 28 19:51:18 mpd: IPADDR 192.168.1.32
Dec 28 19:51:18 mpd: [pt0] IPCP: rec'd Configure Request #2 (Req-Sent)
Dec 28 19:51:18 mpd: [pt0] rec'd unexpected protocol IPV6CP, rejecting
Dec 28 19:51:18 mpd: SECDNS 208.67.220.220
Dec 28 19:51:18 mpd: PRIDNS 192.168.1.1
Dec 28 19:51:18 mpd: IPADDR 192.168.1.32
Dec 28 19:51:18 mpd: [pt0] IPCP: SendConfigNak #1
Dec 28 19:51:18 mpd: NAKing with 208.67.220.220
Dec 28 19:51:18 mpd: SECDNS 0.0.0.0
Dec 28 19:51:18 mpd: NAKing with 192.168.1.1
Dec 28 19:51:18 mpd: PRIDNS 0.0.0.0
Dec 28 19:51:18 mpd: NAKing with 192.168.1.32
Dec 28 19:51:18 mpd: IPADDR 0.0.0.0
Dec 28 19:51:18 mpd: [pt0] IPCP: rec'd Configure Request #1 (Req-Sent)
Dec 28 19:51:17 mpd: Decompress using: mppc (MPPE(128 bits), stateless)
Dec 28 19:51:17 mpd: Compress using: mppc (MPPE(128 bits), stateless)
Dec 28 19:51:17 mpd: [pt0] CCP: LayerUp
Dec 28 19:51:17 mpd: [pt0] CCP: state change Ack-Rcvd –> Opened
Dec 28 19:51:17 mpd: 0x01000040:MPPE(128 bits), stateless
Dec 28 19:51:17 mpd: MPPC
Dec 28 19:51:17 mpd: [pt0] CCP: SendConfigAck #2
Dec 28 19:51:17 mpd: 0x01000040:MPPE(128 bits), stateless
Dec 28 19:51:17 mpd: MPPC
Dec 28 19:51:17 mpd: [pt0] CCP: rec'd Configure Request #2 (Ack-Rcvd)
Dec 28 19:51:17 mpd: 0x01000040:MPPE(128 bits), stateless
Dec 28 19:51:17 mpd: MPPC
Dec 28 19:51:17 mpd: [pt0] CCP: SendConfigNak #1
Dec 28 19:51:17 mpd: 0x01000060:MPPE(40, 128 bits), stateless
Dec 28 19:51:17 mpd: MPPC
Dec 28 19:51:17 mpd: [pt0] CCP: rec'd Configure Request #1 (Ack-Rcvd)
Dec 28 19:51:16 mpd: [pt0] CCP: state change Req-Sent –> Ack-Rcvd
Dec 28 19:51:16 mpd: 0x01000040:MPPE(128 bits), stateless
Dec 28 19:51:16 mpd: MPPC
Dec 28 19:51:16 mpd: [pt0] CCP: rec'd Configure Ack #13 (Req-Sent)
Dec 28 19:51:16 mpd: 0x01000040:MPPE(128 bits), stateless
Dec 28 19:51:16 mpd: MPPC
Dec 28 19:51:16 mpd: [pt0] CCP: SendConfigReq #13
Dec 28 19:51:16 mpd: [pt0] CCP: state change Ack-Rcvd –> Req-Sent
Dec 28 19:51:16 mpd: [pt0] IPCP: rec'd Terminate Ack #21 (Req-Sent)
Dec 28 19:51:16 mpd: COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
Dec 28 19:51:16 mpd: IPADDR XXX.XXX.XXX.XXX
Dec 28 19:51:16 mpd: [pt0] IPCP: SendConfigReq #21
Dec 28 19:51:14 mpd: [pt0] CCP: state change Req-Sent –> Ack-Rcvd
Dec 28 19:51:14 mpd: 0x01000040:MPPE(128 bits), stateless
Dec 28 19:51:14 mpd: MPPC
Dec 28 19:51:14 mpd: [pt0] CCP: rec'd Configure Ack #12 (Req-Sent)
Dec 28 19:51:14 mpd: [pt0] IPCP: rec'd Terminate Ack #20 (Req-Sent)
Dec 28 19:51:14 mpd: 0x01000040:MPPE(128 bits), stateless
Dec 28 19:51:14 mpd: MPPC
Dec 28 19:51:14 mpd: [pt0] CCP: SendConfigReq #12
Dec 28 19:51:14 mpd: [pt0] CCP: state change Starting –> Req-Sent
Dec 28 19:51:14 mpd: [pt0] CCP: Up event
Dec 28 19:51:14 mpd: COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
Dec 28 19:51:14 mpd: IPADDR XXX.XXX.XXX.XXX
Dec 28 19:51:14 mpd: [pt0] IPCP: SendConfigReq #20
Dec 28 19:51:14 mpd: [pt0] IPCP: state change Starting –> Req-Sent
Dec 28 19:51:14 mpd: [pt0] IPCP: Up event
Dec 28 19:51:14 mpd: [pt0] CCP: LayerStart
Dec 28 19:51:14 mpd: [pt0] CCP: state change Initial –> Starting
Dec 28 19:51:14 mpd: [pt0] CCP: Open event
Dec 28 19:51:14 mpd: [pt0] IPCP: LayerStart
Dec 28 19:51:14 mpd: [pt0] IPCP: state change Initial –> Starting
Dec 28 19:51:14 mpd: [pt0] IPCP: Open event
Dec 28 19:51:14 mpd: [pt0] Bundle up: 1 link, total bandwidth 64000 bps
Dec 28 19:51:14 mpd: [pt0] LCP: authorization successful
Dec 28 19:51:14 mpd: [pt0] CHAP: sending SUCCESS len:42
Dec 28 19:51:14 mpd: Reply message: S=51473778AB7C55BF85D91579BE8056CC9BECD7F9
Dec 28 19:51:14 mpd: Response is valid
Dec 28 19:51:14 mpd: [pt0] CHAP: ChapInputFinish: status undefined
Dec 28 19:51:14 mpd: [pt0] AUTH: Auth-Thread finished normally
Dec 28 19:51:14 mpd: [pt0] AUTH: INTERNAL returned undefined
Dec 28 19:51:14 mpd: [pt0] AUTH: Trying INTERNAL
Dec 28 19:51:14 mpd: [pt0] AUTH: Auth-Thread started
Dec 28 19:51:14 mpd: Name: "XXXXXXXX"
Dec 28 19:51:14 mpd: [pt0] CHAP: rec'd RESPONSE #1
Dec 28 19:51:14 mpd: [pt0] LCP: LayerUp
Dec 28 19:51:14 mpd: [pt0] CHAP: sending CHALLENGE len:17
Dec 28 19:51:14 mpd: [pt0] LCP: auth: peer wants nothing, I want CHAP
Dec 28 19:51:14 mpd: [pt0] LCP: state change Ack-Sent –> Opened
Dec 28 19:51:14 mpd: AUTHPROTO CHAP MSOFTv2
Dec 28 19:51:14 mpd: MAGICNUM b206040e
Dec 28 19:51:14 mpd: MRU 1500
Dec 28 19:51:14 mpd: PROTOCOMP
Dec 28 19:51:14 mpd: ACFCOMP
Dec 28 19:51:14 mpd: [pt0] LCP: rec'd Configure Ack #22 (Ack-Sent)
Dec 28 19:51:14 mpd: AUTHPROTO CHAP MSOFTv2
Dec 28 19:51:14 mpd: MAGICNUM b206040e
Dec 28 19:51:14 mpd: MRU 1500
Dec 28 19:51:14 mpd: PROTOCOMP
Dec 28 19:51:14 mpd: ACFCOMP
Dec 28 19:51:14 mpd: [pt0] LCP: SendConfigReq #22
Dec 28 19:51:14 mpd: MP SHORTSEQ
Dec 28 19:51:14 mpd: MP MRRU 1600
Dec 28 19:51:14 mpd: [pt0] LCP: rec'd Configure Reject #21 (Ack-Sent)
Dec 28 19:51:13 mpd: ENDPOINTDISC [802.1] 00 04 23 9a ba 1a
Dec 28 19:51:13 mpd: MP SHORTSEQ
Dec 28 19:51:13 mpd: MP MRRU 1600
Dec 28 19:51:13 mpd: AUTHPROTO CHAP MSOFTv2
Dec 28 19:51:13 mpd: MAGICNUM b206040e
Dec 28 19:51:13 mpd: MRU 1500
Dec 28 19:51:13 mpd: PROTOCOMP
Dec 28 19:51:13 mpd: ACFCOMP
Dec 28 19:51:13 mpd: [pt0] LCP: SendConfigReq #21
Dec 28 19:51:12 mpd: [pt0] LCP: state change Req-Sent –> Ack-Sent
Dec 28 19:51:12 mpd: ACFCOMP
Dec 28 19:51:12 mpd: PROTOCOMP
Dec 28 19:51:12 mpd: MAGICNUM 597b49cb
Dec 28 19:51:12 mpd: ACCMAP 0x00000000
Dec 28 19:51:12 mpd: [pt0] LCP: SendConfigAck #1
Dec 28 19:51:12 mpd: ACFCOMP
Dec 28 19:51:12 mpd: PROTOCOMP
Dec 28 19:51:12 mpd: MAGICNUM 597b49cb
Dec 28 19:51:12 mpd: ACCMAP 0x00000000
Dec 28 19:51:12 mpd: [pt0] LCP: rec'd Configure Request #1 (Req-Sent)
Dec 28 19:51:11 mpd: ENDPOINTDISC [802.1] 00 04 23 9a ba 1a
Dec 28 19:51:11 mpd: MP SHORTSEQ
Dec 28 19:51:11 mpd: MP MRRU 1600
Dec 28 19:51:11 mpd: AUTHPROTO CHAP MSOFTv2
Dec 28 19:51:11 mpd: MAGICNUM b206040e
Dec 28 19:51:11 mpd: MRU 1500
Dec 28 19:51:11 mpd: PROTOCOMP
Dec 28 19:51:11 mpd: ACFCOMP
Dec 28 19:51:11 mpd: [pt0] LCP: SendConfigReq #20
Dec 28 19:51:11 mpd: [pt0] LCP: state change Starting –> Req-Sent
Dec 28 19:51:11 mpd: [pt0] LCP: Up event
Dec 28 19:51:11 mpd: [pt0] link: origination is remote
Dec 28 19:51:11 mpd: [pt0] link: UP event
Dec 28 19:51:11 mpd: [pt0] PPTP: attaching to peer's outgoing call
Dec 28 19:51:11 mpd: [pt0] LCP: LayerStart
Dec 28 19:51:11 mpd: [pt0] LCP: state change Initial –> Starting
Dec 28 19:51:11 mpd: [pt0] LCP: Open event
Dec 28 19:51:11 mpd: [pt0] link: OPEN event
Dec 28 19:51:11 mpd: [pt0] opening link "pt0"…
Dec 28 19:51:11 mpd: [pt0] Accepting PPTP connection
Dec 28 19:51:10 mpd: pptp0: attached to connection with XXX.XXX.XXX.XXX 49762
Dec 28 19:51:10 mpd: PPTP: Incoming control connection from XXX.XXX.XXX.XXX 49762 to XXX.XXX.XXX.XXX 1723
Dec 28 19:50:55 syslogd: kernel boot file is /boot/kernel/kernel

eri--

Hmm did you allow gre in/out?

AhnHEL

Firewall rules are setup this way on the PPTP interface

* PPTP clients * * * * none PPTP -> Any

cmb

I saw the same thing doing some testing last night. It connects just fine, but no traffic will pass. All the rules are good, both on WAN for GRE and 1723, and on $pptp. The pptp interface group is correct (for that one connection at least, client is on ng1, PPTP group contains only ng1). tcpdump on ng1 shows no traffic, tcpdump on WAN shows the GRE traffic. Nothing blocked by pf.

After disconnecting and reconnecting, I was able to panic the box. I believe that's related to PPTP, this box wasn't really doing anything else at the time. backtrace attached.

pptp-panic.png_thumb

cmb

After the reboot from the panic, it's functioning (or rather not functioning) differently than I described above. I can ping the client from the firewall, and I can see traffic initiated by the client when tcpdumping on ng1, but none of the traffic from the client gets a response. It's not being blocked by pf, not showing in the firewall log and the deny rules have log on them.

AhnHEL

Any further updates on this issue?

ushac

I have a problem which I am not sure if it is connected to this or not.
I've described it in this thread: http://forum.pfsense.org/index.php/topic,23446.0.html
Is there anyway I can help, with more logs or anything like that?

/Erik

eri--

There is mpd5 now being used for pptp please try new snaps

ushac

Updated using pfSense-Full-Update-2.0-BETA1-20100311-0216.tgz, but no change for me.
Anyway I can help? Logs of some kind?

/Erik

AhnHEL

Same issue, connecting fine but no traffic passing. :(