5 Jun 2023 |
oddlama | and systemd-network was indeed not active, so I started it manually and everything was up again | 18:18:22 |
@elvishjerricco:matrix.org | it's really weird for networkd to just shut down like that... | 18:18:40 |
oddlama | the shutdown in the first line is in stage1, rest is stage2 | 18:18:55 |
@elvishjerricco:matrix.org | oh | 18:19:00 |
oddlama | Context for first line:
Jun 05 19:38:10 sentinel systemd[1]: Stopped SSH Daemon.
Jun 05 19:38:10 sentinel systemd[1]: dbus.service: Deactivated successfully.
Jun 05 19:38:10 sentinel systemd[1]: Stopped D-Bus System Message Bus.
Jun 05 19:38:10 sentinel systemd[1]: systemd-ask-password-console.service: Deactivated successfully.
Jun 05 19:38:10 sentinel systemd[1]: Stopped Dispatch Password Requests to Console.
Jun 05 19:38:10 sentinel systemd[1]: Stopped target Basic System.
Jun 05 19:38:10 sentinel systemd[1]: Stopped target Network.
Jun 05 19:38:10 sentinel systemd[1]: Stopped target Preparation for Network.
Jun 05 19:38:10 sentinel systemd[1]: Stopped target Path Units.
Jun 05 19:38:10 sentinel systemd[1]: Stopped target Slice Units.
Jun 05 19:38:10 sentinel systemd[1]: Stopped target Socket Units.
Jun 05 19:38:10 sentinel systemd[1]: dbus.socket: Deactivated successfully.
Jun 05 19:38:10 sentinel systemd[1]: Closed D-Bus System Message Bus Socket.
Jun 05 19:38:10 sentinel systemd[1]: Stopped target System Initialization.
Jun 05 19:38:10 sentinel systemd[1]: Stopped target Local Encrypted Volumes.
Jun 05 19:38:10 sentinel systemd[1]: systemd-ask-password-console.path: Deactivated successfully.
...skipping...
Jun 05 19:38:10 sentinel systemd[1]: Stopped target Basic System.
Jun 05 19:38:10 sentinel systemd[1]: Stopped target Network.
Jun 05 19:38:10 sentinel systemd[1]: Stopped target Preparation for Network.
Jun 05 19:38:10 sentinel systemd[1]: Stopped target Path Units.
Jun 05 19:38:10 sentinel systemd[1]: Stopped target Slice Units.
Jun 05 19:38:10 sentinel systemd[1]: Stopped target Socket Units.
Jun 05 19:38:10 sentinel systemd[1]: dbus.socket: Deactivated successfully.
Jun 05 19:38:10 sentinel systemd[1]: Closed D-Bus System Message Bus Socket.
Jun 05 19:38:10 sentinel systemd[1]: Stopped target System Initialization.
Jun 05 19:38:10 sentinel systemd[1]: Stopped target Local Encrypted Volumes.
Jun 05 19:38:10 sentinel systemd[1]: systemd-ask-password-console.path: Deactivated successfully.
Jun 05 19:38:10 sentinel systemd[1]: Stopped Dispatch Password Requests to Console Directory Watch.
Jun 05 19:38:10 sentinel systemd[1]: Stopped target Swaps.
Jun 05 19:38:10 sentinel systemd[1]: systemd-networkd.socket: Deactivated successfully.
Jun 05 19:38:10 sentinel systemd[1]: Closed Network Service Netlink Socket.
Jun 05 19:38:10 sentinel systemd[1]: initrd-nixos-copy-secrets.service: Deactivated successfully.
Jun 05 19:38:10 sentinel systemd[1]: Stopped Copy secrets into place.
Jun 05 19:38:10 sentinel systemd[1]: systemd-network-generator.service: Deactivated successfully.
Jun 05 19:38:10 sentinel systemd[1]: Stopped Generate network units from Kernel command line.
Jun 05 19:38:10 sentinel systemd[1]: systemd-sysctl.service: Deactivated successfully.
Jun 05 19:38:10 sentinel systemd[1]: Stopped Apply Kernel Variables.
Jun 05 19:38:10 sentinel systemd[1]: systemd-modules-load.service: Deactivated successfully.
Jun 05 19:38:10 sentinel systemd[1]: Stopped Load Kernel Modules.
Jun 05 19:38:10 sentinel systemd[1]: systemd-tmpfiles-setup-dev.service: Deactivated successfully.
Jun 05 19:38:10 sentinel systemd[1]: Stopped Create Static Device Nodes in /dev.
Jun 05 19:38:10 sentinel systemd[1]: kmod-static-nodes.service: Deactivated successfully.
Jun 05 19:38:10 sentinel systemd[1]: Stopped Create List of Static Device Nodes.
Jun 05 19:38:10 sentinel systemd[1]: systemd-tmpfiles-setup.service: Deactivated successfully.
Jun 05 19:38:10 sentinel systemd[1]: Stopped Create Volatile Files and Directories.
Jun 05 19:38:10 sentinel systemd[1]: Stopped target Local File Systems.
Jun 05 19:38:10 sentinel systemd[1]: systemd-udev-trigger.service: Deactivated successfully.
Jun 05 19:38:10 sentinel systemd[1]: Stopped Coldplug All udev Devices.
Jun 05 19:38:10 sentinel systemd[1]: run-credentials-systemd\x2dtmpfiles\x2dsetup.service.mount: Deactivated successfully.
Jun 05 19:38:10 sentinel systemd[1]: run-credentials-systemd\x2dsysctl.service.mount: Deactivated successfully.
Jun 05 19:38:10 sentinel systemd[1]: run-credentials-systemd\x2dtmpfiles\x2dsetup\x2ddev.service.mount: Deactivated successfully.
Jun 05 19:38:10 sentinel systemd[1]: initrd-cleanup.service: Deactivated successfully.
Jun 05 19:38:10 sentinel systemd[1]: Finished Cleaning Up and Shutting Down Daemons.
Jun 05 19:38:10 sentinel systemd[1]: Reached target Switch Root.
Jun 05 19:38:10 sentinel systemd[1]: Starting Switch Root...
Jun 05 19:38:10 sentinel systemd[1]: Switching root.
| 18:19:43 |
@elvishjerricco:matrix.org | yea that all seems correct | 18:20:56 |
@elvishjerricco:matrix.org | in stage 2, what does systemctl status systemd-networkd.service look like? | 18:21:24 |
oddlama | I ran that before I restarted it, this was the output: | 18:21:59 |
oddlama |
| 18:22:00 |
oddlama | * ○ systemd-networkd.service - Network Configuration
Loaded: loaded (/etc/systemd/system/systemd-networkd.service; enabled; preset: enabled)
Drop-In: /nix/store/4cx8q44c60saw5jz7qrda31h22qgbviy-system-units/systemd-networkd.service.d
└─overrides.conf
Active: inactive (dead) since Mon 2023-06-05 19:38:12 CEST; 16min ago
Duration: 43.928s
TriggeredBy: ● systemd-networkd.socket
Docs: man:systemd-networkd.service(8)
Main PID: 181 (code=exited, status=0/SUCCESS)
Status: "Shutting down..."
IP: 0B in, 0B out
CPU: 47ms
Jun 05 19:37:28 localhost systemd[1]: Starting Network Configuration...
Jun 05 19:37:28 localhost systemd-networkd[181]: lo: Link UP
Jun 05 19:37:28 localhost systemd-networkd[181]: lo: Gained carrier
Jun 05 19:37:28 localhost systemd-networkd[181]: Enumeration completed
Jun 05 19:37:28 localhost systemd[1]: Started Network Configuration.
Jun 05 19:37:28 localhost systemd-networkd[181]: wan: Configuring with /etc/systemd/network/10-wan.network.
Jun 05 19:37:28 localhost systemd-networkd[181]: wan: Link UP
Jun 05 19:37:29 localhost systemd-networkd[181]: wan: Gained carrier
Jun 05 19:37:30 localhost systemd-networkd[181]: wan: Gained IPv6LL | 18:22:04 |
oddlama | * ○ systemd-networkd.service - Network Configuration
Loaded: loaded (/etc/systemd/system/systemd-networkd.service; enabled; preset: enabled)
Drop-In: /nix/store/4cx8q44c60saw5jz7qrda31h22qgbviy-system-units/systemd-networkd.service.d
└─overrides.conf
Active: inactive (dead) since Mon 2023-06-05 19:38:12 CEST; 16min ago
Duration: 43.928s
TriggeredBy: ● systemd-networkd.socket
Docs: man:systemd-networkd.service(8)
Main PID: 181 (code=exited, status=0/SUCCESS)
Status: "Shutting down..."
IP: 0B in, 0B out
CPU: 47ms
Jun 05 19:37:28 localhost systemd\[1\]: Starting Network Configuration...
Jun 05 19:37:28 localhost systemd-networkd\[181\]: lo: Link UP
Jun 05 19:37:28 localhost systemd-networkd\[181\]: lo: Gained carrier
Jun 05 19:37:28 localhost systemd-networkd\[181\]: Enumeration completed
Jun 05 19:37:28 localhost systemd\[1\]: Started Network Configuration.
Jun 05 19:37:28 localhost systemd-networkd\[181\]: wan: Configuring with /etc/systemd/network/10-wan.network.
Jun 05 19:37:28 localhost systemd-networkd\[181\]: wan: Link UP
Jun 05 19:37:29 localhost systemd-networkd\[181\]: wan: Gained carrier
Jun 05 19:37:30 localhost systemd-networkd\[181\]: wan: Gained IPv6LL
| 18:22:32 |
oddlama | I didn't have these problems some a week ago, so maybe it's something else I enabled that interferes, or this is non-deterministic? I have no idea where to start investigating | 18:27:15 |
oddlama | * I didn't have these problems week ago, so maybe it's something else I enabled that interferes, or this is non-deterministic? I have no idea where to start investigating | 18:27:20 |
@elvishjerricco:matrix.org | yea I'm not really sure where to look next | 18:27:36 |
oddlama | Let me restart with the same configuration to see whether it happens every tiem | 18:27:57 |
oddlama | * Let me restart with the same configuration to see whether it happens every time | 18:27:58 |
@elvishjerricco:matrix.org | maybe systemctl list-dependencies --reverse/--after/--before systemd-networkd.service ? | 18:28:02 |
oddlama | Seems reproducible | 18:30:10 |
oddlama | A notable thing in the logs is that even though | 18:32:14 |
oddlama | * A notable thing in the logs is that even though
Jun 05 20:29:40 sentinel systemd[1]: systemd-networkd.service: Deactivated successfully.
is printed when switching
| 18:32:27 |
oddlama | I get another output from systemd-networkd in stage2 | 18:32:46 |
oddlama | Jun 05 20:29:38 sentinel systemd-networkd[180]: wan: DHCPv6 lease lost | 18:32:49 |
oddlama | No wair | 18:33:12 |
oddlama | * No wait | 18:33:13 |
oddlama | the logs are not in order?! | 18:33:17 |
oddlama | Okay now I'm totally lost. Why would the logs be unordered? | 18:34:05 |
@elvishjerricco:matrix.org | wait wut | 18:36:59 |
@elvishjerricco:matrix.org | maybe systemd-timesyncd is changing the system clock once stage 2 gets going? | 18:37:27 |
oddlama | It's just some select lines | 18:37:47 |
oddlama | Jun 05 20:29:40 sentinel systemd[1]: Starting Journal Service...
Jun 05 20:29:40 sentinel systemd[1]: Starting Load Kernel Modules...
Jun 05 20:29:40 sentinel kernel: fuse: init (API version 7.37)
Jun 05 20:29:40 sentinel systemd[1]: systemd-networkd-wait-online.service: Bound to unit systemd-networkd.service, but unit isn't active.
Jun 05 20:29:40 sentinel systemd[1]: Dependency failed for Wait for Network to be Configured.
Jun 05 20:29:40 sentinel systemd[1]: systemd-networkd-wait-online.service: Job systemd-networkd-wait-online.service/start failed with result 'dependency'.
Jun 05 20:29:40 sentinel systemd[1]: Starting Remount Root and Kernel File Systems...
Jun 05 20:29:40 sentinel systemd[1]: Starting Coldplug All udev Devices...
Jun 05 20:29:40 sentinel systemd[1]: Mounted Huge Pages File System.
Jun 05 20:29:40 sentinel systemd[1]: Mounted POSIX Message Queue File System.
Jun 05 20:29:40 sentinel systemd-journald[730]: Collecting audit messages is disabled.
Jun 05 20:29:40 sentinel systemd[1]: Mounted Kernel Debug File System.
Jun 05 20:29:40 sentinel systemd[1]: Finished Create List of Static Device Nodes.
Jun 05 20:29:40 sentinel systemd[1]: modprobe@configfs.service: Deactivated successfully.
Jun 05 20:29:40 sentinel systemd[1]: Finished Load Kernel Module configfs.
Jun 05 20:29:40 sentinel systemd[1]: modprobe@efi_pstore.service: Deactivated successfully.
Jun 05 20:29:40 sentinel systemd[1]: Finished Load Kernel Module efi_pstore.
Jun 05 20:29:40 sentinel systemd[1]: modprobe@fuse.service: Deactivated successfully.
Jun 05 20:29:40 sentinel systemd[1]: Finished Load Kernel Module fuse.
Jun 05 20:29:40 sentinel systemd-journald[730]: Journal started
Jun 05 20:29:40 sentinel systemd-journald[730]: Runtime Journal (/run/log/journal/25e272da45124b238d42df4ec5fca13c) is 8.0M, max 94.1M, 86.1M free.
Jun 05 20:29:38 sentinel systemd-networkd[180]: wan: DHCPv6 lease lost
Jun 05 20:29:38 sentinel sshd[197]: syslogin_perform_logout: logout() returned an error
Jun 05 20:29:40 sentinel systemd[1]: Started Journal Service.
Jun 05 20:29:39 sentinel systemd[1]: Queued start job for default target Multi-User System.
Jun 05 20:29:39 sentinel systemd[1]: systemd-journald.service: Deactivated successfully.
Jun 05 20:29:40 sentinel systemd[1]: Finished Bind mount or link '/persist/etc/machine-id' to '/etc/machine-id'.
Jun 05 20:29:40 sentinel systemd[1]: Finished Bind mount or link '/persist/etc/ssh/ssh_host_ed25519_key' to '/etc/ssh/ssh_host_ed25519_key'.
Jun 05 20:29:40 sentinel systemd[1]: Finished Bind mount or link '/persist/etc/ssh/ssh_host_ed25519_key.pub' to '/etc/ssh/ssh_host_ed25519_key.pub'.
Jun 05 20:29:40 sentinel systemd[1]: Mounting FUSE Control File System...
Jun 05 20:29:40 sentinel systemd-modules-load[737]: Inserted module 'bridge'
Jun 05 20:29:40 sentinel kernel: bridge: filtering via arp/ip/ip6tables is no longer available by default. Update your scripts to load br_netfilter if you need this.
Jun 05 20:29:40 sentinel systemd[1]: Mounting Kernel Configuration File System...
Jun 05 20:29:40 sentinel systemd[1]: Starting Create Static Device Nodes in /dev...
Jun 05 20:29:40 sentinel systemd[1]: Mounted FUSE Control File System.
Jun 05 20:29:40 sentinel systemd[1]: Mounted Kernel Configuration File System.
Jun 05 20:29:40 sentinel kernel: ACPI: bus type drm_connector registered
Jun 05 20:29:40 sentinel systemd[1]: modprobe@drm.service: Deactivated successfully.
Jun 05 20:29:40 sentinel systemd-modules-load[737]: Inserted module 'macvlan'
Jun 05 20:29:40 sentinel systemd[1]: Finished Load Kernel Module drm.
Jun 05 20:29:40 sentinel systemd-modules-load[737]: Inserted module 'tap'
Jun 05 20:29:40 sentinel kernel: tun: Universal TUN/TAP device driver, 1.6
| 18:38:10 |