Friday, December 28, 2007

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.

Saturday, December 22, 2007

syslog-ng stuff and christmas

We've been busy recently on the syslog-ng front. A new release came out from both the Open Source and Premium Editions, covering various bugfixes, the most important being a fix for an easy denial of service. Please upgrade to at least OSE 2.0.6 and PE 2.1.8, my bugtraq posting has more details.

A new release from the syslog-ng documentation was also published, it contains a new chapter on losing messages and another one which explains the "Log statistics" message generated by syslog-ng.

And since, I'm writing this entry I wanted to say "Merry Christmas" to all the readers of this blog:
Marry Christmas and a Happy New Year.

I'm spending the winter holiday with my wife and I'm going to travel a lot around the country to visit relatives. So I'm not sure I can be very productive in the coming days.

Friday, December 07, 2007

syslog-ng disk based buffering

I've just seen a post on the loganalysis mailing list how easy it is to implement disk-based buffering with perl and a few hours time. The implementation would be as simple as sending the messages to a file and using a script like "tail -f" to follow the file and send messages to the desired log collectors.

Although the scheme that was described would work, I see three important problems:
  • latency: because the solution would work by polling the log file, the latency is severely increased, when you have thousands of log entries per second, a second is a long time. And you don't want to poll more often than every second.
  • disk usage: relaying the data would store everything on the local disk, no upper bound on disk usage, if the disk is full, data is lost
  • load: using an interpreted language and the requirement to store all data on disk puts an enormous load on the system that might be spent better elsewhere.
Syslog-ng on the other hand uses a spool file, but this file is only written when the memory based buffer becomes full. For the generic case all messages come and go, without touching the disk at all or having to poll the disk for changes. The disk space requirements are bounded. Disk buffering with the combination of flow-control and disk buffers you can avoid message loss.

And what's more, the disk spooling in syslog-ng is an independent feature for all flow-controllable destinations: tcp(), unix-stream(), pipe(), program() and also sql().

Adding a disk buffer to a destination is as simple as specifying the buffer size in bytes:

destination d_tcp { tcp("logserver" log_disk_fifo_size(100000000)); };

This means that a 100MB of space is allocated for disk-based spooling to store messages whenever "logserver" is not fast enough or is unavailable.

For more information read the syslog-ng documentation about the way this feature works.

Saturday, December 01, 2007

IBM System i

I was learning computer programming while at secondary school, at as a school assignment we had to create an accounting system on a venerable IBM 360. We had 386dx computers back then with 2MB RAM, the first Linux encounter at this time required me and my friend to put all of our RAM modules to a single computer to get 4 megs and make it suitable for Linux.

This 360 machine had two CPUs, each the size of a large office desk, speed comparable to an 386, had 8MB of RAM. After getting used to the speed it provided (had 8 terminals on a 2400 baud modem) it was fun, completely different to the PCs we've had, but still, interesting.

Some of this memories were brought back by our partnership with Patownsend & Associates, a US based company to deliver System i (formerly AS400) and System z (the mainframe) software. Our partnership focuses on the development of a Syslog agent for System i, this way we could extend our syslog-ng Premium Edition offering with support for IBM midrange servers.

AS/400 (or System i), is a very interesting platform, somewhat reminding me to the IBM mainframe at secondary school. Text display on tn3270 terminals, all commands always starting with the letter 'Q', filenames condensed to a point where it is difficult to understand their meaning (QAUDJRN anyone? :) ), but at the same time a very consistent and very use-case oriented interface. The system is very complete, while a UNIX contains the stream-of-bytes file concept, OS/400 supports many different file types, for instance there's a file type of SQL tables, a complete DB2 is integrated into the OS itself.

It was a great experience to work with the Patownsend guys, knowledgeable people, who know what they are doing. I'm looking forward to our cooperation.

Wednesday, November 07, 2007

public bugzilla

I've started creating a public bugzilla installation for syslog-ng in the last couple of days, however I was interrupted before being to finish it all.

I want to move all opened internal tickets to the public installation, but I only managed to review half of them. Not that it is a large task, I just got distracted all the time by my fellow collegues and customers. But that's the life of a software developer, right? :)

You can find this at http://bugzilla.balabit.com/ , although it is not yet officially announced. Once I'm done with reviewing/translating tickets, I'll send an official announcement to the mailing list.

Wednesday, October 10, 2007

syslog-ng git repository moved

As I announced on the syslog-ng mailing list, the official syslog-ng git repositry has moved and has become accessible using the more effective "git" protocol, instead of plain HTTP.

The change has been described on the syslog-ng webpage, gitweb is also available.

Saturday, September 22, 2007

syslog-ng HP-UX updates

I've just pushed out an update to syslog-ng, which contains various HP-UX fixes backported from the Premium Edition of syslog-ng.

The GPL version of syslog-ng should now work flawlessly on HP-UX. There's one caveat though: there's a buggy system header in HP-UX and gcc 4.x fails to compile it. I copied this header to the gcc private include directory (/usr/local/lib/gcc/hppa2.0w-hp-hpux11.11/4.1.0/include on my system) and applied the following patch:

438a439
> #ifndef _APP32_64BIT_OFF_T
442a444
> #endif

(HP-UX diff does not know how to produce unified diffs), the point is that there are two conflicting declarations of a function and the preprocessor conditional above fixes that. Once this patch is in place, and you have the proper build dependencies syslog-ng works fine on HP-UX.

As I've just pushed these changes to my git repository, you'll need to wait for another day to get a daily snapshot. But hey "git" is what the pros use :)

Saturday, September 15, 2007

Reasons of my silence

Apart from the previous entry I was not posting to this blog for two months. The reason was that I was heavily involved in the development of BalaBit Audit Player, a graphical application to replay RDP/SSH sessions, recorded by our SCB product.

BAP became much larger than I originally expected, it's about 20k lines of code, and the end of the development was done in a rush to meet our deadline of Sep 1, 2007. We've slipped a couple of days, but we've released BAP 2.0.0 on 7th September. Then I spent a week in Karlsruhe on the 5th Netfilter Developer's Workshop.

I returned to Hungary on Friday, I'm spending the weekend with my parents, and hopefully I can be more active on other things, like the syslog-ng mailing list, or this blog. :)

A release of syslog-ng GPL is long due, hopefully I can prepare it next week. I'll also need to schedule some syslog-ng development time as there are some open feature requests by customers.

Netfilter workshop

I've just returned from this year's Netfilter Developer's Workshop, this time held in Karlsruhe, Germany. This year's workshop was the fifth such event, and this time even David S. Miller was there.

All in all the organization was wonderful, kudos to the Astaro guys. We've had about 30 attendants, the largest workshop ever. You can read more about the workshop at http://nfws.inl.fr/en/

Krisztian Kovacs and me were trying to push our TProxy4 patches for merging, the future for tproxy seems bright, as everyone was positive.

We also have some other, minor patches in the queue, I'm working on finalizing them and submit them for inclusion. These are:
  • SO_MARK socket option to be able to specify the mark field of outgoing packets, generated sent from a given socket
  • an extension to the "addrtype" match to limit the match to the incoming interface
  • the notion of interface groups, that make it possible to match a group of similar interfaces
As always, it was very nice to meet Netfilter people, let's hope we meet in Paris next time. :)

Saturday, July 28, 2007

SFTP proxy

I was spending the last couple of hours to implement a simple SFTP proxy, that is capable of logging file transfers, into our Shell Control Box product line. The core idea behind SCB is to perform RDP/SSH screening independently from the end-systems. This SFTP functionality will be a small bonus: in addition to dumping the SSH traffic to an audit trail, we are going to be able to write log transactions to syslog, which is way easier to analyse, if all you want to know is the list of files accessed via SFTP.

I originally thought that SFTP was as simple as FTP, with a transaction being a complete file transfer.

On the contrary, SFTP is much closer to NFS (and other network file system protocols) in spirit: in FTP you have a "RETR" command that fetches a complete file, in SFTP you need to open the file and read it separately using a series of "READ" commands.

Now I understand how sshfs is possible. I thought I'd let you know :)

By the way, syslog-ng 2.0.5 has been released recently. Hopefully this will decrease the stream of "Syslog-ng does not compile, please help" complaints, which was caused by my lazyness to enable spoof-source support unconditionally by default, without writing a proper configure.in test whether libnet was present on the system.

Sunday, July 22, 2007

Syslog-ng status

Things were progressing steadily on the syslog-ng front. About 4 weeks ago I released syslog-ng Premium Edition 2.1.5 which was the first version with integrated SQL support. Since then the first production deployments of PE have been done, shaking out some newly introduced bugs in the process (thus the releases 2.1.5a - 2.1.5d).

Disk buffering works nicely, especially when combined with the new rate-limit option (throttle), if your backend systems are calibrated to a given rate of incoming messages, syslog-ng can ensure that the limit is never exceeded. Whenever bursts end, syslog-ng feeds the messages towards the back-end systems in their idle time. This introduced some latency though.

I've started working on support for the new syslog-protocol work in IETF, but nothing is ready yet. After this is finished, I'm planning to release syslog-ng 2.1 under the GPL license, with some of the new features added.

The GPLd branch also saw a couple of fixes, no release though. If you want the latest set of fixes, please use a daily snapshot.

Saturday, May 26, 2007

Latest happenings

I forgot to mention here that syslog-ng 2.0.4 was released about 10 days ago. Before making an upgrade, be sure to revalidate your max-connections() setting. As previous versions in the 2.0.x tree has failed to enforce this limit.

Apart from the usual bunch of bug fixes, this release features case-insensitive regexps and the ability to track logrotated source files. Now you can actually track any log file, even if it is rotated automatically.

We have also worked hard on the new syslog-ng webpage. Hopefully no information was lost during the transition. If you miss anything that was present on the old one and not available on the new, please let me know.

I'm planning to set up a public bugzilla and a wiki for syslog-ng, so that it will have the standard infrastructure needed for a modern open source projects. Version control, bug tracking and Wiki.

On the Premium Edition front, both the syslog-ng Agent program for Windows and syslog-ng has seen a public release. Check out the syslog-ng Premium Edition pages for more information.

Monday, April 30, 2007

syslog-ng database support and other fixes

As the readers of this blog might know I've been working on persistent disk-buffering and SQL support recently. The configuration interface of the SQL destination became quite close to the description I gave in my last post.

I think from the user side it is pretty neat, no need to rely on the mysql client program or to create "buffer files" that are later fed to the database server. You simply define an SQL destination and tables are created automagically with proper (possibly even disk-based) queueing, flow control and error handling. And by using libdbi we immediately have support for 4 or 5 different database servers.

The implementation side was somewhat more intrusive however, the client libraries for various database servers use a blocking I/O model and syslog-ng was completely non-blocking until now. I had to create a separate thread for inserting records to tables, and there came some required changes to syslog-ng to support that: various reference counters and the internal acknowledge mechanism had to be made thread-aware.

This was not without benefit though, a change of this scale required a thorough review of the code involved and I have found and fixed several bugs that also affected the 2.0.x tree. I have committed some of these to my public git tree already, so it should be synchronized to our public webserver real soon now.

My next thing to do is to prepare 2.0.4 and probably a first public release of the 2.1.x open source tree. Stay tuned. :)

Tuesday, April 24, 2007

Persistent disk-buffering in syslog-ng

Two blog spots in a row on two consecutive days, wow :) Things are happening fast these times. Because of my company's efforts to create a commercial fork of syslog-ng, I have somewhat more time to do syslog-ng hacking. This time I've finished persistent disk-buffering, an often requested feature to be released in the commercial version.

It means that if a target server is down, then in addition to the in-memory buffers, syslog-ng is able to store messages in a disk-based queue until the connection is restored. What's more, this queue is persistent and syslog-ng keeps its contents accross restarts.

One less reason to keep logs locally. :)

Next on my list is native SQL support, combined with this disk-buffer feature to cover times when the database is too slow processing INSERTs. I'm thinking along the lines of:

destination d_sql {
sql(type(pgsql) host("loghost") user("syslog-ng") password("secret-password")
database("logs")
table("messages_
${HOST}_${R_YEAR}${R_MONTH}${R_DAY}")
columns("date", "host", "program", "pid", "message")
values("$R_DATE", "$HOST", "$PROGRAM", "$PID", "$MSGONLY"));


};

Tables would be created/altered automatically on-demand, just like destination files. Values might refer to builtin macros, or matches within the message (like in sed, e.g. $1 refers to the first match).

The actual implementation might be somewhat different though.

Sunday, April 22, 2007

Switching version control systems

We have been using GNU arch the last couple of years as a version control system, however Tom Lords' implementation does not scale well, and some of our software packages have 10 thousands of commits. This means that a single commit operation may take _minutes_. It is awful to wait so much time for a single commit, and it really degrades productivity.

I was considering Mercurial, Bazaar-NG and git, however this was not an easy decision, as the "modern" version control systems promote the use of branches over anything else, and our current version control model relied on cherry-picking heavily:
  • developer commits the solution for each bug separately to his/her branch
  • QA people pick patches from developer branches and integrate them to a 'test' branch, once the test was successful,
  • release manager picks patches from the 'test' branch and integrates to mainline, if he doesn't find anything odd during review
This worked wonderfully in GNU arch, but new VC systems lack in this area. Bazaar has no cherry picking support at all, Mercurial has some incomplete support with a plugin named transplant, git has cherry picking, but that relies on heuristics (it guesses whether a patch was integrated by using a checksum of the patch).

I was considering to change the process I outlined above, but I'm not sure how that would work out. We sometimes need to work with people not really experienced with VC systems at all, asking them to manage their own branches for each bugfix/problem group seems to raise the bar a bit too high.

Nevertheless git seemed to have solutions for both worlds (e.g. picking patches AND merging branches), so I choose git over the other two, and now I converted some of the syslog-ng history to git in order to gather some real-life experience.

I like what I see so far, git 1.5.x is really way better than older versions on the usability and documentation front. I now feel comfortable enough with git as I could finally understand the working model and the structure of the git history.And git is fast like lightning :)

Monday, March 26, 2007

syslog-ng 2.1 is branched

I've just finished preparations for the release of syslog-ng 2.0.3 and now I consider the 2.0.x branch feature complete. As far as I know there's no feature that was present in 1.6.x and missing from the 2.0.x rewrite. The last missing bits were spoof-source and TCP wrapper support, but as those are present in 2.0.3 I consider syslog-ng 2.0 feature complete. I don't plan to add further code that would cause destabilization.

Now some plans about the newly opened 2.1 branch: we (as BalaBit) played with an idea of creating a commercial fork of syslog-ng which could increase the amount of resources that I can allocate to developing syslog-ng code. From 2.1 on, two parallel editions of syslog-ng will become available:
  • syslog-ng 2.1 Open Source Edition: the same as syslog-ng 2.0, available under the GPL
  • syslog-ng 2.1 Premium Edition: a commercial fork of syslog-ng,
The two releases will be produced from the same source tree with some of the commercial functionality stripped during the release process. This ensures that bugfixes/changes that are developed in the branch will automatically be released with the open source edition as well.

In the first release, the difference between the two editions are as follows:
  • TLS support,
  • Support for a Windows agent, capable of sending log messages in syslog-ng's extended log format and TLS encryption.
  • New, updated manual (also covering the Open Source Edition).

Saturday, February 03, 2007

spoof-source added to 2.0.x

As a commenter missed spoof-source support from 2.0, I got my act together for an afternoon hacking session and implemented it in the 2.0.x tree.

The packet generation for IPv4 packets was straightforward, I could simply "forward-port" it from 1.6.x, after creating the proper place for it in the 2.0.x tree. IPv6 support was a bit more difficult as libnet has a nasty bug with IPv6 and UDP. I was looking at my code for hours, when I tried Google codesearch to check whether I was doing something wrong. Then I've found this. Note the comment above the libnet_build_ipv6() call. I also disabled UDP checksumming and now it works like a charm. The last libnet release was almost 3 years ago, it is not reassuring that its webpage is also down. Too bad, libnet is a fine piece of software, but now as its website is down where can I point syslog-ng users to download libnet from?

By the way, I did not announce syslog-ng 2.0.2 here, it was released about a week ago. Nothing fancy, primarily portability fixes and a more important fix in the usertty() destination. Grab it from the usual place.

Tuesday, January 30, 2007

Long time no post

It's been a while since I last posted here. The reason is simple: work and the lack of time. OK, I know, people have time for what they want, but:

* We are launching a nifty new product based on Zorp, but with a much tighter focus. A device capable of recording and replaying SSH sessions for audit purposes.
* We have decided to migrate from C to C++ for our management interface, as it seems Gtk+ style OO programming in C really requires a skill, and a lot of developers don't have that. C++ holds their hands somewhat. Thus, I've been refreshing my C++ skills and learning gtkmm while writing a prototype.
* and of course the "usual" amount of work.

I've tried to provide timely response on the syslog-ng mailing list. I'm sorry if you didn't receive an answer/patch from me in time.

By the way I released syslog-ng 2.0.2 yesterday. Nothing really important, some portability fixes, some usertty fixes and an option missed in the 1.6.x -> 2.0.x change.

Another good news is that Fedora seems to be migrating from syslogd to syslog-ng in Fedora 7. That's simply great :) Guys, if you need help, just drop me a line.