UT9.02 High disk usage by nodes.log and node-4.log caused by “Non-Http Blocking”

[Przemek]

=========================================
There already were some posts on this topic:
- http://forums.untangle.com/hardware/...g-up-fast.html
-http://forums.untangle.com/feedback/...-since-v9.html
-http://forums.untangle.com/installat...d-80-free.html
- http://forums.untangle.com/web-filte...d-x-got-y.html

I decided to start new one with vital information in the topic
I'm not quite sure is it right forum for this topic, if no please move it.
=========================================

In my UT 9.02 I have also encountered the problem of rapid grow disk usage and sometimes also high CPU usage.
In my case the source was not Captive Portal, since It concerns UT9.1.

It came up it is from log files in /var/log/uvm:
nodes.log and node-4.log
Size of those files rising quick and stabilizes at about 22 gigs each !!!
Writing that amount of data consumes lot of CPU power.

As discovered by Merome in http://forums.untangle.com/web-filte...d-x-got-y.html, problematic event in the logs is:

Feb 3 08:41:52 localhost node-4: [HttpParser] <TCP125314711> WARN HttpParser server-side expected: 0 got: 72

It came up, that the source of the problem is option:
Config => System => Protocol Settings => Http => Non Http Blocking, which I recently switched to “Stop non-Http traffic to travel over port 80.”

To be sure, I deleted the nodes.log and node-4.log (for clean start) and turn this option on and off several time.

When it is set to “Allow” (default position), that event comes up from time to time in bunch of aprox. 20 lines in few secs.
- Everything looks fine.

But, when switched to “Stop” - nightmare starts.
I thing it also starts from time to time, but the amount of events is overwhelming. I'll give an example:
Time => Line number in log file.
08:41:49 => 1109
08:41:50 => 4003
08:41:51 => 6782
08:41:52 => 8477

That gives over 2400 of lines “Feb 3 HH:MM:SS localhost node-4: [HttpParser] <TCP125314711> WARN HttpParser server-side expected: XX got: YY” per second !!!

On the forum I found that patch:
http://wiki.untangle.com/index.php/9...sive_logrotate

But I don't know it will solve the problem.
I think, best option would be stop logging that warning, is it possible ?

My UT config is:
- UT ver 9.02 in router mode,
- modules running: all free modules,
- approx 15 computers connected in one time.

[Przemek]

I didn't want to give up on “non http blocking on port 80” feature.
To prevent generating ridiculous log files I decided to prevent creating nodes.log and node-4.log files at all:

1) I deleted 2 files: “nodes.log” and “node-4.log” in /var/log/uvm,
2) I created 2 directories named like 2 deleted files: “nodes.log” and “node-4.log”.


I'm watching the results for for couple of hours now and preformed one restart.
So far, everything looks fine. I didn't notice any side effects.
Disk usage is low like it used to be

Just in case , if you will try the same trick, please remember to delete those 2 folders before proceeding with Untangle Update.

[mrunkel]

An easier fix is to just upgrade to 9.1

[MStauning]

mrunkel - If you look at my installs (we have to logon, everytimes we reinstall), you see I've just this weekend installed many 9.1, and some 9.2's.. Every one of then went down with full harddisks when that filter was active. Nodes.log was 44GB on a 9.2Build1 install.

So not a fix..

[mrunkel]

It does fix the logrotation issue.

If the disk fills up within 24 hours of enabling that option, then yes, it's not a fix.

I just re-read the original post, and am struck by this:

Originally Posted by Przemek

It came up, that the source of the problem is option:
Config => System => Protocol Settings => Http => Non Http Blocking, which I recently switched to “Stop non-Http traffic to travel over port 80.”

To be sure, I deleted the nodes.log and node-4.log (for clean start) and turn this option on and off several time.

When it is set to “Allow” (default position), that event comes up from time to time in bunch of aprox. 20 lines in few secs.
- Everything looks fine.

I will start out by noting that the settings page in question says across the top: "Warning: These settings should not be changed unless instructed to do so by support."

Why not just leave that option off if you know that is the cause instead of hacking around in the file system?

MStauning, if you have that option checked as well, please set it back to the default.

If not, then you have a completely different issue.

This warning means that the HTTP parser is unable to understand some (apparently a lot of it) traffic that is flowing through the Untangle on port 80. You need to identify that traffic and bypass or eliminate it or you will continue to have the issue.

[dmorris]

Originally Posted by MStauning

mrunkel - If you look at my installs (we have to logon, everytimes we reinstall), you see I've just this weekend installed many 9.1, and some 9.2's.. Every one of then went down with full harddisks when that filter was active. Nodes.log was 44GB on a 9.2Build1 install.

So not a fix..

cat /etc/logrotate.d/untangle-vm | grep -A6 node
/var/log/uvm/node*.log {
rotate 2
size 500k
compress
notifempty
copytruncate
}


Did you call support?

[MStauning]

Why mine somehow got on in the firstplace, I've have no idea..
But it came back on with every install, since I've just used a backup file to restore everything with (have just made a new backup file, without that setting). 20 Kids surfing from fre to sat did the trick to fill a 80GB disk up. 120 kids can fill a drive up in hours ;-)

Oh did not call support, since the last one I've moved my license to went dead on me.. So just did something to have internet on monday, to have a look at it. Then call support.. But hey it was a "beta" ;-)

Just rm -f n* and it could boot up again its now useing 13.5gb with 1.9Gb spammails.. Not bad, but thats was 62.49Gb of node*.log !!!

dmorris - want do that do? Compress everthing thats over 500k and something else... Going to update it to build3 ;-)