Google Groups no longer supports new Usenet posts or subscriptions. Historical content remains viewable.
Dismiss
Bug#989943: unattended-upgrades blocking other cron.daily scripts or "'invoke-rc.d rsyslog rotate' called during shutdown sequence."
24 views
Skip to first unread message
Tomas Pospisek
Jun 16, 2021, 8:10:03 AM6/16/21
to
Package: unattended-upgrades
Version: 1.11.2
Severity: normal
Hi!
There are several systems where I get
Date: Tue, 15 Jun 2021 06:00:17 +0200
From: Cron Daemon
Subject: Cron <root@dom> test -x /usr/sbin/anacron || ( cd / && run-parts --report /etc/cron.daily )
/etc/cron.daily/logrotate:
invoke-rc.d: -----------------------------------------------------
invoke-rc.d: WARNING: 'invoke-rc.d rsyslog rotate' called
invoke-rc.d: during shutdown sequence.
invoke-rc.d: enabling safe mode: initscript policy layer disabled
invoke-rc.d: -----------------------------------------------------
whenever unattended-upgrades needs to reboot. *Before* the
reboot the system looks like this:
root 835 0.0 0.0 8504 2336 ? Ss Jun15 0:00 /usr/sbin/cron
root 12595 0.0 0.0 9120 2316 ? S 06:25 0:00 \_ /usr/sbin/CRON
root 12596 0.0 0.0 2388 700 ? Ss 06:25 0:00 \_ /bin/sh -c test -x /usr/sbin/anacron || ( cd / && run-parts --report /etc/cron.daily )
root 12597 0.0 0.0 2284 688 ? S 06:25 0:00 \_ run-parts --report /etc/cron.daily
root 12598 0.0 0.0 2388 764 ? S 06:25 0:00 \_ /bin/sh /usr/lib/apt/apt.systemd.daily
root 12733 0.0 0.0 2388 1488 ? S 06:41 0:00 \_ /bin/sh /usr/lib/apt/apt.systemd.daily lock_is_held
root 13047 0.0 0.2 123308 34548 ? Sl 06:41 0:00 \_ /usr/bin/python3 /usr/bin/unattended-upgrade
root 13057 0.0 0.0 2372 1752 ? S 06:41 0:00 \_ /sbin/shutdown -r 06:00
In human language: this morning at 06:25 cron.daily ran,
which triggered unattended-upgrades, which triggered
`/sbin/shutdown -r 06:00`.
Now one problem here is that `/sbin/shutdown -r 06:00` is
actually blocking. It will *not* exit, but instead will
count waiting time to zero and reboot after.
We are on a system with `sysv-rc` and not `systemd`. I have
*not* verified whether `shutdown -r $TIME` behavior is
identical on a `systemd` system.
The system apparently shut down at:
# cat /var/log/messages
Jun 15 06:00:14 dom shutdown[13634]: shutting down for system reboot
also
# cat /var/log/daemon.log
Jun 15 06:00:15 dom init: Switching to runlevel: 6
also
# last -F
reboot system boot 4.19.0-16-amd64 Tue Jun 15 06:00:28 2021 - Wed Jun 16 10:34:57 2021 (1+04:34)
So my interpretation is this:
1. cron.daily runs
2. it executes unattended-upgrade
3. unattended-upgrade blocks when it calls shutdown -r 06:00
4. in our case that stops the other cron.daily tasks that are
sorted after /etc/cron.daily/apt-compat (that is pretty
much all others since apt-compat is first in the alphabet)
from running
5. the clock hits 06:00:00 and shutdown exits (this is my
guess - I think it's the same behavior as with
`shutdown -r now` which also exits and so you sometimes
see/get back to the prompt before the sytstem *actually*
warm reboots)
6. after `shutdown -r 06:00` exits unattended-upgrade
finishes whatever it was doing, exits and cron.daily continues
with the execution with the other scripts in /etc/cron.daily/
that alphabetically follow apt-compat, which makes a
mess, because we're actually in runlevel 6/shutdown
now. which triggers the warning we saw above from
logrotate/cron.
Now what would a "correct" or "better" behavior be?
I suggest to trigger an asynchronous shutdown, that is *not*
to wait for `shutdown -r $TIME` to come back so that whatever
daily menial taks are scheduled via /etc/cron.daily are able
to be executed.
In other words: fork & exec shutdown...
?
Thanks a lot for maintaining unattended-upgrades!!!! Greetings,
*t
-- System Information:
Debian Release: 10.9
APT prefers stable-updates
APT policy: (500, 'stable-updates'), (500, 'stable')
Architecture: amd64 (x86_64)
Kernel: Linux 4.19.0-16-amd64 (SMP w/8 CPU cores)
Locale: LANG=C, LC_CTYPE=C.UTF-8 (charmap=UTF-8), LANGUAGE=C (charmap=UTF-8)
Shell: /bin/sh linked to /bin/dash
Init: sysvinit (via /sbin/init)
Versions of packages unattended-upgrades depends on:
ii debconf [debconf-2.0] 1.5.71
ii lsb-base 10.2019051400
ii lsb-release 10.2019051400
ii python3 3.7.3-1
ii python3-apt 1.8.4.3
ii python3-dbus 1.2.8-3
ii python3-distro-info 0.21
ii ucf 3.0038+nmu1
ii xz-utils 5.2.4-1
Versions of packages unattended-upgrades recommends:
ii cron [cron-daemon] 3.0pl1-134+deb10u1
Versions of packages unattended-upgrades suggests:
ii bsd-mailx 8.1.2-0.20180807cvs-1
pn needrestart <none>
ii nullmailer [mail-transport-agent] 1:2.2-3
pn powermgmt-base <none>
ii python3-gi 3.30.4-1
-- debconf information:
* unattended-upgrades/enable_auto_updates: true
unattended-upgrades/origins_pattern: "origin=Debian,codename=${distro_codename},label=Debian-Security";
Version: 1.11.2
Severity: normal
Hi!
There are several systems where I get
Date: Tue, 15 Jun 2021 06:00:17 +0200
From: Cron Daemon
Subject: Cron <root@dom> test -x /usr/sbin/anacron || ( cd / && run-parts --report /etc/cron.daily )
/etc/cron.daily/logrotate:
invoke-rc.d: -----------------------------------------------------
invoke-rc.d: WARNING: 'invoke-rc.d rsyslog rotate' called
invoke-rc.d: during shutdown sequence.
invoke-rc.d: enabling safe mode: initscript policy layer disabled
invoke-rc.d: -----------------------------------------------------
whenever unattended-upgrades needs to reboot. *Before* the
reboot the system looks like this:
root 835 0.0 0.0 8504 2336 ? Ss Jun15 0:00 /usr/sbin/cron
root 12595 0.0 0.0 9120 2316 ? S 06:25 0:00 \_ /usr/sbin/CRON
root 12596 0.0 0.0 2388 700 ? Ss 06:25 0:00 \_ /bin/sh -c test -x /usr/sbin/anacron || ( cd / && run-parts --report /etc/cron.daily )
root 12597 0.0 0.0 2284 688 ? S 06:25 0:00 \_ run-parts --report /etc/cron.daily
root 12598 0.0 0.0 2388 764 ? S 06:25 0:00 \_ /bin/sh /usr/lib/apt/apt.systemd.daily
root 12733 0.0 0.0 2388 1488 ? S 06:41 0:00 \_ /bin/sh /usr/lib/apt/apt.systemd.daily lock_is_held
root 13047 0.0 0.2 123308 34548 ? Sl 06:41 0:00 \_ /usr/bin/python3 /usr/bin/unattended-upgrade
root 13057 0.0 0.0 2372 1752 ? S 06:41 0:00 \_ /sbin/shutdown -r 06:00
In human language: this morning at 06:25 cron.daily ran,
which triggered unattended-upgrades, which triggered
`/sbin/shutdown -r 06:00`.
Now one problem here is that `/sbin/shutdown -r 06:00` is
actually blocking. It will *not* exit, but instead will
count waiting time to zero and reboot after.
We are on a system with `sysv-rc` and not `systemd`. I have
*not* verified whether `shutdown -r $TIME` behavior is
identical on a `systemd` system.
The system apparently shut down at:
# cat /var/log/messages
Jun 15 06:00:14 dom shutdown[13634]: shutting down for system reboot
also
# cat /var/log/daemon.log
Jun 15 06:00:15 dom init: Switching to runlevel: 6
also
# last -F
reboot system boot 4.19.0-16-amd64 Tue Jun 15 06:00:28 2021 - Wed Jun 16 10:34:57 2021 (1+04:34)
So my interpretation is this:
1. cron.daily runs
2. it executes unattended-upgrade
3. unattended-upgrade blocks when it calls shutdown -r 06:00
4. in our case that stops the other cron.daily tasks that are
sorted after /etc/cron.daily/apt-compat (that is pretty
much all others since apt-compat is first in the alphabet)
from running
5. the clock hits 06:00:00 and shutdown exits (this is my
guess - I think it's the same behavior as with
`shutdown -r now` which also exits and so you sometimes
see/get back to the prompt before the sytstem *actually*
warm reboots)
6. after `shutdown -r 06:00` exits unattended-upgrade
finishes whatever it was doing, exits and cron.daily continues
with the execution with the other scripts in /etc/cron.daily/
that alphabetically follow apt-compat, which makes a
mess, because we're actually in runlevel 6/shutdown
now. which triggers the warning we saw above from
logrotate/cron.
Now what would a "correct" or "better" behavior be?
I suggest to trigger an asynchronous shutdown, that is *not*
to wait for `shutdown -r $TIME` to come back so that whatever
daily menial taks are scheduled via /etc/cron.daily are able
to be executed.
In other words: fork & exec shutdown...
?
Thanks a lot for maintaining unattended-upgrades!!!! Greetings,
*t
-- System Information:
Debian Release: 10.9
APT prefers stable-updates
APT policy: (500, 'stable-updates'), (500, 'stable')
Architecture: amd64 (x86_64)
Kernel: Linux 4.19.0-16-amd64 (SMP w/8 CPU cores)
Locale: LANG=C, LC_CTYPE=C.UTF-8 (charmap=UTF-8), LANGUAGE=C (charmap=UTF-8)
Shell: /bin/sh linked to /bin/dash
Init: sysvinit (via /sbin/init)
Versions of packages unattended-upgrades depends on:
ii debconf [debconf-2.0] 1.5.71
ii lsb-base 10.2019051400
ii lsb-release 10.2019051400
ii python3 3.7.3-1
ii python3-apt 1.8.4.3
ii python3-dbus 1.2.8-3
ii python3-distro-info 0.21
ii ucf 3.0038+nmu1
ii xz-utils 5.2.4-1
Versions of packages unattended-upgrades recommends:
ii cron [cron-daemon] 3.0pl1-134+deb10u1
Versions of packages unattended-upgrades suggests:
ii bsd-mailx 8.1.2-0.20180807cvs-1
pn needrestart <none>
ii nullmailer [mail-transport-agent] 1:2.2-3
pn powermgmt-base <none>
ii python3-gi 3.30.4-1
-- debconf information:
* unattended-upgrades/enable_auto_updates: true
unattended-upgrades/origins_pattern: "origin=Debian,codename=${distro_codename},label=Debian-Security";
Tomas Pospisek
Jun 17, 2021, 5:10:04 AM6/17/21
to
With respect to "unattended-upgrades blocking other cron.daily scripts via
shutdown -r" I reflected:
> Now what would a "correct" or "better" behavior be?
>
> I suggest to trigger an asynchronous shutdown, that is *not*
> to wait for `shutdown -r $TIME` to come back so that whatever
> daily menial taks are scheduled via /etc/cron.daily are able
> to be executed.
What about the idea of using
echo "shutdown -r now" | at $TIME
instead of directly calling
shutdown -r now
Pro:
* async execution. unattended-update can finish it's stuff and
the rest of cron.daily finishes correctly
* consoles won't be flooded with repeat "Systeme will be going
doing in XX hours"
Con:
* does care have to be taken that unattended-upgrade won't re-run
while it wants the system to reboot?
* behavior change (this should be triggering a major semver change...)
* this could be worked around with yet another config option
(UseAtInstead=True)
* users on the system won't be warned of the system going down in
XX hours
What do you think?
*t
shutdown -r" I reflected:
> Now what would a "correct" or "better" behavior be?
>
> I suggest to trigger an asynchronous shutdown, that is *not*
> to wait for `shutdown -r $TIME` to come back so that whatever
> daily menial taks are scheduled via /etc/cron.daily are able
> to be executed.
echo "shutdown -r now" | at $TIME
instead of directly calling
shutdown -r now
Pro:
* async execution. unattended-update can finish it's stuff and
the rest of cron.daily finishes correctly
* consoles won't be flooded with repeat "Systeme will be going
doing in XX hours"
Con:
* does care have to be taken that unattended-upgrade won't re-run
while it wants the system to reboot?
* behavior change (this should be triggering a major semver change...)
* this could be worked around with yet another config option
(UseAtInstead=True)
* users on the system won't be warned of the system going down in
XX hours
What do you think?
*t
Tomas Pospisek
Jun 18, 2021, 4:00:04 AM6/18/21
to
--- /usr/bin/unattended-upgrade.orig 2021-06-18 09:46:37.434386824
+0200
+++ /usr/bin/unattended-upgrade 2021-06-18 09:47:03.958639111 +0200
@@ -1353,11 +1353,12 @@
when = apt_pkg.config.find(
"Unattended-Upgrade::Automatic-Reboot-Time", "now")
logging.warning("Found %s, rebooting" % REBOOT_REQUIRED_FILE)
- cmd = ["/sbin/shutdown", "-r", when]
+ cmd = ["/usr/bin/at", when]
try:
- shutdown_msg = subprocess.check_output(cmd, stderr=subprocess.STDOUT)
- if shutdown_msg.strip():
- logging.warning("Shutdown msg: %s", shutdown_msg.strip())
+ p = subprocess.Popen(cmd, stdin=subprocess.PIPE, stdout=subprocess.PIPE, stderr=subprocess.STDOUT)
+ p_out = p.communicate(input=b'shutdown -h now\n')[0].decode('utf-8').strip()
+ if p_out:
+ logging.warning("Shutdown msg: %s", p_out)
except Exception as e:
logging.error("Failed to issue shutdown: %s", e)
Feedback about whether this is a good idea is appreciated.
Thanks & greetings,
*t
Tomas Pospisek
Jun 20, 2021, 5:00:03 AM6/20/21
to
Argh, that should of course be:
--- /usr/bin/unattended-upgrade.orig 2021-06-18 09:46:37.434386824 +0200
+++ /usr/bin/unattended-upgrade 2021-06-18 09:47:03.958639111 +0200
@@ -1353,11 +1353,12 @@
when = apt_pkg.config.find(
"Unattended-Upgrade::Automatic-Reboot-Time", "now")
logging.warning("Found %s, rebooting" % REBOOT_REQUIRED_FILE)
- cmd = ["/sbin/shutdown", "-r", when]
+ cmd = ["/usr/bin/at", when]
try:
- shutdown_msg = subprocess.check_output(cmd, stderr=subprocess.STDOUT)
- if shutdown_msg.strip():
- logging.warning("Shutdown msg: %s", shutdown_msg.strip())
+ p = subprocess.Popen(cmd, stdin=subprocess.PIPE, stdout=subprocess.PIPE, stderr=subprocess.STDOUT)
+ p_out = p.communicate(input=b'shutdown -r now\n')[0].decode('utf-8').strip()
As always: feedback appreciated
Thanks & greetings,
*t
--- /usr/bin/unattended-upgrade.orig 2021-06-18 09:46:37.434386824 +0200
+++ /usr/bin/unattended-upgrade 2021-06-18 09:47:03.958639111 +0200
@@ -1353,11 +1353,12 @@
when = apt_pkg.config.find(
"Unattended-Upgrade::Automatic-Reboot-Time", "now")
logging.warning("Found %s, rebooting" % REBOOT_REQUIRED_FILE)
- cmd = ["/sbin/shutdown", "-r", when]
+ cmd = ["/usr/bin/at", when]
try:
- shutdown_msg = subprocess.check_output(cmd, stderr=subprocess.STDOUT)
- if shutdown_msg.strip():
- logging.warning("Shutdown msg: %s", shutdown_msg.strip())
+ p = subprocess.Popen(cmd, stdin=subprocess.PIPE, stdout=subprocess.PIPE, stderr=subprocess.STDOUT)
+ if p_out:
+ logging.warning("Shutdown msg: %s", p_out)
except Exception as e:
logging.error("Failed to issue shutdown: %s", e)
(s/shutdown -h/shutdown -r/)
+ logging.warning("Shutdown msg: %s", p_out)
except Exception as e:
logging.error("Failed to issue shutdown: %s", e)
As always: feedback appreciated
Thanks & greetings,
*t
Tomas Pospisek
Nov 11, 2022, 5:00:04 AM11/11/22
to
Package: unattended-upgrades
Version: 2.8
Followup-For: Bug #989943
X-Debbugs-Cc: Michael Vogt <m...@debian.org>
Hi,
I'm still seeing this problem in unattended-upgrades from Debian bullseye.
Thanks a lot for unattended-upgrades and the maintainance!!!
*t
-- System Information:
Debian Release: 11.5
APT prefers stable-updates
APT policy: (500, 'stable-updates'), (500, 'stable-security'), (500, 'stable')
Architecture: amd64 (x86_64)
Kernel: Linux 4.19.0-22-amd64 (SMP w/8 CPU threads)
Locale: LANG=C, LC_CTYPE=C.UTF-8 (charmap=UTF-8), LANGUAGE not set
ii lsb-base 11.1.0
ii lsb-release 11.1.0
ii python3 3.9.2-3
ii python3-apt 2.2.1
ii python3-dbus 1.2.16-5
ii python3-distro-info 1.0
ii ucf 3.0043
ii xz-utils 5.2.5-2.1~deb11u1
Versions of packages unattended-upgrades recommends:
ii cron [cron-daemon] 3.0pl1-137
Versions of packages unattended-upgrades suggests:
ii bsd-mailx 8.1.2-0.20180807cvs-2
Version: 2.8
Followup-For: Bug #989943
X-Debbugs-Cc: Michael Vogt <m...@debian.org>
Hi,
I'm still seeing this problem in unattended-upgrades from Debian bullseye.
Thanks a lot for unattended-upgrades and the maintainance!!!
*t
-- System Information:
Debian Release: 11.5
APT prefers stable-updates
APT policy: (500, 'stable-updates'), (500, 'stable-security'), (500, 'stable')
Architecture: amd64 (x86_64)
Kernel: Linux 4.19.0-22-amd64 (SMP w/8 CPU threads)
Locale: LANG=C, LC_CTYPE=C.UTF-8 (charmap=UTF-8), LANGUAGE not set
Shell: /bin/sh linked to /bin/dash
Init: sysvinit (via /sbin/init)
Versions of packages unattended-upgrades depends on:
ii debconf [debconf-2.0] 1.5.77
Init: sysvinit (via /sbin/init)
Versions of packages unattended-upgrades depends on:
ii lsb-base 11.1.0
ii lsb-release 11.1.0
ii python3 3.9.2-3
ii python3-apt 2.2.1
ii python3-dbus 1.2.16-5
ii python3-distro-info 1.0
ii ucf 3.0043
ii xz-utils 5.2.5-2.1~deb11u1
Versions of packages unattended-upgrades recommends:
Versions of packages unattended-upgrades suggests:
pn needrestart <none>
ii nullmailer [mail-transport-agent] 1:2.2-3
pn powermgmt-base <none>
ii python3-gi 3.38.0-2
ii nullmailer [mail-transport-agent] 1:2.2-3
pn powermgmt-base <none>
0 new messages