syslogd: server not recording remote events

cygnal · 10-08-2008, 09:55 AM

This is a story about two linux boxes who don't seem to want to talk to one another in just one specific way. I have two virtual linux instances running under VMWare ESX Server 3.0.1, one a Fedora 7 and the other a Debian Etch. The Fedora installation (zenmachine) is set to receive remote syslog messages from the Debian instance (testbed), but no messages related to the host 'testbed' appear in any log file on zenmachine. I have:

On zenmachine
- Edited SYSLOGD_OPTIONS line in /etc/init.d/syslog so that it receives remote logging messages (SYSLOGD_OPTIONS=" -r -m 0")
- Allowed UDP traffic on port 514 through the firewall, although both it and selinux are disabled at the moment
- `netstat -a | grep syslog` gives:

Code:

udp        0      0 *:syslog                    *:*

- `netstat -an | grep 514` gives:

Code:

udp        0      0 0.0.0.0:514                 0.0.0.0:*

- `traceroute testbed` gives:

Code:

1 testbed (10.40.2.235)  0.859 ms  0.439 ms  0.213 ms

On testbed
- Edited /etc/syslog.conf to contain only:
*.* @zenmachine
kern.crit *
- Allowed outgoing UDP traffic on port 514, although firewall is currently disabled
- `netstat -a | grep syslog` gives:

Code:

udp    0    0 *:syslog        *:*

- `netstat -an | grep 514` gives:

Code:

udp    0    0.0.0.0.0:514        0.0.0.0:*
unix  3    [ ]    STREAM    CONNECTED    7514    /var/run/dbus/system_bus_socket

- `traceroute zenmachine` gives:

Code:

1 zenmachine (10.40.2.102)  7.781 ms  0.297 ms  0.437 ms

Restarted syslogd and klogd on both instances. Both systems have each other's IP and hostname info in their respective /etc/hosts file, I can ping, scp, ssh, traceroute, etc from either to the other, but no entries pertaining to testbed are being written to any log files on zenmachine. I read somewhere that /etc/syslog.conf acts funny sometimes if you use whitespace other than tabs, so that's what I used; don't think it made a difference tho. The files in /var/log on testbed aren't being written to, so I'm guessing it's at least trying to send its syslog info to zenmachine. Has anyone else run into this or anything like it?

acid_kewpie · 10-09-2008, 04:28 AM

well divide and conquer. Is data leaving the box and / or hitting the other at an IP level?

on both boxes run "tcpdump -vn port 514" and generate syslog traffic (e.g. via the logger command) and see what shows up where.

cygnal · 10-10-2008, 08:40 AM

Thanks for the help, acid_kewpie. While "tcpdump -vn port 514" was running on both hosts, I ran a sudo command on testbed and got this:

testbed

Code:

tcpdump: listening on eth0, link-type EN10MB (Ethernet), capture size 96 bytes
09:22:23.693927 IP (tos 0x0, ttl  64, id 0, offset 0, flags [DF], proto: UDP (17), length: 110) 10.40.2.235.514 > 10.40.2.102.514: SYSLOG, length: 82
        Facility authpriv (10), Severity notice (5)
        Msg: sudo:    bob : TTY=pts/1 ; PWD=/var/log ; USER=r[|syslog]

zenmachine

Code:

tcpdump: listening on eth0, link-type EN10MB (Ethernet), capture size 96 bytes
09:34:40.699471 IP (tos 0x0, ttl 64, id 0, offset 0, flags [DF], proto UDP (17), length 130) 10.40.2.235.syslog > 10.40.2.102.syslog: SYSLOG, length: 102
        Facility authpriv (10), Severity notice (5)
        Msg: sudo:    bob : TTY=pts/2 ; PWD=/home/bob ; USE[|syslog]
09:34:41.090301 IP (tos 0x0, ttl 64, id 0, offset 0, flags [DF], proto UDP (17), length 76) 10.40.2.235.syslog > 10.40.2.102.syslog: SYSLOG, length: 48
        Facility kernel (0), Severity info (6)
        Msg: kernel: device eth0 entered promiscuous mode\012
09:34:41.090383 IP (tos 0x0, ttl 64, id 0, offset 0, flags [DF], proto UDP (17), length 109) 10.40.2.235.syslog > 10.40.2.102.syslog: SYSLOG, length: 81
        Facility kernel (0), Severity notice (5)
        Msg: kernel: audit(1223644909.878:8): dev=eth0 prom=256 [|syslog]
09:35:14.874730 IP (tos 0x0, ttl 64, id 0, offset 0, flags [DF], proto UDP (17), length 110) 10.40.2.235.syslog > 10.40.2.102.syslog: SYSLOG, length: 82
        Facility authpriv (10), Severity notice (5)
        Msg: sudo:    bob : TTY=pts/1 ; PWD=/var/log ; USER=r[|syslog]

UDP syslog traffic seems to be both leaving testbed and arriving at zenmachine. For temporary convenience, I have all messages being logged to /var/log/ALL_MESSAGES on zenmachine, but still no entries in it referencing testbed.

Also, I started running syslogd manually (syslogd -d -r -m0) on zenmachine and turned on debugging; when I pass a sudo command on zenmachine, I get this output, but nothing when running the same command on testbed (I'm using the command "sudo ls /root" just to generate syslog messages here):

zenmachine

Code:

Successful select, descriptor count = 1, Activity on: 3
Message from UNIX socket: #3
Message length: 99, File descriptor: 3.
logmsg: authpriv.notice<85>, flags 2, from zenmachine, msg Oct 10 11:38:18 sudo:    bob : TTY=pts/2 ; PWD=/var/log ; USER=root ; COMMAND=/bin/ls /root
Called fprintlog, logging to FILE /var/log/ALL_MESSAGES
Listening on syslog UDP port.
Calling select, active file descriptors (max 5): 3 5

acid_kewpie · 10-11-2008, 11:07 AM

all looks pretty good to me... iptables blocking the traffic? if you run "netstat -panu" does that actually show the syslogd process itself listening on that port? not something else maybe? Are you sure you've effectively restarted syslogd after changing config file? I've got caught befor and had two processes runnign at once, with the new config file running on the second process which was unable to bind to the udp port. stop the service, check ps -ef to ensure there are no syslogd processes at all and then start it again.

rgerhards · 10-14-2008, 02:30 AM

The manual run indicates it can not be the Firewall, because it received syslog messages. So I think it must be a problem with the service startup or binding to the port. One issue I see from time to time is that SELinux does not provide the necessary permissions. That shouldn't be a problem in the default install, but you never know.

Other than that, I'd start by verifying that syslogd actually runs (via ps) and check if it logs locally logger-generated traffic.

cygnal · 10-15-2008, 09:44 AM

OK this slipped past me until now. 'ps -ef | grep syslogd' on zenmachine shows one syslogd daemon: 'syslogd -m0', no -r switch, which means 1) it's not set to receive remote messages, and 2) the changes I made to /etc/init.d/syslog weren't implemented (SYSLOGD_OPTIONS="-r -m0"). How come? I used 'service syslog restart' to stop/start the klogd and syslogd daemons, and tried 'service syslog condrestart', but neither result in syslogd being called with -r. I manually killed and restarted syslogd as '/sbin/syslogd -r -m0', which I thought would have solved my problem, but after some activity on testbed, there are still no entries in zenmachine's logs referencing any host other than itself.

Results of 'netstat -panu' for each host are:

zenmachine

Code:

udp        0      0 :::514                      :::*                                    17462/syslogd

testbed

Code:

udp        0      0 0.0.0.0:514             0.0.0.0:*                          4420/syslogd

Iptables is stopped on both hosts, zenmachine has selinux disabled and testbed doesn't have selinux installed at all. Process listing shows only one syslogd daemon running on each, and nothing new is being written to logs on testbed. Even with syslogd on zenmachine running with -r, it looks like the syslog daemon just doesn't want to concern itself with the messages it's being given.

rgerhards · 10-15-2008, 10:02 AM

It may sound silly, but have you rebooted the server that you applied the change to? That should be the ultimate test. If you still don't see -r in the ps list, you probably modified the wrong file (or something else is broken)...

cygnal · 10-15-2008, 11:14 AM

I really need to start looking around me. /etc/init.d/syslog uses its own information only if it can't find an /etc/sysconfig/syslog config file. Changed that file and syslogd comes up with -r every time. That's solved, but the problem that that particular syslogd daemon isn't doing anything with the remote messages it's given is still at large.

cygnal · 10-22-2008, 02:25 PM

Solved. I got kind of suspicious when I saw the difference in the output for 'netstat -panu | grep syslog':

zenmachine

Code:

udp        0      0 :::514            :::*    2873/syslogd

testbed

Code:

udp        0      0 0.0.0.0:514         0.0.0.0:*    14625/syslogd

I'm really not familiar at all with IPv6, but I do know that ::: is IPv6 shorthand. An 'lsof -p `pgrep syslogd`' on zenmachine gave back:

Code:

COMMAND   PID USER   FD   TYPE     DEVICE    SIZE    NODE NAME
syslogd 30515 root  cwd    DIR        8,1    4096       2 /
syslogd 30515 root  rtd    DIR        8,1    4096       2 /
syslogd 30515 root  txt    REG        8,1   39936 2024062 /sbin/syslogd
syslogd 30515 root  mem    REG        8,1  129824 2578562 /lib/ld-2.6.so
syslogd 30515 root  mem    REG        8,1 1673804 2578578 /lib/libc-2.6.so
syslogd 30515 root  mem    REG        8,1   50840 2578600 /lib/libnss_files-2.6.so
syslogd 30515 root    0u  unix 0xf48cea00           54949 /dev/log
syslogd 30515 root    1w   REG        8,1  101821  261997 /var/log/ALL_MESSAGES
syslogd 30515 root    2u  IPv6      54954             UDP *:syslog

zenmachine's syslogd was listening on IPv6, testbed was talking IPv4. The traffic was reaching the system, but not the process, I suppose. So I have two options: make syslogd run using only IPv4, or disable IPv6 on the system entirely. Forcing syslogd to use IPv4 only requires editing /etc/sysconfig/syslog:
SYSLOGD_OPTIONS="-4 -r -m 0"

Disabling IPv6 isn't much harder; add the lines

alias net-pf-10 off
alias ipv6 off

to /etc/modprobe.conf, and the entry

NETWORKING_IPV6=no

to /etc/sysconfig/network, and reboot.

I chose to disable IPv6 since I have no use for it for now. Zenmachine now captures all of testbed's syslog messages.