Tech Enthusiast. Nature Lover. Computer Geek. rsyslog lead developer.
As promised, low activity:
– removed debian subdirectory by request of a debian packager (this is a special
subdir for debian and there is also no point in maintaining it when there
is a debian package available – so I gladly did this)
– improved overall doc quality (some pages were quite old) and linked to
more of the online resources.
– released 1.18.2
I am a bit involved in creating the next-generation on the wire syslog protocol with the IETF. Unfortunately, that activity had to starve a little while I was busy with getting rsyslog to its current state. However, I have not lost it out of my eye. And in fact the rsyslog implementation effort helped my sharpen my mind for what to suggest in the standardization area.
A recap: the IETF tries to standardize the syslog protocol for quite a while now. There were changing thoughts about what was needed, but this spring we agreed on bringing a draft up to the IESG. From there, we received a number of comments. Some easy ones, some of more substance. In July 2007, more or less one topic was left: that on what to do when a syslog sender blocks. I quote the relevant part of the IESG reply here (accentuation by me):
> First, this starts as an issue with TLS over TCP and the
> syslog base protocol.
> It can also arise teorethically for UDP, but as I understand
> not in practice for todays usage. When you are using TCP, in
> case the syslog sender generates events at an rate that is
> higher than available rate over the path used there will be
> build up of a queue. So I would like to have some words
> somewhere saying what you do when you build up a queue of
> messages that should be transmitted, but the queue simply
> keeps growing. What do I do? To me this situation implies
> that one starts discarding syslog messages and starts
> with the least important ones. So I would like to have
> a paragraph on this.
>
> I also included UDP in this in the case that you actually
> have reserved or determined that syslog is allowed to use a
> particular amount of bandwidth, but not more. In this case it
> could be possible that one implements a rate limiter
> and run into exactly the same issue as for TCP.
>
> Please do understand that if syslog was designed from scratch
> today it wouldn’t get away without a congestion control that
> guarantees that it isn’t missbehaving in any situation. But
> being an “old” protocol we are accepting less than that.
> However, we do require it to contain the limitations and
> assumptions that it can be safely operated with. Using it as
> it currently is used is not an issue because the networks it
> is used in has many magnitudes more bandwidth that syslog
> generates. However, what would happen if some one starts
> using syslog in low-powered, low-bitrate sensor network for
> carrying some information. In that situation syslog becomes a
> potential threat to the stability of the network as it
> doesn’t react at all to congestion if run over UDP. Network
> failures are also sitation that are problematic to ensure
> that the inteded resources are available. Thus we do
> like to protect the utility of what resources do exist.
And this sentence covers it all:
> Please seriously consider adding a paragraph about
> how one can thin a queue of syslog messages in
> the base protocol. This as I think it potentially applies
> to any transport.
This basic requirement caused some confusion in the working group (WG). I have to admit, it confused me at that time, too.
In the mean time, I kept working on rsyslogd. I didn’t even realize that I had written code in 2005 (or so) to take care of what was requested by the IESG: if rsyslog runs in single thread mode and it forwards messages via TCP and the send call would block – then we have a problem. Because when we wait, we will potentially hang the whole system. This is unacceptable. So I coded rsyslog in such a way that it discards the message in such a situation.
When I moved rsyslog to a multi-threaded design, that restriction was removed. Now, there was a queue between the receiver and the (potentially blocking) sender. And, as we all know, queues are endless, so we’ll never run into problems ;-]. Of course, that simplistic point of view survived only so long as we did not deliberately bash rsyslogd with lots of traffic. What then happens is pretty much the same as in the single-threaded case: rsyslog freezes. Mildew, a frequent contributor, discovered this problem and also sent a good fix: he throws away messages if the queue is full. Sounds familiar? Yes, there seems to be a real-world problem and there is also a well known cure for it.
In some essence, this is what the IESG is asking for – at least as of my understanding. But the IESG, obviously speaking with a lot of experience, goes a step further. What they recommend is not to discard newly arrived packages. The recommend a way to “thin out the queue“. So we would not just blindly drop whatever comes when the queue is full. No, we should intelligently decide what to drop, and that based on the severity of the message. It sounds only fair that debugging messages get dropped in favor of emergency messages. And, yes, syslog has a field “severity”, which is the right thing to use here.
I thought about implementing a “high watermark” in the rsyslog queuing engine. What that amount of the queue would be full, a filter should be applied to the message. So from that on, only messages with a given severity would be queued, while all others be dropped. Of course, those already in the queue would be sent, no matter how unimportant they are. So far, I have not implemented that algorithm. And I think I am now unlikely to do it that way. It would be much better to follow the advise and, once the queue becomes full, begin to drop messages based on their severity.
I can even envision the algorithm: go forward through the queue starting at the tail and look for messages with the least importance. Once you have found one, drop it. Then enqueue the (new) higher-severity message. When this is done, do not drop any more messages, because it may not be necessary. We can always drop if a newer higher priority message arrives. If, during our queue traversal, we could not find any message with lowest severity, retry with the next lowest severity. Run this algorithm until either a message to drop is found or the drop-severity has reached the severity of the to-be-queued message, which in this case is the youngest and thus the drop target. Of course, that algorithm needs to be tweaked in regard to performance, but basically it should work fine. I even think, a derivative of it will make it into a rsyslog feature request.
… and now back to the IETF. We still need wording for our upcoming standard (called an I-D). Now that I know what I look for, shouldn’t it be easy? Well, to be honest I don’t think its that easy. First of all, I am not sure if, in a protocol specification, I can demand such queue processing. It looks somewhat too algorithmic, too implementation specific to me. So I need to find a better way to phrase it. And of course, peer review will show if that makes sense or not (maybe we even get a better suggestion).
My first try at it is as follows:
In any implementation, a situation can arise in which an originator or relay would need to block sending messages. A common case is when an internal queue is full. This might happen due to rate-limiting or slow performance of the syslog application. In such cases, it is RECOMMENDED that the originator or relay drops messages of lower severity in favor of higher severity messages. Messages with a numerically lower SEVERITY value have a higher severity than those with a numerically higher one. To-be-dropped messages SHOULD simply be discarded. The syslog application may notify a collector or relay about the fact that it drops messages. If the underlying protocol supports congestion control, discarding of messages SHOULD be avoided.
I have to admit that this text is probably too lengthy and imprecise. But hopefully it is a starting point. I’ll post it to the syslog IETF WG and we’ll see…
Still, there is one important message to learn: no matter how hard we try, there is always a chance that we must discard messages. It may be highly unlikely and it may be totally unexpected. But we can not absolutely avoid it. Not even an on-disk queue is large enough, that it can buffer any imaginable message queue. So loss of messages is inherent in any application, also in syslog and auditing. The question is, how we deal smartly with it and how we preserve as much evidence in our logs as possible (and keep the log valid in those cases!). This all sounds pretty basic and easy, we always need to remember ourself’s of this fact…
This was a question I received back from Anton Chuvakin when I asked a number of folks which features they wanted to see in rsyslog. If I could answer that question, he would reply with further details.
Actually, I think that was a very smart reply. It comes down to “why should anybody care about rsyslog at all?”. Aren’t there already enough syslogds? An interesting question.
At first, I was tempted to answer that question by talking about features, all those things that rsyslog will do to rule the world. But – does this answer the question? Nope, it doesn’t. Next, I thought to write about my goals with rsyslog. Why do I do all this work, just to create another free GPLed application. But, again, does this answer why the world needs another syslogd? Oops… no, it doesn’t. Its not about me, but about the world, that’s you, folks. So why do you need another syslogd… Continue reading “why does the world need another syslogd? (aka rsyslog vs. syslog-ng)”
A modern open-source project, at least IMHO, needs a number of supporting web services: a blog, a bug tracker, a forum … and a wiki. For rsyslog, most of this services existed for quite a while. What was missing until now was a wiki. Thanks to Andre Lorbach who set it up, we now have one at http://wiki.rsyslog.com. I have finally found time to add at least some information into it.
And now it is the users turn. The wiki is not meant to be a replacement for the official doc. Instead, it should contain user contributed content and ideas. So it is up to you to fill it with live. Of course, the rsyslog devel team will have a keen eye on the wiki and be as helpful as possible. Please give it a try and help creating a great community-driven wiki.
Yesterday I made a couple of changes:
– fixed a bug in outchannel code that caused templates to be incorrectly
parsed
– fixed a bug in ommysql that caused a wrong “;template” missing message
in some cases
– some text and code cleanup in cflineParseTemplate() to match the changed
design of selector handling
– added new doc files to autotools for make dist
– fixed a bug that would have manifested when module configuration commands
would have been freed. The current code base, however, never does this, so
this is not a real bug fix – it’s in preparation of future work
– fixed a potential memory leak in modules.c, again, this could not happen in
current code
– added interface API for unloading module (a dummy)
– added module unload functionality; rsyslogd now unloads modules on exit
(of course, with only statically linked modules, there is little current
value in this – but it is made towards an upcoming dynaload plugin interface)
This time, I blog the changes for both days. Today was again quite busy, with a number of smaller changes. But all in all you can see that the pace of changes is reducing. I hope that people will test it, but I also hope that we will see no more big bugs the next few weeks. Then, I consider it to be mature for a new stable release.
You will probably see no or very few code changes during that period. You can expect, however, some doc upgrades. All in all, my focus has now moved to the next major release, which I am currently designing. And of course, some other things are also asking for a bit of time now that I have worked very intensely the past two month on rsyslog.
Stay tuned. Any news will appear here in the blog. In the mean time, try 1.18.1 and tell us what needs to be fixed (of course, you may also just praise our work, that’s fine, too ;)).
Here is the work log:
2007-08-07
2007-08-08
Based on my last post on rsyslog multithreading, an email conversation arose. When I noticed I elaborated about a lot of things possibly of general interest, I decided to turn this into a blog post. Here it is.
The question that all this started was whether or not a worker thread pool is good or evil for a syslogd.
Yes, the worker-thread pool has a lot of pros and cons with syslog. I know this quite well, because I am also the main design lead behind WinSyslog, which was the first syslogd available natively on Windows (a commercial app). It is heavily multi-threaded. I opposed a worker pool for a long time but have accepted it lately. In some high-volume scenarios (unusual cases) it is quite valuable. But of course you lose order of messages. For WinSyslog, we made the compromise to have the worker pool configurable and set it to 1 worker if order of events is very important. I designed WinSyslog in 1995 and released the first version in 1996 – so I know quite well what I am talking about (but to be honest the initial multi threading engine got in somewhat later;)).
HOWEVER, especially in high-volume environments and with network senders, you are somewhat playing Russian roulette if you strongly believe that order in which events come in is exactly the same order in which they were sent. Just think routers, switches, congestions, etc… For small volumes, that’s fair enough. But once the volume goes up, you do not get it 100% right. This is one of the reasons I am working quite hard it the IETF to get a better timestamp in into syslog (rsyslog already has it, of course as an option). The right thing to do message sequencing is by looking at a high-precision timestamp, not by looking at time of reception.
For rsyslog, I am not yet sure if it will ever receive a worker pool. From today’s view, it does not look necessary. But if I think about future developments in hardware, the only key in getting more performance is by using the enhanced parallelism the hardware will provide. The time of fast single cores is over. We will have relatively slow (as fast as today ;-]) massively parallel hardware. This is a challenge for all of software engineering. Many folks have not yet realized it. I think it has more problem potential than the last “big software crisis”. As you can see in the sequencing discussion, parallelism doesn’t only mean mutexes and threads – it means you need to re-think on how you do things (e.g. use timestamps for correlation instead of reception/processing order, because the later is no stable concept in a massively parallel program). With the design I am now doing, I will definitely have separate threads for each output action (like file or database writer). I need this, because rsyslog will provide a way to queue messages on disk when a destination is not available. You could also call this “store-and-forward syslog”, just like SMTP is queued while in transit. You can not do this concept with a single thread (at least not in a reasonable complex way). I also do not think that multiple processes would be the right solution. First off, they are too slow. Secondly, multiple processes for this use are much more complicated than threads (I know, I’ve written similar multi-process based things back in the 80s and 90s).
Rsyslog will also most probably have more than one thread for the input. Input will become modular, too. If I use one thread per input, each input can use whatever threading model that it likes. That makes writing input plugins easy (one of my goals). Also, in high volume environments, having the ability to run inputs on multiple CPUs *is* *very* beneficial. One of the first plugins will be RFC 3195 syslog, which is currently run as an external process (communicating via unix local domain socket, which is quite a hack). At the core of 3195 is liblogging, a slim and fast select-server I have written. However, integrating it into a single-threaded application is still a challenge (you need to merge the select() calls and provide an API for that). With multiple threads, you can run that select server on its own thread, which is quite reasonable (after all, why should both UDP and 3195 reception run on the same thread?). The same is true for tcp based processing. Then think about the native ssl support that is coming. Without hardware crypto acceleration, doesn’t it make much sense to run the receiver on its own thread? Doesn’t it even make sense to run the sender on its own thread?
So the threading model of the next major release of rsyslog (called 3.x for reasons not yet elaborated about) will most probably be:
This design will provide superb performance, is oriented on logical needs, allows for easy intrgration of plugins AND will be reasonable easy to manage – at least I hope so.
But, wait, why have I written all this? OK, one reason is that I wanted to document the upcoming threading model for quite a while and now was a good time for doing so. But I think it also shows that you can not say “multithreading is good/bad” without thinking about the rest of the system design. Multi-threading is inherently complex. Humans think sequentially, at least when we think about something consciously. So parallel programming doesn’t match human nature. On the other hand, nature is doing things itself massively parallel. Just think about our human vision: in tech terms, it is massively parallel signal processing. This is where technology is also heading to. As we have learned to program at all, we will also learn to deal with parallel programming. A key thing is that we should never think about parallelism as a feature – it’s actually a tool, that can be used right or wrong. So let’s hope the rsyslog design will do it right. Of course, comments are very much appreciated!
I found a quite interesting discussion on a debian mailing list on why it may be useful (or even evil) for rsyslog to be multi-threaded.
It’s late now, so I can not elaborate in full, but I thought I share a little feedback. First of all, my project description is actually cheating a bit at this time: rsyslog is currently actually dual-threaded, with one thread for message reception and one thread for message processing. And this is even optional, so you can turn it off with a configure option to make it single-threaded. Future versions of rsyslog will have much improved threading model and that has much to do with modular input and output – but that’s a different story.
Run rsyslog compiled for single threading and make it write to a MySQL database, then throw lots of messages at it (let’s say maybe 500 per second, which is not actually much). You’ll soon see that messages are lost, because the receiver can’t receive new messages while the MySQL output module (message processor) is writing messages. So reliability and message reception capability is limited by the slowest output module in use.
With a multi-threaded model, this problem does not exists. Receiver and output modules are de-coupled via an in-memory queue. So when the MySQL server is to slow for the current message rate, messages are buffered in the queue, but the receiver can continue receiving messages. As we have UDP, this is quite important. Please note that in a failover case, the output module may be busy for as long as maybe even a few seconds. This time may be needed to probe if the primary has really failed and then connecting to the secondary. The whole idea not only applies to MySQL (though it is most obvious in this use case) but also for TCP based syslog forwarding. Here, the receiver can actually slow down the sender, so the same problem may occurs. De-coupling receiver and output modules is also of great benefits in high volume environments. It enables bursts to be processed reliably where messages were otherwise lost.
So the main reason for the current threading model is reliability and striving to lose as few messages as possible. Of course, there is also a performance benefit, especially if you think that in the future we will see machines with many more cores – but a single core not beeing considerably faster than today. Rsyslog’s current threading model is not up for this challenge yet – that will happen later this year. Then, each output will receive its own thread. There are good reasons to do that, for example the need to support re-startable action with local disk queueing (aka “store-and-forward syslog). Without parallelism, this is not doable. But I’ll elaborate on that later as the object and threading model design grows.
And, yes, I share concerns that threading makes code more complex. This is the #1 reason that threading is still a compile-time optional feature in the current rsyslog. But as the project evolves, we need to have multiple threads to support a clean object model. And, yes, again, that sounds heavy. All I can say is that I am a performance hog, so you won’t probably see rsyslog taking up huge amounts of CPU just for the sake of having an object model. But of course, I may be cheating here, too (can you trust me? – stay tuned and you’ll see…).
I hope my short notes help to understand a bit why the current rsyslogd uses multiple threads.
EDIT: I have now found some time to elaborate on the upcoming rsyslog threading model and multi-threaded programming in general.
I have been on the road today, so not much happened. But at least some things were done ;)
Keep in mind that the pace of changes will now go down for a few weeks. The code needs to mature. I’ll probably focus more on docs AND *other* projects in the mean time. I guess I’ll also work on no-code things, like config file format and final object design (more on those later, this was just a teaser ;)).
here’s friday’s work log:
– added CODE_STD_FINALIZERparseSelectorAct to module-generation macros
– restructered rsyslogd startup – moved startWorker() to a more
appropriate
place
– updated ommysql.c to fully support suspension/resumption by rule
engine
– I found out that we finally have problems with the (somewhat
recursive)
call to logerror() that many of the modules do. I have not tried it,
but
I think things will become wild when we compile without pthread
support.
Threading prevents full recursion, so we have not seen any bad effects
so far. However, the problems that I experienced in ommysl (that
caused
me to re-structure startWorker()) are actually rooted in this issue.
I
first thought to fix it via a module interace, but I now came to the
conclusion that it is not more effort and much cleaner to do an
internal
error buffering class. This is implemented in errbuf.c/h.
– I just noticed that this is not actually an error buf, but the core of
an input module for all internal messages. As such, I implement it now
as iminternal.c/h. Of course, there is no input module interface yet
designed, but that doesn’t matter. Worst-case, I need to re-write the
im, best case I can use the im (at least partly) to define the
interface.
– added a few functions to the linkedlist class
– error messages during startup are now buffered – so we do no longer
need
to think about how emergency logging might work. Actually, these are
logged
to whatever is instatiated in the log file. This enhances the chance
that
we will be able to drop the error message somewhere it is seen.
– released 1.18.0
– reduced number of identical error messages in ommysql.c while
suspended