Date: Wed, 20 Aug 2003 22:06:25 -0700 (PDT) From: Jeff Leary <quixoticsycophant@yahoo.com> To: freebsd-questions@freebsd.org Subject: Intermittent failures with mpd VPN Message-ID: <20030821050625.71488.qmail@web13114.mail.yahoo.com>
next in thread | raw e-mail | index | archive | help
Hi, I have a 4.5-release firewall / VPN server which has been humming along without a glitch since 4.5-release first came out. I have applied only relevant patches during this time since this box's only job is ipfilter, ipnat, and mpd. Just recently there's been this intermittent behavior of not being able to login -- but if you keep trying you'll eventually get in after 4 or 5 attempts. Failed logins look like PPTP connection from 1.2.3.4:1705 pptp0: attached to connection with 1.2.3.4:1705 [pptp0] IFACE: Open event [pptp0] IPCP: Open event [pptp0] IPCP: state change Initial --> Starting [pptp0] IPCP: LayerStart [pptp0] IPCP: Open event [pptp0] bundle: OPEN event in state CLOSED [pptp0] opening link "pptp0"... [pptp0] link: OPEN event [pptp0] LCP: Open event [pptp0] LCP: state change Initial --> Starting [pptp0] LCP: LayerStart [pptp0] device: OPEN event in state DOWN [pptp0] attaching to peer's outgoing call [pptp0] device is now in state OPENING [pptp0] device: UP event in state OPENING [pptp0] device is now in state UP [pptp0] link: UP event [pptp0] link: origination is remote [pptp0] LCP: Up event [pptp0] LCP: state change Starting --> Req-Sent [pptp0] LCP: phase shift DEAD --> ESTABLISH [pptp0] LCP: SendConfigReq #50 ACFCOMP PROTOCOMP MRU 1500 MAGICNUM 88c318a0 AUTHPROTO CHAP MSOFTv2 MP MRRU 1600 MP SHORTSEQ ENDPOINTDISC [802.1] 00 10 4b 06 de cf pptp0-0: ignoring SetLinkInfo [pptp0] LCP: rec'd Configure Request #0 link 0 (Req-Sent) MAGICNUM 3b27257f PROTOCOMP ACFCOMP CALLBACK Not supported MP MRRU 1614 ENDPOINTDISC [LOCAL] <MAC address snipped> [pptp0] LCP: SendConfigRej #0 CALLBACK [pptp0] LCP: SendConfigReq #51 ACFCOMP PROTOCOMP MRU 1500 MAGICNUM 88c318a0 AUTHPROTO CHAP MSOFTv2 MP MRRU 1600 MP SHORTSEQ ENDPOINTDISC [802.1] 00 10 4b 06 de cf [pptp0] LCP: rec'd Configure Request #1 link 0 (Req-Sent) MAGICNUM 3b27257f PROTOCOMP ACFCOMP CALLBACK Not supported MP MRRU 1614 ENDPOINTDISC [LOCAL] <MAC address snipped> [pptp0] LCP: SendConfigRej #1 CALLBACK [pptp0] LCP: SendConfigReq #52 ACFCOMP PROTOCOMP MRU 1500 MAGICNUM 88c318a0 AUTHPROTO CHAP MSOFTv2 MP MRRU 1600 MP SHORTSEQ ENDPOINTDISC [802.1] 00 10 4b 06 de cf [pptp0] LCP: rec'd Configure Request #2 link 0 (Req-Sent) MAGICNUM 3b27257f PROTOCOMP ACFCOMP CALLBACK Not supported MP MRRU 1614 ENDPOINTDISC [LOCAL] <MAC address snipped> [pptp0] LCP: SendConfigRej #2 CALLBACK [pptp0] LCP: SendConfigReq #53 ACFCOMP PROTOCOMP MRU 1500 MAGICNUM 88c318a0 AUTHPROTO CHAP MSOFTv2 MP MRRU 1600 MP SHORTSEQ ENDPOINTDISC [802.1] 00 10 4b 06 de cf [pptp0] LCP: SendConfigReq #54 ACFCOMP PROTOCOMP MRU 1500 MAGICNUM 88c318a0 AUTHPROTO CHAP MSOFTv2 MP MRRU 1600 MP SHORTSEQ ENDPOINTDISC [802.1] 00 10 4b 06 de cf [pptp0] LCP: rec'd Configure Request #3 link 0 (Req-Sent) MAGICNUM 3b27257f PROTOCOMP ACFCOMP CALLBACK Not supported MP MRRU 1614 ENDPOINTDISC [LOCAL] <MAC address snipped> [pptp0] LCP: SendConfigRej #3 CALLBACK [pptp0] LCP: SendConfigReq #55 ACFCOMP PROTOCOMP MRU 1500 MAGICNUM 88c318a0 AUTHPROTO CHAP MSOFTv2 MP MRRU 1600 MP SHORTSEQ ENDPOINTDISC [802.1] 00 10 4b 06 de cf [pptp0] LCP: SendConfigReq #56 ACFCOMP PROTOCOMP MRU 1500 MAGICNUM 88c318a0 AUTHPROTO CHAP MSOFTv2 MP MRRU 1600 MP SHORTSEQ ENDPOINTDISC [802.1] 00 10 4b 06 de cf [pptp0] LCP: rec'd Configure Request #4 link 0 (Req-Sent) MAGICNUM 3b27257f PROTOCOMP ACFCOMP CALLBACK Not supported MP MRRU 1614 ENDPOINTDISC [LOCAL] <MAC address snipped> [pptp0] LCP: SendConfigRej #4 CALLBACK [pptp0] LCP: SendConfigReq #57 ACFCOMP PROTOCOMP MRU 1500 MAGICNUM 88c318a0 AUTHPROTO CHAP MSOFTv2 MP MRRU 1600 MP SHORTSEQ ENDPOINTDISC [802.1] 00 10 4b 06 de cf [pptp0] LCP: SendConfigReq #58 ACFCOMP PROTOCOMP MRU 1500 MAGICNUM 88c318a0 AUTHPROTO CHAP MSOFTv2 MP MRRU 1600 MP SHORTSEQ ENDPOINTDISC [802.1] 00 10 4b 06 de cf [pptp0] LCP: rec'd Configure Request #5 link 0 (Req-Sent) MAGICNUM 3b27257f PROTOCOMP ACFCOMP CALLBACK Not supported MP MRRU 1614 ENDPOINTDISC [LOCAL] <MAC address snipped> [pptp0] LCP: not converging [pptp0] LCP: parameter negotiation failed [pptp0] LCP: state change Req-Sent --> Stopped [pptp0] LCP: LayerFinish [pptp0] device: CLOSE event in state UP pptp0-0: clearing call pptp0-0: killing channel [pptp0] PPTP call terminated [pptp0] IFACE: Close event [pptp0] IPCP: Close event [pptp0] IPCP: state change Starting --> Initial [pptp0] IPCP: LayerFinish [pptp0] IFACE: Close event pptp0: closing connection with 1.2.3.4:1705 [pptp0] IFACE: Close event [pptp0] device is now in state CLOSING [pptp0] bundle: CLOSE event in state OPENED [pptp0] closing link "pptp0"... [pptp0] device: DOWN event in state CLOSING [pptp0] device is now in state DOWN [pptp0] link: CLOSE event [pptp0] LCP: Close event [pptp0] LCP: state change Stopped --> Closed [pptp0] device: DOWN event in state DOWN [pptp0] device is now in state DOWN [pptp0] link: DOWN event [pptp0] LCP: Down event [pptp0] LCP: state change Closed --> Initial [pptp0] LCP: phase shift ESTABLISH --> DEAD [pptp0] link: DOWN event [pptp0] LCP: Down event pptp0: killing connection with 1.2.3.4:1705 successful logins look like PPTP connection from 1.2.3.4:2738 pptp0: attached to connection with 1.2.3.4:2738 [pptp0] IFACE: Open event [pptp0] IPCP: Open event [pptp0] IPCP: state change Initial --> Starting [pptp0] IPCP: LayerStart [pptp0] IPCP: Open event [pptp0] bundle: OPEN event in state CLOSED [pptp0] opening link "pptp0"... [pptp0] link: OPEN event [pptp0] LCP: Open event [pptp0] LCP: state change Initial --> Starting [pptp0] LCP: LayerStart [pptp0] device: OPEN event in state DOWN [pptp0] attaching to peer's outgoing call [pptp0] device is now in state OPENING [pptp0] device: UP event in state OPENING [pptp0] device is now in state UP [pptp0] link: UP event [pptp0] link: origination is remote [pptp0] LCP: Up event [pptp0] LCP: state change Starting --> Req-Sent [pptp0] LCP: phase shift DEAD --> ESTABLISH [pptp0] LCP: SendConfigReq #59 ACFCOMP PROTOCOMP MRU 1500 MAGICNUM 89dadabc AUTHPROTO CHAP MSOFTv2 MP MRRU 1600 MP SHORTSEQ ENDPOINTDISC [802.1] 00 10 4b 06 de cf pptp0-0: ignoring SetLinkInfo [pptp0] LCP: rec'd Configure Request #0 link 0 (Req-Sent) MAGICNUM 47f55acf PROTOCOMP ACFCOMP CALLBACK Not supported MP MRRU 1614 ENDPOINTDISC [LOCAL] <MAC address snipped> [pptp0] LCP: SendConfigRej #0 CALLBACK [pptp0] LCP: rec'd Configure Reject #59 link 0 (Req-Sent) MP SHORTSEQ [pptp0] LCP: SendConfigReq #60 ACFCOMP PROTOCOMP MRU 1500 MAGICNUM 89dadabc AUTHPROTO CHAP MSOFTv2 MP MRRU 1600 ENDPOINTDISC [802.1] 00 10 4b 06 de cf [pptp0] LCP: rec'd Configure Request #1 link 0 (Req-Sent) MAGICNUM 47f55acf PROTOCOMP ACFCOMP MP MRRU 1614 ENDPOINTDISC [LOCAL] <MAC address snipped> [pptp0] LCP: SendConfigNak #1 MP MRRU 1600 [pptp0] LCP: rec'd Configure Ack #60 link 0 (Req-Sent) ACFCOMP PROTOCOMP MRU 1500 MAGICNUM 89dadabc AUTHPROTO CHAP MSOFTv2 MP MRRU 1600 ENDPOINTDISC [802.1] 00 10 4b 06 de cf [pptp0] LCP: state change Req-Sent --> Ack-Rcvd [pptp0] LCP: rec'd Configure Request #2 link 0 (Ack-Rcvd) MAGICNUM 47f55acf PROTOCOMP ACFCOMP MP MRRU 1600 ENDPOINTDISC [LOCAL] <MAC address snipped> [pptp0] LCP: SendConfigAck #2 MAGICNUM 47f55acf PROTOCOMP ACFCOMP MP MRRU 1600 ENDPOINTDISC [LOCAL] <MAC address snipped> [pptp0] LCP: state change Ack-Rcvd --> Opened [pptp0] LCP: phase shift ESTABLISH --> AUTHENTICATE [pptp0] LCP: auth: peer wants nothing, I want CHAP [pptp0] CHAP: sending CHALLENGE [pptp0] LCP: LayerUp [pptp0] LCP: rec'd Ident #3 link 0 (Opened) MESG: MSRASV5.00 [pptp0] LCP: rec'd Ident #4 link 0 (Opened) MESG: MSRAS-1-ARDA [pptp0] CHAP: rec'd RESPONSE #1 Name: "SOMEDOMAIN\somename" Peer name: "somename" Response is valid [pptp0] CHAP: sending SUCCESS [pptp0] LCP: authorization successful [pptp0] LCP: phase shift AUTHENTICATE --> NETWORK [pptp0] up: 1 link, total bandwidth 64000 bps [pptp0] IPCP: Up event [pptp0] IPCP: state change Starting --> Req-Sent [pptp0] IPCP: SendConfigReq #3 IPADDR 192.168.1.1 COMPPROTO VJCOMP, 16 comp. channels, no comp-cid [pptp0] error writing len 20 frame to bypass: Network is down [pptp0] CCP: Open event [pptp0] CCP: state change Initial --> Starting [pptp0] CCP: LayerStart [pptp0] CCP: Up event [pptp0] CCP: state change Starting --> Req-Sent [pptp0] CCP: SendConfigReq #2 MPPC 0x01000040: MPPE, 128 bit, stateless [pptp0] error writing len 14 frame to bypass: Network is down pptp0-0: ignoring SetLinkInfo [pptp0] CCP: rec'd Configure Request #5 link 0 (Req-Sent) MPPC 0x01000041: MPPC MPPE, 128 bit, stateless [pptp0] CCP: SendConfigNak #5 MPPC 0x01000040: MPPE, 128 bit, stateless [pptp0] IPCP: rec'd Configure Request #6 link 0 (Req-Sent) IPADDR 0.0.0.0 NAKing with 192.168.1.206 [pptp0] IPCP: SendConfigNak #6 IPADDR 192.168.1.206 [pptp0] CCP: rec'd Configure Request #7 link 0 (Req-Sent) MPPC 0x01000040: MPPE, 128 bit, stateless [pptp0] CCP: SendConfigAck #7 MPPC 0x01000040: MPPE, 128 bit, stateless [pptp0] CCP: state change Req-Sent --> Ack-Sent [pptp0] IPCP: rec'd Configure Request #8 link 0 (Req-Sent) IPADDR 192.168.1.206 192.168.1.206 is OK [pptp0] IPCP: SendConfigAck #8 IPADDR 192.168.1.206 [pptp0] IPCP: state change Req-Sent --> Ack-Sent [pptp0] IPCP: SendConfigReq #4 IPADDR 192.168.1.1 COMPPROTO VJCOMP, 16 comp. channels, no comp-cid [pptp0] CCP: SendConfigReq #3 MPPC 0x01000040: MPPE, 128 bit, stateless [pptp0] IPCP: rec'd Configure Reject #4 link 0 (Ack-Sent) COMPPROTO VJCOMP, 16 comp. channels, no comp-cid [pptp0] IPCP: SendConfigReq #5 IPADDR 192.168.1.1 [pptp0] CCP: rec'd Configure Ack #3 link 0 (Ack-Sent) MPPC 0x01000040: MPPE, 128 bit, stateless [pptp0] CCP: state change Ack-Sent --> Opened [pptp0] CCP: LayerUp Compress using: MPPE, 128 bit, stateless Decompress using: MPPE, 128 bit, stateless [pptp0] IPCP: rec'd Configure Ack #5 link 0 (Ack-Sent) IPADDR 192.168.1.1 [pptp0] IPCP: state change Ack-Sent --> Opened [pptp0] IPCP: LayerUp 192.168.1.1 -> 192.168.1.206 [pptp0] IFACE: Up event [pptp0] exec: /sbin/ifconfig ng0 192.168.1.1 192.168.1.206 netmask 0xffffffff -link0 [pptp0] exec: /usr/sbin/arp -s 192.168.1.206 0:10:4b:6:de:cf pub [pptp0] IFACE: Up event One difference being repeated cycles of "CALLBACK not supported" for the failed login and only one instance of "CALLBACK not supported" for the sucessful login. The two attempts shown above were 5 minutes apart with absolutely no changes being made to the client or server. The generic reason here is a hardware failure. Indeed, this box was someone's workstation for a couple years before it became a VPN server. However, I am hoping in a very serious way that there is another explanation. Any ideas? Thanks, Jeff __________________________________ Do you Yahoo!? Yahoo! SiteBuilder - Free, easy-to-use web site design software http://sitebuilder.yahoo.com
Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?20030821050625.71488.qmail>