phpLogCon now in FreeBSD ports tree

Good news, folks: phpLogCon is now available in the FreeBSD ports treee. I’ve just read confirmation on a forum thread. This is obviously very good news, thanks everyone for making that happen. Given that there is also a port for rsyslog, now both components can work together and benefit from each other.

Of course, phpLogCon does not require rsyslog. It can work perfectly with any other syslogd, as long as it is pointed to the right files or databases. But having rsyslog’s ability at hand in addition to phpLogCon is quite handy – and vice versa.

Good news to start a day ;)

RFC 3195 back in the game?

RFC 3195 was thought to be the solution for reliable syslog. It is based on TCP and the BEEP protocol. It was written in November 2001 but never gained much attention. The premier reason everyone tells you is complexity of BEEP (and lack of toolkits). A few years ago, I wrote my own logging-related RFC 3195 toolkit, liblogging. It, too, did not get much momentum.

Anyhow, I used a modified version of liblogging to offer RFC 3195 support under Windows as part of the MonitorWare product line. Again, we never heard much of this feature. In rsylog, I created an input plugin for RFC 3195. At that time, however, I already had the feeling 3195 was a failure. So I was hesitant to implement an output plugin, too. And, as expected: nobody every cared, except for some folks building packages. And these not for practical needs but for the sake of getting packages for everything…

So up until now, I would conclude that 3195 is indeed a failure. However, there seems to be some increasing interest. At least, I got a couple of questions the past weeks on RFC3195 and Adiscon, my company, just got a not-so-small order of its EventReporter product which explicitly has RFC 3195 put into the requirements. Is this a sign of increasing interest? Or is just somebody filling check mark items? This remains to be seen.

So, there seems to be a slight chance that RFC 3195 is getting revived. Maybe it took just some year so that the idea could ripen. In any case, I am prepared for RFC 3195 demand. Maybe finally doing all that work begins to pay off…

Theoretical vs. Practical Performance

I found an interesting post “Algorithm Performance in Academic Papers and Practice” by fellow security blogger Steve Burnett on the SecurityBloggersNetwork.

Steve questions whether theoretical performance gains, often given based on big O notation, can really be realized in practice. He claims they often can not.

I tend to agree to his point, at least in broad terms. One must first remind oneself that big O notation is quite coarse, it tells you about the potential extremes. In practice, however, these extreme cases may routinely never hit. Even further, I think it depends very much on what the algorithm in question is actually doing. If it is “just” doing calculations on its own, theoretical performance benefits can much better be predicted than if there is any external reference.

The obvious case is code that needs to do some library or operating system calls inside the algorithm. A good example is the performance optimization I and David Lang did on rsyslog in fall of 2008. Here, and I have to admit partly to my surprise, it turned out that optimizing rsyslog algorithms actually had almost no effect in boosting the daemon’s performance. Why? Simply because a hand full of system calls, many time-related, used up the majority of execution time. So rather than optimizing the algorithms used, we optimized out OS calls and that had a very big effect (and even after that initial optimization, there is still much room for improvement just by looking at the APIs). Of course, this is an extreme sample, because usual syslog server processing is not at all computational and the frequent context switches themselves are performance intense. The picture for a graphics application is probably totally different.

However, many less obvious cases exist, and I guess lots of them have to do with the fact that multiple processes and/or thread are executed. So resources are shared. On such a system, for example, theoretical performance gains may be lost due to task switches which purge vital data off the CPU cache. Even worse, a theoretically optimized algorithm may require additional main memory, which may, in practice, force cache purges because the cache size now is insufficient. Funny, eh?

Wrap-up: big O notation is useful, but for practical needs, it needs to be taken with a grain of salt. For real world deployments, actual performance testing is quite important. And as a side-note, test results on a dedicated system may be quite different from practical performance on a system where other things are also executed…

Use of application-level acks in RELP

I received a very well crafted question about RELP reliability via the rsyslog mailing list this morning. I think it makes perfect sense to highlight this question here in the blog instead of letting it die unread and hard to find in the mailing list archives. Before reading this post, it would be useful to read my rant on “On the unreliability of plain tcp syslog” if you have not already done so. It will greatly help understand the fine details of what the message talks about.

Here we go, original posters’s text in italics, my replies in between it:

In my research of rsyslog to determine its suitability for a
particular situation I have some questions left unanswered. I need
relatively-guaranteed delivery. I will continue to review the
available info including source code to see if I can answer the
questions, but I hope it may be productive to ask questions here.

In the documentation, you describe the situation where syslog silently
loses tcp messages, not because the tcp protocol permits it but
because the send function returns after delivering the message to a
local buffer before it is actually delivered.

But there is a more-fundamental reason an application-level ack is
required. An application can fail (someone trips over the power cord)
between when the application receives the data and when it records it.

1. Does rsyslog send the ack in the RELP protocol occur after the
message has been safely recorded in whatever queue has been configured
or forwarded on so its delivery status is as safe as it will get (of
course how safe depends upon options chosen), or was it only intended
to solve the case of TCP buffering-based unreliability?


RELP is designed to provide end-to-end reliability. The TCP buffering issue is just highlighted because it is so subtle that most people tend to overlook it. An application abort seems to be more obvious and RELP handles that.

HOWEVER, that does not mean messages are necessarily recorded when the ACK is sent. It depends on the configuration. In RELP, the acknowledgment is sent after the reception callback has been called. This can be seen in the relevant RELP module. For rsyslog’s imrelp, this means the callback returns after the message has been enqueued in the main message queue.

It now depends on how that queue is configured. By default, messages are buffered in main memory. So when rsyslog aborts for some reason (or is terminated by user request) before this message is being processed, it is lost – while the sender still got a positive ACK. This is how things are done by default, and it is useful for many scenarios. Of course, it does not provide the audit-grade reliability that RELP aims for. But the default config needs to take care of the usual use case and this is not audit-grade reliablity (just think of the numerous home systems that run rsyslog and should do so in the least intrusive way).

If you are serious about your logs, you need to configure the engine to be fully reliable. The most important thing is a good understanding of the queue engine. You need to read and understand the rsyslog queue docs, as they form the basis on which reliability can be built.

The other thing you need to know is your exact requirements. Asking for reliability is easy, implementing it is not. The more you near 100% reliability (which you will never reach for one reason or the other) the more complex scenarios get. I am sure the original post knows quite well what he want, but I am often approached by people who just want to have it “totally reliable” … but don’t want to spent the fortune it requires (really – ever thought about the redundant data centers, power plants, satellite and sea links et all you need for that?). So it is absolutely vital to have good requirements, which also includes of when loss is acceptable, and at what cost this comes.

Once you have these requirements, a rsyslog configuration that matches them can be designed.

At this point, I’d like to note that it may also be useful to consider rsyslog professional services as it provides valuable aid during design and probably deployment of a solution (I can’t go into the full depth of enterprise requirements here).

To go back to the original question: RELP has almost everything that is needed, but configuring the whole system in an audit-grade way requires (ample) work.

2. Presumably there is a client API that speaks RELP. Can it be
configured to return an error to the client if there is no ACK (i.e.
if the log it sent did not make it into the configured safe location
which could be on a disk-based queue), or does it only retry? Where is
this API?


The API is in librelp. But actually this is not what you are looking for. In rsyslog, an output module (here: omrelp) provides the status back to the caller. Then, configuration decides what happens. Messages may be discarded, sent to a different destination or retried.

With omrelp, I think we have some hardcoded ways to preserve the message, but I have no time yet to look this up in detail. In any case, RELP will not loose messages but may duplicate few of them (within the current unacked window) if the remote peer simply dies. Again, this requires proper configuration of the rsyslog components.

Even with that, you may loose messages if the local rsyslogd dies (not terminates, but dies for some unexpected reason, e.g. a segfault, kill -9 or whatever) but still has messages in a not persisted queue. Again, this can be mitigated by proper configuration, but that must be designed. Also, it is very costly in terms of performance. A good reading on the subtleties can be in the rsyslog mailing list archive. I suggest to have a look at it.

Certainly the TCP caching case you mention in your pages is one a user
is more likely to be able to reproduce, but that is all the more
reason for me to be concerned that the less-reproducible situations
that could cause a message to occasionally become lost are handled
correctly.


I don’t think app-abort is less reproducable – kill -9 `cat /var/run/rsyslog.pid` will do nicely. Actually, from feedback I received, many users seem to understand the implications of a program/system abort. But far fewer understand the issues inherent in TCP. Thus I am focusing so much on the later. But of course, everything needs to be considered. Read the thread about the reliable queue (really!). It goes great lengths, but still does not offer a full solution. Getting things reliable (or secure) is very, very challenging and requires in-depth knowledge.

So I am glad you asked and provided an opportunity for this to be written :)

Rainer

Back from the break ;)

Hi folks,

I am right now back from my extended xmas break. Well, actually I’ve been gone right after xmas and been away – even mostly without email – for two weeks.

I was delighted to see that the rsyslog community was quite active during this time (which usually has low activity at all due to the holidays). An the sad side, that also means I have a couple of bug reports outstanding. One I managed to fix today, the others will need a little more time. Obviously, there are quite a lot of things going on, and these need to be taken care of, too. I need to do a few changes to our internal infrastructure, and then I’ll look into rsyslog, phpLogCon and the appliances.

One of the major undertakings I hope to finish in the not so distant future is fixing a stability bug that seems to occur on 4+ core machines only. I got another but report over the holidays and hope that I get enough momentum to finally track it down – we’ll see…

That’s it for now, I just wanted to keep you updated.

Oh – and did I mention happy new year ;) [it’s not too late right now…]

Rainer

root cause of security issue in rsyslog

If you have followed the rsyslog mailing list, you have noticed that we had a small, but still noteworthy, security issue in rsyslog recently. In short words, the $AllowedSender directive was accepted but no longer honored, given potentially any remote system a chance to send messages to the instance in question (its a minor issue because most people rightfully tend to use firewalls to carry out that kind of access control).

After this is now settled, I sat back, relaxed and meditated a bit about the root cause of the issue. Acutally, I didn’t need to think very hard. The problem was introduced when I implemented the netstream driver class. During that implementation, I shuffled a lot of code to the now-modular interfaces. Among them were the access control lists, whose roots were kept in global variables at this time.

I screwed up the first time when I allowed them to remain global variables. We all know that global variables are evil, especially when making publically accessible. Now that we moved to a proper interface, I should have replaced them by a function call. Doing that in the first place had prevented the problem. Why? Because I just initialized the now-interface specific global variable “representative” with the value at time of interface creation, which meant NULL in all cases. So whoever used the interface, always got an empty list, which meant no access control was configured.

Any user-configuration still hit the global variable, which caused the ACLs to be created, but no part of the code ever accessed it any longer. One may argue if that is a simple coding error, and there is some truth in it, but I’d still say its primarily a design issue (bad design promises to provide the quick solution, but it seldom does…).

And as it always takes at least two faults to really screw up, the next major issue wasn’t around to far. Rsyslog had not – and still has not! – a formal test suite that you can simply run each time code changes. I have begun to employ some limited test cases via “make check”, but they cover primarily exotic aspects and do not yet contain any serious test case that involves actually running rsyslogd against any serious number of messages. One of the reasons is that I had no good tool for doing so, or that I considered building the test suite to be too expensive (in comparison what else needed to do). As a small excuse I would like to mention that some others have encouraged this view. But I always new it is a lame excuse…

So it exactly happened what usually happens in such cases: the test case vital to discover this problem was not present in the series of test I ran against the new code. As usual, the programmer himself tests whatever he thinks needs testing. And, also as usual, this means that the programmer doesn’t test those things that he can not think of being wrong. Usually, these are the real problems, because if the programmer did not think of a potential problem, he did not implement, or at least carefully check, for it. This is just another example, why external testers are needed.

In open source, users adopting the devel and beta releases are often considered to be these testers. Quite frankly, I could not afford a full testing lab and continue developing the project. I think this is true for most open source projects. “Free testing” by early adopters is a major advantage over closed source. But this time, this failed, too. Probably the (small) club of early adopters also did not think about this issue. Maybe that’s because the more knowledgeable folks prefer to solve this problem with a firewall, which is the better approach to use for various reasons (not to be outlined here, see security advisory for details).

Finally, the issue came up in the form of a bug report. Unfortunately quite later, month after the initial release. But it was reported and so I could fix it as quickly as possible once I knew.

The important lesson to learn is that it usually takes more than one error to cause real problems. But these things happen!

I think the case also strengthens the need for good, systematic testing. Some time ago, I began to look into the DejaGnu testing suite and asked the mailing list if somebody had some experience in it. Unfortunately, nobody showed up. I’ll now give it another shot. There have been too-often small problems that were rooted in things not being consistently tested. Most often, it were only really small issues, like missing files, or some variables not defined in some conditional path. Since I improved my “make distcheck” settings, many of these small items no longer appear. Even the small set of current exotic tests reveal a problem from time to time.

So I think it would be wise to try to expand the test cases that rsyslog runs on regular basis. Frankly, I will not be able to create a full suite from the ground up. But the idea is if I once manage to get DejaGNU – or something similar – up and running, and acquire the necessary knowledge, I could gradually add tests as I go along. So over time, the tests would increase and we could finally very much better, automatic, that existing functionality is no longer broken by new features.

I will try to get the focus for my next release steps on DejaGNU. Obviously, any help in doing so is appreciated.

security…

No system is totally secure. Few systems are totally insecure. Most systems are between these two extremes. But what does “more secure” mean? We had an interesting discussion on the rsyslog mailing list on the use of root jails. I’d like to reproduce one of my posts here, not only because it is mine, but because it can guard us a bit towards the security goals for rsyslog.

Let me think of security as a probability of security breach. S_curr is the security of the reference system without a root jail. S_total is the security of a hypothetical system that is “totally secure” (knowing well that no such system exists). In other words, the probability S_total equals 0.

I think the common ground is that a root jail does not worsen security. Note that I do not say it improves security, only that it does not reduce a system’s security. S_jail is the security of a system that is otherwise identical to the reference system, but with a root jail. Than S_jail <= s_curr, because we assume that the security of the system is not reduced.

I think it is also common ground that the probability of a security breach is reduced if the number of attack vectors is reduced, without any new attack vectors being added. [There is one generic “attack vector”, the “thought of being secure and thus becoming careless” which always increases as risk is reduced – I will not include that vector in my thoughts]

We seem to be in agreement that a root jail is able to prevent some attacks from being successful. I can’t enumerate them and it is probably useless to try to do so (because attackers invent new attacks each day), but there exist some attacks which can be prevented by a root jail. I do not try to weigh them by their importance.

For obvious reasons, there exist other attacks which are not affected by the root jail. Some of them have been mentions, like the class of in-memory based attacks, code injection and many more.

I tend to think that the set of attack vectors that can be prevented by a root jail is much smaller than the set of those which can not. I also tend to think that the later class contains the more serious attack vectors.

But even then, a root jail seems to remove a subset of the attack vectors that otherwise exist and so it reduces the probably of security breach. So it benefits security. We can only argue that it does not benefit security if we can show that in all cases we can think of (and those we can not), security is not improved. However, some cases have been show, where it improves, so it can not be that security is not improved in all cases. As such, a root jail improves security, or more precisely the probability of a security breach is

0 < S_jail < S_curr

We can identify the benefit we gain is the difference between the reference system’s probability of security breach and the system with the jail. Be S_impr this improvement, than

S_impr = S_curr – S_jail

Now the root jail is just one potential security measure. We could now try to calculate S_impr for all kinds of security measures, for example a privilege drop. I find it hard to do the actual probability calculations, but I would guess that S_impr_privdop > S_impr_jail.

Based on the improvements, one may finally decide what to implement first (either at the code or admin level), all of this of course weighted with the importance of the numbers.

In any case, I think I have shown that both is correct:

  • the root jail is a security improvement
  • there exist numerous other improvements, many of them probably more efficient than the jail

starting with rsyslog v4…

Finally, rsyslog v4 is materializing. Yesterday, I released the first devel version that is named 4.1.0. This starts a totally new branch. I decided to finally move on to v4 because I am enhancing performance quite a bit and this causes a number of big changes to the core engine as well as many modules. So rather than doing all of this in v3, I thought it is a good time to move to a new major version.

I expect that the new code will de-stabilize the project for some time and so I have now a feature-rich v3-stable release which will be available to everyone, at the price of less performance. That doesn’t mean v3 is slow, but v4 is even much faster. So I can finally begin to experiment a bit more with the new v4 branch and don’t need to think too hard that I may be introducing changes that are hard to roll into a stable within a reasonable time frame.

As far as the first v4-stable is concerned, I do not expect one to surface before February 2009 and, obviously, it will be not as stable as v3-stable is.

So the game is starting once again, and I hope you enjoy it ;)

regular expression tool for rsyslog

Regular expressions are quite powerful, but the syntax in rsyslog is, well, not easy to use. Also, as we have seen, the usual regex check tools don’t work always well with rsyslog’s POSIX expressions. I have created a web-based regular expression checker/generator today. It is more or less finished, but of course needs fine-tuning.

If this tool turns out to be useful (judging on comments and access count over the next weeks), I will probably do some other online tools aiding in config generation. This will be part of the overall effort to make it easier to unleash rsyslog’s full potential (all too often people simply do not know what magic they could do ;)).

New rsyslog HUP processing

There has been some discussions about rsyslog HUP processing. Traditionally, SIGHUP is used to signal the syslogd to a) close its files and b) reload its config. Rsyslog carried over this behavior from sysklogd.

However, rsyslog is much more capable than sysklogd. Among others, it is able to buffer messages that were received, but could not yet be processed. To remain compatible to the sysklogd of doing HUP, rsyslogd does a full daemon restart when it is HUPed. Among others, that means that messages from the queue are discarded, at least if the queue is configured with default settings. David Lang correctly stated that this may surprise some, if not most users. While I am still of the view that discarding the queue, under these circumstances, is the right thing to do, I agree it may be surprising (I added a hint to the man pages recently to reduce the level of surprise).

Still, there is no real need to do a full daemon restart in most cases. The typical HUP case is when logrotation wants to rotate files away and it needs to tell rsyslogd to close them. Actually, I asked if anybody knew any script that HUPs rsyslog to do a full config reload. The outcome was that nobody knew. However, some people liked to stick with the old semantics, and there may be reason to do so.

I have now implemented a lightweight HUP to address this issue. It is triggered via a new configuration directive, $HUPisRestart. If set to “on”, rsyslogd will work as usual and do a (very, very expensive) full restart. This is the default to keep folks happy that want to keep things as backwards-compatible as possible. Still, I guess most folks will set it to “off”, which is the new non-restart mode. In it, only output files are closed. Actually, the output plugin receive a HUP notification and can do whatever it likes. Currently, onle omfile acts on that and closes any open files. I can envision that other outputs, e.g. omfwd, can also be configured to do some light HUP action (for example close outbound connections).

The administrator needs to select either mode for the system. I think this is no issue at all and it safes me the trouble to define multiple signals just to do different types of HUP. My suggestion obviously is to use the new lightweight HUP for file closing, which means you need not to change anything for logrotate et al. Then, when you need to do a config reload, do a “real” restart by issuing a command like “/etc/init.d/rsyslogd restart”. And if there really exists a script that requires a config-reload HUP, that should be changed accordingly.