Systemd: Asynchronous forwarding options for journald

[vcaputo]

Submission type

• [ ] Bug report
• [X ] Request for enhancement (RFE)
  

  Enhancement description

It would be useful if one could specify something like ForwardToConsole=async to enable something akin to a journalctl --follow redirected to the console, but internal to journald, potentially utilizing journald's already opened journals and mmap cache for improved efficiency, configured in the same place and fashion the existing synchronous forwarding is configured.

Today if you utilize ForwardToConsole=yes, all logging of sufficient priority becomes serialized on the console output, which may be redirected to a serial port.

In CoreOS we enabled ForwardToConsole=yes on some cloud providers to facilitate the troubleshooting of inaccessible instances where only a non-interactive, read-only serial console is provided (aws for example). This can be incredibly useful, but we recently received a report of this creating a significant journald performance problem for at least one user and there's no reason to believe it isn't happening elsewhere. Indeed, if one configures ForwardToConsole=yes in a qemu vm it's trivial to see a substantial performance degradation in journald's throughput; this isn't something limited to the cloud provider's implementation of virtual serial ports.

Upon examining how the forwarding is implemented in journald, it becomes clear how the writev()'s implementing the forwarding blocking on a serial console would bottleneck logging for the entire daemon.

It may make sense to perform the forwarding synchronously if you require lossless forwarding under all circumstances, but this simply isn't always the case.

If we could treat the journal files as buffers and simply have threads or processes perform the forwarding similar to how rsyslog or journalctl --follow may consume the journals in real-time, we can allow journald to perform logging at the speed of storage, while forwarding may lag behind as needed. Should forwarding fall so far behind the journal file being forwarded becomes vacuumed then losses occur and are simply tolerated in the forwarded logs, perhaps with an entry noting the drops, before resuming at start of the next available journal files.

[poettering]

Well, isn't that just a matter of writing a unit file that uses TTY=/dev/some-tty and invokes journalctl -f?

There's no need to change anything in the C sources, is there?

[credmon]

We, as well, have encountered issues with logging to a console with limited bandwidth, such as a serial port; we are using an ARM based embedded system with ForwardToConsole=yes, and console is a UART at 115200 baud. When kernel printks are logged at high enough severity level as to be printed directly to the console by the kernel, and the rate of printks is faster than the bandwidth of the terminal, journald can block indefinitely trying to acquire the console in open_terminal() until the printks subside. We found that when journald blocks indefinitely trying to open the console, this can cause services that log to syslog to block until journald is able to acquire the terminal, or fails to acquire the console. Journald was never failing or succeeding to acquire the console in the scenario described, which might be a kernel bug.

The net result though, was that we were able to create a denial of service, because the processes that log to syslog would be blocked until journald became unblocked. Services like SSHD would not allow the user to login.

We did implement the asyncronous journal following service, and this seems to be a good workaround for this situation. It is very concerning that a denial of service attack could be launched because journald might not be able to log data to the console, and also because ForwardToConsole=yes might be a default setting depending on which linux distribution you may be running, and most rational people would believe that this option would be safe to turn on.

One thing I noticed when looking into this issue was that messages to console are not rate limited, but they are to journal. Having a rate limit for the console could be useful, and the rate limit could be separate of that for the journal, and based on the bandwidth of the console in question.

[vcaputo]

IMHO since ForwardToConsole= is the documented and hence readily discoverable means of achieving this, it should Do The Right Thing without involving workarounds. The workaround is only arrived at after being bitten by the synchronous implementation of ForwardToConsole, assuming the user has been able to figure it out and hasn't instead just thrown their hands up in frustration at poor journald performance.

At the very least the documentation should be amended to say not to use ForwardToConsole except for temporary debugging, with mention of the bottleneck it creates. Perhaps also mention of this in the provided journald.conf where one currently would simply uncomment the line without any suggestion of the synchronous surprise.

If these forwarding flags were just prefixed with Sync e.g. SyncForwardToConsole it'd be a whole lot more self-evident what is going to happen. Since they aren't, I feel we should reimplement them to all be asynchronous and lossy when they can't keep up if enabled, with an explicit sync option for the synchronous behavior.