MonitorWare Knowledge Base

[jmo]

Hi all,

I hope you will understand my poor english...

I cannot record netfilter log messages on xen based kernel (amd64)! /proc/kmsg is written, and read, but kernel messages are written once in log files (syslog, kern.log, debug) at rsyslog restart. Iptables log level for the LOG target is currently debug (other levels does not matter: I tried with notice and warn).

Here is my /etc/rsyslog.d/remote.conf, included in /etc/rsyslog.conf (Debian lenny configuration).

Code: Select all

$WorkDirectory /var/log/rsyslog-queue
$ActionQueueType LinkedList
$ActionQueueFileName remote-queue
$ActionResumeRetryCount -1 # infinite retries on failure
$ActionQueueSaveOnShutdown on
$ActionQueueMaxDiskSpace 5M
$ActionQueueDiscardMark 6000 # Nb d'éléments, en moyenne 768 octets/elt
$ActionQueueDiscardSeverity 8 # 5=Notice 7=Debug 8=Hors limite

if $programname != 'jsvc.exec' and $programname != 'slapd' then @@127.0.0.1:61514


If I remove the queue, kernel messages are discarded (never written). If I keep the queue running, kernel messages are written on rsyslogd restart, or when rsyslogd catches the HUP signal.
Removing, or not, the `if` stanza does not matter.

All my dom0 hosts act this way. And all domU virtual machines too. DomU and Dom0 are Debian Lenny boxes.

The first time I added iptables logging, iptables log messages were progressively delivered to log files. After rsyslogd restart, because of logrotate jobs, the queue buffer began to be filled and the kernel messages were not delivered any more (but at next restart, and so on).

The server receiving the dom0 and domU logs is a 686 machine (uname -r is 2.6.26-2-686, Debian Lenny). Kernel logging is ok on this single machine. Problem with xen based kernels ?

Any idea on what is going wrong? I think that I could use ULOG for netfilter logging, but what about all other kernel messages?

[jmo]

Add on : rsyslog for Lenny is 3.18.6. I tried with rsyslog from lenny-backports, which is 4.4.2. No changes!

[rgerhards]

can you provide a debug log?

[jmo]

can you provide a debug log?

Trace sent at your private mail address. Currently, rsyslog 4.4.2, with "-c4 -d" startup options.

[rgerhards]

just for the others following this thread: I analyzed the debug log, but it did not yet contain the information that I need. We are working via private mail for the moment. We will post more as soon as we found out something.

[rgerhards]

oh, and one question to the original poster: you say that kernel messages are not written. But you do not write them, but instead send them to another syslogd on the same machine. Is that what you intend to do?

[jmo]

Summing up of private exchanges

I made a test, and have sent the debug trace to Rainer:

1. look at /proc/kmsg and saw lot of iptables log
2. reload rsyslog: kmsg empty, no logs!!
3. restart rsyslog in debug mode (-c4 -d)
4. send packets with `hping3 -S -p 113 <host-ip>
5. look at /proc/kmsg: saw it filled with some entries, then read (and
empty), then filled again, no logs written when it became empty.
5. C-c to rsyslog in debug mode to kill it: no logs
6. restart rsyslog in normal mode (-c4): no logs. All my iptables logs
are discarded.

The kernel logs I expect are basics iptables logs like this one (my host ip is hidden):

Feb 9 06:25:03 vm1 rsyslogd: [origin software="rsyslogd" swVersion="4.4.2" x-pid="7618" x-info="http://www.rsyslog.com"] rsyslogd was HUPed, type 'restart'.
Feb 9 06:25:03 vm1 kernel: Kernel logging (proc) stopped.
Feb 9 06:25:04 vm1 kernel: imklog 4.4.2, log source = /proc/kmsg started.
Feb 9 06:25:04 vm1 kernel: 92666.219857] LOGDROP : IN=eth0 OUT= MAC=00:16:3e:00:00:01:00:
0b:ab:1c:5c:07:08:00 SRC=133.5.6.10 DST=xxx.xxx.xxx.xxx LEN=48 TOS=0x00 PREC=0x00 TTL=46 ID
=17280 DF PROTO=TCP SPT=56974 DPT=113 WINDOW=49640 RES=0x00 SYN URGP=0

Please note the sequence: first, ryslog caught the HUP signal at 06:25:03. That's the result of cron daily job (/etc/crontab). Then is the first (of 80) lines of iptables logging at loglevel "debug" (-j LOG --log-level debug --log-prefix "LOGDROP : "). All iptables logs (and I suppose all messages with kernel facility if any) are flushed after the rsyslog restart.

One would expect to find the logs in the debug trace. But there were none.
I was able to read the debug log while running rsyslog in debug mode, using the `tee` command, and while running the syn scan with hping3. And I did not see anything written as long as the scan was up. I saw some postfix logs, but nothing about kernel facility.

rsyslog runs as root:

Code: Select all

VM1:~# ps aux|grep rsyslog
root      7618  0.0  0.1  68464  1736 ?        Sl   18:27   0:00
/usr/sbin/rsyslogd -c4


One of the machine which is not logging kernel facility is vm1 (virtual machine).

Code: Select all

VM1:~# uname -r
2.6.26-2-xen-amd64


This is a Debian Lenny. All my servers, virtuals or not are Lenny boxes. Rsyslog is version 3.18.6 on all machines, except vm1 currently running 4.4.2

My backup server, ael03, is a Debian Lenny, as I said above, with rsyslog 3.18.6. Kernel facility is logged on this machine.

The differences I see between ael03 (the machine logging kernel facility), and other machines (virtuals domU's as vm1 is, and physicals dom0 hosts) are:

kernels : xen-amd64 for virtual machines and dom0's, 686 for the backup server
rsyslog usage : virtual machines and dom0's are sending all their logs to the backup server via stunnel (thanks to rsyslog web site doc!) in addition to recording these log
files on their own filesystem.

/etc/rsyslog.conf is basically the same for all machines (the one that logs kernel facility, and the others that does not). The backup machine load ommail, in addition.

Replying to your previous post: all vm1 logs should be written to log files and sent to the backup server. That's the way it is for other facilities. eg: I have a /var/log/syslog file in vm1 filesystem, and a /var/log/remote/vm1-syslog file in the ael03 (backup server) filesystem. And remember my first post: the first time I added the logging mode in my iptables rules, the logs where written to syslog (and kern.log) and sent to the backup server. I am sure of this, because I have a log analyser (fwanalog) running on the backup server. And, for now, I can only read ael03 iptables logs on the ael03 box (which should centralize all firewall logs).

Have you heard of weird things about xen, or amd64 kernels? I can not understand what could be the differences between the box that is properly logging, and the others that does not.

[rgerhards]

I have to admit I am more than slightly puzzled. I went through the debug log again, but there is no indication of any problem encountered by imklog (I had assumed that it had some issues...). I'll try to look into the issue some more, but we may need to add additional instrumentation that you could try out in your environment. This is based on the assumption that imklog has a problem, but does not log it.

I have never heard of any similar issue.

[rgerhards]

mhhh... I have just setup a lab on debian sid with rsyslog 4.4.2, but without any issues at all. But I don't have the same kernel here. So I am somewhat out of other options.

To solve this, I would need to provide some instrumented code to you. In order to get to a stable baseline, I ask you to both try the current v4-stable and v4-beta from git. These versions are ahead of 4.4.2 and have not yet been released. I first want to make sure that the problem still exists.

There is some information on how to obtain and build rsyslog from the git archive on this page:

http://www.rsyslog.com/doc-build_from_repo.html

It would be great if you could find time to do these tests and later on run an instrumented version.

[jmo]

mhhh... I have just setup a lab on debian sid with rsyslog 4.4.2, but without any issues at all. But I don't have the same kernel here. So I am somewhat out of other options.

To solve this, I would need to provide some instrumented code to you. In order to get to a stable baseline, I ask you to both try the current v4-stable and v4-beta from git. These versions are ahead of 4.4.2 and have not yet been released. I first want to make sure that the problem still exists.

There is some information on how to obtain and build rsyslog from the git archive on this page:

http://www.rsyslog.com/doc-build_from_repo.html

It would be great if you could find time to do these tests and later on run an instrumented version.

Great new ! (Hmm, that's humor !)

We have tested an iptables rule on a test machine. The test machine is a virtual machine, xen kernel amd64, the same as in our prod virtual machines (Lenny box too, we are very fond of Debian !). /proc/kmsg is full and the log is not written to disk (same rule as above :
iptables -A INPUT -p tcp --dport 113 -j LOG --log-level debug --log-prefix "IPT-DEBUG : "
).

We are going to try to build your v4-stable first, then v4-beta (heu... after investigations on git usage, I am used to subversion !).

[rgerhards]

Thanks, I am looking forward to the results. Please note that in the git web interface you can also download tarballs of each release. So if getting git going is too much pain, you can use these.

I'll continue to use the public forum forum for discussion, so that others can benefit. We'll switch back to private mail if there is sensitive data, like debug logs.

thanks again,
Rainer

[jmo]

Thanks, I am looking forward to the results. Please note that in the git web interface you can also download tarballs of each release. So if getting git going is too much pain, you can use these.

We build the v4 stable:

What we made:

Code: Select all

git clone git://git.adiscon.com/git/rsyslog.git
cd rsyslog
git checkout --track -b v4-stable
./autogen.sh
make
make install


Then we used the Debian /etc/init.d/rsyslog to start the new rsyslogd daemon, modifying the RSYLOGD_BIN variable. Default option in /etc/default/rsyslog modified to "-c4", then "-c5" (we made two tests, stopping, then restarting rsyslogd).
kern.log said:

Code: Select all

imklog 5.5.2, log source = /proc/kmsg started.


We filled kmsg with a syn scan. No logs written, neither in kern.log, nor in syslog. At rsyslog restart, kmsg is empty. The logs are "garbage collected" and discarded.

Do you want us to build another version (checkout v4-beta)? A new run with debug mode enabled? Something else?

[rgerhards]

trying v4-beta would be great, as it contains a number of improvements. If that fails, a debug log from that run would be useful.

As I wrote, I do not expect that it immediately runs. I just want to set a baseline. I can then add some extra instrumentation to gain more insight into what happens.

Thanks!

[mbiebl]

Could this be related to http://osdir.com/ml/debian-bugs-dist/20 ... 01947.html

What exact kernel version are you using?

[mbiebl]

Could this be related to http://osdir.com/ml/debian-bugs-dist/20 ... 01947.html

What exact kernel version are you using?

As the referenced bug report is about klogd, it might be worth installing sysklogd/klogd and test if you can reproduce the problem there, too.
If so, this would indicate that it is a kernel bug indeed