Performance degradation of ausearch depending from rotation settings
Hello!
audit 3.0.8, glibc 2.31.
The first configuration:
localhost ~ # grep -e num_logs -e max_log_file -e max_log_file_action /etc/audit/auditd.conf num_logs = 10 max_log_file = 100 max_log_file_action = ROTATE
There are 100 files of 10 MB, ausearch takes a long time:
localhost ~ # time ausearch -k adjtime real 1m51,008s
If I set 50 * 20 MB or 100 * 10 MB, then ausearch takes about 30 seconds, but the total size of logs is the same.
I tried to understand why this happens, looked into the code and saw nothing special, it seems to just read the files line by line...
Is this a known issue? If yes, I would suggest to document it and recommend optimal log sizes.
This is expected. The extra open/close takes time. Also, ausearch opens files with the memory map flag. That also adds startup/shutdown costs. It is impossible to guess what is optimal for any workload. You may want to optimize for searching. Someone else may want to optimize for the rotation to contain about a days worth of events. It really depends on what your rules are as to how much logging you get. I personally use 100 for the log size.
This is expected. The extra open/close takes time. Also, ausearch opens files with the memory map flag. That also adds startup/shutdown costs.
But then 10 files per 100 MiB would be processed faster than 50 files per 20 MiB and it would make sense, but it is not so...
I don't have a good answer for why it's taking longer. One thing is that it starts with audit.log.1 and check it exists and then increments until it finds the oldest file, then it turns around and starts processing them. I wouldn't think the check for existence would account for all of the extra time. But it is another difference.
Thanks for reporting this. I have no good explanation for this. The perf command might show something in the kernel that is causing the delay. Unless there is a pull request, I won't be able to look into this. Closing this out.