100% CPU-load and memory leak (v5.2.0)

[Hexogen]

Software/OS: WinGate v5.2.0 on Windows 2000 SP4, with KAV plugin v1.2.1/4.0.2.22

WinGate config: NAT, transparent proxy, firewall and KAV plugin enabled.
Traffic to port 80 is being redirected to an internal web server.

What happened: The WinGate server suddenly became unresponsive. Only reacted to a ping.
When I unplugged the internet connection (without a reboot), the server was responsive
again. WINGATE.EXE had allocated almost 1 GB of RAM (although according to the Task
Manager it was only using 10 MB or so), and written more than 230 thousand lines in
the NAT log! A server reboot was still needed to get everything working again.

Some snippets from the logs:

WWW PROXY LOG:
...
12/02/03 18:14:17 192.168.1.13 Guest 0000030854 Requested: http://www.promise.com/images/home/bg.gif
12/02/03 18:14:17 192.168.1.13 Guest 0000030849 Traffic 2082 309 253 2082 1s
12/02/03 18:14:17 192.168.1.13 Guest 0000030851 Traffic 752 316 260 752 1s
12/02/03 18:14:17 192.168.1.13 Guest 0000030854 Traffic 391 306 250 391 0s
12/02/03 18:14:59 192.168.1.13 Guest 0000030853 Traffic 5315 316 260 5315 42s
12/02/03 18:15:19 192.168.1.8 Guest 0000030856 Error: Malformed Request
12/02/03 18:15:24 192.168.1.13 Guest 0000030855 Traffic 0 0 0 0 26s
12/02/03 18:15:24 192.168.1.8 Guest 0000030856 Traffic 336 557 0 0 21s
12/02/03 18:15:34 192.168.1.13 Guest 0000030857 Requested: http://www.promise.com/
12/02/03 18:15:34 192.168.1.13 Guest 0000030858 Requested: http://www.promise.com/Products/FastTra ... _Sheet.pdf
12/02/03 18:15:34 192.168.1.8 Guest 0000030859 Error: Malformed Request
12/02/03 18:15:34 192.168.1.8 Guest 0000030859 Traffic 336 199 0 0 8s
12/02/03 18:15:57 192.168.1.13 Guest 0000030857 Error: Caught socket exception in CWWWSession::HTTPProcessRequest() Connection to Remote Host timed out - terminating
12/02/03 18:15:57 192.168.1.13 Guest 0000030858 Error: Caught socket exception in CWWWSession::HTTPProcessRequest() Connection to Remote Host timed out - terminating
12/02/03 18:16:00 192.168.1.13 Guest 0000030857 Traffic 215 254 0 0 51s
12/02/03 18:16:00 192.168.1.13 Guest 0000030858 Traffic 215 230 0 0 41s
... no other entries until the reboot (30 minutes later)


NAT LOG:
...
12/02/03 18:11:34 192.168.1.8 Guest 0000030600 Requested: NAT: UDP 192.168.1.8:2592 <-> 131.x.x.x:123
12/02/03 18:12:05 192.168.1.8 Guest 0000030598 Traffic 0 76 76 0 31s
12/02/03 18:12:05 192.168.1.8 Guest 0000030600 Traffic 76 76 76 76 31s
12/02/03 18:12:10 192.168.1.8 Guest 0000030599 Traffic 124 63 63 124 36s
12/02/03 18:14:19 Authorisation failure: NAT STATUS: firewall relay: TCP src 64.x.x.x:0 dst 213.x.x.x:80
12/02/03 18:14:19 Authorisation failure: NAT STATUS: firewall relay: TCP src 64.x.x.x:0 dst 213.x.x.x:80
12/02/03 18:14:19 Authorisation failure: NAT STATUS: firewall relay: TCP src 64.x.x.x:0 dst 213.x.x.x:80
... more than 230 thousand lines in less than 2 minutes! ...
12/02/03 18:16:11 Authorisation failure: NAT STATUS: firewall relay: TCP src 64.x.x.x:0 dst 213.x.x.x:80
... no other entries until the reboot (30 minutes later)


Although this may look like a DOS-attack, I think these authorisation failures are
probably being caused by some sort of infinite loop or other problem in WinGate.
Possibly triggered by a single malicious or corrupt packet.

This happened within a day after updating WinGate v5.0.9 to v5.2. So far it only
happened once, but I'm afraid this problem may occur again.

Any ideas? Perhaps there's a setting I can try?

[adrien]

Hi

This NAT log message happens if you have that port number configured in the ENS to "notify when this range is accessed", so I would also expect that the firewall tab in GateKeeper (if open) would have filled up pretty quickly as well.

How fast is your internet link? Would it have been fast enough for each of these log entries to have been triggered by a packet each, or would the loop theory then come into play...

also the source port of 0 is odd in the log message. Were all the source IP addresses different? That would be a clue to whether it really was a SYN flood or not.

Sounds like the main loading on the server was due to the logging though - WinGate queues log messages internally whilst it is logging them to disk.... if the number of items inserted is much more than the disk can handle, then they can back up inside WinGate (shows as VM in Taskmon rather than memory)

Adrien

[Rroff]

I'm having this problem crop up repeatedly with Wingate 5.2.0, after ~50hours of run time the server will be crawling with 100% CPU used and all physical memory allocated. Both times I actually looked into it the wingate process was allocated 380megs of memory, the machine only has 256Mb physical memory, sorry I can't provide more details, but this time I was woken in the middle of sleeping, to fix it, and I simply uninstalled wingate and reinstalled an older release.

At this point I've had to give up and go back to 5.0.7 the build that runs the longest before problems crop up. We ever gonna see a decent build of wingate 5.x? this is the first time I've run into memory/cpu problems with wingate 5.x tho I've seen it a few times with the 4.x series. But I'm constantly plagued with DNS problems, certain web pages not loading (they load fine on the server, but not on the clients) and the most annoying one is the BSOD with an error related to some qbik dll, which happens fairly frequently depending on teh build of wingate I'm using.

EDIT: Just mention, I have logging disabled for most stuff other than the ENS/Firewall stuff. My IP is fairly well known :( and at times I get around 50+megs of firewall details logged in 24 hours, tho I think the avg. is around 20megs. Also I'm on a fairly fast internet connection.

[Hexogen]

Thanks for your reply adrien.
Option "notify" (and also "cloak") is indeed enabled for the redirect of TCP port 80.
The general UDP/TCP logging options (ENS firewall tab) were enabled as well.
GateKeeper was also opened IIRC.

The internet link is max 2 Mbit/s, but with lousy latencies and a large packet loss
(probably caused by the ISP). During the problem, before I unplugged the cable, I
checked the traffic LED on the internet NIC, and it was blinking like usual.
The internal web server (to which all traffic is redirected) didn't receive any
requests (not HTTP at least). And according to the WinGate logs, there was only 1
remote IP-nr involved, using port 0. (v5.0.9 sometimes also reported a remote port 0
by the way) So it's not very likely that the problem was caused by an attack.

Although... I just noticed yesterday's WinGate system log, it also contains about
230 thousand lines. Each line is 179 bytes (160 bytes excluding date/time/tabs),
containing some obscure data (perhaps an attack packet, although I'm not sure if
those should end up in the system log). However, these lines are spread over a
longer period (first at 18:14:19 and last at 18:38:14), starting with just a few
lines per second. Whereas in the NAT-log there are 230 thousand lines within 2
minutes (18:14:19 to 18:16:11), immediately starting with 1000+ lines per second!