Filter mechanism for logs in journald

[PhilippWendler]

Submission type

• Request for enhancement (RFE)

systemd version the issue has been seen with

234

Used distribution

irrelevant

Description

A possibility to filter logs in journald, i.e., before they are written to the journal, would be helpful in cases where some daemon spams the log with countless messages.

Of course, it is better to fix the source instead of filtering away log messages, but for many users the former is not possible and the latter is a helpful workaround until the real problem is fixed.
As an example, my concrete current problem is that I need to run snmpd for lack of alternatives and it spams the log with error messages (so just reducing the log level would mean I also do not see other errors), and this behavior exists for years but is not getting fixed (Debian bug from 2015, Red Hat bug from 2016). This shows that in practice, a log-filter possibility would indeed be helpful.

I know that journalctl can filter log messages, but for cases like this I do not want these messages to be written to the journal, because for example many such messages can lead to earlier-than-desired log truncation due to the SystemMaxUse/SystemKeepFree options.

rsyslog has an equivalent feature (which I have been using until now), so I could solve this by ignoring the journal and using traditional syslog, but I really like the additional features of the journal and do not want to fall back to syslog just because of this.

I do not have a full proposal how the syntax for log filters could look like. I suggest to start with an option in journald.conf that can take an expression similar to that of journalctl, but I assume that for such a feature to be most useful there would need to be the possibility to due regexp or at least substring matches on the message field, like rsyslog has. Maybe a syntax inspired by CSS attribute selectors could be used or something like Perl-style =~ for regexp matches?

[poettering]

This has been requested before, but I am still not convinced we should do filtering at collection time, but instead do that at query time. We should work on making journald data collection quicker to make this less of a hassle (for example through #6392 and such).

[PhilippWendler]

Note that it might not only be a performance problem, but also a disk-space problem that leads to earlier-than-desired log truncation.

[dkg]

See also #2447

[aldem]

Performance is not an issue (not a big one), disk/RAM storage is (and rotations because of it).

There are plenty of applications/daemons (rrdcached is one of them, as an example) which simply do not offer granular logging control - while spamming a lot, thus leaving us no choice.

Additional issue is "out of band" log rotation (and retention policies) for services that log to stdout/stderr - systemd/journald does not offer functionality like daemontools' multilog does - it is "all or nothing" choice - while per app/service configurable log rotation policies are desirable, but with journald this is simply impossible - one heavy on logging app may spoil everything.

Sure, it is easy to say "fix at the source" - but this won't work, while collection time filtering, even with regexes or whatever else similar is relatively easy to implement and solves the problem once and forever.

Love it or hate it, but there are plenty of apps that do not care about logging control but are stick for quite a while, and we have to deal with them...

[folknor]

@poettering What would it take to convince you that filtering at collection time is a worthwhile endeavour? If the answer is "nothing can convince me", then there's nowhere to go. I suspect that's not the case, since this issue remains open - in which case it would be helpful to have a list of actual criteria for consideration.

Steam spams the logs with 60 megabytes of total garbage every day. You can say "fix Steam", or "fix dbus", and I'd agree with that, but I'd also say that one job of a system-level utility is to allow for easier system management where you don't necessarily have total control of the software stack.

Steam repeats this from startup to shutdown, at seemingly random intervals (1-60 seconds):

nov. 01 12:12:12 foo bar[1216]: process 15988: arguments to dbus_connection_unref() were incorrect, assertion "connection->generation == _dbus_current_generation" failed
nov. 01 12:12:12 foo bar[1216]: This is normally a bug in some application using the D-Bus library.

Of course, I could just filter the Steam spam at query time, but most of the friend+family machines that I manage use spinning disks, and I'm not a stranger to disk failures from both SSD and HDDs. Of course I'm not blaming neither journald nor Steam, I'm just saying that surely this kind of behavior is not helpful.

This behavior has been present in both the live and beta Steam versions for linux since at least the end of August.

[laktak]

@poettering systemd is also used on rasperry pi's and other IoT devices. Here the whole file system is stored on a SSD. To avoid premature SSD death we have to limit the number of writes to the filesystem as much as possible.

[BryanQuigley]

I actually just found a bug that this would help me avoid -BOINC/boinc#2256

• but really this feature would be used just to paper over other bugs in other programs -that could still be having an impact on CPU usage... or causing other issues.

If this feature existed I would just modify the unit file to ignore it, and never work to fix the actual problem. Given that, I think it might be better overall for the ecosystem to not have this feature.

[Vash63]

I'd also love this feature for the same reason listed above - Steam floods my journal with tens of thousands of lines of errors every day. Just in the last 15 minutes I've had 3,775 lines of spam that I'd love to filter out at collection time to not waste my disk space and SSD wear.

[Ynot82]

Just to add my +1 for this.

There are certain circumstances where messages from units (particularly error messages) are expected and ideally should be ignored.

Example:
Nagios check verifying if an OpenVPN server is up and running.

The way check works, it opens a connection to the OpenVPN server, verifies if it gets the expected response, then just exits.
I'm guessing this is to save on resources, and also to not have to supply authentication credentials and varies other gubbins that aren't needed.

Issue is, from OpenVPN's POV, this looks like a client error.
Client connects, but then disappeared before it could be authenticated.

Errors written to journal

ovpn-server[29338]: <IP>:<PORT> TLS Error: TLS key negotiation failed to occur within 60 seconds (check your network connectivity)
ovpn-server[29338]: <IP>:<PORT> TLS Error: TLS handshake failed

While not a major issue, it's kind of annoying to have these plastered all over the journal at 10 min intervals.
And when looking for genuine errors, means it's difficult to see the wheat from the chaff.

Some method of filtering messages prior to inclusion in the journal log would be very helpful here.

Thanks

[bbetter173]

I too have a similar issue using some legacy in-house applications that we don't have the source code to. Having just migrated to CentOS 7 and porting all the init.d scripts to systemd units, one application writes an "Everything is OK" line to stdout every 15 seconds.