We have many production apps (first and third-party) that leave logging up to the process that runs the app and just log to stdout
for INFO
and stderr
for ERROR
logs (ie only 2 log priorities: INFO|ERROR
).
With a systemd service unit for an app this can be setup like this:
StandardOutput=journal
StandardError=journal
This allows devops to manage everything through systemd units and the journal in order to facilitate centralized log collection, monitoring whatever...and they don't need to worry about locating and parsing different logs in different formats/locations for every app they deploy.
systemd's journal has a message priority system compatible with syslog's 7 level message priority system. INFO
is level 6
and ERROR
is level 3
. See references for more details.
The problem is... systemd/journal apparently does not distinguish between messages written to the journal from stdout vs stderr. Both stdout and stderr messages are all written to the journal with default priority of 6 (INFO
).
Example: "Fancy App"
/opt/log-test.sh
#!/bin/bash
echo "This is ERROR" 1>&2
echo "This is INFO"
exit 0
/etc/systemd/system/log-test.service
[Unit]
Description=log test for journal
[Service]
Type=simple
ExecStart=/opt/log-test.sh
StandardOutput=journal
StandardError=journal
SyslogIdentifier=log-test
run it and check journal
$ systemctl start log-test
$ journalctl -u log-test
-- Logs begin at Thu 2022-04-07 08:17:16 UTC, end at Thu 2022-04-07 16:35:02 UTC. --
Apr 07 16:34:58 host.example.com systemd[1]: Started log test for journal.
Apr 07 16:34:58 host.example.com log-test.sh[29909]: This is ERROR
Apr 07 16:34:58 host.example.com log-test.sh[29909]: This is INFO
$ journalctl -u log-test -p 6 # syslog info priority
-- Logs begin at Thu 2022-04-07 08:17:16 UTC, end at Thu 2022-04-07 16:35:08 UTC. --
Apr 07 16:34:58 host.example.com systemd[1]: Started log test for journal.
Apr 07 16:34:58 host.example.com log-test.sh[29909]: This is ERROR
Apr 07 16:34:58 host.example.com log-test.sh[29909]: This is INFO
$ journalctl -u log-test -p 3 # syslog error priority
-- No entries --
$
You can see that both stderr and stdout messages are set to priority 6
(INFO
) when written to the journal.
This is a problem because we don't have an easy way of differentiating output on stdout vs stderr when using stdio->journal
as primary logging facility.
This has been discussed before and solutions are possible, but not implemented. I'm hoping the systemd team eventually implements this, but meanwhile I need a solution.
Has anyone found a reasonable solution to get messages written to stdout and stderr to be different priorities in the journal without modifying how an app does logging?
I don't want all the apps we deploy (not all written by us) to have to implement journal or syslog integrations in order to get log priority when we really only need two levels: INFO
(stdout) and ERROR
(stderr).
Much of what we deploy is not containerized, so relying on logging facilities of the container is also not a solution for us.
Having stderr and stdout go to journal/syslog at different priorities by default is pretty critical for making distributed log error monitoring easier (assuming good developer hygiene about only writing stuff that needs attention to stderr).