Rainer's Blog

omudpspoof, threads, and libnet..

2012-05-14T09:51:00.000+02:00

I today ran into a problem with omudpspoof (rsyslog's UDP spoofing output module) that only occured when multiple output threads were used. If that perquisite was given and a larger traffic volume was generated, rsyslog relatively quickly aborted - often even during startup, otherwise very quickly thereafter. Diging down to the potential troublespot, it turned out that libnet is not threadsafe (and I have to admit they do not explicitely claim that). That was a very quick hint, and I now protect libnet calls via a mutex, ensuring that only one thread at a time will ever call into libnet. Of course, this somewhat limits concurrency, but for obvious reasons stability is far more important. There was also recently some discussion on different-kind problems with omudpspoof. While I do not think that this was releated to multithreading (data was malformed, what I could not reproduce), I can not totally outrule that. Will try to follow up with that on the mailing list as well.

The problem probably took quite some while to surface, as people usually have a single UDP spoofing action AND do not run it on multiple threads (given the i/o-boundness of this action, you probably can not gain much be using more than the standard single instance thread).

If you are interested in patching older versions, the patch is available via git (use the raw link to obtain a file usuable with patch). New releases are due soon.

RFC5424 or cee-enhanced syslog?

2012-04-20T16:40:00.001+02:00

I recently got a question if it would be better to implement RFC5424 or cee-enhanced syslog in a new project. This sounds like a though question, but looking at the details helps to ease it a bit.

First of all, RFC5424 has a far broader scope than cee-enhanced syslog. RFC5424 is the base RFC of a new series of syslog RFCs that solve many problems, among them (this list for sure will not be complete):

finally a standardized syslog format (no standard exists before, just a weak understanding)
supports multiple transports, e.g. UDP and TLS (all in their own RFCs)
solves some long-standing nits, like the date format (RFC5424 supports high precision and demands a year as part of the timestamp)
increases the syslog message size and permits operators to set an (almost) arbitrary upper limit for message sizes
supports structured logging via so-called "structured data"

In contrast, cee-enhanced syslog only cares about the structured logging feature - none of the others is addressed with it. This is the case because its intent is different: the goal here is to have a format that can work with existing technology and still provide the best possible structured logging solution. Depending on circumstances, "best possible" can be quite different. For example, in a scenario where it needs to work with crufty old syslogds, it can mean that message content can not be longer than 1k, a serious restriction. Even more, it is envisioned that cee-enhanced syslog will also work over non-syslog transport, and may even be transported by simply copying (and merging) files.

CEE has long thought about using RFC5424 structured data format for its structured logging needs. However, that would have limited its ability to work with all these older (and deployed) syslog implementations. Thus, the decision was made to use text that purely resides inside the message part and, without transformation, can be used in legacy systems (with given restrictions, of course).

So now back to the question: what to implement? With this facts, I think it boils down to "both". To use the benefits of modern-day syslog (as described above), you definitely need to implement RFC5424 and its helper RFCs (like 5425 for TLS). HOWEVER, the question remains if one should use structured data or cee-enhanced syslog. This, I have to admit, is indeed a though question.

My personal opinion, which can be totally wrong and is solely based on my experience (aka "gut feeling" ;)), cee-enhanced syslog sounds more promising for structured data. The main reason for this is that the format has received very good responses from major players and a lot of work is currently being done by a lot of folks driving important projects in the logging environment. There is also a lot of supporting libraries upcoming AND some of them already available. Most importantly, this effort is thightly integrated with Mitre and it probably is not to far-fetched to assume that cee-enhanced syslog will appear on some purchasing checklists in the not so distant future. RFC5424 structured data does not have this broad backing. So while cee-enhanced syslog is a very fresh project, my personal assumption is that it will take off.

But again, that does not mean that RFC5424 shall not be implemented. I think RFC5424 technology is vital for a number of reasons. Of course, things like TLS can also be obtained without RFC5424, but not in a standards-compliant way. So to ensure interoperability, going the 5424 way is a good idea.

MongoDB, BSON and templates...

2012-04-20T15:10:00.000+02:00

After I have improved the template system yesterday, I have begun to think again about the integration of custom templates (actually field lists) with ommongodb (rsyslog's mongodb output plugin). A "problem" with the mongo interface is that it does not support native JSON but rather BSON, its binary equivalent. So what needs to be done is convert the textual JSON representation to BSON before it can be stored in MongoDB. Given the fact that the JSON representation must be build with the property replacer, this looks like a was of coding/enconding. Assuming that I would take JSON and tansfrom it to BSON (all this in ommongodb), the workflow would be as follows:

text properties -> encode JSON -> decode JSON -> generate BSON

The "encode JSON" step would happen inside the template processr, the "decode JSON" part in ommongodb. In essence, this looks like a quite flexible, but rather slow approach. After all, it would serialize to JSON just for interim needs. What I am actually looking for is this workflow:

text properties -> generate BSON

In that we would replace the JSON format with some internal format. That internal format in a kind already exists, in array passing mode. In this mode, the property text is passed in via an array. As a side-note, some transformations are necessary and desired even in internal format, as the property replacer permits to use not only the raw properties themselves but substrings, case conversions, regexes and the like. The problem with array passing mode is that it provides just the plain values. However, for BSON (and MongoDB) we also need to know the field name - and type information. The latter is probably easy, as rsyslog usually deals with text, only, and so we could stick to strings except maybe for dates. The field name is available since yesterday inside the template structure. However, there currently is no way for a plugin to access this information.

So it looks like the decent thing is to create a new interface that passes in a (description,value) pair to the plugin. The description most probably could be the template structure (or some abstraction if we feel bad about tying things too deeply together). That will prevent the detour via JSON, but still provide otherwise full capabilities. The bad thing, however, is that some complex interface gets yet another option (maybe it is time for a general cleanup?).

Feedback on this issue is appreciated.

rsyslog templates & json

2012-04-19T15:53:00.000+02:00

I today added a simpler method to specify JSON inside rsyslog templates. The new method simplifies specifying JSON-encoded fields. It still looks a bit ugly, but if you look closely enough, you'll quickly notice that it no longer needs "quoting magic" and thus is far easier to work with.

Previously, you had to define a template like this:

$template tpl, "{\"message\":\"%msg:::json%\",\"fromhost\":\"%HOSTNAME:::json%\",\"facility\":\"%syslogfacility-text%\",\"priority\":\"%syslogpriority-text%\",\"timereported\":\"%timereported:::date-rfc3339%\",\"timegenerated\":\"%timegenerated:::date-rfc3339%\"}"

The template given above is the default for ElasticSearch. With the new code, this can be replaced by:

$template tpl,"{%msg:::jsonf:message%,%HOSTNAME:::jsonf:fromhost%,%syslogfacility-text:::jsonf:facility%,%syslogpriority-text:::jsonf:priority%,%timereported:::date-rfc3339,jsonf%,%timegenerated:::date-rfc3339,jsonf%}"

It's a bit shorter, but most importantly the JSON field is now generated by the property itself. This is triggered by the "jsonf" (json field) option. If it is given, a

"fieldname"="value"

is automatically generated. The fieldname is either the forth parameter (see "message" in the msg field in the example above) or, if not given, defaults to the property name. If I hadn't insisted on specific field names, I could have written the sample as such:

$template tpl,"{%msg:::json%,%HOSTNAME:::jsonf%,%syslogfacility-text:::jsonf%,%syslogpriority-text:::jsonf%,%timereported:::date-rfc3339,jsonf%,%timegenerated:::date-rfc3339,jsonf%}"

Note that the commas to separate the various JSON fields must still be included inside the template as literal text.

This new system works pretty well within the current template system. The config format will probably become a bit more intuitive when moving it over to the new config language. But the exact how's of that are still to be decided. In fact, I think this string-based way of specifying templates is not so bad. In any case, I am also considering a template option which would take a template of pure field lists and generate proper JSON out of that. But that's work for another day (or so ;)).

This is to be released with 6.3.9 and already available via the git master branch.

rsyslog & elasticsearch: async replication and timeout

2012-04-16T16:59:00.003+02:00

Today I have added the capability to specify asynchronous replication support and timeout settings to omelasticsearch. Code-wise it's a small change - it just passed the required parameters to ElasticSearch via the proper REST URL parameters. By default, both parameters are not set, that means default timeout and synchronous replication.

To set parameters, use

*.*     action(type="omelasticsearch"
           ... other params ...
           asyncrepl="on" timeout="1m")

If you leave "asyncrepl" out or set it to "off", synchronous replication is used. For greatest flexiblity, the value of the "timeout" parameter is not checked. While this enables you to use anything ElasticSearch supports, invalid values can not be detected by omelasticsearch and thus will cause all inserts to fail (or misbehave). Note that some basic integrity checking is done, but we do not go great length here. So use with care.

rsyslog & ElasticSearch: using dynamic index and type

2012-04-13T15:40:00.004+02:00

Today, I have added support for dynamically taking search index and type from the message itself. It works much like dynafiles do. If dynamic mode is selected (via config params), the index name and type given in the configuration are template names instead of literal ones. That means the rsyslog core will generate the actual name at runtime, based on actual message content. These dynamically generated values will then be used inside the request.

Here is a quick howto: you need to define the templates first, like this:

$template srchidx,"%hostname%"
$template srchtype,"%programname%"

In this example, the hostname (from the message) is used as name for the search index, and the programname (usually part of the syslog tag) is used as searchtype. The full power of templates, including all properties, can be used, so this is highly flexible.

To actually use these dynamic values, omelasticsearch must be called like this (line break do not matter):

*.*     action(type="omelasticsearch"
           searchIndex="srchidx" dynSearchIndex="on"
           searchType="srchtype" dynSearchType="on")

The "dynSearch..." setting tells the engine if it is a dynamic name or not. If set to on, like above, a template name is given and the actual name will be dynamically generated. If set to "off", the literal value will be used ("off" is the default, so the parameters do not need to be specified if "off" is desired). For example:

*.*     action(type="omelasticsearch"
           searchIndex="srchidx"   searchType="srchtype")

will use the index "srchidx" and type "srchtype" literally. No template-based name extension will happen in this case. Please note that it is ok for only one parameter to by dynamic. It's not "all or nothing".

I hope this is a useful addition for omelasticsearch. Several folks have indicated that this method can increase throughput in a couple of use cases, for example to split of indexes based on host names, host functions and the like.

new rsyslog v5-beta released

2012-04-12T15:41:00.002+02:00

I just released rsyslog 5.9.6, now a beta and no longer a development version. I have done a big merge today of bug fixes and small enhancements from the v5 branch and combined that all into 5.9.6. The plan is to mature this version as quickly as possible, which could really mean "rather quick". For one, 5.9.5 is released for three month now and seem to have not broken quite a bit. Secondly, there are only very few new features and those that have been added already got their practice drill in some large environments (and such seem to be save for wider consumption).

I also sincerely hope that this will conclude the v5-devel branch for the foreseeable future. Having two active development branches always is a big burden, and merges are both time-consuming and error-prone. So if at all possible, I'll try to refrain from doing any larger-scale development work in v5. It needs to be seen if I can hold to that when it comes to paid custom work. On the other hand, the v6 engine has also gotten both rather stable AND much feature enhanced. So it probably is a good idea to being to ask people to move up to v6. But that's another story, to be written in the not so distant future ;)

rsyslog group on Facebook

2012-04-12T15:32:00.002+02:00

I just created a rsyslog group on facebook. I hope it is useful. It's a very interesting experiment for me. Are the tech folks available there as well? Will it work better than e.g. the rsyslog forum itself? I guess time will (quickly) tell. At best, this could become a nice new channel to get news out and motivate people to try out new versions.

Using different templates with rsyslog's ElasticSearch plugin

2012-04-10T15:19:00.000+02:00

Recently, an experimental ElasticSearch plugin has been added to rsyslog, omelasticsearch. Like all other output plugins, it comes with a canned template, which specifies a default "schema". However, the template engine provides capabilities to use a completely different set of fields. In this blog post, I'll briefly describe how this is done.

Note: all work is based on the current (April, 10th 2012) implementation of both omelasticsearch as well as the rsyslog core. Future implementation changes are expected in an effort to make things more intuitive. This may even break what I describe here. So if you come to this blog post at a later time, it probably is best to check if things have changed by "now" (especially if the procedure does not work ;)).

The current implementation ties into the template system. The default template looks as follows (all on one line, broken for readability):

$template JSONDefault, "{\"message\":\"%msg:::json%\",\"fromhost\":\"%HOSTNAME:::json%\",\"facility\":\"%syslogfacility-text%\",\"priority\":\"%syslogpriority-text%\",\"timereported\":\"%timereported:::date-rfc3339%\",\"timegenerated\":\"%timegenerated:::date-rfc3339%\"}"

The '\"' sequence is needed to represent a quote character inside the template. To format JSON, this is pretty ugly, but that's the way the template processor currently works (and that is one reason why it is under review). As you can see, the JSON is actually "hand-crafted", with the "json" option specifying that property text needs to be properly escaped to be well-formed JSON. If that option is specified, the template processor does the necessary escaping. Note that not all properties have the "json" option. This is purely for performance reasons. For example, time stamps do never include characters that need to be escaped. Consequently, the "json" option is not used there (but could be, e.g. "date-rfc3339,json").

So now let's define a different set of fields to be used. Let's say we just want to have the date from the syslog message and the MSG part of the message itself. That would be as follows:

$template miniSchema, "{\"message\":\"%msg:::json%\",\"timereported\":\"%timereported:::date-rfc3339,json%\"}"

Note: I requested JSON formatting in this example just to prove the point - don't use it in a real deployment, as it is nonsense that costs CPU cycles ;)

Now I need to use the template within the omelasticsearch action. This is done as follows:

*.* action(type="omelasticsearch" template="miniSchema")

Note: the "all" ("*.*") filter of course can be replaced with a different type of filter.

That's all that needs to be done. Please note that you can add several templates and use these in several different elasticsearch output actions. Just exactly the same thing used in other actions. Also keep in mind that the property replacer permits to access a wide range of message properties. Most importantly, normalized properties or cee-enhanced syslog properties can be accessed via the CEE family of property names (essentially "$!cee-name" style). Just be sure that you include the "json" option into any property that may contain unsafe characters (which means almost all of the fields). This is not done automatically by the current engine and invalid characters can lead to strange problems, even aborts of ElasticSearch itself!

In the future, a more intuitive syntax is planned for JSON template definitions. Nevertheless, the current code permits full customization but requires taking care of the details.

Which command line tools would you like to see for logging?

2012-04-10T12:00:00.000+02:00

As part of project lumberjack, I am considering which tools would be vital to have in your logging infrastructure. Assume that you have a database that contains security relevant events, like syslog data or events from the Windows Event Log. Which tools would you like to have to access (and modify?) the database? Note that I am asking for small things, not something like "I'd like to have a full-blown SIEM" (of course you do). I am more focussed on tools like auditctl, tools that can be made the building blocks of your security system.

Current state of ommongodb default schema

2012-03-30T18:54:00.001+02:00

Rsyslog's ommongodb provides a default schema which is used for syslog data if no other is specified. It tries to align with the lumberjack project, so the schema may change in the next weeks, as hopefully a standard field set is defined there. I originally started with a very small set of fields (based on early cee/lumberjack schema), but it turned out to be too small to be really useful for real-world applications. So I have added a couple of fields today. The currently supported fields are:

sys - name of the system the message originated from (STRING)
time - timestamp from the syslog message (UTC_DATETIME)
time_rcvd - timestamp when the rsyslog instance received the message (UTC_DATETIME)
msg - the free-form message text (STRING)
syslog_fac - the syslog facility in numerical form, see RFC5424 to decode (INT32)
syslog_sever - the syslog severity in numerical form, see RFC5424 to decode (INT32)
syslog_tag - the traditional syslog tag (STRING)
procid - the name of the process that emitted the message (STRING)
pid - the process id of the the process that emitted the message (STRING)
level - a severity level based on the lumberjack schema definition (STRING)

Please also see my previous blog post on cee/lumberjack schema mapping, which most importantly describes the current level mapping.

Note that the default schema currently does NOT contain data obtained by parsing cee-enhanced syslog JSON part of the message. Current thinking is that we probably best include this as a sub-elements, maybe together with other structured data like RFC5424 structured data. This is currently being worked on. It's less missing time to implement but the desire to avoid re-doing things as the spec changes. Anyhow, I'll probably have a "timeout" after which I will implement at least some idea (after all, not too much work will be lost if things change).

If you use this schema, please keep in mind that it is experimental. At this stage I will not try to remain backwards compatible when I do changes. So excpect that newer versions may break your things!

Adiscon LogAnalyzer now supports MongoDB

2012-03-30T17:49:00.001+02:00

I just wanted to share the good news that Andre, LogAnalyzer's development lead, today finished implementing a logstream driver for MongoDB. So this nice tool can now also be used to access MongoDB based data. Andre's lab data was created by rsyslog's ommongo output module (you currently need rsyslog git master branch to make this work). The logstream driver is not yet really optimized and we do not make full use of the NoSQL capabilites (like different schemas inside a single collection and all this). However, there is lots of exciting stuff on the todo list and I thought I mention a first successful step - and probably a quite important one if you "just want to use that thing" ;) So: good news for a Friday!

[OT] friend needs help in music contest ;)

2012-03-26T18:34:00.001+02:00

Hi folks, my blog's title says it is about the many thing's Rainer is interested in. If you look at the postings, that seems to mean "syslog". Today is one of the rare occurences that I write about something else, and it is also a request for a little bit of help...

Friends of mine produce fine (non-mainstream) music. They have entered a local contest over here with a re-interpretation of a classical theme. I really enjoy the modern "feeling" of the theme. I would like to invite all of you to listen yourself - and vote for them if you like what you hear. "Pepper Dance", as it is called, is available form this site. Unfortunately it is in German only, but navigation shouldn't be too hard: the play button is pretty universal ;-). And if you'd like to vote for it, just follow the big "Jetzt Abstimmen" link below the photo.

rsyslog / CEE base schema mapping

2012-03-19T08:46:00.000+01:00

I am giving a first shot at a mapping of the CEE base schema (as currently described in project lumberjack, NOT on the CEE site!) to rsyslog properties. The core idea is to use this mapping as the default for ommongodb. Then, rsyslog shall be able to write this schema, while logtools (and others) can rely on it. For obvious reasons "rely" is not to be treated literally, as the whole thing currently is a moving target.

So I would deeply appreciate feedback for improving this mapping.

In the following mapping, the cee field name is first, the rsyslog property second.

Fields we can always map:

srchost -> hostname
time -> timestamp (rsyslog currently populates subseconds, what seems not to be supported in lumberjack)
msg -> msg (initially used rawmsg, but decided against this)
pid -> procid (may not actually be a Linux process ID)
proc -> app-name
level -> generated based on syslog severity (value mapping see below)

Translation of syslog severity to lumberjack level (not bijective, syslog first, number in parenthesis denotes numerical value):

emergency(0) -> FATAL
alert(1), critical(2), error(3) -> ERROR
warning(4) -> WARN
notice(5), informational(6) -> INFO
debug(7) -> DEBUG
(never mapped) -> TRACE

Fields we do not currently provided, but could be in some cases:
Note that these fields may or may not be present inside a JSON/BSON document.

ppid -> parent process ID (SCM_CREDENTIALS, local only?)
uid -> (SCM_CREDENTIALS, local only?)
gid -> (SCM_CREDENTIALS, local only?)
tid -> thread ID (questionable, can probably not provided with current logging API)

As I said, feedback and suggestions are highly welcome. This list ist work in progress and can change in any instant. I'll provide notification when the interface has stabilized. Do not expect this soon.

next steps for ommongodb

2012-03-18T12:33:00.001+01:00

I just wanted to give you a heads-up on my work on ommongodb. During the past couple of days I have converted it to libmongo-client, which gives us a much more solid basis. I have also refactored it to some degree and adopted it to the new v6 config interface. Also, ommongodb will not be supported on pre-v6 platforms. This enables me to use the v6-exclusive features I am building now, especially great JSON and CEE support. Right now, ommongodb uses a very limited field set, and this set is hardcoded (so you can change it, but that means you need to change code).

My next step is to make ommongodb support the base event (as currently being discussed in project lumberjack). I will also provide a capability to add "extra" information from the cee field set. That's probably not a perfect solution, but the goal is to get ready for some command line tools that are able to extract data from mongodb and thus make the system mimic it is a traditional flat-file syslog format. I have also asked Andre, the lead behind Adiscon LogAnalyzer to consider adding support for MongoDB to loganayzer. I have not yet heard back from him and don't know exactly about his schedule, but I hope we will be able to make this happen very soon.

Only after that - somewhat hardcoded - work is done I'll go back and look at JSON and templates in a more native way (very probably also looking at the contributed JSON string generator in more depth).

JSON and rsyslog templates

2012-03-15T10:02:00.000+01:00

Rsyslog already supports JSON parsing and formatting (for all cee properties). However, the way formatting currently is done is unsatisfactory to me. Right now, we just take the cee properties as they are and format them into JSON format. In this mode, we do not have any way to specify which fields to use and we also do not have a way to modify the field contents (e.g. pick substrings or do case conversions). Exactly these are the use cases rsyslog invented templates for.

One way to handle the situation is to have the user write the JSON code inside the template and just inject the data field where desired. This almost works (and I know Brian Knox tries to explore that route). IT just works "almost" as there is currently no property replacer option to ensure proper JSON escaping. Adding this option is not hard. However, I don't feel this approach is the right route to take: making the admin craft the JSON string is error-prone and very user-unfriendly.

So I wonder what would be a good way to specify fields that shall go into a JSON format. As a limiting factor, the method should be possible within the limits of the current template system - otherwise it will probably take too long to implement it. The same question also arises for outputs like MongoDB: how best to specify the fields (and structure!) to be passed to the output module?

Of course, both questions are closely related. One approach would be to solve the JSON encoding and say that to outputs like MongoDB JSON is passed. Unfortunately, this has strong performance implications. In a nutshell, it would mean formatting the data to JSON, and then re-parsing it inside the plugin. This process could be be somewhat simplified by passing the data structure (the underlaying tree) itself rather than the JSON encoding. However, this would still mean, that a data structure specific for this use would need to be created. That obviously involves a lot of data-copying. So it would probably be useful to have a capability to specify fields (and replacement options) that are just passed down to the module for its use (that would probably limit the required amount of data copying, at least in common cases). Question again: what would be a decent syntax to specify this?

Suggestions are highly welcome. I need to find at least an interim solution urgently, as this is an important building block for the MongoDB driver and all work that will depend on it. So please provide feedback (note that I may try out a couple of things to finally settle on one - so any idea is highly welcome ;)).

signifying the local host IP in rsyslog

2012-03-14T14:45:00.002+01:00

I had an interesting enhancement request these days: make rsyslog emit a real interface address with local-generated messages (inside the fromhost-ip property). Until now, rsyslog always uses the localhost IP (127.0.0.1) when it talks of the local machine being the message source. This request makes a lot of sense and I wonder that I didn't receive it earlier.

We started with the imuxsock module, quickly followed by imklog ... and now some other internal message sources. Thinking of a local "problem" I so far have integrated the functionality into each plugin in question. It works via config directives, which enable to tell which interface's (e.g. eth0) IP is to be used. If not specified, we default back to "127.0.0.1", especially important for backward compatibility reasons (this change could cause a lot of harm to analysis tools!).

The current work can be found in the git v5-devel branch. However, the approach seems to be unsatisfactory: it looks like it is the right path to permit each message source to grab a real IP address. With the way it is currently done, the code for doing that needs to be replicated to all sources. That doesn't look very smart.

So I am thinking about refactoring the refactored code ;) The core idea is that a single global function could be used to provide the local IP. Then, each plugin could query that function when it needs to know the local IP (much in the same way this currently happens for the hostname). The drawback of this approach is that only a single IP can be used across all sources. Is that a problem or a feature? Please provide comments! Also, in pre-v6 the config may be somewhat inconsistent depending on where the interface setting is made. The reason is that in pre-v6 we do not have a clear point where we know the config is fully processed (but I may somewhat work around this inside the plugins themselves). Note that this is similar to the max message size config ugliness, where the size must be set right at the top of rsyslog.conf to work properly across all modules (and this causes confusion every now and then). In v6 (6.3 and above to be precise) this is no problem due to the enhanced and much more structured config processing.

Please let me know your thoughts about this issue, so that I can take the right direction!

finally... rsyslog agent for windows released

2012-03-05T18:21:00.000+01:00

It's done! We have finally released the rsyslog Agent for Windows, a nice piece of software that enables easy integration of Windows Event Logs into a rsyslog backend system. Ideas for this tool floated around for roughly four to five month, and we had lots of internal discussions. It is important to note that we at Adiscon already have the necessary technology as part of our Windows products (actually, we invented this whole event-log-to-syslog type of software...), so it was just a matter of fine-tuning the code and selecting some useful default settings and policies.

The release is important because it makes clear that there actually is a Windows component (while I tried to convey that several times, people most often did not realize it due to name differences - something with "rsyslog" inside the name was expected). It is also important for me at Adiscon internally: the rsyslog Agent is a commercial product and license sales will make clear that this business is driven by rsyslog. And, obviously, I hope that this will help fund the project without need to resort to other things like premium plugins. This is also why the Agent is so important for the rsyslog project as whole: it will hopefully help to stabilize the funding situation even more.

EDIT: I should probably mention that the Windows Agent was more or less ready when I held its release in order to integrate support for cee-enhanced syslog into it. I am glad I could convince my folks at Adiscon, so that we now have this exciting feature actually available.

CEE-enhanced syslog defined

2012-03-05T12:42:00.002+01:00

CEE-enhanced syslog is an upcoming standard for expressing structured data inside syslog messages. It is a cross-platform effort that aims at making log analysis (and log processing in general) much more easy both for log producers and consumers. The idea was originally born as part of MITRE's CEE effort. It has been adopted by a larger set of logging stakeholders in an initiative that was named "project lumberjack". Under this project, cee-enhanced syslog, and a framework to make full use of it, is being openly advanced. It is hoped (and planned) that the outcome will flow back to the CEE standard.

In a nutshell cee-enhanced syslog is very simple and powerful: inside the syslog message, a special cookie ("@cee:") is followed by a JSON representation of the data. The cookie tells processors that the format is actually cee-enhanced. If you are interested in a more technical coverage, have a look at my cee-enhanced syslog howto presentation.

Adiscon is one of the main supporters of project lumberjack and CEE enhanced syslog. Since February 2012, Adiscon products offer basic support for cee-enhanced syslog, being among the first tools to do so.

What is CEE-enhanced syslog?

2012-03-01T17:39:00.001+01:00

I just did a quick presentation on what cee-enhanced syslog actually is and how it works. I suggest to have at least a peek, as this format will probably become very important in the future. But why say more... just get the full story in 5 minutes ;)

cee-enhanced event log to syslog forwarding

2012-03-01T12:52:00.000+01:00

As many know, we at Adiscon also work hard at Windows Event Log to syslog forwarding software. During the past days we have taken the time to implement cee-enhanced syslog format inside these products as well. It is currently a proof of concept stage, but mostly because the relevant specs are also at PoC. This effort nicely integrated with the new project lumberjack, which aims at providing structured logging. New releases of the relevant Windows products (EventReporter and MonitorWare Agent) will be released very soon. With these releases, we are again the first-ever folks to release something never seen before, this time CEE support for windows logging ;)

But how does it work? Basically, it is a message format option of the "format syslog" option. If you select cee-enhanced syslog, messages will be emitted in that format. Most importantly, they will included nice name/value pairs of the Windows events (if Windows provided names, else the previous "Paramn" replacement names will be used). For example, a security event is described as follows:

@cee: {"source": "machine.local", "nteventlogtype": "Security", "sourceproc": "Microsoft-Windows-Security-Auditing", "id": "4648", "categoryid": "12544", "category": "12544", "keywordid": "0x8020000000000000", "user": "N\\A", "SubjectUserSid": "S-1-5-11-222222222-333333333-4444444444-5555", "SubjectUserName": "User", "SubjectDomainName": "DOMAIN", "SubjectLogonId": "0x5efdd", "LogonGuid": "{00000000-0000-0000-0000-000000000000}", "TargetUserName": "Administrator", "TargetDomainName": " DOMAIN ", "TargetLogonGuid": "{00000000-0000-0000-0000-000000000000}", "TargetServerName": "servername", "TargetInfo": " servername ", "ProcessId": "0x76c", "ProcessName": "C:\\Windows\\System32\\spoolsv.exe", "IpAddress": "-", "IpPort": "-", "catname": "Logon", "keyword": "Audit Success", "level": "Information"}

Note that we currently focus on cee-enhanced syslog format. We did not yet try to map the Windows field names to the CEE dictionary/profile terms. Probably the most important reason for this focus is that we do not yet have any definite spec to write to. Obviously, once the spec is out, it is fairly easy to upgrade the implementation to support these other names.

A co-worker is right now doing some more testing with rsyslog, which is able to understand that new format. I'll update you with the findings, and procedures, once they are ready.

Announcing Project Lumberjack

2012-02-28T18:06:00.000+01:00

Two weeks ago, along with the Fedora Developer's Conference in Brno, Czech Republic, a couple of logging and auditing folks from Red Hat, Balabit (syslog-ng), the MITRE Corporation, and Adiscon (me) stuck their heads together to talk about the future of structured logging. It quickly became clear that extending syslog in the CEE spirit is the right thing to do.

We observed that almost all technology is present to provide a rich framework to support structured logging. Actually, both syslog-ng and rsyslog provide the necessary plubming since long (for, example, as part of the RFC5424 effort), but that functionality is relatively seldom explored actively by other developers. A core problem in that regard is that most applications rely on the good old syslog() API, which does not provide structured logging by itself. Also, there is no common log storage database available, which tools could be based on.

In order to evolve syslog, we defined a three-layer architecture, with applications and logging libraries/APIs being the top layer, the syslogd the middle layer and the datastore the bottom layer. Multiple APIs must be supported as noone can expect projects to change their existing logging infrastructure. Also, existing frameworks like log4j or log4j and even glibc's syslog() will stay around for a while longer. New libraries (like ELAPI) will probably become more dominant for new applications. So how to tie these different libraries to the syslogd subsystem (the second layer)?

The solution is rather simple: we use what we already achieved in CEE and support cee-enhanced syslog on the system log socket. The core idea is very simple: we use the regular syslog message part, but include JSON-encoded structured data with it. To signify to the syslog system that this is actually cee-enhanced, a cookie string ("@cee:") is used in front of the JSON data. It is then easy to decide for the syslogd which message format it deals with: if the cookie is present and the rest of the message is a valid JSON representation, the message is cee-enhanced. If one of the two conditions fails, it is traditional syslog. As both conditions are checked together, it is highly unlikely that a legacy syslog message will ever fit into that criteria (and if it really does, nothing is lost: after all, the syslogd has correctly understood that format). It must be noted that the necessary parsing and internal plumbin is available both in syslog-ng as well as rsyslog (I committed the missing JSON parser, held back awaiting a more final CEE standard, yesterday).

The interface to the log database layer is currently not as well defined and needs to be worked on. Note that both syslog-ng and rsyslog support multiple datastores, so there already exist solutions. The group as whole was of the opinion that some unified API for a log data store would be useful and something that should be looked at as a longer-term target.

After reaching this rough consensus, we were delighted to see that most of the base technology is already and place and just needs to be tied correctly together. It is more an effort of doing detail implementations and documenting the various pieces (and how they work exactly together) than creating a totally new system (aka "can be quickly done"). We agreed that it probably is best to reach for the low-hanging fruit first: get structured logging integrated first, then do the other steps. So an initial milestone will be making sure cee-enhanced syslog is supported by all of the subsystem and only after this is done reach for the other things.

One of these next things definitely is a dictionary of field names (and exact structure) to be used to describe events in a standard way (for example a logon event). While the whole effort is highly inspired by CEE, it probably is best to try out initial efforts outside of the formal CEE framework. That will enable rapid development, discussion and the capability to check what works in practice. The experience gained in such PoC can than be feed back to the formal CEE process (along the old IETF mantra "running code and rough consensus first").

We agreed that such an effort is best be done in a tranparent and flexible open source process. With that, project lumberjack was born: an effort to provide better structured logging for Linux, being supported by many major players in that arena. We agreed that it would be a good idea if Red Hat provided some of the project infrastructure. This is why you find project lumberjack now at fedorahosted.org (note that the project will probably contain mostly specs and less code, which is kept in the individual project's repositories).

parsing JSON-enhanced syslog

2012-02-21T13:00:00.001+01:00

Strucuted logging is cool. A couple of month ago, I added support for log normalization and the 0.5 draft CEE standard to rsyslog. At last weeks Fedora Developer's Conference, there was a huge agreement that CEE-like JSON is a great way to enhance syslog logging. To follow up on this concept, I have integrated a JSON decoder into libee, so that it can now decode JSON with a single method call. It's a proof of concept, and for serious use performance optimization needs to be done. Besides that, it's already quite solid.

Also, I just added the mmjsonparse message modification module to rsyslog (available now in git master branch!). It checks if the message contains an "@JSON: " cookie and, if so, tries to parse the resulting string as JSON. If that succeeds, we obviously have a JSON-enhanced message and the individual name/value pairs are stored and can be used both in filters and output templates. This provides some really great opportunities when it comes to processing the structured data. Just think about RESTful interfaces and such!

Right now, everything is at proof of concept level, but works well enough for you to try it. I'll smoothen some edges but will release the versions rather soon. Probably the biggest drawback is that the JSON processor currently flattens the event, with structure being conveyed via field names. That means if you have a JSON object "SUPER" containing a number of fields "field1" to "fieldn", the current implementation will be a single level and the names are "SUPER.field1",... I did this in order to have a quick solution and one that fits into the existing framework. I'll work on creating real structure soon. It's not really hard, but I probably do some other PoCs first ;)

I considered several approaches, among them moving over to libcollection (part of ding-libs) or a pure JSON parser. The more I worked with the code, the more it turned out that libee already has a lot of the necessary plumbing and could simply been enhanced/modified under the hood. The big plus in that approach is that is immediately plugs in into rsyslog and the other solutions that already built on it. This even enables to use the new functionality in the v6 context (I originally thought I'd need to move on to rsyslog v7 for the name-value pair changes). Now that I have written mmjsonparse, this really seems to work out. No engine change was required, and I expect little need for change even for the final version. As such, I'll proceed in that direction. Actually, what I now use is kind of a hybrid approch: I use a lot of philosophy of libcollection, which showed me the right route to take. Then, I use cJSON, which is a really nice JSON parser. In the proof of concept, I use both cJSON's object model and libee's own. I expect to merge them, actually tightly integrating cJSON. The reason is that CEE has evolved quite a bit in the mean time, and many complex constructs are no longer required. As such, I can streamline the library as well, what not only reduces complexity but speeds up the whole process.

I would like to express my sincere thank to Dmitri Pal, Keith Robertson and Bill Heinbockel, which provided great advise and excellent discussion. And the best is that this part of the effort is just the beginning... Stay tuned for more!

Java Exceptions and syslog, anyone?

2012-02-01T14:49:00.002+01:00

Anyone out there having problems receiving Java exceptions via syslog? If so, please let me know. We have begun to look into log4j and potential formatting problems. However, we need someone who is really bugged by this in order to see real-world cases so that we can think about real-world cures. So if you have issues, please let me know.

imuxsock rate limiting now opt-in feature

2012-01-16T18:07:00.003+01:00

I added rate-limiting capabilities directly into rsyslog's imuxsock some time ago. These were turned on by default and blocked processes from writing more than 200 messages within a 5-second interval (accounted on a per-pid level). This default, however, caused quite some confusion. I monitored reactions since the feature was introduced. Last week, I noticed Chris Gaffney, too, telling about his bad experience on twitter and suggesting to change that feature from opt-out to opt-in. That was the missing complaint ;) So I did exactly what Chris suggested, and starting with 5.9.7 that feature requires an explicit opt-in. To do so, I have simply changed the default. Now, you need to tell it the rate limiting interval, which must be non-zero, in order to activate rate limiting. The default is zero, what keeps it deactivated. Currently available via git. It will take some time, though, for this changed default to migrate to the stable branch.