Thread Info
  • State Not Answered
  • Locked Locked
  • Replies 4 replies
  • Subscribers 1 subscriber
  • Views 1767 views
  • Users 0 members are here
Options
Suggested
This discussion has been locked.
You can no longer post new replies to this discussion. If you have a question you can start a new discussion

PPTP Stopped working - CPU at 100%

bdog68
Ver  4.0.20 and Ver 4.0.21 - registered unlimited Gig

Servers = Dell 650 / 1GB Ram

First problem ever with pptp since installs 1 yr ago.

This problem came out of nowhere and I need help resolving.

One of the three ASL servers is my primary pptp vpn server and mysteriously it no longer will accept a pptp connection.  The win2k (patched) clients just stop on "verifying username/password".

Using 128bit encyption / local users

Tried multiple local user accounts

Tried multiple client PCs

Tried enabling / disabling pptp roadwarrior access

Here is what I have sound so far:

The very first attempt causes pppd to go to from 0% to ~97-99% CPU.  A restart clears the High CPU condition.

root      4112  97.0  0.0  1956  824 ?        R    07:30   2:42 /usr/sbin/pppd local file /etc/ppp/options 115200 10.20.70.1:10.20.70.2  


Here is  the PPTP log from the failing ASL:

2004-Mar  7 08:03:02 (none) pptpd[5429]: MGR: Launching /usr/local/sbin/pptpctrl to handle client
2004-Mar  7 08:03:02 (none) pptpd[5429]: CTRL: local address = 10.20.70.1
2004-Mar  7 08:03:02 (none) pptpd[5429]: CTRL: remote address = 10.20.70.2
2004-Mar  7 08:03:02 (none) pptpd[5429]: CTRL: pppd options file = /etc/ppp/options
2004-Mar  7 08:03:02 (none) pptpd[5429]: CTRL: Client 68.xxx.xxx.xxx  control connection started
2004-Mar  7 08:03:02 (none) pptpd[5429]: CTRL: Received PPTP Control Message (type: 1)
2004-Mar  7 08:03:02 (none) pptpd[5429]: CTRL: Made a START CTRL CONN RPLY packet
2004-Mar  7 08:03:02 (none) pptpd[5429]: CTRL: I wrote 156 bytes to the client.
2004-Mar  7 08:03:02 (none) pptpd[5429]: CTRL: Sent packet to client
2004-Mar  7 08:03:02 (none) pptpd[5429]: CTRL: Received PPTP Control Message (type: 7)
2004-Mar  7 08:03:03 (none) pptpd[5429]: CTRL: Set parameters to 1525 maxbps, 64 window size
2004-Mar  7 08:03:03 (none) pptpd[5429]: CTRL: Made a OUT CALL RPLY packet
2004-Mar  7 08:03:03 (none) pptpd[5429]: CTRL: Starting call (launching pppd, opening GRE)
2004-Mar  7 08:03:03 (none) pptpd[5429]: CTRL: pty_fd = 5
2004-Mar  7 08:03:03 (none) pptpd[5429]: CTRL: tty_fd = 6
2004-Mar  7 08:03:03 (none) pptpd[5429]: CTRL: I wrote 32 bytes to the client.
2004-Mar  7 08:03:03 (none) pptpd[5429]: CTRL: Sent packet to client
2004-Mar  7 08:03:03 (none) pptpd[5435]: CTRL (PPPD Launcher): Connection speed = 115200
2004-Mar  7 08:03:03 (none) pptpd[5435]: CTRL (PPPD Launcher): local address = 10.20.70.1
2004-Mar  7 08:03:03 (none) pptpd[5435]: CTRL (PPPD Launcher): remote address = 10.20.70.2
2004-Mar  7 08:03:03 (none) pptpd[5429]: CTRL: Received PPTP Control Message (type: 15)
2004-Mar  7 08:03:03 (none) pptpd[5429]: CTRL: Got a SET LINK INFO packet with standard ACCMs
2004-Mar  7 08:03:03 (none) pppd[5435]: pppd 2.4.2b1 started by (unknown), uid 0

** End of log 


Here is the PPTP log from a second (working) ASL:

2004-Mar  7 07:38:11 (none) pptpd[19445]: MGR: Launching /usr/local/sbin/pptpctrl to handle client
2004-Mar  7 07:38:11 (none) pptpd[19445]: CTRL: local address = 10.20.50.1
2004-Mar  7 07:38:11 (none) pptpd[19445]: CTRL: remote address = 10.20.50.4
2004-Mar  7 07:38:11 (none) pptpd[19445]: CTRL: pppd options file = /etc/ppp/options
2004-Mar  7 07:38:11 (none) pptpd[19445]: CTRL: Client 68.xxx.xxx.xxx control connection started
2004-Mar  7 07:38:11 (none) pptpd[19445]: CTRL: Received PPTP Control Message (type: 1)
2004-Mar  7 07:38:11 (none) pptpd[19445]: CTRL: Made a START CTRL CONN RPLY packet
2004-Mar  7 07:38:11 (none) pptpd[19445]: CTRL: I wrote 156 bytes to the client.
2004-Mar  7 07:38:11 (none) pptpd[19445]: CTRL: Sent packet to client
2004-Mar  7 07:38:11 (none) pptpd[19445]: CTRL: Received PPTP Control Message (type: 7)
2004-Mar  7 07:38:11 (none) pptpd[19445]: CTRL: Set parameters to 1525 maxbps, 64 window size
2004-Mar  7 07:38:11 (none) pptpd[19445]: CTRL: Made a OUT CALL RPLY packet
2004-Mar  7 07:38:11 (none) pptpd[19445]: CTRL: Starting call (launching pppd, opening GRE)
2004-Mar  7 07:38:11 (none) pptpd[19445]: CTRL: pty_fd = 5
2004-Mar  7 07:38:11 (none) pptpd[19445]: CTRL: tty_fd = 6
2004-Mar  7 07:38:11 (none) pptpd[19445]: CTRL: I wrote 32 bytes to the client.
2004-Mar  7 07:38:11 (none) pptpd[19445]: CTRL: Sent packet to client
2004-Mar  7 07:38:11 (none) pptpd[19446]: CTRL (PPPD Launcher): Connection speed = 115200
2004-Mar  7 07:38:11 (none) pptpd[19446]: CTRL (PPPD Launcher): local address = 10.20.50.1
2004-Mar  7 07:38:11 (none) pptpd[19446]: CTRL (PPPD Launcher): remote address = 10.20.50.4
2004-Mar  7 07:38:11 (none) pppd[19446]: pppd 2.4.2b1 started by (unknown), uid 0
2004-Mar  7 07:38:11 (none) pppd[19446]: using channel 7
2004-Mar  7 07:38:11 (none) pppd[19446]: Starting negotiation on /dev/ttyp1
2004-Mar  7 07:38:11 (none) pppd[19446]: sent [LCP ConfReq id=0x1        ]
2004-Mar  7 07:38:11 (none) pptpd[19445]: CTRL: Received PPTP Control Message (type: 15)
2004-Mar  7 07:38:11 (none) pptpd[19445]: CTRL: Got a SET LINK INFO packet with standard ACCMs
2004-Mar  7 07:38:11 (none) pppd[19446]: rcvd [LCP ConfReq id=0x0      ]
2004-Mar  7 07:38:11 (none) pppd[19446]: sent [LCP ConfRej id=0x0 ]
2004-Mar  7 07:38:11 (none) pppd[19446]: rcvd [LCP ConfNak id=0x1  ]
2004-Mar  7 07:38:11 (none) pppd[19446]: sent [LCP ConfReq id=0x2       ]
2004-Mar  7 07:38:11 (none) pppd[19446]: rcvd [LCP ConfReq id=0x1     ]
2004-Mar  7 07:38:11 (none) pppd[19446]: sent [LCP ConfAck id=0x1     ]
2004-Mar  7 07:38:11 (none) pppd[19446]: rcvd [LCP ConfNak id=0x2 ]
2004-Mar  7 07:38:11 (none) pppd[19446]: sent [LCP ConfReq id=0x3       ]
2004-Mar  7 07:38:11 (none) pppd[19446]: rcvd [LCP ConfNak id=0x3 ]
2004-Mar  7 07:38:11 (none) pppd[19446]: sent [LCP ConfReq id=0x4       ]
2004-Mar  7 07:38:11 (none) pppd[19446]: rcvd [LCP ConfNak id=0x4 ]
2004-Mar  7 07:38:11 (none) pppd[19446]: sent [LCP ConfReq id=0x5       ]
2004-Mar  7 07:38:11 (none) pppd[19446]: rcvd [LCP ConfNak id=0x5 ]
2004-Mar  7 07:38:11 (none) pppd[19446]: sent [LCP ConfReq id=0x6       ]
2004-Mar  7 07:38:11 (none) pppd[19446]: rcvd [LCP ConfNak id=0x6 ]
2004-Mar  7 07:38:11 (none) pppd[19446]: sent [LCP ConfReq id=0x7       ]
2004-Mar  7 07:38:11 (none) pppd[19446]: rcvd [LCP ConfNak id=0x7 ]
2004-Mar  7 07:38:11 (none) pppd[19446]: sent [LCP ConfReq id=0x8       ]
2004-Mar  7 07:38:11 (none) pppd[19446]: rcvd [LCP ConfNak id=0x8 ]
2004-Mar  7 07:38:11 (none) pppd[19446]: sent [LCP ConfReq id=0x9       ]
2004-Mar  7 07:38:11 (none) pppd[19446]: rcvd [LCP ConfNak id=0x9 ]
2004-Mar  7 07:38:11 (none) pppd[19446]: sent [LCP ConfReq id=0xa       ]
2004-Mar  7 07:38:11 (none) pppd[19446]: rcvd [LCP ConfNak id=0xa ]
2004-Mar  7 07:38:11 (none) pppd[19446]: sent [LCP ConfReq id=0xb       ]
2004-Mar  7 07:38:11 (none) pppd[19446]: rcvd [LCP ConfRej id=0xb ]
2004-Mar  7 07:38:11 (none) pppd[19446]: sent [LCP ConfReq id=0xc      ]
2004-Mar  7 07:38:11 (none) pptpd[19445]: CTRL: Received PPTP Control Message (type: 15)
2004-Mar  7 07:38:11 (none) pptpd[19445]: CTRL: Ignored a SET LINK INFO packet with real ACCMs!
2004-Mar  7 07:38:11 (none) pppd[19446]: rcvd [LCP ConfAck id=0xc      ]
2004-Mar  7 07:38:11 (none) pppd[19446]: sent [LCP EchoReq id=0x0 magic=0x5264777f]
2004-Mar  7 07:38:11 (none) pppd[19446]: sent [CHAP Challenge id=0x1 ɟee7cc34557f3e17be8fdfad3ee52674>, name = "pptp"]
2004-Mar  7 07:38:11 (none) pppd[19446]: rcvd [LCP code=0xc id=0x2 72 39 7d 6f 4d 53 52 41 53 56 35 2e 30 30]
2004-Mar  7 07:38:11 (none) pppd[19446]: sent [LCP CodeRej id=0xd 0c 02 00 12 72 39 7d 6f 4d 53 52 41 53 56 35 2e 30 30]
2004-Mar  7 07:38:11 (none) pppd[19446]: rcvd [LCP code=0xc id=0x3 72 39 7d 6f 4d 53 52 41 53 2d 30 2d 42 44 4c 41 50 32]
2004-Mar  7 07:38:11 (none) pppd[19446]: sent [LCP CodeRej id=0xe 0c 03 00 16 72 39 7d 6f 4d 53 52 41 53 2d 30 2d 42 44 4c 41 50 32]
2004-Mar  7 07:38:11 (none) pppd[19446]: rcvd [LCP EchoRep id=0x0 magic=0x72397d6f]
2004-Mar  7 07:38:11 (none) pppd[19446]: rcvd [CHAP Response id=0x1 e969058fc971d63e2e67e51fe3c8000000000000000003dd7a67d881cd60eeac0fd2c72178628e623062bd4cb2fa200>, name = "Username"]
2004-Mar  7 07:38:11 (none) pppd[19446]: No CHAP secret found for authenticating Username, trying aua now.
2004-Mar  7 07:38:11 (none) pppd[19446]: sent [CHAP Success id=0x1 "S=5A09C7CD4CCC9BD3B7ECA92F1C606CE5A0122C11 M=Welcome to wfw1.maine207west.k12.il.us."]
2004-Mar  7 07:38:11 (none) pppd[19446]: Using interface ppp1
2004-Mar  7 07:38:11 (none) pppd[19446]: sent [CCP ConfReq id=0x1 ]
2004-Mar  7 07:38:11 (none) pppd[19446]: CHAP peer authentication succeeded for Username
2004-Mar  7 07:38:11 (none) pppd[19446]: rcvd [CCP ConfReq id=0x4 ]
2004-Mar  7 07:38:11 (none) pppd[19446]: sent [CCP ConfNak id=0x4 ]
2004-Mar  7 07:38:11 (none) pppd[19446]: rcvd [IPCP ConfReq id=0x5     ]
2004-Mar  7 07:38:11 (none) pppd[19446]: sent [IPCP TermAck id=0x5]
2004-Mar  7 07:38:11 (none) pppd[19446]: rcvd [CCP ConfAck id=0x1 ]
2004-Mar  7 07:38:11 (none) pppd[19446]: rcvd [CCP ConfReq id=0x6 ]
2004-Mar  7 07:38:11 (none) pppd[19446]: sent [CCP ConfAck id=0x6 ]
2004-Mar  7 07:38:11 (none) pppd[19446]: MPPE 128-bit stateless compression enabled
2004-Mar  7 07:38:11 (none) pppd[19446]: sent [IPCP ConfReq id=0x1  ]
2004-Mar  7 07:38:11 (none) pppd[19446]: rcvd [IPCP ConfRej id=0x1 ]
2004-Mar  7 07:38:11 (none) pppd[19446]: sent [IPCP ConfReq id=0x2 ]
2004-Mar  7 07:38:11 (none) pppd[19446]: rcvd [IPCP ConfAck id=0x2 ]
2004-Mar  7 07:38:12 (none) pppd[18686]: sent [LCP EchoReq id=0x27 magic=0xa75dc7c9]
2004-Mar  7 07:38:12 (none) pppd[18686]: rcvd [LCP EchoRep id=0x27 magic=0x9e66b1]
2004-Mar  7 07:38:13 (none) pppd[19446]: rcvd [IPCP ConfReq id=0x7     ]
2004-Mar  7 07:38:13 (none) pppd[19446]: sent [IPCP ConfRej id=0x7    ]
2004-Mar  7 07:38:13 (none) pppd[19446]: rcvd [IPCP ConfReq id=0x8 ]
2004-Mar  7 07:38:13 (none) pppd[19446]: sent [IPCP ConfNak id=0x8 ]
2004-Mar  7 07:38:13 (none) pppd[19446]: rcvd [IPCP ConfReq id=0x9 ]
2004-Mar  7 07:38:13 (none) pppd[19446]: sent [IPCP ConfAck id=0x9 ]
2004-Mar  7 07:38:13 (none) pppd[19446]: Cannot determine ethernet address for proxy ARP
2004-Mar  7 07:38:13 (none) pppd[19446]: local  IP address 10.20.50.1
2004-Mar  7 07:38:13 (none) pppd[19446]: remote IP address 10.20.50.4


Thanks in advance for the help.  


This thread was automatically locked due to age.
Parents
  • 0
    Is there another routing device in front of the box that stopped accepting PPTP traffic?

    If so, has there been a configuration change on this other device, preventing GRE (port 47) traffic from getting through?

    PPTP uses port 1723 for tunnel authentication and control, while port 47 handles the tunnel payload.  Unless both ports are open, you won't get a working connection.  
Reply
  • 0
    Is there another routing device in front of the box that stopped accepting PPTP traffic?

    If so, has there been a configuration change on this other device, preventing GRE (port 47) traffic from getting through?

    PPTP uses port 1723 for tunnel authentication and control, while port 47 handles the tunnel payload.  Unless both ports are open, you won't get a working connection.  
Children
  • 0 in reply to VelvetFog
    >>>>Is there another routing device in front of the box that stopped accepting PPTP traffic?

    no, just an edge router w/ no ACLs on the traffic

    >>>If so, has there been a configuration change on this other device, preventing GRE (port 47) traffic from getting through?

    >>>>PPTP uses port 1723 for tunnel authentication and control, while port 47 handles the tunnel payload. Unless both ports are open, you won't get a working connection. 

    Also, I tried temporarily putting in a new rule #1 in the packet filters as Any - Any.  No luck

    Thanks anyways....Any other ideas? 
  • 0 in reply to bdog68
    Hmmm.  Looking at your logs, it seems to me that the port 1723 authentication worked, but the GRE (port 47) payload connection never got opened up.

    It has been a while since I played with PPTP connections on Win2K, as I use WinXPpro exclusively these days. Win2K tended to be less forgiving than WinXP if the protocols bound to the VPN virtual interface on the client did not exactly match  what was available on the PPTP host. WinXP is more forgiving in this regard, making a best effort connection. But the WinXp VPN client connection, as initially created by the New Connection Wizzard, defaults to "Auto", which makes  it first try to create a L2TP connection with the ASL box, something that simply won't work with ASL v4. Changing "Auto" to "PPTP" under "Properties", "Network" tab fixes this. 

    I'm just thinking aloud here, hoping that I might give you some ideas for things to look at.

    The high CPU utilization issue puzzles me.
    How much RAM do you have in the ASL box?
    How much swap space is it using?
        
  • 0 in reply to VelvetFog
    Resolved, for now,  [:)]

    VF...thanks for the quick responses.   

    I noticed that on the _working_ ASL, there were two .pid and one .tdb files in /var/chroot-pptp/var/run .

     On the _failing_ system, I never saw a ppp0.pid so I moved /var/chroot-pptp/var/run/pppd.tdb and tried connecting again.  

    Connect fine now via pptp, and ppp0.pid and pppd.tdb both showed up again w/ no high CPU issue.  Shot in the dark seemed to have worked.     
Cookie Information Banner