journal: optimize metadata collection for udev devices, cache udev props between subsequent messages

Submission type

• Bug report

systemd version the issue has been seen with

237

Used distribution

Debian Sid

In case of bug report: Expected behaviour you didn't see

when a kernel device driver outputs load of output to kmsg. I expect to get all or most of its output.
This one was rtl8xxxu driver with those modprobe settings
options rtl8xxxu dyndbg="+pltf" debug=0xffff

In case of bug report: Unexpected behaviour you saw

I get a truncated an output: chunks of hundreds of lines are reported as missed.

In case of bug report: Steps to reproduce the problem

setup a device driver with debug on then load it.

I worked around this issue by rebuilding the systemd packages with a section of code disabled. Namely:
https://github.com/systemd/systemd/blob/v237/src/journal/journald-kmsg.c#L229 to https://github.com/systemd/systemd/blob/v237/src/journal/journald-kmsg.c#L275 .

The rationale is that kmsg returns EPIPE when the reader is too slow reading (ring buffer overflows). systemd journald-kmsg handles this EPIPE in server_read_dev_kmsg and silently returns zero. Then dev_kmsg_record tells about missed kernel messags as it detect lost messages (kernel seq_num).

The udev calls on each dev_kmsg_record decorate or at best enhance journald output. This is unfortunate that in their current state they forbid kernel work.

Start with src/journal/journald-kmsg.c, especially the server_read_dev_kmsg and dev_kmsg_record paths around lines 229-275. Trace how udev metadata is collected for successive kernel messages and verify that the change avoids dropped kmsg output while retaining the metadata behavior described in the issue.