Hi,

Today I picked up a problem with MySQL CPU usage going through the roof.
After quite a bit of testing (*panic*) I finally found that it was only when I was accessed ASL Web.

More digging revealed that my tortix database tables are rather HUGE

alerts table has 1,550,979 rows
ARCHIVE_201201_alert 28,640,493 rows
ARCHIVE_201201_data 28,640,493 rows
data table has 1,550,977 rows

The entire tortix database has 61,063,084 rows and is now 11.2 GiB with a 2.5GiB overhead.

I am no expert, but I am sure that something has gone horribly wrong.

I have disabled logging on events lower than 3 for now try an limit the ever increasing rows.

Filtering the logs I can see 146454 events for the following Level 2 - ID 1002

sa1 abrtd: Corrupted or bad dump /var/spool/abrt/pyhook-2012-03-26-13:38:18-29470 (res:2), deleting

which related to a recent post I made here: http://www.atomicorp.com/forum/viewtopic.php?f=1&t=5811

Spamd Level 2 - ID 1002
Spamdyke Level 2 - ID 103505
Combined have 191346 events

Any suggestions (besides Napalm) would be greatly appreciated.

Based on your input and from another big (1 million+ events a day!) environment, we updated asl_db_rotate to work with these monster datasets better.

Its in the asl 3.0.22 release, so Id recommend you do 2 things:

1) check your rotate schedule under ASL_DB_RETENTION. In 2.0 this was set to 30 days, newer installs default to 7. Adjust that accordingly

2) Run it manually with:
/var/asl/bin/asl_db_rotate

This runs from cron as well, the main thing to look at is the retention period. Im going to guess yours is 30.

Hello Scott

I looked at the ASL_DB_RETENTION yesterday - it was set to 7 Days.
I changed it this morning to 3 Days (is that too low?)

In an attempt to reduce the load and gain access to ASL-WEB, I simply emptied the large tables and stared again.
Sadly, I did not look investigate the date of the first entry in the tables to determine the age.

I will monitor the table more closely over the next few days.

I have disabled logging on events lower than 3 for now to see if that makes any difference.

7 is a good general use setting. If you have huge volume though, go lower since this is just what is stored in the DB. For long term purposes there are also flat files of all the HIDS events in /var/ossec/logs/alerts/.

Thanks Scott, I will monitor and update this post in a few days.

I spent the day trying to find out what was generating all the rows.
Seeing the tortix data table increasing rapidly again, I noticed a large volume of SPAMDYKE entries.

This led me to start filter all mail traffic using the psa-spamdyke interface.
I found this rather sluggish - just the same as ASL was the day before -- MM - must be mega rows
I then connected to the spamdyke database using Navicat

I first ran a query to count by IP

SELECT
spamdyke_log_table.ip,
Count(spamdyke_log_table.ip) AS total,
spamdyke_log_table.`from`,
spamdyke_log_table.time
FROM spamdyke_log_table
GROUP BY ip
ORDER BY count(ip) DESC

This gave me

197.xxx.xxx.xxx 133032 info@***
41.xxx.xxx.xxx 103925 accounts@**

The first IP is the server IP & the other gave me a domain name

I then counted by email address

SELECT
spamdyke_log_table.`from`,
Count(spamdyke_log_table.`from`) AS total,
spamdyke_log_table.ip,
spamdyke_log_table.reason
FROM spamdyke_log_table
GROUP BY `from`
ORDER BY count(`from`) DESC

Email 1 = 132831 - 1 email address - 1 domains
Email 2 = 89577 (1 email address for 41.xxx.xxx.xxx)
Email 3 =14232 (1 email from 41.xxx.xxx.xxx - same domain above)

So email 2 + 3 sent out 103809 email today!

I then checked against the maillog

cat /usr/local/psa/var/log/maillog | grep ***.co.za | wc -l
118619

This one was easy to block because I had the ADSL IP that was sending.

The top offender was sending mail using a PHP script the broadcast a bulk mailer.
This is normal and has been for the past 4 years.
However the number don’t match - the db size of the mailing list is 13000
For an number of other reason, I believe that a another script is running elsewhere sending as well.

Looking at the mail log

cat /usr/local/psa/var/log/maillog | grep newsletter@*** | wc -l
150633

I then filtered by ALLOWED to get check only SPAMDYKE values to get SMTP authorized sends

cat /usr/local/psa/var/log/maillog | grep newsletter@*** | grep ALLOWED | wc -l
132907

OK so great now I know why the two tables - grew at such a rate and why it was killing MySQL CPU
I was also happy to find the two offenders.

My questions related to the original post.

* Is there a way to not log SPAMDYKE messages to ASL?
* Is this a good Idea?
* Is there a way to not log based on keywords?
* I get a load of other events logged (level 2) from the maillog that I don’t really want.


On a side note

Now that I have identified that a user can send over 130 000 emails per day, best I find a way to stop that from happening again.
I did ask once before in this forum if Qmail / Plesk could do it. As far as I remember it can’t set a max send per hour per domain or mailbox.
I think it was Scott who mentioned that Postfix can – but that is not an option – I really like Qmail and Spamdyke.

A collogue of mine suggested maybe using IPTABLES to limit 300 connections per hour.

$IPTABLES -N SMTP_CHECK
$IPTABLES -A INPUT -p tcp --dport 25 -m state --state NEW -j SMTP_CHECK
$IPTABLES -A SMTP_CHECK -m recent --set --name SMTP
$IPTABLES -A SMTP_CHECK -m recent --update --seconds 3600 --hitcount 300 --name SMTP -j LOG --log-prefix="SMTP ATTACK: "
$IPTABLES -A SMTP_CHECK -m recent --update --seconds 3600 --hitcount 300 --name SMTP -j DROP

Is this an option?
If it is - is there a clever way to do this maybe through ASL?

In the interim, I have through about setting up a script that runs the query against the spamdyke table and counts on a per hour basis.
If the count > X, then it fires off an email to the offending email address & one to myself

This is more of an early warning system - rather be proactive that reactive as I have been the past two days.

you can turn logging on/off for a rule through the rule manager. Other actions (like blocks) would still occur, it just wouldnt capture it in the DB.

I've unfortunately been hit by the same problem.

It was triggered when I did a live migration of the Container (VPS) between two hardware nodes. After the successful migration, I logged in to the GUI because I saw a large-ish number of asl-shun.pl processed with delete then with add going on, and I wanted to know what was going on. The gui took ages to respond, with MySQL using 100% CPU for soome time.

It responded eventually (many minutes) with a huge list of INNODB shutdown messages listed (these are level 3 so I don't know why they were visible). There are 227 pages in total in the GUI, even with a 7 day retention span (and there's nothing other than the expected single entry in /var/log/mysql.log and nothing in /var/log/messages so I have no idea where these INNODB messages came from).

I restarted the Container. Still takes a minute or two for anything to appear when I login to the GUI. Still 100% CPU. Also takes ages and ages to view an entry in the log, or change from level 7 to level 3 (where these INNODB entries are).

I'm migrating the data from this Plesk installation to a shiny new one on Saturday, so there's no big deal right now, but please can we have a way to purge the DB is we need to, if a situation like this arises again in the future? Obviously this isn't an isolated incident.

I think there used to be a script that could kill off old entries, but I can't remember if that was pre-GUI (database) days or not, and in any case I can't find a reference to it anymore.

Faris.

we are having the same problem across dozens of servers, and its causing huge customer impact.
We need to either get this fixed asap or turn off the tortix DB part completely until a fix can be made.

I wonder if ossec is logging stuff with .22 that it didn't log before? something really common, which is clogging up the database, and causing additional load by logging them in the first place?

When I had the patience to wait all those minutes after each click of a button I did see stuff I wasn't expecting to see - like individual normal pop3 logins - but I don't usually look below level 6 so it is possible these have always been logged.

When I looked at one box at random, the first 10 pages were all the same thing basically:

Integrity check sum
FTP Logins (both good and bad)
Wordpress Brute force logins
/proc and /tmp counts not matching
yum packages installed/removed
log file rotation notifications or inode changes

Those items were almost all of the entire first 10 pages, I got tired of paging through them after that.

It just really sucks that on 3/25 everything was working great, and then by 3/27 with asl-3.0.22-0.6.el5.art.x86_64 everything was on fire. So something has definately changed since asl-3.0.22-0.5 that has introduced this problem.

We didnt change anything in OSSEC or its rules in the 3.0.22 release.

Fortunately only one of our systems is currently affected. Unfortunately the one I mentioned didn't get migrated as planned -- I'll have to wait until this weekend. The ones running el6, 10.4.4 and spamdyke are fine, although they are low traffic.

OK, lets try to find something in common with the machines that are experiencing problems:

Mine: virtuozzo-based el4, plesk 8.6, no spamdyke.

In my case all of the machines have >2mm rows in the ossec alerts/data tables, and the asl_db_rotate script is not removing the old rows based on the db retention period. It was set to 30 days, and I have also tried 7 and 1 and re-ran the script each time and its still not removing any rows.

There are also numerous tweaks to mysql that were made such as adding indexes, enabling caching, setting max packet size, and also editing the db rotate script itself. I think Scott may have a good handle on whats going on and I really hope soon if not today will release something to address it, as we really would like to see this issue closed out.

That's good to know. Thanks for the update. I'll keep my fingers crossed.