Bug #11970: sys-subsystem-net-devices-multi-user.device/start times out

Bug #11970

sys-subsystem-net-devices-multi-user.device/start times out

Added by intrigeri 2016-11-20 11:38:32 . Updated 2017-03-13 09:23:47 .

Status:

Resolved

Priority:

Elevated

Assignee:

Category:

Target version:

Start date:

2016-11-20

Due date:

% Done:

100%

Feature Branch:

Type of work:

Research

Blueprint:

Starter:

Affected tool:

Deliverable for:

289

Description

On feature/5630-deterministic-builds at commit bfbfecc4a3e0979c862525fa81abe431c9bdecfe I see:

Nov 20 11:30:43 amnesia NetworkManager[3947]: <info>  [1479641443.8669] manager: (lo): new Generic device (/org/freedesktop/NetworkManager/Devices/0)
Nov 20 11:30:43 amnesia NetworkManager[3947]: <info>  [1479641443.8676] manager: startup complete
Nov 20 11:30:43 amnesia NetworkManager[3947]: <info>  [1479641443.8766] ModemManager available in the bus
Nov 20 11:31:54 amnesia systemd[1]: sys-subsystem-net-devices-multi-user.device: Job sys-subsystem-net-devices-multi-user.device/start timed out.
Nov 20 11:31:54 amnesia systemd[1]: Timed out waiting for device sys-subsystem-net-devices-multi-user.device.
Nov 20 11:31:54 amnesia systemd[1]: Dependency failed for WPA supplicant daemon (interface-specific version).
Nov 20 11:31:54 amnesia systemd[1]: wpa_supplicant@multi-user.service: Job wpa_supplicant@multi-user.service/start failed with result 'dependency'.
Nov 20 11:31:54 amnesia systemd[1]: sys-subsystem-net-devices-multi-user.device: Job sys-subsystem-net-devices-multi-user.device/start failed with result 'timeout'.
Nov 20 11:31:54 amnesia systemd[1]: Reached target Network.
Nov 20 11:31:54 amnesia systemd[1]: Starting Network Name Resolution...
Nov 20 11:31:54 amnesia systemd[1]: Starting load-balanced unspoofable packet switching network...
Nov 20 11:31:54 amnesia systemd[1]: Starting Anonymizing overlay network for TCP...
Nov 20 11:31:54 amnesia systemd[1]: Starting /etc/rc.local Compatibility...
Nov 20 11:31:54 amnesia systemd[1]: Starting Permit User Sessions...
Nov 20 11:31:54 amnesia systemd[1]: Started Permit User Sessions.
Nov 20 11:31:54 amnesia systemd[1]: Started /etc/rc.local Compatibility.
Nov 20 11:31:54 amnesia systemd[1]: Starting Hold until boot process finishes up...
Nov 20 11:31:54 amnesia systemd[1]: Starting GNOME Display Manager...

This is a regression vs. feature/stretch.

Subtasks

Related issues

Related to Tails - Bug #10709: Convert most of 52-update-rc.d to a systemd.preset(5) file

Confirmed

2015-12-03

History

#1 Updated by intrigeri 2016-11-20 12:43:52

Deliverable for set to 289

#2 Updated by intrigeri 2016-11-20 14:00:04

related to Bug #10709: Convert most of 52-update-rc.d to a systemd.preset(5) file added

#3 Updated by intrigeri 2016-11-20 14:00:51

Status changed from Confirmed to In Progress
Assignee set to intrigeri
% Done changed from 0 to 10

On the reproducible builds branch, NetworkManager is started way earlier than usual, before GDM is started. That’s buggy. Apparently the service + a few others that we disable at build time are enabled during boot (since their mtimes match boot time, while most other ones were clamped to $SOURCE_DATE_EPOCH during build):

amnesia@amnesia:~$ ls -ltr /etc/systemd/system/multi-user.target.wants/
total 0
lrwxrwxrwx 1 root root 50 Nov 19 20:30 tor-controlport-filter.service -> /lib/systemd/system/tor-controlport-filter.service
lrwxrwxrwx 1 root root 60 Nov 19 20:30 tails-set-wireless-devices-state.service -> /lib/systemd/system/tails-set-wireless-devices-state.service
lrwxrwxrwx 1 root root 56 Nov 19 20:30 tails-sdmem-on-media-removal.service -> /lib/systemd/system/tails-sdmem-on-media-removal.service
lrwxrwxrwx 1 root root 54 Nov 19 20:30 tails-reconfigure-memlockd.service -> /lib/systemd/system/tails-reconfigure-memlockd.service
lrwxrwxrwx 1 root root 51 Nov 19 20:30 tails-reconfigure-kexec.service -> /lib/systemd/system/tails-reconfigure-kexec.service
lrwxrwxrwx 1 root root 55 Nov 19 20:30 tails-autotest-remote-shell.service -> /lib/systemd/system/tails-autotest-remote-shell.service
lrwxrwxrwx 1 root root 33 Nov 19 20:30 rsync.service -> /lib/systemd/system/rsync.service
lrwxrwxrwx 1 root root 36 Nov 19 20:30 remote-fs.target -> /lib/systemd/system/remote-fs.target
lrwxrwxrwx 1 root root 36 Nov 19 20:30 pppd-dns.service -> /lib/systemd/system/pppd-dns.service
lrwxrwxrwx 1 root root 41 Nov 19 20:30 open-vm-tools.service -> /lib/systemd/system/open-vm-tools.service
lrwxrwxrwx 1 root root 38 Nov 19 20:30 networking.service -> /lib/systemd/system/networking.service
lrwxrwxrwx 1 root root 40 Nov 19 20:30 ModemManager.service -> /lib/systemd/system/ModemManager.service
lrwxrwxrwx 1 root root 36 Nov 19 20:30 memlockd.service -> /lib/systemd/system/memlockd.service
lrwxrwxrwx 1 root root 36 Nov 19 20:30 lmt-poll.service -> /lib/systemd/system/lmt-poll.service
lrwxrwxrwx 1 root root 38 Nov 19 20:30 live-tools.service -> /lib/systemd/system/live-tools.service
lrwxrwxrwx 1 root root 37 Nov 19 20:30 laptop-mode.timer -> /lib/systemd/system/laptop-mode.timer
lrwxrwxrwx 1 root root 39 Nov 19 20:30 laptop-mode.service -> /lib/systemd/system/laptop-mode.service
lrwxrwxrwx 1 root root 32 Nov 19 20:30 cron.service -> /lib/systemd/system/cron.service
lrwxrwxrwx 1 root root 41 Nov 19 20:30 console-setup.service -> /lib/systemd/system/console-setup.service
lrwxrwxrwx 1 root root 43 Nov 20 13:28 wpa_supplicant@.service -> /lib/systemd/system/wpa_supplicant@.service
lrwxrwxrwx 1 root root 42 Nov 20 13:28 wpa_supplicant.service -> /lib/systemd/system/wpa_supplicant.service
lrwxrwxrwx 1 root root 31 Nov 20 13:28 tor.service -> /lib/systemd/system/tor.service
lrwxrwxrwx 1 root root 44 Nov 20 13:28 systemd-resolved.service -> /lib/systemd/system/systemd-resolved.service
lrwxrwxrwx 1 root root 32 Nov 20 13:28 sudo.service -> /lib/systemd/system/sudo.service
lrwxrwxrwx 1 root root 42 Nov 20 13:28 NetworkManager.service -> /lib/systemd/system/NetworkManager.service
lrwxrwxrwx 1 root root 31 Nov 20 13:28 i2p.service -> /lib/systemd/system/i2p.service
lrwxrwxrwx 1 root root 29 Nov 20 13:28 cups.path -> /lib/systemd/system/cups.path

I think that’s explained by:

Nov 20 13:28:53 localhost.localdomain systemd[1]: Running with unpopulated /etc.
Nov 20 13:28:53 localhost.localdomain systemd[1]: Set hostname to <localhost.localdomain>.
Nov 20 13:28:53 localhost.localdomain systemd[1]: Initializing machine ID from random generator.
Nov 20 13:28:53 localhost.localdomain systemd[1]: Populated /etc with preset unit settings.

So I’ll give Bug #10709 a closer look.

#4 Updated by intrigeri 2016-11-20 14:55:56

Status changed from In Progress to Resolved
% Done changed from 10 to 100

Applied in changeset commit:0d5d4d42919818a63bfd604c62737ce337ac9d01.

#5 Updated by intrigeri 2017-03-13 09:23:47

Assignee deleted (~~intrigeri~~)