[Bug 2067057] [NEW] Unattended-upgrades order of restart caused failure to bind address

Fri May 24 11:37:04 UTC 2024

Public bug reported:

This morning, nginx wan't working, so I checked the journal. It appears
an overnight unattended-upgrades restarted a lot of services, including
systemd-networkd and nginx. Logs pasted at the end, I am running Ubuntu
24.04.

I bind nginx to specific IP addresses, because different daemons listen
on different addresses. When nginx was brought back up, it failed
because the requested IP address had not yet come back up.

It would appear unattended-upgrades attempted to restart a lot of
services at once, causing nginx to attempt to bind to an address which
had not yet come back up.

Could there be more careful ordering of execution to avoid such
problems?

May 24 06:27:54 alpha systemd[1]: Stopping packagekit.service - PackageKit Daemon...May 24 06:27:54 alpha systemd[1]: packagekit.service: Deactivated successfully.
May 24 06:27:54 alpha systemd[1]: Stopped packagekit.service - PackageKit Daemon.
May 24 06:27:54 alpha systemd[1]: exim4.service: Deactivated successfully.
May 24 06:27:54 alpha systemd[1]: Stopped exim4.service - exim Mail Transport Agent.
May 24 06:27:54 alpha systemd[1]: exim4.service: Consumed 15.241s CPU time, 26.4M memory peak, 0B memory swap peak.
May 24 06:27:54 alpha systemd[1]: Starting exim4.service - exim Mail Transport Agent...
May 24 06:27:54 alpha systemd[1]: Starting packagekit.service - PackageKit Daemon...
May 24 06:27:54 alpha systemd[1]: Stopping php8.3-fpm.service - The PHP 8.3 FastCGI Process Manager...
May 24 06:27:54 alpha systemd[1]: Stopping ssh.service - OpenBSD Secure Shell server...
May 24 06:27:54 alpha sshd[1427]: Received signal 15; terminating.
May 24 06:27:54 alpha systemd-journald[365]: Journal stopped
May 24 06:27:55 alpha systemd[1]: Stopping systemd-journald.service - Journal Service...
May 24 06:27:55 alpha systemd-journald[365]: Received SIGTERM from PID 1 (systemd).
May 24 06:27:55 alpha systemd[1]: netplan-ovs-cleanup.service - OpenVSwitch configuration for cleanup was skipped because of an unmet condition check (ConditionFileIsExecutable=/usr/bin/ovs-vsctl).
May 24 06:27:55 alpha systemd[1]: systemd-networkd-wait-online.service: Deactivated successfully.
May 24 06:27:55 alpha systemd[1]: Stopped systemd-networkd-wait-online.service - Wait for Network to be Configured.
May 24 06:27:55 alpha systemd[1]: Stopping systemd-networkd-wait-online.service - Wait for Network to be Configured...
May 24 06:27:55 alpha systemd[1]: Stopping systemd-networkd.service - Network Configuration...
May 24 06:27:55 alpha systemd[1]: ssh.service: Deactivated successfully.
May 24 06:27:55 alpha systemd[1]: Stopped ssh.service - OpenBSD Secure Shell server.
May 24 06:27:55 alpha systemd[1]: Starting ssh.service - OpenBSD Secure Shell server...
May 24 06:27:55 alpha systemd[1]: nginx.service: Deactivated successfully.
May 24 06:27:55 alpha systemd[1]: Stopped nginx.service - A high performance web server and a reverse proxy server.
May 24 06:27:55 alpha systemd[1]: nginx.service: Consumed 6.168s CPU time, 21.6M memory peak, 0B memory swap peak.
May 24 06:27:55 alpha systemd[1]: Starting nginx.service - A high performance web server and a reverse proxy server...
May 24 06:27:55 alpha systemd[1]: Stopping systemd-timesyncd.service - Network Time Synchronization...
May 24 06:27:55 alpha systemd[1]: systemd-journald.service: Deactivated successfully.
May 24 06:27:55 alpha systemd[1]: Stopped systemd-journald.service - Journal Service.
May 24 06:27:55 alpha systemd[1]: systemd-journald.service: Consumed 49.437s CPU time, 173.6M memory peak, 0B memory swap peak.
May 24 06:27:55 alpha systemd[1]: systemd-networkd.service: Deactivated successfully.
May 24 06:27:55 alpha systemd[1]: Stopped systemd-networkd.service - Network Configuration.
May 24 06:27:55 alpha systemd[1]: systemd-networkd.service: Consumed 3.016s CPU time, 3.6M memory peak, 0B memory swap peak.
May 24 06:27:55 alpha systemd[1]: systemd-timesyncd.service: Deactivated successfully.
May 24 06:27:55 alpha systemd[1]: Stopped systemd-timesyncd.service - Network Time Synchronization.
May 24 06:27:55 alpha systemd[1]: systemd-timesyncd.service: Consumed 1.742s CPU time, 2.2M memory peak, 0B memory swap peak.
May 24 06:27:55 alpha systemd[1]: Starting systemd-journald.service - Journal Service...
May 24 06:27:55 alpha systemd[1]: Starting systemd-networkd.service - Network Configuration...
May 24 06:27:55 alpha systemd-journald[224525]: Collecting audit messages is disabled.
May 24 06:27:55 alpha systemd[1]: Starting systemd-timesyncd.service - Network Time Synchronization...
May 24 06:27:55 alpha systemd[1]: Started ssh.service - OpenBSD Secure Shell server.
May 24 06:27:55 alpha systemd[1]: nginx.service: Control process exited, code=exited, status=1/FAILURE
May 24 06:27:55 alpha systemd[1]: nginx.service: Failed with result 'exit-code'.
May 24 06:27:55 alpha systemd-journald[224525]: Journal started
May 24 06:27:55 alpha systemd-journald[224525]: System Journal (/var/log/journal/f6231ff3466048acbfd448f890443035) is 173.0M, max 4.0G, 3.8G free.
May 24 06:27:55 alpha systemd[1]: Failed to start nginx.service - A high performance web server and a reverse proxy server.
May 24 06:27:54 alpha systemd-networkd[714]: enp0s6: DHCPv6 lease lost
May 24 06:27:54 alpha named[186157]: received control channel command 'stop'
May 24 06:27:54 alpha named[186157]: no longer listening on 127.0.0.1#53
May 24 06:27:55 alpha nginx[224476]: nginx: [emerg] bind() to [2603:c020:x:x:x:x:x:x]:80 failed (99: Cannot assign requested address)
May 24 06:27:55 alpha nginx[224476]: nginx: configuration file /etc/nginx/nginx.conf test failed

** Affects: unattended-upgrades (Ubuntu)
     Importance: Undecided
         Status: New

-- 
You received this bug notification because you are a member of Ubuntu
Foundations Bugs, which is subscribed to unattended-upgrades in Ubuntu.
https://bugs.launchpad.net/bugs/2067057

Title:
  Unattended-upgrades order of restart caused failure to bind address

Status in unattended-upgrades package in Ubuntu:
  New

Bug description:
  This morning, nginx wan't working, so I checked the journal. It
  appears an overnight unattended-upgrades restarted a lot of services,
  including systemd-networkd and nginx. Logs pasted at the end, I am
  running Ubuntu 24.04.

  I bind nginx to specific IP addresses, because different daemons
  listen on different addresses. When nginx was brought back up, it
  failed because the requested IP address had not yet come back up.

  It would appear unattended-upgrades attempted to restart a lot of
  services at once, causing nginx to attempt to bind to an address which
  had not yet come back up.

  Could there be more careful ordering of execution to avoid such
  problems?

  May 24 06:27:54 alpha systemd[1]: Stopping packagekit.service - PackageKit Daemon...May 24 06:27:54 alpha systemd[1]: packagekit.service: Deactivated successfully.
  May 24 06:27:54 alpha systemd[1]: Stopped packagekit.service - PackageKit Daemon.
  May 24 06:27:54 alpha systemd[1]: exim4.service: Deactivated successfully.
  May 24 06:27:54 alpha systemd[1]: Stopped exim4.service - exim Mail Transport Agent.
  May 24 06:27:54 alpha systemd[1]: exim4.service: Consumed 15.241s CPU time, 26.4M memory peak, 0B memory swap peak.
  May 24 06:27:54 alpha systemd[1]: Starting exim4.service - exim Mail Transport Agent...
  May 24 06:27:54 alpha systemd[1]: Starting packagekit.service - PackageKit Daemon...
  May 24 06:27:54 alpha systemd[1]: Stopping php8.3-fpm.service - The PHP 8.3 FastCGI Process Manager...
  May 24 06:27:54 alpha systemd[1]: Stopping ssh.service - OpenBSD Secure Shell server...
  May 24 06:27:54 alpha sshd[1427]: Received signal 15; terminating.
  May 24 06:27:54 alpha systemd-journald[365]: Journal stopped
  May 24 06:27:55 alpha systemd[1]: Stopping systemd-journald.service - Journal Service...
  May 24 06:27:55 alpha systemd-journald[365]: Received SIGTERM from PID 1 (systemd).
  May 24 06:27:55 alpha systemd[1]: netplan-ovs-cleanup.service - OpenVSwitch configuration for cleanup was skipped because of an unmet condition check (ConditionFileIsExecutable=/usr/bin/ovs-vsctl).
  May 24 06:27:55 alpha systemd[1]: systemd-networkd-wait-online.service: Deactivated successfully.
  May 24 06:27:55 alpha systemd[1]: Stopped systemd-networkd-wait-online.service - Wait for Network to be Configured.
  May 24 06:27:55 alpha systemd[1]: Stopping systemd-networkd-wait-online.service - Wait for Network to be Configured...
  May 24 06:27:55 alpha systemd[1]: Stopping systemd-networkd.service - Network Configuration...
  May 24 06:27:55 alpha systemd[1]: ssh.service: Deactivated successfully.
  May 24 06:27:55 alpha systemd[1]: Stopped ssh.service - OpenBSD Secure Shell server.
  May 24 06:27:55 alpha systemd[1]: Starting ssh.service - OpenBSD Secure Shell server...
  May 24 06:27:55 alpha systemd[1]: nginx.service: Deactivated successfully.
  May 24 06:27:55 alpha systemd[1]: Stopped nginx.service - A high performance web server and a reverse proxy server.
  May 24 06:27:55 alpha systemd[1]: nginx.service: Consumed 6.168s CPU time, 21.6M memory peak, 0B memory swap peak.
  May 24 06:27:55 alpha systemd[1]: Starting nginx.service - A high performance web server and a reverse proxy server...
  May 24 06:27:55 alpha systemd[1]: Stopping systemd-timesyncd.service - Network Time Synchronization...
  May 24 06:27:55 alpha systemd[1]: systemd-journald.service: Deactivated successfully.
  May 24 06:27:55 alpha systemd[1]: Stopped systemd-journald.service - Journal Service.
  May 24 06:27:55 alpha systemd[1]: systemd-journald.service: Consumed 49.437s CPU time, 173.6M memory peak, 0B memory swap peak.
  May 24 06:27:55 alpha systemd[1]: systemd-networkd.service: Deactivated successfully.
  May 24 06:27:55 alpha systemd[1]: Stopped systemd-networkd.service - Network Configuration.
  May 24 06:27:55 alpha systemd[1]: systemd-networkd.service: Consumed 3.016s CPU time, 3.6M memory peak, 0B memory swap peak.
  May 24 06:27:55 alpha systemd[1]: systemd-timesyncd.service: Deactivated successfully.
  May 24 06:27:55 alpha systemd[1]: Stopped systemd-timesyncd.service - Network Time Synchronization.
  May 24 06:27:55 alpha systemd[1]: systemd-timesyncd.service: Consumed 1.742s CPU time, 2.2M memory peak, 0B memory swap peak.
  May 24 06:27:55 alpha systemd[1]: Starting systemd-journald.service - Journal Service...
  May 24 06:27:55 alpha systemd[1]: Starting systemd-networkd.service - Network Configuration...
  May 24 06:27:55 alpha systemd-journald[224525]: Collecting audit messages is disabled.
  May 24 06:27:55 alpha systemd[1]: Starting systemd-timesyncd.service - Network Time Synchronization...
  May 24 06:27:55 alpha systemd[1]: Started ssh.service - OpenBSD Secure Shell server.
  May 24 06:27:55 alpha systemd[1]: nginx.service: Control process exited, code=exited, status=1/FAILURE
  May 24 06:27:55 alpha systemd[1]: nginx.service: Failed with result 'exit-code'.
  May 24 06:27:55 alpha systemd-journald[224525]: Journal started
  May 24 06:27:55 alpha systemd-journald[224525]: System Journal (/var/log/journal/f6231ff3466048acbfd448f890443035) is 173.0M, max 4.0G, 3.8G free.
  May 24 06:27:55 alpha systemd[1]: Failed to start nginx.service - A high performance web server and a reverse proxy server.
  May 24 06:27:54 alpha systemd-networkd[714]: enp0s6: DHCPv6 lease lost
  May 24 06:27:54 alpha named[186157]: received control channel command 'stop'
  May 24 06:27:54 alpha named[186157]: no longer listening on 127.0.0.1#53
  May 24 06:27:55 alpha nginx[224476]: nginx: [emerg] bind() to [2603:c020:x:x:x:x:x:x]:80 failed (99: Cannot assign requested address)
  May 24 06:27:55 alpha nginx[224476]: nginx: configuration file /etc/nginx/nginx.conf test failed

To manage notifications about this bug go to:
https://bugs.launchpad.net/ubuntu/+source/unattended-upgrades/+bug/2067057/+subscriptions