Hello fiddlesticks! Today I will be telling you how to track down and fix rsyslogd spamming “action-0-builtin:omfile suspended” messages on an Ubuntu 22.04.5 LTS server.
TL;DR: It’s a permission issue with /var/log.
The Problem
I was checking the logs on the Minecraft Thailand community server (limitrack) and noticed the journal was getting spammed with this every 30 seconds:
Nov 10 19:11:59 limitrack rsyslogd[2089872]: action 'action-0-builtin:omfile' suspended (module 'builtin:omfile'), retry 0. There should be messages before this one giving the reason for suspension. [v8.2112.0 try https://www.rsyslog.com/e/2007 ]
Nov 10 19:11:59 limitrack rsyslogd[2089872]: action 'action-0-builtin:omfile' suspended (module 'builtin:omfile'), next retry is Tue Nov 10 19:12:29 2026, retry nbr 0. There should be messages before this one giving the reason for suspension. [v8.2112.0 try https://www.rsyslog.com/e/2007 ]
Every 30 seconds when new logs come in, rsyslogd resumes action-0-builtin:omfile, fails to write 10 times in a row, and suspends it again.
What makes e/2007 annoying is that action-0-builtin:omfile doesn’t tell you which log file is broken, rsyslog just numbers them starting from 0 in the order the config files get loaded. also the “There should be messages before this one giving the reason for suspension” part is useless if its been broken for days cus rsyslogd only logs the actual error once when it first breaks, then buries it under thousands of retry lines.
Finding what action-0 is
I checked disk space, inodes, and the config first, everything was fine:
root@limitrack:~# df -h /var/log
Filesystem Size Used Avail Use% Mounted on
/dev/mapper/ubuntu--vg-ubuntu--lv 914G 200G 676G 23% /
root@limitrack:~# df -i /var/log
Filesystem Inodes IUsed IFree IUse% Mounted on
/dev/mapper/ubuntu--vg-ubuntu--lv 60850176 870100 59980076 2% /
root@limitrack:~# rsyslogd -N1
rsyslogd: version 8.2112.0, config validation run (level 1), master config /etc/rsyslog.conf
rsyslogd: End of config validation run. Bye.
So I grepped the rules in /etc/rsyslog.conf and /etc/rsyslog.d/*.conf to see what action-0 actually is:
root@limitrack:~# grep -rnvE '^\s*(#|$|\$|module|input|global)' /etc/rsyslog.conf /etc/rsyslog.d/*.conf
/etc/rsyslog.d/20-ufw.conf:2::msg,contains,"[UFW " /var/log/ufw.log
/etc/rsyslog.d/21-cloudinit.conf:2::syslogtag, isequal, "[CLOUDINIT]" /var/log/cloud-init.log
/etc/rsyslog.d/21-cloudinit.conf:6:& stop
/etc/rsyslog.d/50-default.conf:8:auth,authpriv.* /var/log/auth.log
/etc/rsyslog.d/50-default.conf:9:*.*;auth,authpriv.none -/var/log/syslog
/etc/rsyslog.d/50-default.conf:12:kern.* -/var/log/kern.log
/etc/rsyslog.d/50-default.conf:14:mail.* -/var/log/mail.log
/etc/rsyslog.d/50-default.conf:23:mail.err /var/log/mail.err
/etc/rsyslog.d/50-default.conf:39:*.emerg :omusrmsg:*
root@limitrack:~#
Rule 0 is in /etc/rsyslog.d/20-ufw.conf which sends [UFW ...] messages to /var/log/ufw.log. Everytime UFW blocked a random packet, rsyslogd tried to write to /var/log/ufw.log and failed.
Finding the actual error
Filtering out all the suspended and resumed spam in journalctl shows what actually broke:
root@limitrack:~# journalctl -u rsyslog --no-pager | grep -vE 'suspended|resumed' | tail -n 15
Oct 25 14:34:32 limitrack rsyslogd[2089872]: imuxsock: Acquired UNIX socket '/run/systemd/journal/syslog' (fd 3) from systemd. [v8.2112.0]
Oct 25 14:34:32 limitrack rsyslogd[2089872]: rsyslogd's groupid changed to 113
Oct 25 14:34:32 limitrack rsyslogd[2089872]: rsyslogd's userid changed to 106
Oct 25 14:34:32 limitrack rsyslogd[2089872]: [origin software="rsyslogd" swVersion="8.2112.0" x-pid="2089872" x-info="https://www.rsyslog.com"] start
Oct 25 14:34:35 limitrack rsyslogd[2089872]: file '/var/log/ufw.log': open error: Permission denied [v8.2112.0 try https://www.rsyslog.com/e/2433 ]
Nov 01 00:00:03 limitrack systemd[1]: rsyslog.service: Sent signal SIGHUP to main process 2089872 (rsyslogd) on client request.
Nov 01 00:00:35 limitrack rsyslogd[2089872]: [origin software="rsyslogd" swVersion="8.2112.0" x-pid="2089872" x-info="https://www.rsyslog.com"] rsyslogd was HUPed
Nov 01 00:00:35 limitrack rsyslogd[2089872]: file '/var/log/ufw.log': open error: Permission denied [v8.2112.0 try https://www.rsyslog.com/e/2433 ]
Nov 08 00:00:02 limitrack systemd[1]: rsyslog.service: Sent signal SIGHUP to main process 2089872 (rsyslogd) on client request.
Nov 08 00:00:35 limitrack rsyslogd[2089872]: [origin software="rsyslogd" swVersion="8.2112.0" x-pid="2089872" x-info="https://www.rsyslog.com"] rsyslogd was HUPed
Nov 08 00:00:35 limitrack rsyslogd[2089872]: file '/var/log/ufw.log': open error: Permission denied [v8.2112.0 try https://www.rsyslog.com/e/2433 ]
root@limitrack:~#
There it is! file '/var/log/ufw.log': open error: Permission denied.
You can also see in the startup lines right above it that rsyslogd drops root on startup ($PrivDropToUser syslog + $PrivDropToGroup syslog in /etc/rsyslog.conf) so it runs as syslog (uid 106, gid 113).
How did this happen?
Checking the permissions on /var/log and /var/log/ufw.log:
root@limitrack:~# ls -ld /var/log /var/log/ufw.log
ls: cannot access '/var/log/ufw.log': No such file or directory
drwxr-xr-x 17 root syslog 4096 Nov 10 15:29 /var/log
root@limitrack:~#
/var/log/ufw.log didn’t exist, and /var/log was 0755 (drwxr-xr-x) instead of ubuntu’s default 0775 (drwxrwxr-x).
syslog and auth.log still worked fine cus they were already created earlier and owned by syslog:adm, and opening an existing file only needs +x on /var/log. since ufw.log didn’t exist yet, rsyslogd needed +w on /var/log to create the file, which failed cus the syslog group didn’t have write permission on /var/log.
and since /etc/logrotate.d/ufw has missingok and notifempty, every sunday logrotate saw ufw.log wasn’t there, skipped creating it, and sent SIGHUP to rsyslogd which just restarted the spam.
Fixing the issue
Give the syslog group write permission on /var/log, create /var/log/ufw.log as syslog:adm, and restart rsyslog:
sudo chmod g+w /var/log
sudo install -m 0640 -o syslog -g adm /dev/null /var/log/ufw.log
sudo systemctl restart rsyslog
Then test it with logger to make sure it actually writes to /var/log/ufw.log:
root@limitrack:~# logger "[UFW TEST] meow meow meow meow meow purrr nya"
root@limitrack:~# sudo tail -n 5 /var/log/ufw.log
Nov 10 19:59:59 limitrack kernel: [5182374.453772] [UFW BLOCK] IN=[REDACTED] OUT= MAC=[REDACTED] SRC=[REDACTED] DST=[REDACTED] LEN=60 TOS=0x08 PREC=0x40 TTL=49 ID=23897 DF PROTO=TCP SPT=43092 DPT=2377 WINDOW=64240 RES=0x00 SYN URGP=0
Nov 10 20:00:05 limitrack root: [UFW TEST] meow meow meow meow meow purrr nya
root@limitrack:~#
And that’s it, no more rsyslogd spam!