Bug 1370195

Summary:	Journald fails to forward to syslog message with level above its storing level
Product:	Red Hat Enterprise Linux 7	Reporter:	Assen Totin <assen>
Component:	systemd	Assignee:	systemd-maint
Status:	CLOSED CANTFIX	QA Contact:	qe-baseos-daemons
Severity:	unspecified	Docs Contact:
Priority:	unspecified
Version:	7.2	CC:	bblaskov, kwalker, msekleta, systemd-maint-list
Target Milestone:	rc
Target Release:	---
Hardware:	All
OS:	Linux
Whiteboard:
Fixed In Version:		Doc Type:	If docs needed, set a value
Doc Text:		Story Points:	---
Clone Of:		Environment:
Last Closed:	2017-11-07 12:51:50 UTC	Type:	Bug
Regression:	---	Mount Type:	---
Documentation:	---	CRM:
Verified Versions:		Category:	---
oVirt Team:	---	RHEL 7.3 requirements from Atomic Host:
Cloudforms Team:	---	Target Upstream Version:
Bug Depends On:
Bug Blocks:	1420851, 1466365

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):
systemd-219-19.el7_2.12.x86_64

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.