13

I'm running a Debian server and a couple of days ago my rsyslog started to behave very weird, the daemon is running but it doesn't seem to do anything. Many people use the system but I'm the only one with (legal) root access.

I'm using the default rsyslogd configuration (if you think is relevant I'll attach it, but it's the one that comes with the package).

After I rotated all the log files, they have remained empty:

# ls -l /var/log/*.log
-rw-r--r-- 1 root root 0 Jun 27 00:25 /var/log/alternatives.log
-rw-r----- 1 root adm  0 Jun 26 13:03 /var/log/auth.log
-rw-r----- 1 root adm  0 Jun 26 13:03 /var/log/daemon.log
-rw-r--r-- 1 root root 0 Jun 27 00:25 /var/log/dpkg.log
-rw-r----- 1 root adm  0 Jun 26 13:03 /var/log/kern.log
-rw-r----- 1 root adm  0 Jun 26 13:03 /var/log/lpr.log
-rw-r----- 1 root adm  0 Jun 26 13:03 /var/log/mail.log
-rw-r----- 1 root adm  0 Jun 26 13:03 /var/log/user.log

Any try to force a log writing does not have any effect:

# logger hey
# ls -l /var/log/messages 
-rw-r----- 1 root adm 0 Jun 26 13:03 /var/log/messages

Lsof shows that rsyslogd does not have any log files opened:

# lsof -p 1855
COMMAND   PID USER   FD   TYPE     DEVICE SIZE/OFF       NODE NAME
rsyslogd 1855 root  cwd    DIR      202,0     4096          2 /
rsyslogd 1855 root  rtd    DIR      202,0     4096          2 /
rsyslogd 1855 root  txt    REG      202,0   342076      21649 /usr/sbin/rsyslogd
rsyslogd 1855 root  mem    REG      202,0    38556      32153 /lib/i386-linux-gnu/i686/cmov/libnss_nis-2.13.so
rsyslogd 1855 root  mem    REG      202,0    79728      32165 /lib/i386-linux-gnu/i686/cmov/libnsl-2.13.so
rsyslogd 1855 root  mem    REG      202,0    26456      32163 /lib/i386-linux-gnu/i686/cmov/libnss_compat-2.13.so
rsyslogd 1855 root  mem    REG      202,0   297500    1061058 /usr/lib/rsyslog/imuxsock.so
rsyslogd 1855 root  mem    REG      202,0    42628      32170 /lib/i386-linux-gnu/i686/cmov/libnss_files-2.13.so
rsyslogd 1855 root  mem    REG      202,0    22784    1061106 /usr/lib/rsyslog/imklog.so
rsyslogd 1855 root  mem    REG      202,0  1401000      32169 /lib/i386-linux-gnu/i686/cmov/libc-2.13.so
rsyslogd 1855 root  mem    REG      202,0    30684      32175 /lib/i386-linux-gnu/i686/cmov/librt-2.13.so
rsyslogd 1855 root  mem    REG      202,0     9844      32157 /lib/i386-linux-gnu/i686/cmov/libdl-2.13.so
rsyslogd 1855 root  mem    REG      202,0   117009      32154 /lib/i386-linux-gnu/i686/cmov/libpthread-2.13.so
rsyslogd 1855 root  mem    REG      202,0    79980      17746 /usr/lib/libz.so.1.2.3.4
rsyslogd 1855 root  mem    REG      202,0    18836    1061094 /usr/lib/rsyslog/lmnet.so
rsyslogd 1855 root  mem    REG      202,0   117960      31845 /lib/i386-linux-gnu/ld-2.13.so
rsyslogd 1855 root    0u  unix 0xebe8e800      0t0        640 /dev/log
rsyslogd 1855 root    3u  FIFO        0,5      0t0       2474 /dev/xconsole
rsyslogd 1855 root    4u  unix 0xebe8e400      0t0        645 /var/spool/postfix/dev/log
rsyslogd 1855 root    5r   REG        0,3        0 4026532176 /proc/kmsg

I was so frustrated that even reinstall the rsyslog package, but it still refuses to log anything:

# apt-get remove --purge rsyslog
# apt-get install rsyslog

I thought someone had hacked the system, so run rkhunter, chkrootkit, unhide in an attempt to find hide processes / ports and nmap in a remote host to compare with the ports shown by netstat. And I know this doesn't mean anything, but all looks ok. The system also have an iptables firewall that is very restrictive with incoming / outgoing connections.

This is driving me crazy, any idea what is going on here?

[EDIT - disk space info]

# df -h
Filesystem            Size  Used Avail Use% Mounted on
rootfs                 24G   22G  629M  98% /
/dev/root              24G   22G  629M  98% /
devtmpfs               10M  112K  9.9M   2% /dev
tmpfs                  76M   48K   76M   1% /run
tmpfs                 5.0M     0  5.0M   0% /run/lock
tmpfs                 151M   40K  151M   1% /tmp
tmpfs                 151M     0  151M   0% /run/shm

[EDIT - strace info]

Strace looks ok for me

[pid 28824] access("/var/log/auth.log", F_OK) = 0
[pid 28824] access("/var/log/syslog", F_OK) = 0
[pid 28824] access("/var/log/daemon.log", F_OK) = 0
[pid 28824] access("/var/log/kern.log", F_OK) = 0
[pid 28824] access("/var/log/lpr.log", F_OK) = 0
[pid 28824] access("/var/log/mail.log", F_OK) = 0
[pid 28824] access("/var/log/user.log", F_OK) = 0
[pid 28824] access("/var/log/mail.info", F_OK) = 0
[pid 28824] access("/var/log/mail.warn", F_OK) = 0
[pid 28824] access("/var/log/mail.err", F_OK) = 0
[pid 28824] access("/var/log/news/news.crit", F_OK) = 0
[pid 28824] access("/var/log/news/news.err", F_OK) = 0
[pid 28824] access("/var/log/news/news.notice", F_OK) = 0
[pid 28824] access("/var/log/debug", F_OK) = 0
[pid 28824] access("/var/log/messages", F_OK) = 0

The complete strace log can be downloaded from here

Victor Henriquez
  • 243
  • 1
  • 3
  • 8
  • 2
    Is the log disk full? – Jenny D Jun 27 '13 at 10:03
  • Oh sorry, I forgot to add that info, I'll update the question. But there's still enough space to write logs. – Victor Henriquez Jun 27 '13 at 10:09
  • 2
    try and strace -p or start rsyslog manually under strace and check if it is complaining about something – manjiki Jun 27 '13 at 10:45
  • Good advice, unfortunately I haven't been able to find anything relevant. I've updated the question with the strace log, just in case you can find something I'm missing. I'm really frustrated. – Victor Henriquez Jun 27 '13 at 11:16
  • run manually in debug mode (-d if iirc), so it won't fork, or use strace's follow forks option. My bad, sorry. – manjiki Jun 27 '13 at 11:41
  • I did use the fork option, I didn't write the console command in my edit, sorry, but it was like this: strace -f /usr/sbin/rsyslogd – Victor Henriquez Jun 27 '13 at 11:51
  • I am going to go out on a limb and say disable xconsole logging and check if tty1 is currently the master console. dmesg might provide something as well – manjiki Jun 27 '13 at 12:37
  • I have disabled the xconsole log, dmesg does not show anything interesting and I don't have access to any tty1 console. Should I look for something specific? paste the output of strace with this configuration? I really don't know how to proceed... this is making me crazy – Victor Henriquez Jun 27 '13 at 13:53
  • can you free up some space in your root partition? how is is mounted (WRT options)? – dawud Jun 29 '13 at 12:35

4 Answers4

15

Most probably it's a file ownership problem. rsyslog starts running as root but then drops privileges and runs as user syslog (configuration directive $PrivDropToUser).

syslog files (auth.log, daemon.log, etc.) initially are owned by syslog:adm but if you change ownership to root (as it seems from your file list) then no matter if you HUP (i.e., reload) rsyslog or restart it, that it will be denied to open those files due to the lack of privileges.

If the change of ownership happened after log rotation, then check the create option of your logrotate configuration. Either configure it like create 0644 syslog adm in /etc/logrotate.d/rsyslog or even better, define it globally at /etc/logrotate.conf omitting the mode, owner and group, simply like this create (which is the default configuration by the way), in which case the same values of the file will be used. Consult man logrotate for the full details.

Some versions of rsyslog include a directive $omfileForceChown as a workaround for the external change of file ownership, but it's not recommended. The recommended way is to configure properly the ownership and permissions. Further information about this issue may be found following that link.

Per Lundberg
  • 171
  • 1
  • 9
AAA
  • 166
  • 1
  • 3
2

If file permissions are all good and logrotate is correctly configured, your next step will be to have a look at rsyslog system calls.

# find the start command 
me@d2-slprod02:~$ sudo systemctl status rsyslog
● rsyslog.service - System Logging Service
   Loaded: loaded (/lib/systemd/system/rsyslog.service; enabled; vendor preset: enabled)
   Active: active (running) since Fri 2019-06-21 10:04:43 CEST; 2h 26min ago
     Docs: man:rsyslogd(8)
           http://www.rsyslog.com/doc/
 Main PID: 18753 (rsyslogd)
    Tasks: 4
   Memory: 1.4M
      CPU: 291ms
   CGroup: /system.slice/rsyslog.service
           └─18753 /usr/sbin/rsyslogd -n

 # let's have a look at syscalls.
 sudo strace /usr/sbin/rsyslogd -n
 ...
 write(2, "rsyslogd: error during parsing f"..., 206rsyslogd: error during parsing file /etc/rsyslog.d/50-default.conf, on or before line 8: warnings occured in file '/etc/rsyslog.d/50-default.conf' around line 8 [v8.16.0 try http://www.rsyslog.com/e/2207 ]
 ...

As soon as my typo was fixed in this file /etc/rsyslog.d/50-default.conf, syslog started to write to /var/log/syslog again!

0

Encountered issues with permissions today --- in my case it was SELINUX shutting it down. The rsyslog was pushing to a dedicated mount and was denying permissions.

Following was how I resolved it:

ls -Zd /var/log
drwxr-xr-x root root system_u:object_r:var_log_t:s0  /var/log

Taking this information, I applied the changes to the rsyslog location:

chcon -tR var_log_t /new/directory

Restarted rsyslog and immediately saw the a successful run. Linked the other RHEL servers to the logging server and watched the other RHEL servers immediately start to feed into it. note, the directory worked fine with just 600 permissions.

Nathaniel
  • 11
  • 1
0

I had this problem because my /var/log was residing on a ramdisk to reduce wear on my SSD and I wanted to move it to a HDD so I had more history than just the current boot.

Funny thing was, since it was a ramdisk, I didn't have one to copy from in single-user mode, so I didn't know what the permissions and ownership were supposed to be! Duh.

Short story, with your new location:

chmod 770 /var/log
chgrp syslog /var/log
initctl restart rsyslog

Rsyslog will now be able to write to /var/log since it runs as the 'syslog' user, group 'syslog'.

Greg Bell
  • 317
  • 2
  • 8