1

Does systemd use a different timeout setting for stopping a running daemon (e.g., rsyslog) when rebooting the system (e.g., by running reboot) vs when you simply restart the daemon (e.g., systemctl restart rsyslog)?

I've checked the systemd.service page, but I didn't spot it. Instead I only found the TimeoutStopSec and TimeoutStartSecoptions. I've set the TimeoutStopSec option, but it appears that systemd may be killing the daemon before it has a chance to safely save its state and terminate cleanly.

EDIT 1:

As @sourcejedi suggested (thanks), I should emphasize that this is not a desktop installation where rsyslog is running, but an Ubuntu 16.04 server install of rsyslog that receives messages from client nodes and may still be holding many messages in memory when asked to terminate by systemd.

I attempted to help work around some corrupt disk queue issues by increasing the value for the TimeoutStopSec option from 90 seconds to 240 seconds, but I still observed this message multiple times in the related log file:

rsyslogd: queue 'strm 0x26b4800', file '/var/spool/rsyslog/q_ForwardToNode2.00000003' opened for non-append write, but already contains 983505 bytes  [v8.29.0 try http://www.rsyslog.com/e/0 ]

The idea was that system might be impatient and was killing rsyslog while it was still saving content to disk.

I attempted to work around another issue by forcing systemd to wait on an active network connection before attempting to start rsyslog. I've included the contents of both systemd Drop-Ins that I am using below for reference in case it adds helpful context to this entry.

cat /etc/systemd/system/rsyslog.service.d/*.conf | grep -Ev '#|^$'

Attempt to work around github #1656

[Unit]
Documentation=https://internal/wiki/url/here
After=network.target
Wants=nework.target

Attempt to work around github #1704

[Unit]
Documentation=https://internal/wiki/url/here
[Service]
TimeoutStopSec=240

Thank you for reading this.

  • Thanks, I updated my question in an attempt to add more context. Please let me know of any other improvements I can make and I'll try to do so. – deoren Aug 17 '17 at 22:15
  • 1
    For future events, I would recommend using persistent logging for the systemd journal. It is nicely integrated and able to log until very late: you should see it gets terminated after shutdown.target, which is when all services (which don't have DefaultDependencies=no) are stopped. This means it will record any systemd log messages about timeouts of such services, and you'll also be able to look at the specific timings. – sourcejedi Aug 18 '17 at 8:47
  • 1
    I wonder if ryslog is stopped after the network is stopped. I think your Wants=network.target is wrong and would possibly cause some problem. Use After=network.target only. Source: freedesktop.org/wiki/Software/systemd/NetworkTarget I don't know what the effect of your typo Wants=nework.target would be though, does your real file look like that? – sourcejedi Aug 18 '17 at 8:53
  • @sourcejedi Unfortunately I do have that typo in the original file. Thank you for catching that. Thank you for also flagging the Wants=network.target as problematic. I'll get that fixed as well. – deoren Aug 18 '17 at 23:39
  • @sourcejedi I just saw your notes re persistent logging of the systemd journal. I'll definitely do that and will look for messages there that could help confirm what is going on. Thank you for your detailed responses. – deoren Aug 19 '17 at 0:13
1

Does issuing a reboot command result in systemd ignoring the TimeoutStopSec value?

No. That would be horrible, and it's not what happens.

EDIT: Some systemd version above v233 adds JobTimeoutSec=30min to reboot.target. So in this case there would be an upper limit (after which the unit forces a reboot), but it is several times higher than the values you've been setting so far.

EDIT: Re "the idea was that system might be impatient and was killing rsyslog while it was still saving content to disk", the message seems to have been a bug in rsyslog.

queue bugfix: file write error message was incorrect #1759 #1759

when a queue was restarted from disk file, it almost always emitted a message claiming "file opened for non-append write, but already contains xxx bytes" This message was wrong and did not indicate a real error condition. The predicate check was incorrect.


Looking at the service files on Debian 9, note that syslog.socket (supplied by systemd) has DefaultDependencies=no, but also Before=shutdown.target and Conflicts=shutdown.target. The latter line is commented Don't allow logging until the very end. If you didn't have those last two AND rsyslog.service had DefaultDependencies=no, the syslog daemon could be re-activated immediately, and get killed by systemd-shutdown.service (systemd-shutdown) instead. systemd-shutdown uses the built-in default timeout between SIGTERM and SIGKILL, which I think is 90 seconds.

  • Thank you for your detailed feedback. Does the use of the Drop-Ins I noted in my first edit change that behavior in any meaningful way? In other words, could my attempt to have rsyslog delayed from starting until an active network connection is active remove the protection applied by the specific Before and Conflicts settings you note in your Answer? – deoren Aug 17 '17 at 22:22
  • 1
    @deoren thx for mentioning the drop-in here, but those look fine and shouldn't affect it. (E.g. you can add as many lines/dropins for After= as you like, and they're all applied). – sourcejedi Aug 18 '17 at 8:39
  • thank you reviewing those files. Aside from the typo you identified, I'm glad to hear that the changes listed within shouldn't be responsible for the behavior I noted. – deoren Aug 19 '17 at 0:11

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service, privacy policy and cookie policy

Not the answer you're looking for? Browse other questions tagged or ask your own question.