Bug 1370195 - Journald fails to forward to syslog message with level above its storing level
Summary: Journald fails to forward to syslog message with level above its storing level
Alias: None
Product: Red Hat Enterprise Linux 7
Classification: Red Hat
Component: systemd
Version: 7.2
Hardware: All
OS: Linux
Target Milestone: rc
: ---
Assignee: systemd-maint
QA Contact: qe-baseos-daemons
Depends On:
Blocks: 1420851 1466365
TreeView+ depends on / blocked
Reported: 2016-08-25 13:48 UTC by Assen Totin
Modified: 2020-12-14 07:41 UTC (History)
4 users (show)

Fixed In Version:
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
Last Closed: 2017-11-07 12:51:50 UTC
Target Upstream Version:

Attachments (Terms of Use)

Description Assen Totin 2016-08-25 13:48:15 UTC
Description of problem:
When journald is configured to store messages up to a given log level, it fails to forward to syslog any received message with higher log level, even when forwarding to syslog permits it.

Version-Release number of selected component (if applicable):

How reproducible:
Every time

Steps to Reproduce:
1. Start with a default RHEL-7 configuration for journald (/etc/systemd/journald.conf) and rsyslog (/etc/rsyslog.conf).
2. Edit rsyslog config file and add a route which sends *.debug to /var/log/debug. Restart rsyslog service and verify that /var/log/debug has been created.
3. Send a syslog message to system's syslog service with LOG_DEBUG level (facility does not matter). Verify that message is visible in both journal and /var/log/debug. 
4. Edit journald config file and change MaxLevelStore to "info" while keeping MaxLevelSyslog at "debug" and ForwardToSyslog to "yes". Restart the service.
5. Repeat step 3.

Actual results:
Message is not present neither in the journal output nor in the syslog file.

Expected results:
Message should be missing from journal (not saved as saving level is below the message level), but should be forwarded to syslog (because forward-to-syslog level matches the one of the message).

Additional info:
The documentation for systemd at https://www.freedesktop.org/software/systemd/man/journald.conf.html makes no mention of any dependency between MaxLevelStore and MaxLevelSyslog, hence these are considered independent and the observed behaviour is a bug. 

We actually want to use the described scenario to make sure journal only gets messages up to certain level (which are interesting to sysadmins), while rsyslog receives all messages (which are interesting to developers). This specifically applies to LOG_DEBUG in our product, which, even if only used in dev environments, produces huge amount of output; we find it much easier to drop a syslog-produced file than to clean up (and free the space used by) cluttered journal. 

Sample C code to send message to syslog:

#include <syslog.h>
int main(int argc, char *argv[]) {
	openlog("test", LOG_PID, LOG_LOCAL5);
        syslog(LOG_DEBUG, "Hello World");
        return 0;

Comment 1 Assen Totin 2016-08-25 13:58:54 UTC
The same issue is observed when using systemd's native C API:

#include <systemd/sd-journal.h>
int main(int argc, char *argv[]) {
       	sd_journal_print(LOG_DEBUG, "Hello World");
        return 0;

Comment 3 Lukáš Nykrýn 2016-08-30 08:16:27 UTC
The problem here is that by default rsyslog does not listen on syslog.socket, but directly reads the journal files. This has the advantage that you will have logs from early boot in /var/log/messages. The disadvantage is that what is not in journal will not be in /var/log/messages.

What you can do is to reconfigure rsyslog to read the redirected messages. I know almost nothing about rsyslog but I have tried this:

0) (setup journal to skip debug messages and rsyslog to accept them)
1) comment $ModLoad imjournal in rsyslog.conf
2) set $OmitLocalLogging off in rsyslog.conf
3) cp /usr/lib/systemd/system/rsyslog.service /etc/systemd/system/rsyslog.service 
4) uncomment Requires=syslog.socket and Alias=syslog.service in /etc/systemd/system/rsyslog.service
5) systemctl daemon-reload; systemctl reenable rsyslog
6) systemctl restart rsyslog systemd-journald

and now:
[0 root@qeos-150 ~]# logger -p user.debug "yippee yay yeah"
[0 root@qeos-150 ~]# tail -1 /var/log/messages 
Aug 30 04:13:50 qeos-150 root: yippee yay yeah

Comment 4 Assen Totin 2016-09-08 12:54:54 UTC
Thanks, Lukas, 

I'm aware tat I can change the order in which rsyslogd and systemd-journald get the syslog messages, or even separate them. 

However, RHEL chose to configure the system by default the way it comes, with systemd-journald being the first in the chain. Also, RHEL chose to use imjournal rsyslogd moudle instead of $SystemLogSocketName, which on RHEL points to the non-existent /run/systemd/journal/syslog. The latter might be a suitable way of solving this?

Comment 11 Lukáš Nykrýn 2017-11-07 12:51:50 UTC
Well this is design issue that can't be fix. By default rsyslog is reading journal files, so the messages that are not in journal can't appear in rsyslog.

Note You need to log in before you can comment on or make changes to this bug.