MonitorWare Knowledge Base

I'm setting up Rsyslog to handle logs from multiple machines with embedded Linux and have come across a problem. One of the main features of Rsyslog that I'm trying to use is the ability to have a separate log file for each source machine. It appears that the machines that use the Busybox syslogd break this feature in Rsyslog.

I've started with the example "rsyslog.conf" file from here:
http://wiki.rsyslog.com/index.php/Syskl ... _directory

Syslog messages received from Fedora boxes correctly go into a messages file in a subdirectory with the name of the source machine.
Syslog messages received from my embedded machines wind up in /var/log/messages.

I've looked at the packets coming in and only found one difference; the normal syslogd packets have a source and destination port of 514. The packets that come from the Busybox syslogd have a random source port and a destination port of 514.

It seems to me that if the difference in the source port number is really what's causing the messages to be logged incorrectly, then this is a bug in Rsyslog.

Does anyone see any other explanation? I'm running Rsyslog-3.19.9 (the latest not marked "devel" or "beta") on a CentOS 5.2 machine.

I was going to add a capture file showing the two packets, but phpBB wouldn't let me attach a file with either a ".pcap" or ".cap" extension, I'm tired, I gave up. It anyone thinks it'll help, I'll put it somewhere else.

Thanks,
Brad

• Custom written rsyslog.conf?
• Maintenance Contract?
• Installation support?

More information. In my messages, both messages appear to be "info" severity level.

Regards,
Brad

Okay, it let me attached the file if I put it a ZIP file first. Weird.

Brad

are these two files from the busybox machine? One thing I notice is that they contain an, well, underspecified syslog header. It is correct under the rule that anything that goes to port 514 is a syslog message, and it also heems to have a valid PRI, but the rest of the header is missing. Anyhow, that should not cause any issues.

The source port is irrelevant. rsyslog itself uses a random source port.

The config in the wiki looks rather complicated. Can you re-create the problem with a simpler config? Please let me know.

The capture was taken from the machine running rsyslog. One source machine is a stock Fedora 8 (sysklogd 1.3) (ip ending in .198), the other source is a custom Linux distro (busybox 1.00) (ip ending in .79).

I've simplified the config some with no change, I'll try and simplify it more and post it.

OK, that explains the malformed package for .198 (sysklogd does emit malformed headers).

To further solve it, a debug log would be most helpful. See here for details:

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

#This config has the same problem.
#simplified beyond normal for testing of remote logging problem.
$ActionFileDefaultTemplate RSYSLOG_TraditionalFileFormat

#Local logs
if \
$source == 'localhost' \
then /var/log/messages

# Remote logging
$ModLoad imudp
$UDPServerAddress 0.0.0.0
$UDPServerRun 514

$template DYNmessages,"/var/log/%HOSTNAME%/messages"

if \
$source != 'localhost' \
then ?DYNmessages

Here's the debug output. I started it in debug mode, used logger to send a packet from each test client, then shutdown rsyslogd.

Thanks,
Brad

I haven't jet looked at the debug because you stated logger. I need to see processing of messages from those two machines...

Okay, I didn't think logger would cause anything different from any other program. Here's a new debug file, same procedure except I logged into each client as root to generate a log entry.

Oh, also the full command line used: /usr/local/sbin/rsyslogd -c3 -4 -x -f /etc/rsyslog.conf -dn > rsyslog.debug

Brad

sorry, I thought you used logger instead sending the messages from the remote machines.

Please note that the version you use is outdated, I suggest updating to a current release. The relevant part of the debug log is

Code: Select all

7880.076961925:imudp.c: Host name for your address (192.168.102.79) unknown
7880.077006024:imudp.c: Message from inetd socket: #5, host: 192.168.102.79
7880.077038332:imudp.c: logmsg: flags 0, from '192.168.102.79', msg  root: test-dtg
7880.077050733:imudp.c: Message has legacy syslog format.
7880.077075446:imudp.c: main queue: entry added, size now 1 entries
7880.077096444:imudp.c: main queue: EnqueueMsg signaled condition (0)
7880.077117111:imudp.c: 7880.077118981:wtpAdviseMaxWorkers signals busy
main queue:Reg/w0: main queue: entering rate limiter
7880.077144224:imudp.c: 7880.077164127:main queue:Reg/w0: main queue: Listening on UDP syslogd socket 5 (IPv4/port 514).
entry deleted, state 0, size now 0 entries
7880.077189240:imudp.c: --------imUDP calling select, active file descriptors (max 5): 5
7880.077246539:main queue:Reg/w0: result of expression evaluation: 0
7880.077273065:main queue:Reg/w0: result of expression evaluation: -9
7880.077291026:main queue:Reg/w0: Called action, logging to builtin-file
7880.077318248:main queue:Reg/w0:  (DYNmessages)
7880.077348255:main queue:Reg/w0: Added new entry 1 for file cache, file '/var/log//messages'.
7880.077381331:main queue:Reg/w0: main queue: entering rate limiter
7880.077394634:main queue:Reg/w0: main queue:Reg/w0: worker IDLE, waiting for work.
7885.694060073:imudp.c: Host name for your address (192.168.100.198) unknown
7885.694099801:imudp.c: Message from inetd socket: #5, host: 192.168.100.198
7885.694113736:imudp.c: dropped LF at very end of message (DropTrailingLF is set)
7885.694140246:imudp.c: logmsg: flags 0, from '192.168.100.198', msg bsilva: fedora
7885.694151955:imudp.c: Message has legacy syslog format.
7885.694167232:imudp.c: HOSTNAME contains invalid characters, assuming it to be a TAG.
7885.694180959:imudp.c: main queue: entry added, size now 1 entries
7885.694202710:imudp.c: main queue: EnqueueMsg signaled condition (0)
7885.694222068:imudp.c: 7885.694223822:wtpAdviseMaxWorkers signals busy
main queue:Reg/w0: main queue: entering rate limiter
7885.694246632:imudp.c: 7885.694317088:main queue:Reg/w0: Listening on UDP syslogd socket 5 (IPv4/port 514).
main queue: entry deleted, state 0, size now 0 entries
7885.694342092:imudp.c: --------imUDP calling select, active file descriptors (max 5): 5

As can be seen the .79 box has two spaces following the PRI, whereas the .198 box has just a single space following the PRI. Without re-consulting RFC3164, I think two spaces terminate the header, thus we get potentially different output. Anyhow, it would be useful to see the exact properties as they have been parsed.

Please create a template with the host and fromhost properties, and asssign it to a file writer that writes everything into a file. Post the result.

Sorry I didn't reply to this, I got laid off from that job. Sigh, well, it's their problem now.

Meanwhile, I'm deploying rsyslog at another site as part of some contract work I'm doing until I get a new job.

I won't be updating this thread, but you'll probably see me on here with other questions.


Thanks for the help,
Brad

Hi Brad,

thanks for letting me know. Perfectly understandable. I am glad you continue to work with rsyslog, please spread the word And feel free to ask as much as you like

Rainer