Wednesday, December 21, 2011

Happy Holidays to Everyone!

           *             ,
                       _/^\_
                      <     >
     *                 /.-.\         *
              *        `/&\`                   *
                      ,@.*;@,
                     /_o.I %_\    *
        *           (`'--:o(_@;
                   /`;--.,__ `')             *
                  ;@`o % O,*`'`&\ 
            *    (`'--)_@ ;o %'()\      *
                 /`;--._`''--._O'@;
                /&*,()~o`;-.,_ `""`)
     *          /`,@ ;+& () o*`;-';\
               (`""--.,_0 +% @' &()\
               /-.,_    ``''--....-'`)  *
          *    /@%;o`:;'--,.__   __.'\
              ;*,&(); @ % &^;~`"`o;@();         *
              /(); o^~; & ().o@*&`;&%O\
        jgs   `"="==""==,,,.,="=="==="`
           __.----.(\-''#####---...___...-----._
         '`         \)_`"""""`
                 .--' ')
               o(  )_-\ 
 
Happy holidays to everyone! It was fun communicating with all of your and bringing new features online. This year, we did not only extend rsyslog, but worked an a couple of enhancement in related topics, like log normalization, the log store, better Windows support and many improvements in the web based viewer.

Special thanks to all of who contributed code, good bug reports, ideas and encouragement - or helped funding the project by purchasing support contracts or incidents.

It was a busy year and I will try to relax a bit the next days. So please bear with me if I do not respond as quickly as usual (I will try to even be a few days offline ;)).

Thanks again guys, have a great holiday season and all the best, most importantly health, for 2012!

Rainer


PS: if you enjoy the ASCII art, have a look at the artist's web site!

Wednesday, December 14, 2011

Feedback Request for digitally signed log store

I have just written about how I plan to implement digital signatures in LogStore, the secure store used by LogTools. The log store digital signature proposal details how and when signatures are written and provides reasoning why it will probably happen this way. There are two goals for the proposal: one is to document how things will work and the other, probably more important, one is to draw some feedback. It is easy to get security tools wrong, and even those with highest experience in that area (which I have not!) can fail. So it would be very beneficial to have some other folks read the proposal and comment on weaknesses they find - or simply things they would do differently or add to the overall idea. With that said, please read the (small) paper and provide feedback ;-).

Please keep on your mind that his is not only related to syslog but can  be used with any text-based log (including binary logs that are converted to text, e.g. by base64 encoding them). So it can affect you even if you are not interested in syslog itself. My (mostly uneducated) assumption is that this could be a toolset of great use for computer forensics.

Tuesday, December 13, 2011

LogTools 0.1.0 Released

I finally managed to do the initial public release of LogTools, a set of useful utilities for log data processing. Their current most important feature is the initial version of LogStore, a tamper-proof way to store textual log data especially designed for long-term archival. Note that LogTools perfectly process syslog messages, but can be used for anything that is text-based (like Apache or other application text logs).

I am very happy to finally have the initial release ready. Full details can be found in the release announcement. I initially thought it would become available early last week, but I wanted to create some packages. As I had never done this before, it turned out to become a bit of a problem for me. For the time being, I have settled to do an experimental Debian package via checkinstall. While this is obviously a quick and dirty solution, it enables folks to obtain LogTools via the easy way. Also, I don't think it is too problematic, because in essence only some user-tools are installed that do not affect anything else on the system. But, of course, I'll think about better packaging as the project continues.

At this point, I would be very interested in feedback both on the current tools as well on what would be considered a plus in the future. Please let me know!

Tuesday, December 06, 2011

Announcing LogStore

While it probably is a bit early for a "real" announcement,  I wanted to tell a bit about the project I have been working on the past days, a dedicated storage for (sys)log messages. It will be available as part of LogTools, the actual project I am working with. A key feature of the LogStore format will be its tamper-proofness. I wanted to write such an improved storage system for quite a while. However, I have to admit that the recent journald proposal brought more life to it. While the journald proposal aims at building a kind of Window Event Log for Linux, the LogTools effort is more interested in traditional text log files (but I won't outrule going beyond that in the future).

It is important to note that LogTools, and their storage format LogStore, can protect any kind of text file. Of course, it is great for syslog logs, but you may also secure things like Apache http logs or whatever else you have in text format.

You may probably remember that I was - and still am - very skeptic about the way journald tries to secure logs via hash chains (be sure to read the comments as well!). While the journald propsal has some technical deficits, I learned that many folks we interested in this kind of hash-chaining, even though they knew it would not be truly tamperproof (I followed a lot of forum posts). Seeing this, I thought it may be useful to provide this level of protection inside some simple to use tools, what gave birth to LogTools. Still, my assesment in regard to journald holds to the current LogStore format as well: it is far from being real cryptography, it is insecure and it may be counter-productive if it generates a false sense of security. However, if one knows the limits, it can provide some useful function. So be sure to know what you do when you use these tools!

For LogStore, I have also planned to employ some real cryptography and cryptographically sign the hash chain. This will actually make the log tamperproof in a very strong sense as long as the signing key is not compromised. That functionality will be addressed once the initial release is out.

The LogStore format itself is deliberately defined in a text-tool friendly way and well documented. For your initial review, I have included its man page below.

The LogTools project is currently available only via the LogTools git. I plan to finish the remaining man pages soon (at latest this week), and then create distribution tarballs (and hopefully some simple packages, but this needs to be seen).

Feedback on this effort is appreciated.


NAME

logstore - enhanced log message storage  

DESCRIPTION

The logstore is an enhanced log message storage. It can be used to store log messages in a way that secures their integrity. Currently, all data is stored in sequential files.
The logstore provides integrity checks by chaining of SHA1-checksums. Each log record (except the first) is hashed, together with the hash of the previous record. As such, manipulations inside the log store can be detected, as long as the checksums of all records are not also recomputed. Sequential logstore files are pure text files.
 

FORMAT

A sequential logstore is a text file containing variable-length records. Within each record, there is recordtype, cryptodesignator and content.
recordtype
A single character designating the type of record. Currently only "m" is defined, which specified original message text.
cryptodesignator
Variable length, terminated by a colon. The is printable data that has some cryptographic function. For example, for "m"-type recrods it is the message's chained SHA1 hash.
content
Variable length content terminated by a LF (. For obvious reasons, LF is not permitted within the message. Also, the US-ASCII NUL character ( ) is forbidden in order to prevent trouble with text based tools. It is suggested that only printable characters are used inside the message, but this is currently not enforced.
The structure is recordtype Rsyslog has a modular design. Consequently, there is a growing number of modules. See the html documentation for their full description.
 

SECURITY

In its current form, logstore provides limited security. While it is possible to verify the correctness of the hash chain, an attacker may simply rewrite the complete file, computing new hashes. However, protection can be (manually) gained by saving the last hash inside the file to a separate location. If so, one can compare the last hash with this previously saved information and check if it is still valid. If someone mangeled the store, this will not be the case. Once the authenticy of the last hash has been proven, it is easy to verify the rest ot the file. The logreader (1) tool can be used to do that.
In the future, cryptographic signatures based on public key cryptography will be used to protect the hash chain.
 

SAMPLE

The following is a minimalistic 4-line sample of a sequential logstore file.
m04e3324670626451755aa2257a9b92395e26c2e4:line 1
m347d4500ea11fa41800a58972699e57e0c0d7cd7:line 2
m3c329d40e37ae20c475c06bfaab892892ef4579d:line 3
m807cc61d7b04cbc1f048810df9d3a652988d745e:line 4
Note that all records have "m" in the first postion, designating them as message records. The cryptographic hash in line one is a SHA1 hash of just line one's content, whereas the hashes for lines n (with n>1) are taken after the concatenation of hash(n-1) and line(n), without the colon. So in order to obtain line two's hash, the following string is hashed:
04e3324670626451755aa2257a9b92395e26c2e4line2
 

SEE ALSO

logreader(1), logwriter(1), liblogtools(3)
 

AUTHORS

Rainer Gerhards (rgerhards@adiscon.com)

Tuesday, November 29, 2011

Serious syslog problems?

In the paper introducing journald/Linux Journal a number of shortcommings in current syslog practice are mentioned. The authors say:
Syslog has been around for ~30 years, due to its simplicity and ubiquitousness it is an invaluable tool for administrators. However, the number of limitations are substantial, and over time they have started to be serious problems:
I have now taken some time to look at each of these claims in depth. But before I start, I need to tell that I am working in the IT logging field for nearly 15 years, have participated in a number of standards efforts and written a lot of syslog-related software with rsyslog being a prime example (some commercial tools I have been involved with can be found here). So probably I have a bias and my words need to be taken with a grain of salt. On the other hand, the journald authors also have a bias, so I guess that's a fair exchange of arguments ;). 

In my analysis, I compare the journald effort with what rsyslog currently provides and leave closed source software out. It is also important to note that there is a difference between syslog, the protocol, a specific syslog application (like rsyslog) and a system log message store. Due to tradition, these terms are often used for different things and one must deduce from context, what is meant. The paper applies the same sloppiness in regard to terms. I use best effort to extract the proper meaning. I quote the arguments as they originally appeared inside the paper. However, I rearrange them a bit in order to put related things closer together. I retain the original numbering so that you can compare to the original paper. I also tried to be similar brief with my arguments. Now proof-reading the post, I see that I failed with that. Sorry, but that's as brief as I can provide serious counterargument. I broadly try to classify arguments in various levels of "True" vs "Wrong", so you may take this as an ultra-short reply. 

So let's start with Arguments related to the log storage system. In general, the paper is right that there is no real log storage system (like, for example, the Windows Event Log). Keeping logs only in sequential text files definitely has disadvantages. Syslog implementations like rsyslog or syslog-ng have somewhat addressed this by providing the ability to use databases as storage backends (the commercial syslog-ng fork also has a proprietary log store). This has some drawbacks as well. The paper proposes a new proprietary indexed syslog message store. I kind of like this idea, have even considered to write something like this as an optional component for rsyslog (but had no time yet to actually work on it). I am not convinced, though, that all systems necessarily need such a syslog storage subsystem.

With that said, now let's look at the individual arguments:
5. Reading log files is simple but very inefficient. Many key log operations have a complexity of O(n). Indexing is generally not available.
True. It just needs to be said that many tools inside the tool chain only need sequential access. But those that need random access have to pay a big price. Please note, however, that it is often only necessary to "tail" log files, that is act on the latest log entries. This can be done rather quickly even with text files. I know both the problems and the capabilities, because Adiscon LogAnalyzer, in which I am involved, is a web-based analysis and reporting tool capable of working on log files. Paging is simple, but searching is slow with large files (we recommend databases if that is often required). Now that I write that, a funny fact is that one of the more important reasons for creating rsyslog was that we were unhappy with flat text files (see rsyslog history doc). And so I created a syslogd capable of writing to databases. Things seem to be a bit cyclic, though with a different spin ;)
8. Access control is non-existent. Unless manually scripted by the administrator a user either gets full access to the log files, or no access at all.
Mostly True and hard to make any argument against this (except, of course, if you consider database back ends as log stores, but that's not the typical case).
10. Automatic rotation of log files is available, but less than ideal in most implementations: instead of watching disk usage continuously to enforce disk usage limits rotation is only attempted in fixed time intervals, thus leaving the door open to many DoS attacks.
Partly True, at least in regard to current practice. Rsyslog, for example, can limit file sizes as they are written ("outchannel action"), but this feature is seldomly used and due to be replaced by a better one. The better one is partly implemented but received no priority because nobody in the community flagged this as an urgent requirement. As a side-note: Envision that journald intends to shrink the log and/or place stricter restrictions on rate-limiting when disk space begins to run low. If I were an attacker, I would simply begin to fill the disk then, and make journald swipe out the log store for me.
11. Rate limiting is available in some implementations, however, generally does not take the disk usage or service assignment into account, which is highly advisable.
It needs to be said what "rate limiting" means. I guess it means preventing an application from spamming the logs with frequently repeated messages. This feature is available  in rsyslog. It is right that disk usage is not taken into account (see comment above on implications). I don't know what "service assignment" means in this context, so I don't comment on that one. Rate limiting is more than run-away or spamming processes. It is a very complex issue. Rsyslog has output rate limiting as well, and much more is thinkable. But correct, current rate limiting looks at a number of factors but not the disk assignment. On the other hand, does that make sense, if e.g. a message is not even destined to go to the disk?
12. Compression in the log structure on disk is generally available but usually only as effect of rotation and has a negative effect on the already bad complexity behaviour of many key log operations.
Partly True. Rsyslog supports writing in zip format for at least one and a half year (I am too lazy to check the ChangeLog). This provides huge savings for those that turn on the feature. Without doubt, logs compressed in this way are much harder to process in real-time.
7. Log files are easily manipulable by attackers, providing easy ways to hide attack information from the administrator
Misleadingly True. If thinking of a local machine, only, this is true. However, all security best practices tell that it is far from a good idea to save logs on a machine that is publicly accessible. This is the reason that log messages are usually immediately sent do some back end system. It is right that this can not happen in some setup, especially very small ones.

My conclusion on the log store: there definitely is room for improvement. But why not improve it within the existing frameworks? Among others, this would have the advantage that existing methods could be used to decide what needs to be stored inside the log store. Usually, log contain noise events that administrators do not want to log at all, because of the overhead associated with them. The exists best practices for the existing tool chain on how to handle that.

Now on to the other detail topics:
1. The message data is generally not authenticated, every local process can claim to be Apache under PID 4711, and syslog will believe that and store it on disk.
9. The meta data stored for log entries is limited, and lacking key bits of information, such as service name, audit session or monotonic timestamps.

Mostly wrong. IMHO, both make up a single argument. At the suggestion of Lennart Poettering, rsyslog can force the pid inside the TAG to match the pid of the log message emitter - for quite a while now. It is also easy to add additional "trusted properties". I made an experimental implementation in rsyslog yesterday. It took a couple of hours and the code is available as part of rsyslog 5.9.4. As a side-note, the level of "trust" one wants to have in such properties needs to be defined - for truly trusted trusted properties some serious cryptography is needed (this is not specified in the journald proposal nor currently implemented in rsyslog).
2. The data logged is very free-form. Automated log-analyzers need to parse human language strings to a) identify message types, and b) parse parameters from them. This results in regex horrors, and a steady need to play catch-up with upstream developers who might tweak the human language log strings in new versions of their software. Effectively, in a away, in order not to break user-applied regular expressions all log messages become ABI of the software generating them, which is usually not intended by the developer.
Trivial (I can't commit myself to a "True" or "Wrong" on such a trivial finding). Finally, the authors have managed to describe the log analysis problem as we currently face it. This is not at all a syslog problem, it is problem of development discipline. For one, syslog has "solved" this issue with RFC5424 structured data. Use it and be happy (but, granted, the syslog() API currently is a bit problematic). The real problem is the missing discipline. Take, for example, the Windows Event Log. The journald proposal borrows heavily on its concepts. In Windows Event Log, there is a developer-assigned unique ID within the application's reserved namespace available. The combination of both app namespace (also automatically created) and ID together does exactly the same thing as the proposed UUID. In Windows Event Log, there are also "structured fields" available, but in the form of an array (this is a bit different from name-value pairs but far from totally different). This system has been in place since the earliest versions of Windows NT, more than 15 years ago. So it would be a decent assumption that the problem described as a syslog problem does not exist in the Windows world, right (especially given the fact that Windows purposefully does not support syslog)? Well, have a look at the problems related to Windows log analysis: these are exactly the same! I could also offer a myriad of other samples, like WELF, Apache Log Format, ... The bottom line is that developer discipline is not easy to achieve. And, among others, a taxonomy is actually needed to extract semantic meaning from the logged event. It probably is educating to read the FAQ for CEE, a standard currently in development that tries to somewhat solve the logging mess (wait a moment: before saying that CEE is a bunch of clueless morons, please have a look at the CEE Board Members first).
3. The timestamps generally do not carry timezone information, even though some newer specifications define support for it.
Partly Wrong. High-Precision timestamps are available for many years and default in rsyslog. Unfortunately, many distros have turned them off, because they break existing tools.  So in current practice this is a problem, but it could be solved by deleting one line in rsyslog.conf. And remember that if that causes trouble to some "vital" tool, journald will break that tool even more. Note that some distros, like Gentoo, already have enabled high precision timestamps.
4. Syslog is only one of many log systems on local machines. Separate logs are kept for utmp/wtmp, lastlog, audit, kernel logs, firmware logs, and a multitude of application-specific log formats. This is not only unnecessarily complex, but also hides the relation between the log entries in the various subsystems.
Rhetorically True - but what why is that the failure of syslog? In fact, this problem would not exist if developers had consistently used syslog. So the problem is not rooted in syslog but rather in the fact that syslog is not being used. Lesson learned: even if standards exist, many developers simply ignore them (this is also an interesting argument in regard to problem number #2, think about it...).
13. Classic Syslog traditionally is not useful to handle early boot or late shutdown logging, even though recent improvements (for example in systemd) made this work.
True - including that fact that systemd already solved that problem.
14. Binary data cannot be logged, which in some cases is essential (Examples: ATA SMART blobs or SCSI sense data, firmware dumps).
Wrong, the short answer is: it can be logged, but must be properly encoded. In the IETF syslog working group we even increased the max message sizes for this reason (actually, there is no hard limit anymore).

The longer, and more correct, answer is that this is a long-standing discussion inside the logging world. Using that view, it is hard to say if the claim is true or false; it often even is argued like being a religion. Fact is that the current logging toolset does not work well for binary data (even encoded). This is even the case for the Windows Event Log, which supports binary data. In my view, I think most logging experts lean towards the side that binary data should be avoided and, if unavoidable, must be encoded in a text-friendly way. A core problem with the usefulness of binary data is that it often is hard to decode, and even more to understand, on the non-native platform (remember that the system used during analysis is often not the system where the event was initially recorded).
6. The syslog network protocol is very simple, but also very limited. Since it generally supports only a push transfer model, and does not employ store-and-forward, problems such as Thundering Herd or packet loss severely hamper its use.
Wrong,  missing all improvement made in the past ten years. There is a new RFC series which supports TLS-secured reliable transmission of syslog messages and which permits to place fine-grain access control on who can talk with whom inside a relay chain. UDP syslog is still available and is so for good reason. I cannot dig into the details here, part of that reasoning is on the same grounds why we use audio more often over UDP than TCP. Using UDP syslog is strictly optional and there are few scenarios where it is actually needed. And, if so, the "problem" mentioned is actually a "solution" to a much more serious problem not even mentioned in the journald paper. For a glimpse at these problems, have a lock at my blog post on the "reliability problem". Also, store-and-foward is generally available in rsyslog via action queues, failover handling and a lot of other things. I admit that setting up a complex logging system, sometimes requires an expert. On the "loss issue", one may claim that I myself say that plain TCP syslog is not totally lossless. That claim is right, but the potential loss Window is relatively small. Also, one can use different protocols that solve the issue. In rsyslog, I introduced proprietary RELP for that very reason. There is also completely lossless RFC3195, which is a great protocol (but without future). It is supported by rsyslog, but only extremely few other projects implement it. The IETF (including me) assumes that RFC3195 is a failure - not from technical fact but in the sense that it was too far away from the usual logging practice to be picked up by enough folks. [Just to avoid mis-intepretation: contrary to RFC3195, RELP is well alive, well-accepted and in widespread use. It is only RFC3195 that is a failure.]

Concluding my remarks, I do not see anything so broken in syslog that it can only be fixed by a total replacement of technology. Right contrary, there is a rich tool set and expertise available. Existing solutions, especially in the open source world, are quite modular and can easily be extended. It is not even necessary to extend existing projects. A new log store, for example, could also be implemented by a new tool that imports a decent log format from stdin to a back end data store. That would be easily usable not only from rsyslog but from any other tool that is part of the current log tool chain. For example, it may immediately consume Apache or other application logs (of course, such a tool would require proper cryptography to be used for cryptographic tasks...). There is also need for a new logging API - the catch-all syslog() call is clearly insufficient (an interesting detail fact is that journald promises to retain syslog() as a first-class logging interface -- that means journald can solve none of the issues associated with that API, especially in regard to claim #2).

So extending existing applications, or writing new ones that tightly integrate into the existing toolset is the right thing to do. One can view journald as such an extension. However, this extension is somewhat problematic as its design document tells that it intends to replace the whole logging system. Especially disturbing is that the reasoning, as outlined above, essentially boils down to a new log store and various well-known mostly political problems (with development discipline for structured formats right at the top of them). Finally, the proposal claims to provide more security, but fails to achieve at least the level that RFC5848 syslog is able to provide. Granted, rsyslog, for example, does not (yet) implement RFC5848. But why intends journald to implement some home-grown pseudo security system when a standard-based method designed by real crypto experts is available? I guess the same question can be applied to the reasoning for the journald project at large.

Let me conclude this posting with the same quote I started with:
Syslog has been around for ~30 years, due to its simplicity and ubiquitousness it is an invaluable tool for administrators. However, the number of limitations are substantial, and over time they have started to be serious problems:
Mostly Wrong. But it is true that syslog is an invaluable tool,especially in heterogeneous environments.

Trusted Properties in rsyslog

Today, I implemented "trusted (syslog) properties" inside rsyslog's imuxsock module. The term "trusted" refers to the fact that these properties can not be faked by the logging application, creating an additional layer of log integrity protection. The idea is rooted in the journald proposal, where they are called "metadata" and "trusted fields". Actually I liked the idea implied by "trusted", but thought "property" would be a better name than "field".

The concept is not totally new. Actually, for some month rsyslog can patch the PID field of the syslog TAG with the correct pid, so that this cannot be mangled with. This was based on an idea from Lennart Poettering, which I found nice and implemented quickly (I met him at Linux Tag 2010 in N├╝rnberg, Germany where we discussed this and other things). The core idea is to use SCM_CREDENTIALS so that the OS itself records pid, gid and uid. With the new feature, this is taken one step further. Now, we also query the /proc virtual file system for additional information like the location of the logging application's binary. Undoubtedly, this provides some extra protection against faked messages. On the downside, it has some obvious overhead. A simple and immediate solution to this is to use rsyslog's omfile in zip mode. In journald, overhead is tried to avoid via a proprietary binary format, its event log, which provides compression features (but for syslog transmission the journald event log obviously needs to be decompressed as well). Some restrictions exist with trusted properties, some obvious, some less obvious (see the trusted property doc for details; it also has the list of currently supported properties).

The current implementation is in experimental status. Based on feedback, some specifics may be changed in future versions. Also, the current implementation does not try to be standards-compliant. This will probably also change in the future. I hope that the new capability is useful to the logging community. As a side-note, the new feature, implemented in one morning, also shows that it often is easy to extend existing technology instead of writing everything new from scratch ;)

The actual release announcement will go out either today or tomorrow. The code is available via the v5-devel git branch right now.

Friday, November 25, 2011

What I don't like about journald / Linux Journal

I heard of journald only a couple of hours ago (Tuesday?) and since then some intense discussion is going on. I had a chance to look at the journald material in more depth. I also had a quick look at journald's source, but (as I know) Lennart and I are on the strictly opposite sides in regard to the amount of comment lines in source files (I put half the spec in, Lennart nothing at all ;-)). So I did not try too hard to make sense of the code and my impression is still primarily based on the initial paper (though I have to admit his code is probably simpler as he does not need to carry any legacy nor consider platforms other than recent Linux). 

The contra-syslog arguments can be classified in two classes: vaporware and correct fact. In the vaporware camp are things like the hash chaining "security urban legend", the timezone argument (though he is right in regard to current practice inside distros), syslog network transport and compression (this list is not conclusive). Technically correct is the current store format, different log sources, and free-formedness of messages (I prefer the term "semi-structuredness"). This list is also not conclusive.

I think Lennart makes some good points, but discredits the paper somewhat by going overboard at times. It looks like he really needed some hard selling points (I also got this impression by his usage of the kernel.org breakage to promote this effort...). I think his paper would have been more useful if he had argued only those problems that actually exist. I am in full agreement that there are some spots that really deserve to be changed and addressed. Unfortunately, the paper is phrased in such terms that people not at least at the medium expert level on logging tend to believe everything that is stated.

The question is how the actual problems can best be fixed. Is it necessary to create a totally new infrastructure and throw away everything that exists? Maybe. I still prefer the alternative approach: why not extend existing technology? I modeled rsyslog specifically for this reason to be a highly modular system where extensions can easily be added. As far as I understand, syslog-ng has also moved to such a design in the recent v3 version. In rsyslog, I have accepted even experimental technology inside the source tree quickly. Getting a new log store was on my agenda for quite some month (the syslog-ng commercial fork already has it). I unfortunately had not enough time to implement it - and nobody else helped out with it. Wouldn't it have been a good idea to contribute something to rsyslog instead of crafting something totally new?

Another thing that I strongly doubt is if the Linux journal idea will actually manage to solve the logging format dilemma. Microsoft's event log is in place for 15+ years, and app developer still don't use it correctly (as I initially wrote, the Linux Journal looks quite similar to the Windows Event Log). While I think the UUID idea is actually not a bad one, I seriously doubt all developers will understand and use it (correctly). This is a problem with the Windows Event log as well. One needs to know that a lot of high-profile folks are working for several years (10+) on solving this dilemma. Lennart may be a genius, but I have concerns that he over-promises (but I really wish he has success, that would be a very, very big advantage for the community).

One thing, I have to admit, that disappoints me is that Lennart never approached me with his proposal. He knows me (even personally) and we have worked together on systemd/rsyslog integration. I heard about journald first on a Google Alert and quickly after from some folks who asked me what went on. Then  I found out that the systemd development mailing list also never mentioned any work on journald. So, to me, it looks the idea was well hidden for a surprise at Kernel Summit. Well done, but not my style ;-) This missing openness concerns me. My decisions in regard to rsyslog were controversial at times and dictatorial at others (and for sure sometimes wrong). And we currently have some big and controversial discussion on rsyslog going on (partly fueled by the arrival of journald). But I have always played very open, communicated what I had on my mind (in advance), discussed and did never try to hide something. This, to be honest, is how I expect work to be carried out on an important system component. I also never met Lennart at any of the standard bodies work on logging. Not everyone runs Linux and probably not even everyone on Linux will run journald. So standards matter.

journald log hash chaining is broken

I promised to dig into some of the details of the journald announcement. One of the most hyped features is log hash chaining. Lennart describes this in his paper as follows (highlighting by me):
The Internet is a dangerous place. Break-ins on high-profile web sites have become very common. After a successful break-in the attacker usually attempts to hide his traces by editing the log files. Such manipulations are hard to detect with classic syslog: since the files are plain text files no cryptographic authentication is done, and changes are not tracked. Inspired by git, in the journal all entries are cryptographically hashed along with the hash of the previous entry in the file. This results in a chain of entries, where each entry authenticates all previous ones. If the top-most hash is regularly saved to a secure write-only location, the full chain is authenticated by it. Manipulations by the attacker can hence easily be detected.
For a moment, let's assume he really means what he writes (I somewhat doubt that...). Then this is vaporware. You don't get anything by providing a hash chain by itself. Let's assume you have a log of 2,000 records. Now an attacker wants to remove record number 1,001 to 1,010. All he needs to do is seek to the proper location inside the (binary) file, and remove these 10 records, regenerating the hashes for record 1,011 to 2,000. Now let's assume that you saved your initial hash to write only memory. First thing is that it probably is complicated to read the hash off from an unreadable location (write-only medium, mhhh ;)). Assuming you manage that, you can verify the whole log of now 1,990 records. You will not detect the missing records because the chain as such is perfectly well. This, by the way, is the main reason why I have not (yet) implemented such a simplistic method inside rsyslog.

This approach is "data sheet cryptography" at best. To do it right, you need some crypto experts. Bruce Schneier and John Kelsy have written a non-nonsene paper on securing computer audit logs (often called "Counterpane Paper") in 1999. Note that John Kelsy and others have also written RFC5848, which describes how to securely sign syslog messages. This RFC went through numerous revisions and took a couple of years to complete. An interesting fact is that Albert Mietus reported the first implementation of syslog-sign (as RFC5848 was called these days) on EuroBSDCon in 2002! In his presentation "Securing Syslog on FreeBSD" he nicely describes what needs to be done.

I have not yet implemented this method in rsyslog because it has some serious issues when used in larger environments. When CEE discussed about signature chaining (note the difference to hash chaining!), I wrote a small paper about the issues with log signature chaining and remote logging. As I describe there, RFC5848 addresses only the less complex issues. This is not a failure of it's authors, which for sure are real crypto experts - and me not. This is rooted in the fact that this is a very complex problem and a real good answer is still not known. As you can see, this is not something you can solve in with a few hours (or even days) of hacking.

Let me close with a quote from the journald paper: "The Internet is a dangerous place.". And, indeed, it is. The most dangerous thing in my experience is a false sense of security. I guess black hats will *absolutely love* journald and its crypto stuff ;)

Update: Lennart's non standard (for the logging comminity) use of the term top vs. bottom caused some confusion. Please be sure to read the comments attached to this posting. I probably need to blog about the issue again, but right now there are so many things going on. Again, read the comments, they have all information.

Quick update on log normalization

I just wanted to give a heads up on the status of log normalization. We have just released updated versions of libee and liblognorm. These provide important new features, like the capability to annotate events based on classification. This, among others, brings the libraries more back inline with recent CEE developments. Also, the log normalizer tool is nearly ready for prime time. The "only" thing that is missing is a decent set of rule bases. Thankfully, sagan already has a couple. I guess besides programming obtaining rule bases is a major thing to target.

As soon as I find time (I hope soon!), I'll finalize some lose ends on the software side and get doc online on how to use the normalizer tool. I think with that a great tool for everyday use in log analysis will become available. Feedback and collaboration is always appreciated!

Wednesday, November 23, 2011

funding rsyslog development

To be honest, funding the rsyslog project is not easy these days. It never was, but has seen an extra hit by the current economic crisis. Rsyslog, in its initial phase, has been sponsored exclusively by Adiscon as part of its open source involvement. In 2007, we added rsyslog professional services with things like support contracts or custom development. While some customers used these services, Adiscon was still required to sponsor the project and is so until now. Unfortunately, professional services are not doing extremely well (to phrase it politely) and the global crisis is having a hit on Adiscon's customers. As a consequence, I have been more involved with paid work during the past weeks and could not work as much on rsyslog as I had liked to. The shift in Linux logging that probably will be brought by journald (read blog posting) doesn't strengthen my position inside Adiscon either and works as an accelerator for change...

We have been discussing for quite some while how to improve this situation. While I don't like the idea, we probably need to think about a dual licensing approach for rsyslog. Please keep reading, you can be upset when I have made the rest of my argument ;-). First of all, I really don't like dual-licensing. In fact, syslog-ng's dual licensing approach was one reason that made me start working on rsyslog (blog post). I also know that rsyslog's simple GPL license was one of the major "buying points" that made rsyslog become the default syslogd on Fedora and later many other distributions. In order to permit reuse of rsyslog technology in some other tools, in 2008 we created a licensing model that puts the so-called runtime - a large part of rsyslog - under LGPL (see "licensing rsyslog" and a previous blog post outlining the change). Syslog-ng later cloned this licensing model, but it seems like they put a couple of more things under LGPL than we did (so there seem to be rather weak "product driver" with most of the "real meat" being under LGPL - in rsyslog larger parts are GPL, only). There is an interesting article on lwn.net that tells about this development, and does so from a syslog-ng point of view. The most interesting fact I got from this article was that syslog-ng faced quite the same problems we have with rsyslog --- and could not solve them without a commercial fork. Bare other options, it looks like this is a path that rsyslog needs to go, too. If so, of course this needs to be done as careful as possible.

After dual-licensing finally surfaced as something hard to avoid yesterday evening, I have done git log review today. I have to admit it was a bit scary: we have had some excellent and larger code contributions by Fedora folks in rsyslog's infancy (and continuous support since them), we have had some larger chunks of code in form of modules contributed and there is Michael Biebl, who not only creates great Debian packages but always helps with autotools and smoothing some edges. Finally, we have a couple of folks who sent in very specific patches. But I have to admit that the very vast majority of code was written by myself ;) As of today, we have 2819 git commits. Out of them 2676 were made by me (and another 50 or so by other Adiscon folks). These number need to be taken with a grain of salt: rsyslog was initially kept in a CVS archive, and all contributions at that time were logged with my user account. The early Fedora patches were in that timeframe. That have been around 20 or so. Also, my commit count is a bit higher due to automatic merges. On the other hand, the difference in code lines is probably even a bit higher than the difference in commit count. I have not done any in-depth analysis, bu an educated guess is that more than 98% of code lines were written by me (after all, I have worked a couple of years on this project...).

I am now tasked with actually looking at the code. I will try to differentiate addon user contributions (like omoracle) from core files. This is useful anyway, because it makes clearer to users what is directly supported by the project and what not. Then, I will probably look into contributions and see which code remains at which locations. After that is know, I need to have another set of talks with my peers at Adiscon (and probably the top contributors) and see where we can head from here.


This is, honestly, how the state of affairs in regard to the rsyslog project currently is. Most probably we need to move to some commercial licensing model. I know this is not ideal. I know many of you will not really like it. On the other hand, it is plain fact that many for-profit organizations greatly benefit from rsyslog without ever contributing anything. While they can continue to do so, it is probably a good idea to help them find an offering that funds the project. As final remark for today, let me introduce you to a blog post that IMHO very nicely describes the problems, and needs, around dual licensing. I am not affiliated with the author, do not even know him.

I hope that the ideas described here will enable us to keep pushing forward with rsyslog technology, something I would really like to do!

Tuesday, November 22, 2011

journald and rsyslog


I was made aware of the proposed new Linux logging interface via journald by a couple of questions I received today. I have to admit that I was not aware of this effort. I follow the systemd development mailing list, but as far as I can see (and search the archives), journald was never mentioned there.

This is meant as a first comment on the relationship between the journald project and the rsyslog project. I have obviously not done any in-depth analysis of the proposed new logging system. I have just quickly skimmed through Lennart's paper in which he introduces journald. As such, I do not intend to talk about the technical details of the journald and rsyslog, more on the bigger picture of how it affects rsyslog (and probably the syslog community at large).

In a nutshell, the systemd/journald logging system looks much like the Windows Event Log to me.  This is not necessarily bad news, because the Microsoft system is not bad, at least with the recent enhancements made. As some of you probably know, I have worked with the Windows Event Log quite a bit and even invented the first-ever (and still best ;)) eventlog to syslog tool. This, however, shows that a local event log alone is typically not sufficient. Such a system is excellent for a local desktop, but it needs a network component for centralized administration. Lennart wrote that journald will be a local component in the first iteration but this may change in the future. In Windows, the event log evolved into such a network-aware system and still Adiscon (my company) has many customers who need agents for integrating the proprietary log format into a standardized format -- that being syslog. MonitorWareAgent and EventReporter are still heavily used for that purpose.

Coming back to journald and looking at Lennart's reasoning: some of his arguments in regard to syslog are technically wrong, but can be considered  true if one looks at current practice: let me take up on the timestamp. Lennart claims that syslog does not contain a timezone and mentions that journald will provide much finer resolution. Actually, the timestamp is a source of deep frustration to me. Ages ago (2006?) I implemented high-precision timestamps (including TZ info) in rsyslog, and RFC5424 has brought them to the on-the-wire protocol. As far as I know, syslog-ng supports them for quite a while as well (but I am not a syslog-ng expert ;)). HOWEVER, all distributions turn high precision timestamps off and set the dumb old format as this is a requirement to keep old tools working. Initially Michael Biebl was brave enough to keep high-precision timestamps active in Debian's rsyslog package, but was forced by complaints to go back to imprecise ones (here is an example). Nobody seems to be really interested in updating the other tools (and lots of custom programs).

If I understood Lennart correctly, he will not only write a new log API and log store, but also new tools for log processing, a completely new log management subsystem. This may not be a bad idea. Apple has done the same in OS X. It may even be the only way to force people to switch to a newer and better system. The gradual approach I took with rsyslog and my other implementations was possibly a wrong path. Backward compatibility may actually be not that important on a typical desktop system. However, in an enterprise environment such harsh moves can not be done. Even though Linux has become quite important, we still need to integrate various log sources, and syslog is still an excellent tool for doing so. The good news is that journald will not prevent the integration. For those in the need, a syslogd can run alongside journald. This is exactly what we do on Windows, when EventReporter runs alongside the Windows event log and reformats Windows events into standard syslog format for consumption by some central system.

Will journald succeed and replace the current logging system? It is hard to say with the few information I have at hand. But I'd say that chances are not bad it will on most systems. Thinking about home desktop machines, Laptops and a myriad of other personal computers: Rsyslog runs on (almost) all of them, and nobody knows it does ;) The folks operating these machines are not at all interested in logging, so I think it is a valid assumption that none of them will care which logging system is running. Thinking about resources, Red Hat funds the journald development (I wonder how it plays with auditd, btw - will they merge?). If journald will make its way via systemd into Fedora (and I guess it will), other users of systemd will probably follow. Using this chain of arguments, I'd say it is likely that journald will replace local syslogging. I have to say that this concerns me a bit, because the systemd/journald relationship looks so close that it will probably be hard to gain some healthy competition in this regard. After all, this concerns was a big argument for me to start the rsyslog project. Read my 2007 blog post "Why does the world need another syslogd?" and think of its arguments in regard to journald. I am happy to say that rsyslog helped make syslog-ng a much better choice by the competition it introduced. I am unsure if there can be real competition to journald (but, to be honest, one can question if my concern is worth the effort...).

So let's assume journald will wipe out the rest of the Linux logging tools. What does that mean for the rsyslog project? Well, it gives it a somewhat different twist. I don't think that rsyslog (or syslog-ng) will completely go away. Replacing the local logging system on a desktop is one story, but replacing heterogeneous network logging is a totally different one. Of course, nothing is made for eternity, but I envision syslog to be healthy for at least the next 10 to 20 years. But there will be a shift inside the user base. Today, rsyslog tries hard to be a platform useful both for low-end, home systems as well as enterprise environments. With journald, non-enterprise environments will probably disappear from the picture. This also puts rsyslog in a purely commercial context, and this is definitely something we have to think about. What is the point of open source software, if only commercial entities benefit from it, but not the authors? Today, we receive motivation (and some money-worth arguments!) from the fact that there is a very large installed base. Losing that motivation would of course have an effect. At least, it would be pointless to work on non-enterprise features. Why put a lot of effort into something that nobody uses?

So is the arrival of journald good or bad for the community? For someone with my bias, you would probably expect that I say "it's bad". But I am not sure. It has good points as well. Maybe Lennart really manages to set a new, better standard that application developers will utilize in a useful way. Maybe forcing projects like rsyslog to a high-end, commercial focus brings much more improvement in that area (just think about all that restrictions that I maintain purely for low-end systems or backward compatibility). I really don't know if it is good or bad. There are risks, yet there are also chances. I will try to get some more details about journald and will probably post a couple of technical remarks to the claims Lennart makes. Other than that, I'll probably just stand by as an interested observer. There is no urgent need to respond, maybe a little fiddling with feature priorities to not waste too much time. But other than that, I think I can just safely see how things progress. And rsyslog users can do so, too. If you don't have any strong opinion on the situation, there is really no need to involve yourself.

Update: I now had a deeper look at the Linux Journal and journald, and there are a couple of things I don't like. I suggest to read this post in addition to my first reaction here.

Friday, November 18, 2011

How to display XML data in Adiscon LogAnalyzer?

Log files usually do not contain XML data. However, this does not mean logs are necessarily non-XML. A prominent example is IHE, which transports XML documents inside syslog message. My post on Adiscon LogAnalyzer 3.3 drew some interesting comments from John Moerke, who sees use for it in an IHE environment.

I have now discussed with Andre on how to integrate such functionality inside the log analyzer. There are obviously a couple of questions to address, but a core question is how to deal with the hierarchic structure that XML offers. Traditionally, log file contain flat name-value pairs, so they can easily be mapped into a two-dimensional array (which is what you see when you look at Adiscon LogAnalyzer). The application is build around this concept. So a fundamental question is how to make sense out of an XML stream. An obvious answer is that we may display some fields in a flat overview, but display the full structure in detail view. This makes sense, but there are ample complexities in things like queries. Plus, it would probably require big changes to the engine.

Putting implementation effort aside for the moment, the big question is how users (you!) would like to work with XML data in a tool like Adiscon LogAnalyzer. Feedback is most appreciated!

Wednesday, November 16, 2011

log annotation with liblognorm

I have recently written about the concept of event (log) annotation and liblognorm. During the past days I have made my mind up and have begun implementing some stuff today. In essence, rule bases will receive a new rule type "annotate", which contains the annotation part. Here is a sample from my lab environment:
rule=logon:<%-:number%>1 %timestamp:date-rfc5424% %src-id:word% ...
annotate=logon:+action="login"

Note the text in red. This is a liblognorm tag (not to confuse with a CEE tag!). This rule base tells the normalizer to append, according to the target format, the fields that are given in the annotate statement to any events that have the tag in question ("logon" in our case).

Today, I am extending the rule base parser to support the annotate rule. Within the next days, I'll update the rest of the system. When this is done, I'll probably release that version so that you can try out the new functionality in your own environment.

Tuesday, November 15, 2011

Some sample Adiscon LogAnalyzer Reports...

I thought I provide you a glimpse of which reports Adiscon LogAnalyser can generate. There are some interesting summary reports, like the Windows Event Log Summary Report  and the Syslog Summary Report. Of course, you can customize these reports based on the usual filtering capabilities. As an example, have a look at the syslog summary report just for "today".  You can play with these options life at the Adiscon LogAnalyzer demo site.

Please note that we will be working on more reports in the months to come. Also, if you miss some report, you may consider sponsoring its development. This can be quite cost-effective compared to the many quite expensive solutions you otherwise need to use -- or your programming time ;-)

Potential Blog Unreliability

Hi all, as you probably know, my blog's design hasn't changed in ages (yup, I'm a conservative guy). However, it finally is time to update things, so I'll look at some new design (and maybe software) options. That means that the blog may be a bit under construction during the  next couple of days. Please pardon any problems associated with that -- they will be temporary.

Monday, November 14, 2011

Adiscon LogAnalyzer 3.3.0 beta is out

Adiscon's open source log analysis frontend LogAnalyzer has grown with some exciting new features. Most importantly, report generation speed has been much increased. This was made possible via tighter integration of the report logic with the actual log source (database or file). As a result, all reports are generated in considerably less time and require far fewer system resources to complete. Along the same lines, Adiscon LogAnalyzer now offers suggestions for indexing database sources. If it finds room for improvement, new indexes are automatically suggested. This results in overall improved speed throughout the application.

Also, finally a long-due user interface improvement has been made: to access the reporting feature, users needed to access the admin panel. This was kind of well-hidden and cumbersome. In 3.3.0, reports are directly available from Adiscon LogAnalyzer's main panel. With this change, some users may even discover the reporting feature for the first time. The screenshot below gives you a sneak preview of the new interface.


Best of all, the new version has brought some under-the-hood improvements that we will utilize in the future to generate some really exciting new reports. Stay tuned, there is much more to come...

And finally let me say that work with the LogAnalyzer team to improve integration into rsyslog and the Adiscon's Windows logging components. We are trying very hard to provide an easy to use, integrated solution.

Friday, November 11, 2011

thinking about a rsyslog client for Windows...

I have had a series of interesting talks during the past weeks. We at Adiscon have seen that there is high demand for closely integrating Windows machines into an rsyslog enterprise logging infrastructure. Of course, there are various ways to do that, and probably the best is using Adiscon's other members of the MonitorWare product line. However, we can obviously go one step further and provide even thighter integration. For that reason, we will most probably soon create a special software package, the rsyslog for Windows client. It will provide
  • Event Log Forwarding
  • Log File Forwarding
  • Syslog Relay
capabilities, probably in different editions so that users can cover exactly their needs. While event log and file forwarding seem natural, syslog relay functionality may be a bit surprising, given the fact that rsyslog is available as a direct receiver. This feature is primarily targeted towards larger enterprises which may have no Linux machines in remote offices, but equipment they need to monitor via syslog. The core idea here is that we provide that functionality on a Windows box, which can than talk to the central rsyslog server via a reliable way.

We are currently discussing the details of this plan. I hope we will be able to show first results soon.

Wednesday, November 09, 2011

liblognorm event annotation ... and CEE

As you probably know, CEE is an effort driven by MITRE to support a common event expression format. Liblognorm is a log normalizer library (aka "network event normalizer"). One of its primary target formats is CEE.

For pure normalizing needs, liblognorm extracts data fields from semi-structured log message. The extracted fields are available inside a (basically) name/value property list. Liblognorm also permits to classify messages, e.g. as being a logon or logoff message. For this classification, liblognorm provides so-called "tags". These are simple words (strings of characters) which can be specified by the user. Tags reside in a special property called "tags", but otherwise occupy a flat space (tags can easily be structured via punctuation).

CEE takes a slightly different approach: while it shares the tag concept (actually liblognorm inherited tags from an earlier version of CEE), CEE classifies tags into different tag types. For example, "logon" may be a tag, but can only be used to describe an action(-field). As such, "logon" can not be present by itself in a CEE log record, it must be given as value of the action field ('action="logon"'). Also, CEE requires some other fields which may not be present explicitly from the original message even though the information may implicitly be present inside it. To express such information entities (and tags in the CEE way), liblognorm needs the capability to add additional fields to an  extracted event. Let call these set of fields the "annotation" for easier future reference. Liblognorm needs to annotate the event so that the target format's (CEE) requirements are met. While I was talking about CEE so far, I assume (and know from previous experience) that other formats may have similar requirements, albeit different fields that need to be annotated.

The question is now: how to implement this in liblognorm? The initial idea was to include the annotation inside the normalization rule itself. That has a major drawback: If a rule base is to be used for CEE and some other format, the annotation may be different, and thus the same rule base cannot be used. These two rule bases would differ in just the annotation. So it seems more natural, and easier to maintain, to split the recognition rule from the annotation rule. In that setting, the message is recognized and classified by recognition rules and the annotation is based on (different) annotation rules. So only one set of recognition rules can be used by multiple annotation rules. Only the latter need to be redefined for different target formats (or systems).

This split-rule method is the way I intend to head to. In essence, the current "rule=" rule and its format will remain untouched. It will be augmented by "annotate=" rules, which contain the full annotation. The binding between these two will be done via classification (liblognorm tags): in the first step, the message is recognized, data extracted and tags assigned, just like it is currently done. Then a second step will be added. It traverses through the tags and adds all annotation that are defined for the message's tag set. So the binding is on the tag set. Finally, it is probably necessary to add a third step that can remove unwanted fields. This step is probably target-format specific. For example, this step could eliminate the liblognorm tag set from an event if CEE compliance is desired, because CEE does not support, not even permit, an extra tag set.

Feedback on this approach is appreciated. It is my hope to be able to implement this in the near future.

Tuesday, November 08, 2011

filler fields in log normalization

When looking at some real-world rule bases for liblognorm, I noticed that it is often required to check for the presence of a specific field, but the value is actually not needed. This leads to fields named e.g. "filler", "dummy", "dummy<n>" with n being an increasing number. This is both clumsy and requires unnecessary processing power. For that reason, I have introduced "-" (dash) as field name. When this special name is used, the field as parsed as usual, but immediately discarded after the successful parse. So while we need to parse and extract in order to get the parse logic right, we save the effort to keep a copy of this unneeded data. This also means that output log records produced by the normalizer tool are cleaned up. I hope this is a useful addition.

Monday, November 07, 2011

Paper on LogNormalization

I wanted to make all of your aware that I have posted a paper on log normalization . This was originally done in regard to CEE, but I noticed that the classification of different log sources and the way to handle them is of broader use. I hope you find the paper useful.

Thursday, July 14, 2011

new rsyslog config: a thank you to our users

I wanted to thank all those users who have commented during the past three (!) years on config format questions. I have consolidated all input and hope I have come up with a decent solution. Obviously, not everyone will like everything, but I hope I could find a good compromise.

So far, my blog (and the rsyslog site) has the best glimpse at the new format:

http://blog.gerhards.net/2011/07/rsyslog-633-config-format-improvements.html

It is compatible with the old legacy format, supports simple control-flow structures (no loops, by intension) and builds heavily on name value pairs for things like actions, inputs, global settings, ...

A real-world sample I used for parser development can be found at the rsyslog git web.

You'll also find the grammar files inside that source directory in the git tree. It may be interesting for those used to flex/bison. My next step is to develop the necessary code for the name/value pair objects. That requires some more plumbing inside the core and changes to *all* loadable modules. Sounds like a lot of work, but I still hope to get this done before the summer break.

I have also started thinking about v7. It will contain a tree-based execution engine, which potentially offers even higher speed and far more options for configuration. This change is too big to make it into v6. Note that v6 will support "if .. then" and probably "if .. then .. else" but not nesting of these statements -- because the rule engine does not support that. The main goal for v7 is to support nesting, including the (considerable) relevant engine changes.

I hope the new format is useful and does not upset too many. Sorry for the silence on the final selection. Past experience told me that there were too many totally conflicting views of what  the format should look like. I was deeply concerned that a broader detail discussion would have derailed this effort again. So I used known arguments and my best judgment to create the final format. Please all be assured that your arguments were deeply considered and extremely useful in getting this done.

For example, a recent mailing list discussion brought up very good argument why we actually needed to support old- and new-style config for include files. It turned out that actually the best way to solve that problem was to actually extend legacy format rather than completely replace it. This has the added advantage that textbooks, courses and a myriad of Internet-HowTos do not need to be rewritten. Besides that, I think that constructs like
mail.info /var/log/maillog
are really hard to beat in simplicity and clearness, so I think it is valuable to have them as part of the config language.

Thanks again to everyone for helping make this happen.

Rainer

Wednesday, July 13, 2011

rsyslog 6.3.3 config format improvements

In rsyslog 6.3.3, the config processor has finally changed. The old legacy processor (and with it the early RainerScript implementation) is thrown out and has been replaced by the so-called RainerScript processor (why that crazy name?). This is an extremely important step for rsyslog, as it now has the foundation for a much better and intuitive rsyslog.conf format. However, most of that can not be seen in 6.3.3, as it requires more work, especially in the plugin arena. Still, there are a couple of smaller improvements available.

Most importantly, the performance of script based filters has been considerably enhanced. Preliminary testing shows a three times speedup (we'll do more benchmarking at a later stage; there is also still lots of room for optimization ;-)).

The ugliness of continuation lines has been removed. They may still be used, and this may make a lot of sense with some actions, but you are usually no longer forced to use continuation lines. Take this config snippet from a leading distro:

if ( \
     /* kernel up to warning except of firewall  */ \
     ($syslogfacility-text == 'kern')      and      \
     ($syslogseverity <= 4 /* warning */ ) and not  \
     ($msg contains 'IN=' and $msg contains 'OUT=') \
 ) or ( \
     /* up to errors except of facility authpriv */ \
     ($syslogseverity <= 3 /* errors  */ ) and not  \
     ($syslogfacility-text == 'authpriv')           \
 ) \
then /dev/tty10
& |/dev/xconsole
This can now be written as follows:

if ( 
     /* kernel up to warning except of firewall  */
     ($syslogfacility-text == 'kern')      and     
     ($syslogseverity <= 4 /* warning */ ) and not 
     ($msg contains 'IN=' and $msg contains 'OUT=')
 ) or (
     /* up to errors except of facility authpriv */
     ($syslogseverity <= 3 /* errors  */ ) and not 
     ($syslogfacility-text == 'authpriv')          
 ) 
then /dev/tty10
& |/dev/xconsole
Of course, this is not a real big advantage, but can be very useful during day-to-day operations. Forgetting the continuation marker is easy and has happend quite often, causing many more problems than necessary.

Also, the somewhat unintuitive use of "&" to chain actions together can now (optionally) be replaced by so-called blocks. For example,

authpriv.err /dev/tty10
&            |/dev/xconsole
can now be written as

authpriv.err { /dev/tty10
               |/dev/xconsole
             }
This looks much more familiar and thus intuitive to many users. Of course, both the old style as well as the new style is supported.

Finally, the need to use single quote characters (') over the usual double quotes (") in script based filters was often a source of confusion. You may now use both, so 'string' and "string" works both. However, strings in double quotes will support parameter replacement in later versions of rsyslog. That is "Message is $msg" will evaluate to exactly this string in 6.3.3, but $msg will be resolved to the actual message content some time in the future. So be careful if you use double quotes.

Of course, none of these changes are the important ones so many users are waiting for, most importantly an intuitively-usable scoping for actions and inputs. These will be coming up shortly. I need to write some more engine code *and* need to enhance plugins to support that. I'll probably start with actions as first. Note that the RainerScript processor already parses some of these constructs, but the rest of the engine simply ignores them. In order to get you an idea of how it will look, see this hypothetical example:

if $msg contains "error" then {
    action(type="omfwd" protocol="tcp" target="10.0.0.1:514"
           action.retryCount="-1"
           queue.type="linkedList" queue.fileName="fwdRule" queue.maxDiskSpace="1g"
           queue.saveOnShutdown="on"
          )
    action(type="omfile" target="/var/log/somelog.log")
    action(type="omuser" target="all" action.onceInterval="30")
}
I hope the example is intuitive enough to grasp it's meaning ;) In current format, you need to write

$ActionQueueFileName fwdRule1
$ActionQueueMaxDiskSpace 1g 
$ActionQueueSaveOnShutdown on 
$ActionQueueType LinkedList
$ActionResumeRetryCount -1
if $msg contains 'error' then @@10.0.0.1:514
& /var/log/somelog.log
$ActionExecOnlyOnceEveryInterval 30
& :omusrmsg:*
At least to me, the upcoming new way looks much nicer ;)

In regard to the distro-example given above, I'll try to simplify it towards this form:

if ( /* kernel up to warning except of firewall  */
     hasPRI("kern.warn") and not 
     ($msg contains 'IN=' and $msg contains 'OUT=')
    ) or hasPRI("authpriv.err")
    then { /dev/tty10
          |/dev/xconsole
         }

But that's the second step after introducing the new action statements.

Please note that the final format selection was very carefully based on many discussions both on the mailing list and inside the forum as well as needs to preserve backwards compatibility. For example, on Debian, packages drop rsyslog-specific configs into the /etc/rsyslog.d directory and expect them to be understood. In order to break things here, we needed to remain compatible with the legacy format and extend it. Only thanks to the good user feedback we could finally come up with a solution that the majority of users hopefully will find good.

With that said, I'll now see that I create the actual release. For obvious reasons, 6.3.3 will be a bit shaky as far as the config is concerned. Most probably it will also not run the full testbench successfully (due to some very esoteric tests that are broken by actual functionality changes). However, you can be sure that the engine works well as long as it passed the config stage, because there were almost no changes during runtime (well... script filter expression evaluation has been rewritten from scratch).

Tuesday, July 12, 2011

rsyslog: important step to new config format

I have just merged the master-newconf git branch into rsyslog's master branch. With that, the new config parser becomes part of the main line. This is a very important step, as it lays the foundation to an enhanced, easier to use config format. The current version has only few enhancements, but provides the necessary plumbing to do some real nice work within the next couple of weeks. Not only as a side-effect, the performance of script-based filters has been notably increased.

I expect a release with the current state within this week. Mostly cleanup and doc work remains to be done.

Wednesday, July 06, 2011

Why omusrmsg is evil - and how it is fixed...

Traditional syslog files simply use the user name (or "*" for all) to send messages to users. For example, this selector will forward all mail error messages to the poor mail admin named "madmin":

mail.err madmin

This syntax is (somewhat) intuitive, but causes severe issues when it comes to extending the configuration language. Let's assume the mail admin is named Ian Faber and has the user name "if". So the syslog selector would be

mail.err if


This is ok with traditional config files, but creates a problem if the language is extended. For example, rsyslog has an "if expression then" construct. Question now: how to differentiate between the user name "if" and the "if" construct? Rsyslog uses context information in order to do this. At the start of a line "if" must be the "if" construct, because "if" as a user name would require a filter in front of it. This works pretty well, but creates some complexity during config file parsing. It may also be counter-intuitive to many users. If the language is further extended (as I am doing in v6), it creates considerable extra complexity.

To resolve that ambiguity, I have upgraded omusrmsg, which handles this kind of actions, to support the regular rsyslog syntax for action configuration. You now write:

mail.err :omusrmsg:if


The extra ":omusrmsg:" tells rsyslog explicitely that an action starts and so clearly flags what the "if" stand for. This is a very vital update, and so I am extending it into all versions starting with v4. I am right now working on these changes and will release all versions ASAP. I'll create another post when this is done. It is highly recommended to use the new syntax exclusively. The older syntax will go away in a while.

Tuesday, June 07, 2011

full blown dns cache for rsyslog

Up until and including version 5 rsyslog does actually not implement a real DNS cache. Instead, it uses some sort-of caching methods. They seem to work surprisingly well, as almost no real pain was reported by users in regard to this system. The big exception is UDP traffic, if combined with template options that require host resolution and a larger number of different hosts sending messages.

Starting with 6.3.1, I have now implemented a real, full-blown cache system which will resolve the issues with that use case. The initial implementation is not perfect, but I thought it would be best to gain some feedback from the community first before deciding on the final implementation. Most importantly, it currently does not expire entries (this was considered not necessary in many previous discussions we had on the mailing list). Also the current linear list data structure and locking method used is not optimal. However, it is very simple and easy to maintain. So if there is no need for more advanced (aka "complex") code, it probably is not bad to stay simple.

I hope to get some feedback from the community, and most importantly feedback from folks who actually use the new capability to their benefit. In those cases where it matters, the speedup can be "immense".

Wednesday, June 01, 2011

new rsyslog config system materializes...

The past weeks I have worked pretty hard on the new rsyslog config system. The legacy system was quite different from what you expect in modern software. Most importantly, the legacy system applied directives as the config file was read, which made it extremely hard to restructure the config file format. That also prevented features like privilege drop from working fully correct.

I have now basically changed the config system so that there is a clear difference between the config load phase and applying the config. Most importantly, this means privilege drop now works correctly in all cases (but I bet some users taking advantage of oddities of the old system will probably complain soon ;)). Other than that, there are no user-visible enhancements at the moment. However, the internal plumbing has changed dramatically and enables future change. Most importantly, this finally creates a path to a new config language, as we now have a clear interface as part of the in-memory representation of the config, which is config language agnostic.

With this initial release, there may still be some things inside the core that can be optimized. Right now, the system aims at the capability to have multiple config objects loaded (but not active) at the same time. However, there are some data instances where this is not cleanly followed in order to reuse some code. This is not a problem, because the rest of the rsyslog engine does not support dynamic config reload (and thus multiple configs at runtime) at all.

Also it must be noted that the current code is quite experimental. So there is some risk involved in running the initial 6.3.0 version. However, all dramatic changes were made to the config system. That means if the system initializes correctly, it will most probably run without any issues. The risk window is constrained to the initial startup, what should be quite controllable. Users that use privilege drop are advised to check that their configurations work as expected. The previous system did some initialization with full privileges. This is no longer the case, except for modules that actually require full privileges (e.g. imtcp to bind privileged ports). Most importantly, files are now created with dropped privileges right from the beginning. I expect that some (unclean) configurations will run into trouble with that. The good news about that is that the would run into trouble with older releases as well, but only after a HUP. Now things break immediately, what makes them much easier to diagnose.

So what's next in regard to the config? It depends a bit on the overall workload. I will probably try to have a look at the config language next, which is another non-trivial task. Also past discussions tell me that it is extremely hard to find a format that satisfies all needs. I have already reviewed the last elaborated discussion (June and July 2010 - search for "conf" on these pages) and begun to reconsider some of the options. But this is probably a topic for a separate blog posting...

Tuesday, May 31, 2011

supported rsyslog versions

Every now and then I am asked which versions the rsyslog project officially supports. I track the current version on the rsyslog status page. To me as a surprise, I was recently asked what that really means. And I have to admit that the page actually does not spell this out in detail. So I thought it may be a good idea to write some small comments on this.


First, what does "officially supported" mean? I think the best definition is that this is the software we expect users to run and we will most probably not look into problems in older versions. At least I will usually not craft patches for older versions. Note that things are a bit different for customers with rsyslog support contracts: here Adiscon as rsyslog's prime sponsor provides support for all stable versions ever created (as long as this is technically possible, e.g., there are some things which simply can not be fixed in very old versions).


So which versions are officially supported? It is first important to note that for each major version (v4, v5, ...) there exist three branches: stable, beta and development. In practice, there usually exists only a beta and development version for the most recent major version and maybe the one before (but we try to avoid that). All other active versions are stable. An older but still useful plot of this concept can be seen in my blog post on the rsyslog family tree. The idea is that new functionality goes into the devel branch, is then slowly migrated to beta and moved to stable state once it gets sufficiently mature (read my blog post on "How Software get Stable" for more on this philosophy).


It is important to note, however, that only the current versions of each branch are officially supported (but note the extension for support contracts I stated above). Today exist far more than 100 versions of rsyslog. It is absolutely impossible to maintain all of them. So we focus on what we expect a careful user should run. For the ultra-conservative folks, we keep older versions, like v4, inside the supported range, but we can (and will) not support any interim version. For example, the some early 4.6.x versions were bugged by some really nasty problems in the TLS arena. This has been fixed in later versions, so why should we still support the known-to-be-faulty versions? This sounds like a big waste of time. Note the difference between, e.g. 4.6.0 and 4.6.5 is just bug fixes (!). So if you follow the "How Software get Stable" spirit, there is absolutely no point in running software with more bugs than necessary and so it sounds like a really bad idea to run those versions. We understand that corporate guys may still have valid reasons to use outdated versions, but that's covered by the support contracts (think about it this way: this generates a lot of technically unnecessary work, so someone needs to pay for that...).

The story is of course slightly different for version shifts from e.g. 4.4.x to 4.6.x. Note that even number denote stable versions (odd ones are either devel or beta, depending on how they are declared). Here, some new functionality is introduced, and thus there is additional risk for regressions. We try to mitigate this potential by our beta phase, which usually lasts three month. In my opinion, a beta is very close to a stable version. So for this time period, we support something like two stables in order to make sure users can migrate to the new version without risk. Of course, this doesn't outrule the chance that some regression is left uncaught. But, some risk is always involved in life...

Note that we do not generally provide patches for older stable versions once the next one is out. Even when we patch older versions for support contract customers, we usually patch exactly the problem they see, and not more (what usually is exactly within their minimal-change strategy). So to re-use our 4.x TLS example: the nasty TLS bug was fixed in 4.6.5, which was declared the current stable. So the patch is not available in 4.6.0 to 4.6.4. This also means that no 4.2.x or 4.4.x version will ever get it, because these versions were quite outdated (and unsupported) when the problem was fixed.

If you are still not convinced, just think if this: what would happen if I applied all patches to 4.6.0 that went into 4.6.5? Yes, exactly -- it would be the exact same code. This is because 4.6.5 is version 4.6.0 plus all patches ever created for that version ;)

To sum up in one sentence: the project officially supports the head versions of all supported branches (as of the rsyslog status page).

Wednesday, April 27, 2011

rsyslog config reload - random thoughts

This blog post is more or less a think tank, maybe even an utility to clear my mind. Please note that I am not talking about anything that is right now present in rsyslog. I am not even saying that it will be in the near future. But I'd like to think a bit about alternatives on the route to there.

Let's assume rsyslog shall have two abilities:
  • use different config languages
  • dynamically reload a config without a full restart (thus applying a delta between new and old config)
In any case, the usual approach is to have an object representing a full configuration. This is an in-memory object. Usually, it is created during parsing the configuration file(s). During that parsing, nothing of the new config is actually carried out, just the in-memory presentation build. In that model, it would also be possible to have several fully populated config objects in core at the same time. The important thing to note is that none of them actually affects the current system - they are just loaded and ready to use.

Usually, in such a design, there is one thing that is called the "running conf". This configuration is the one the system actually uses for processing.

So how is a new configuration activated? In a first step, the config parsers create an in-memory object. Once this is done, that object is a candidate config, one that could be activated. To actually activate it, the candidate config is loaded as running config. During that process, all the settings are applied and services are started. Please note that a dynamic config reload can be done by first creating a delta between the candidate config and the current running config. This delta can then be used to keep the currently existing config running, but just modify it so that it is equivalent to the candidate config. This process can be less intrusive than shutting down the running config and restarting it based on the candidate config. As an example, a rsyslog system may have several hundered incoming TCP connections open. If the delta is just the addition of a new output file, there is no need to shut down these TCP connections as part of the (delta-driven) candidate config activation. Whereas, if no delta were to be used, all connections would need to be shut down and re-established after restart. There is obviously benefit in delta-based configuration apply. However, it should be noted that there are many subtle issues associated with creating and applying the delta.

Thinking about such a loaded/candidate/running config system for rsyslog, there is one overall issue that complicates things: loadable modules! Each module not only provides extra functionality, it also provides a set of configuration settings to modify its functionality. As such, we have a problem with config parsing: in order to fully parse a config file, we actually need to load the module as part of config processing. Or more precisely, we need to load its configuration file processor. However, it does not make sense to split each module into a config file processor and the actual module, at least I think so. Splitting them up would make things over-complex IMHO. However, we must demand that a module, in its config processing code, must not do anything other then creating configuration objects. Most importantly, it must not start any service or act out any non-config related activity. If it would do so, it would possibly affect the current running configuration. Also, config processing does not necessarily mean that the config will actually be activated, so the module must not assume that its processing will ever be called. As a side-note, this is one of the issues with the current legacy configuration system (as seen in all versions prior to v6 and early v6 versions).

Rsyslog traditionally keeps a list of loaded modules. Modules are added to that list when they are loaded inside the configuration system. During system startup, that very same list is also used to activate services inside the module. So that single list serves both as
  • a registry of loaded modules (e.g. to know what is already available and what needs to be unloaded)
  • a registry of modules required to for configuration
Both functions are tied together into a single list because rsyslog currently has only the concept of a single configuration, and not a candidate/running (multi-)config system. For the latter, it is necessary to differentiate between the two cases:

As we need to load modules during config parsing, we still need a single global list that keeps track of modules already present inside the system. Please note that with a multi-config system, a module that is first "loaded" inside a currently being parsed configuration file may actually already be loaded inside the system. In that case, a duplicate load must be avoided and the already existing module be used. The global, config-independent list is required to support this functionality.

On the other hand, such a global list can no longer be used to activate services for a specific config. This is easy to see when we have a config A which uses e.g. a TCP listener and we have a config B which does not. If B is activated, the TCP listener shall obviously not be activated. As such we need a dedicated, config-specific list of modules that are part of the current configuration. Let's call this one the "config module list" and the other one the "loaded module list".

The loaded module list is than just use to keep track of which modules are loaded. Also, it will/can be used to locate a module, so that global functions (like the config parser) can be found and carried out. Note that I call the config parser global, not config-specific. The reason is that the config parser does not take a config instance as input, but rather has no input (other than the config language) but has the config instance as output. As such, it emits config specific data, but does not require it for processing. So it is global.

The config module list in contrast must hold all config specific data elements for the module (most importantly the module specific config instance itself). The config module list is to be used for all config-specific actions. For example, it will be used to activate a module's services when the candidate config becomes a running config (maybe via a delta-apply process).

Note that on-demand module unload can be done via reference counting, which is already implemented in rsyslog. When a module is put onto a config module list, the count is incremented. If it is removed from such a list (usually because the in-memory config is destroyed), the count is decremented. An unload happens if the reference count reaches zero. If the module would be required by later processing another config, that would trigger a reload just as if the module had never before been loaded.

Note that a clearly defined and implemented split in global vs. configuration specific functionality is of vital importance for a multi-config system. This probably has some subtle issues as well. Right out of my head, I can think of the problem of some potentially global configuration settings (a term that seems to contradict itself in this context - just think a bit about it...). For example, we have the module search path, which tells us from where to load modules. With different configs, we can potentially have different module search pathes. That, in turn, can load to modules with the same name being loaded from different locations. That means we could potentially have different functionality, including different sets of config parameters (!) in the system at the same time. This could lead to some hard to diagnose issues. So it looks necessary to have the ability to load the same module via different pathes concurrently, and apply only the "right" module to the config in question. Looking at the current code base, implementing this would be even harder than just splitting out the global/config-specific lists. Maybe this would be something that shall be added at a later stage, *if* at all we take the path down that road. Also, there may be other issues along the way that I do not currently envision...