TwitterFacebookGoogle

Tag Archives: 5.7.1

Installing RSyslog 5 on RHEL 4 / 5

Posted on by

To have rsyslog working correctly on RHEL 4 or 5, some conditions have to be met. The method described has been tested with rsyslog 5.7.1.

First of all compile and install the dependencies.

  • gnutls-2.8.6.tar.bz2
  • libgcrypt-1.4.6.tar.gz
  • libgpg-error-1.9.tar.gz
  • libtasn1-2.2.tar.gz

After that, you can install rsyslog using the following commands:

./configure PKG_CONFIG_PATH=/usr/local/lib/pkgconfig --enable-gnutls
make
make install

It could happen, that the install might complain about gnutls.pc. Simply comment out the URL found near the start of the file /usr/local/lib/pkgconfig/gnutls.pc.

Credit for this find goes to Forum member Johann Reinhard (johannreinhard).

How to use rate limiting in rsyslog?

Posted on by

This article is tested with rsyslog 5.7.1 on Fedora 13. It will not work with version of rsyslog prior to 5.7.1.

In rsyslog 5.7.1 we introduced rate limiting. This is a option for the Unix Socket Input module called imuxsock. In short, this option limits the amount of messages written into logfiles by a process, if the process tries to write huge amounts of messages in a short period of time.

If you look a bit more into the details, this new feature makes a lot of sense. Because when regular logging happens, this makes no difference. But if a process goes wild (and I bet everyone has experienced this at least once) and starts to create large bulks of log messages, this affects the whole system in general. This blocks not only your I/O, but creates a large amount of logs that usually is simply not necessary and doesn’t really hold useful information. Therefore such messages are now discarded automatically. We will describe later how you can customize these settings for this.

This article is aimed for those who want to learn a bit more about how the rate limit works or who are new to this topic. Therefore we will not only describe how to set this up or change settings, but we want to show you some ways of testing, how imuxsock works and where some caveats are lying.

Please go on to the following pages.

What is imuxsock?

Changing the settings

First try to test rate limiting (fail)

How to build test-tools?

Second try to test rate limiting (success)

Changing the settings

Posted on by

Go back to What is imuxsock?

Before we can begin testing on how rate limiting works, we should change the default settings. By default, rate limiting will only work, if a process sends more than 200 messages in 5 seconds.To have some influence on the rate limiting we have basically two options:

$SystemLogRateLimitInterval [number]
$SystemLogRateLimitBurst [number]

The SystemLogRateLimitInterval determines the amount of time that is being measured for rate limiting. By default this is set to 5 seconds. The SystemLogRateLimitBurst defines the amount of messages, that have to occur in the time limit of SystemLogRateLimitInterval, to trigger rate limiting. Here, the default is 200 messages. For creating a more effective test, we will alter the default values.

To change these settings we open the rsyslog configuration. Open the configuration with vi (please note, that we use the default configuration path):

vi /etc/rsyslog.conf

Now we need to search the right spot for the entries. Find the following:

$ModLoad imuxsock.so

This entry will load the imuxsock module.

Now insert two new lines under the ModLoad command and fill them as follows:

$SystemLogRateLimitInterval 2
$SystemLogRateLimitBurst 50

These are the option for the module with some values. This means in plain words, that rate limiting will take effect if more than 50 messages occur in 2 seconds.

To make sure, that we will see all messages that are logged, we insert another entry into the configuration. Go to the section in the rsyslog.conf that holds the “Rules”. Insert a new rule that looks like this:

*.* /var/log/everything.log

You can name the file as you want. Every log message will be written into this file for our review.

Save the configuration file and exit vi. Now we need to restart rsyslog. This is necessary because it will only load the configuration once on startup.

Go on to First try to test rate limiting (fail)

First try to test rate limiting

Posted on by

Go back to Changing the settings

For a first test of the rate limiting feature we made up our mind on how to test it. We soon came up with the idea of a small shell script that will run logger with a test message. The script looks as follows

n=1000
i=0

while [ $i -lt $n ]
do
logger "This is Testmessage #$i"
echo "Messages: $i"
i=`expr $i + 1`
done

In this example, we have a pretty simple while loop. The loop will terminate, once the variable i has the size of n. In every run, i will be incremented by 1. After that a message is logged via logger and the message will be written to the terminal. You can download the script file here. Please note, that after downloading, you need to set chmod to 755 for this file.

Now run the file.

/foldername/ratelimittest

You will see a lot of lines being written to the terminal. In the current configuration, the while loop has 1000 iterations. When finished, the terminal will show the input prompt again. We can now review the log file to see if rate limiting worked.

vi /var/log/everything.log
Oct  5 17:01:57 client test: This is Testmessage #43
Oct  5 17:01:57 client test: This is Testmessage #44
Oct  5 17:01:57 client test: This is Testmessage #45
Oct  5 17:01:57 client test: This is Testmessage #46
Oct  5 17:01:57 client test: This is Testmessage #47
Oct  5 17:01:57 client test: This is Testmessage #48
Oct  5 17:01:57 client test: This is Testmessage #49
Oct  5 17:01:57 client test: This is Testmessage #50
Oct  5 17:01:57 client test: This is Testmessage #51
Oct  5 17:01:57 client test: This is Testmessage #52
Oct  5 17:01:57 client test: This is Testmessage #53
Oct  5 17:01:57 client test: This is Testmessage #54
Oct  5 17:01:57 client test: This is Testmessage #55
Oct  5 17:01:57 client test: This is Testmessage #56
Oct  5 17:01:57 client test: This is Testmessage #57
Oct  5 17:01:57 client test: This is Testmessage #58
Oct  5 17:01:57 client test: This is Testmessage #59
Oct  5 17:01:57 client test: This is Testmessage #60
Oct  5 17:01:57 client test: This is Testmessage #61

Let’s take a look at the messages around message 50. Usually, there should be a message after message 50, that some messages are not logged due to rate limiting. So either our test is not suitable because of the runtime or it isn’t  recognized correctly. To check on this, we make another change to the rsyslog configuration file as we did before. Again, go to the section for imuxsock at the beginning. Now we add a third option for imuxsock.

$SystemLogUsePIDFromSystem on

With this option, the PID of the process that is sending a message to imuxsock will be added to the log. Therefore we can check if the process has run correctly. Save the config and restart rsyslog again. Now once more, let the script run and take a look at the log afterwards.

Oct  5 17:27:01 client test[6941]: This is Testmessage #41
Oct  5 17:27:01 client test[6943]: This is Testmessage #42
Oct  5 17:27:02 client test[6945]: This is Testmessage #43
Oct  5 17:27:02 client test[6947]: This is Testmessage #44
Oct  5 17:27:02 client test[6949]: This is Testmessage #45
Oct  5 17:27:02 client test[6951]: This is Testmessage #46
Oct  5 17:27:02 client test[6953]: This is Testmessage #47
Oct  5 17:27:02 client test[6955]: This is Testmessage #48
Oct  5 17:27:02 client test[6957]: This is Testmessage #49
Oct  5 17:27:02 client test[6959]: This is Testmessage #50
Oct  5 17:27:02 client test[6961]: This is Testmessage #51
Oct  5 17:27:02 client test[6963]: This is Testmessage #52
Oct  5 17:27:02 client test[6965]: This is Testmessage #53
Oct  5 17:27:02 client test[6967]: This is Testmessage #54
Oct  5 17:27:02 client test[6969]: This is Testmessage #55
Oct  5 17:27:02 client test[6971]: This is Testmessage #56
Oct  5 17:27:02 client test[6973]: This is Testmessage #57
Oct  5 17:27:02 client test[6975]: This is Testmessage #58
Oct  5 17:27:02 client test[6977]: This is Testmessage #59
Oct  5 17:27:02 client test[6979]: This is Testmessage #60

What we see now behind the username is the PID (Process ID). As we can see now, the PID is different for every log entry. That means, that a new process has been started for every message, thus rendering our test useless, because rate limiting only works if the same PID is given.

Therefore we need a specialized test tool. How to build the appropriate tool is shown on the next page.

Go on to How to build test-tools?

Second try to test rate limiting

Posted on by

Go back to How to build test-tools?

After building the test tool syslog caller, we can give the testing another try. The syslog caller tool will be one process that creates the designated amount of messages. Since it has a very large output, we need it to produce a lot of messages to see the proper effects. We leave the rsyslog config as it is now.

Before we start, delete the logfile and restart rsyslog.

rm /var/log/everything.log
/etc/rc.d/init.d/rsyslog restart

Now we start the syslog caller tool with the following command:

/path/to/rsyslog/tests/syslog_caller -m 1000000

This will run for a little while and then bring you back onto the command prompt. With “-m 1000000” we determine how many messages will be generated. In this case we try 1 million messages, just to be on the safe side.

The entries in the logfile should look like this:

Oct  5 18:22:51 client kernel: imklog 5.7.1, log source = /proc/kmsg started.
Oct  5 18:22:51 client rsyslogd: [origin software="rsyslogd" swVersion="5.7.1" x-pid="7193" x-info="http://www.rsyslog.com"] startOct  5 18:23:52 client syslog_caller[7200]: test message nbr 0, severity=6
Oct  5 18:23:52 client syslog_caller[7200]: test message nbr 0, severity=6
Oct  5 18:23:52 client syslog_caller[7200]: test message nbr 1, severity=6
Oct  5 18:23:52 client syslog_caller[7200]: test message nbr 2, severity=6
Oct  5 18:23:52 client syslog_caller[7200]: test message nbr 3, severity=6
.
.
.
Oct  5 18:23:52 client syslog_caller[7200]: test message nbr 47, severity=6
Oct  5 18:23:52 client syslog_caller[7200]: test message nbr 48, severity=6
Oct  5 18:23:52 client syslog_caller[7200]: test message nbr 49, severity=6
Oct  5 18:23:52 client rsyslogd-2177: imuxsock begins to drop messages from pid 7200 due to rate-limiting
Oct  5 18:23:57 client rsyslogd-2177: imuxsock lost 111673 messages from pid 7200 due to rate-limiting
Oct  5 18:23:57 client syslog_caller[7200]: test message nbr 111723, severity=6
Oct  5 18:23:57 client syslog_caller[7200]: test message nbr 111724, severity=6
Oct  5 18:23:57 client syslog_caller[7200]: test message nbr 111725, severity=6
Oct  5 18:23:57 client syslog_caller[7200]: test message nbr 111726, severity=6
Oct  5 18:23:57 client syslog_caller[7200]: test message nbr 111727, severity=6

The first two messages that we have in the logfile are the startup messages. Right after that, the messages from syslog_caller appear. In the brackets behind the process name we find again the PID. If you compare the PID to the other log messages, you will find that is always the same. Syslog_caller is definately suitable for the test. In the shown log above, i skipped some messages, but the essence is visible. Take a look at message 49 (which is message 50 obviously). Right after that, you find a message logged from rsyslog directly. It states that imuxsock starts dropping messages from PID 7200, in this case the syslog_caller. The next message is again from rsyslog and states the amount of messages that have been lost due to rate-limiting. After this, messages are logged again, at least until rate limiting intervenes again.

This is how we can test the rate limiting properly.

Changelog for 5.7.1 (v5-devel)

Posted on by

Version 5.7.1  [V5-DEVEL] (rgerhards), 2010-10-05

  • support for Hadoop’s HDFS added (via omhdfs)
  • imuxsock now optionally use SCM_CREDENTIALS to pull the pid from the log socket itself (thanks to Lennart Poettering for the suggesting this feature)
  • imuxsock now optionally uses per-process input rate limiting, guarding the user against processes spamming the system log (thanks to Lennart Poettering for suggesting this feature)
  • added new config statements
    • $InputUnixListenSocketUsePIDFromSystem
    • $SystemLogUsePIDFromSystem
    • $SystemLogRateLimitInterval
    • $SystemLogRateLimitBurst
    • $SystemLogRateLimitSeverity
    • $IMUxSockRateLimitInterval
    • $IMUxSockRateLimitBurst
    • $IMUxSockRateLimitSeverity
  • imuxsock now supports up to 50 different sockets for input
  • some code cleanup in imuxsock (consider this a release a major modification, especially if problems show up)
  • bugfix: /dev/log was unlinked even when passed in from systemd in which case it should be preserved as systemd owns it

How to build the testing tools?

Posted on by

This article has been tested with rsyslog 5.7.1 on Fedora 13. It is part of the article “How to use rate limiting?”

Go back to First try to test rate limiting (fail)

When building a configuration for rsyslog, you will sometimes stumble upon the question, if your setup really works. To prove this in your environment is very complicated in most cases. For this we have made some test tools, which help you test your configuration. The main reason for us to create these tools was for testing new features and try out scenarios. But in the end we deliver them with every release. We will describe the way how to create and use the testing tools with the example of the tool syslog_caller. This tool creates a bunch of messages for the local loghost.

First you need to navigate to your rsyslog folder. From there you need to go to the subfolder tests. The path could look like this:

/home/username/rsyslog/tests/

We need to “make” the tests first before we can use it.

# make syslog_caller

The make process gives you some output. It looks like this:

CC syslog_caller.or
CCLD syslog_caller

After that, we are ready to use the test-tool. Use the following command:

./syslog_caller

This will generate 500 messages by default. You can change the default values with some switches. The switches are usually documented in the .c file of the tool. In this case, when using the following:

./syslog_caller -m 10000

will generate 10000 messages. With the test tools, you can do some stress-testing for your rsyslog installation. A good way to proof, if your configuration is working correctly.

Go on to Second try to test rate limiting (success)