syslog-ng fun with performance

I like christmas for a number of reasons: in addition to the traditional "meet and have fun with your family", eat lots of delicious food and so on, I like it because this is the season of the year when I have some time to do whatever I feel like.

This year I felt like doing some syslog-ng performance analysis. After reading Ulrich Deppert's series about stuff "What every programmer should know about memory" on LWN, I thought I'm more than prepared to improve syslog-ng performance. Before going any further, I'd recommend this reading to any programmer, it's a bit long but every second reading it is worth it.

As you need to measure performance in order to improve it, I wrote a tool called "loggen". This program generates messages messages at a user-specifyable rate. Apart from the git repository you can get this tool from the latest syslog-ng snapshots.

Loggen supports TCP, UDP and UNIX domain sockets, so really almost everything can be measured.

Then I've put together a test environment, which consisted of a 4-way Opteron box as a server (two dual-core CPUs at 2.6GHz and 1MB of cache), where the syslog-ng center ran in 64 bit mode, and a venerable P4 Xeon 2.4GHz as client. I verified that the client was more than capable of saturating a 100MBit link that was used to connect the two boxes. Then I've installed syslog-ng on the server, using the simplest configuration possible: fetching messages from the TCP/UDP socket and writing everything to disk into a plain, text file without macros in the filename.

Syslog-ng 2.o OSE performed somewhat better than I had anticipated. When using TCP it could successfully process messages at about 44000 messages/sec without losing a single message. Each message was 150 byte long (I've started with 200, but the 100MBit link proved to be the bottleneck) Some funny findings:

• Enabling flow-control did not really make the results worse.
• Increasing log-fetch-limit to a large number (10000) made the results worse.
• Using the Glib GSlice allocator instead of malloc/free didn't improve the numbers.

Of course once you have a baseline, there are a lot of possibilities to try how that given change affects performance, but I only had a day :)

I've found some things that improved performance even further, the most important bottleneck was the time related functions in libc (localtime, mktime, strftime, etc.) For some reason they reread /etc/localtime upon every invocation. I'm going to file a ticket in their bugzilla as it's completely unnecessary to do that, especially if the value of the TZ environment variable does not change.

At the end of the day I finished with syslog-ng chewing messages at around 68500 messages/sec which is a 55.9% improvement. I can see some further possibilities, but I doubt I could increase performance over 75000 msg/sec. This means that syslog-ng can process messages at about wirespeed of a 100MBit/sec ethernet link. (68500*150 = 10275000 bytes/sec)

I was very satisfied at this point, even explained my findings to my wife and my elder brother :)

This of course does not apply to legacy UDP based syslog traffic directly, unless a really large socket buffer is set for syslog-ng. I'd say that you need 3-5 seconds worth of receive buffer in order to avoid losing messages, which with the above rate would be about 30MB-50MB of non-swappable kernel memory.

These changes were committed to the Premium Edition of syslog-ng, although the loggen program is GPLed, so anyone can do performance testing their own setup/configuration.