rsyslog error reporting improved

Rsyslog provides many up-to-the point error messages for config file and operational problems. These immensly helps when troubleshooting issues. Unfortunately, many users never see them. The prime reason is that most distros do never log syslog.* messages and so they are just throw away and invisible to the user. While we have been trying to make distros change their defaults, this has not been very successful. The result is a lot of user frustration and fruitless support work for the community — many things can very simple be resolved if only the error message is seen and acted on.

We have now changed our approach to this. Starting with v8.21, rsyslog now by default logs its messages via the syslog API instead of processing them internally. This is a big plus especially on systems running systemd journal: messages from rsyslogd will now show up when giving

$ systemctl status rsyslog.service

This is the place where nowadays error messages are expected and this is definitely a place where the typical administrator will see them. So while this change causes the need for some config adjustment on few exotic installations (more below), we expect this to be something that will generally improve the rsyslog user experience.

Along the same lines, we will also work on some better error reporting especially for TLS and queue-related issues, which turn out high in rsyslog suport discussions.

Some fine details on the change of behaviour:

Note: you can usually skip reading the rest of this post if you run only a single instance of rsyslog and do so with more or less default configuration.

The new behaviour was actually available for longer, It needed to be explicitly turned on in rsyslog.conf via

global(processInternalMessages=”off”)

Of course, distros didn’t do that by default. Also, it required rsyslog to be build with liblogging-stdlog, what many distros do not do. While our intent when we introduced this capability was to provide the better error logging we now have, it simply did not turn out in practice. The original approach was that it was less intrusive. The new method uses the native syslog() API if liblogging-stdlog is not available, so the setting always works (we even consider moving away from liblogging-stdlog, as we see this wasn’t really adopted). In essence, we have primarily changed the default setting for the “processInternalMessages” parameter. This means that by default, internal messages are no longer logged via the internal bridge to rsyslog but via the syslog() API call [either directly or
via liblogging). For the typical single-rsyslogd-instance installation this is mostly unnoticable (except for some additional latency). If multiple instances are run, only the “main” (the one processing system log messages) will see all messages. To return to the old behaviour, do either of those two:

  1. add in rsyslog.conf:
    global(processInternalMessages=”on”)
  2. export the environment variable RSYSLOG_DFLT_LOG_INTERNAL=1This will set a new default – the value can still be overwritten via rsyslog.conf (method 1). Note that the environment variable must be set in your startup script (which one is depending on your init system or systemd configuration).

Note that in most cases even in multiple-instance-setups rsyslog error messages were thrown away. So even in this case the behaviour is superior to the previous state – at least errors are now properly being recorded. This also means that even in multiple-instance-setups it often makes sense to keep the new default!

Disappointing press reactions…

Friday, 13th… Systemd v38 went out recently and it includes a journald test release. That’s great and congrats to the systemd team to that release. What me saddens is the that the press still conveys only Lennart’s position on how bad syslog is. The counter arguments (http://blog.gerhards.net/2011/11/serious-syslog-problems.html) are mentioned nowhere. Lesson learned? All it takes is some interesting-sounding claims and everyone believes them. Does anybody still wonder why I think journald will become standard [and would do so even if it were totally evil]? ;-)

But don’t get me wrong: while I think the journald proposal and the way it is getting pushed has some flaws, I also see good in it. My initial reaction still stands: http://blog.gerhards.net/2011/11/journald-and-rsyslog.html Unfortunately, the world, and us, the masses, seems not to be prepared for weighted arguments… On to the weekend, have a great one :-)

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.

new rsyslog/systemd work going on

This is just a quick note that systemd is doing really well in providing logging right from the system startup, even when no syslogd is running. The magic is that messages are put into the kernel log, where the (later started) syslogd can pull them from. Unfortunately, there are some downsides from this mode, and we are currently working to solve them. For more details, please follow this thread:

http://lists.freedesktop.org/archives/systemd-devel/2011-March/001558.html

I guess the remaining issues will be settled soon, as almost everything is in place and I just need to add some additional parsing logic to rsyslog. Due to the conference next week, I may need one extra week to complete that. All of this work will be part of the newly opened v5-devel (and above).