Skip to content

Instantly share code, notes, and snippets.

@kanaka
Last active October 5, 2021 14:31
Show Gist options
  • Save kanaka/2317db82e525f4d8b59834bf98ca54a5 to your computer and use it in GitHub Desktop.
Save kanaka/2317db82e525f4d8b59834bf98ca54a5 to your computer and use it in GitHub Desktop.
Containerized systemd startup race condition reproducer (https://github.com/systemd/systemd/issues/20939)
version: "2.4"
x-deps:
systemd-base: &systemd-base
#build: {context: ., dockerfile: Dockerfile} # distro systemd
build: {context: ., dockerfile: Dockerfile-build} # cloned/built systemd
image: systemd-debug
network_mode: none
cap_add: [SYS_ADMIN, NET_ADMIN]
tty: true
security_opt: [ 'apparmor:unconfined' ] # if host apparmor enabled
tmpfs: [ "/sys/fs/cgroup" ]
command: /sbin/init.sh
services:
i0:
<<: *systemd-base
command: /sbin/init.sh #0
i1:
<<: *systemd-base
command: /sbin/init.sh #1
i2:
<<: *systemd-base
command: /sbin/init.sh #2
i3:
<<: *systemd-base
command: /sbin/init.sh #3
i4:
<<: *systemd-base
command: /sbin/init.sh #4
i5:
<<: *systemd-base
command: /sbin/init.sh #5
i6:
<<: *systemd-base
command: /sbin/init.sh #6
i7:
<<: *systemd-base
command: /sbin/init.sh #7
i8:
<<: *systemd-base
command: /sbin/init.sh #8
i9:
<<: *systemd-base
command: /sbin/init.sh #9
FROM ubuntu:20.04
#FROM ubuntu:21.10
RUN apt-get -y update # 6
RUN DEBIAN_FRONTEND="noninteractive" apt-get -y install tzdata
ENV container docker
RUN apt-get -y install systemd ifupdown net-tools isc-dhcp-client
RUN systemctl enable networking && \
systemctl set-default multi-user.target && \
rm -f /etc/systemd/system/*.wants/getty* && \
rm -f /lib/systemd/system/*.wants/getty*
VOLUME [ "/sys/fs/cgroup" ]
STOPSIGNAL SIGRTMIN+3
ADD init.sh /sbin/init.sh
FROM ubuntu:21.04
RUN sed -i 's/# deb-src/deb-src/' /etc/apt/sources.list
RUN apt-get -y update
RUN DEBIAN_FRONTEND=noninteractive apt-get -y build-dep systemd
RUN apt-get -y install git python3 python3-jinja2
RUN cd /root && git clone https://github.com/systemd/systemd
RUN mkdir /root/systemd/build && \
cd /root/systemd/build && \
meson --prefix=/usr \
--buildtype=release \
-Dblkid=true \
-Ddefault-dnssec=no \
-Dfirstboot=false \
-Dinstall-tests=false \
-Dldconfig=false \
-Dman=auto \
-Dsysusers=false \
-Drpmmacrosdir=no \
-Db_lto=false \
-Dhomed=false \
-Duserdb=false \
-Dmode=release \
-Dpamconfdir=/etc/pam.d \
..
RUN cd /root/systemd/build && \
ninja -j4
RUN cd /root/systemd/build && \
ninja install
RUN systemctl set-default multi-user.target && \
rm -f /etc/systemd/system/*.wants/getty* && \
rm -f /usr/lib/systemd/system/*.wants/getty* && \
rm -f /usr/lib/systemd/system/*.wants/systemd-logind*
VOLUME [ "/sys/fs/cgroup" ]
STOPSIGNAL SIGRTMIN+3
ADD init.sh /sbin/init.sh
#!/bin/bash
set -e
echo "Starting init.sh"
echo "Setup journalctl to copy logs to console"
echo -e '#!/bin/bash\njournalctl -f --no-tail > /dev/console &' > /etc/rc.local
chmod +x /etc/rc.local
if [ "${1}" ]; then
# Sleep by command line argument
sleep_val=0.$(( 1 + ${1} * 2 ))
echo "Sleeping ${sleep_val} seconds"
sleep ${sleep_val}
fi
echo "Starting /usr/lib/systemd/systemd"
exec /usr/lib/systemd/systemd
#!/usr/bin/env bash
die() { echo "${*}"; exit 1; }
svc_cnt=10
# Check for already running services
running=$(docker-compose ps --services --filter "status=running")
run_cnt=$(echo "${running}" | grep '.' | wc -l)
if [ "${run_cnt}" != "0" ]; then
die 1 "${run_cnt} service(s) already running, unable to start test"
fi
cnt=0
while true; do
cnt=$((cnt+1))
echo "Test $cnt"
echo " - starting"
docker-compose up -d --force-recreate
echo " - waiting for startup"
while true; do
logs=$(docker-compose logs)
[ "$?" != 0 ] && break
starts=$(echo "${logs}" | grep "systemd.*Startup finished in" | wc -l)
echo " - started: ${starts}"
[ "${starts}" -ge "${svc_cnt}" ] && break
sleep 1
done
echo " - checking logs"
docker-compose logs | grep "FAILED" && break
echo " - stopping"
docker-compose stop
echo " - sleeping 1"
sleep 1
done
$ ./loop-compose.sh
Test 1
- starting
Recreating systemd-debug_i0_1 ... done
Recreating systemd-debug_i1_1 ... done
Recreating systemd-debug_i3_1 ... done
Recreating systemd-debug_i4_1 ... done
Recreating systemd-debug_i6_1 ... done
Recreating systemd-debug_i2_1 ... done
Recreating systemd-debug_i8_1 ... done
Recreating systemd-debug_i5_1 ... done
Recreating systemd-debug_i9_1 ... done
Recreating systemd-debug_i7_1 ... done
- waiting for startup
- started: 3
- started: 10
- checking logs
i0_1 | [FAILED] Failed to start Remount Root and Kernel File Systems.
i7_1 | [FAILED] Failed to start Create Static Device Nodes in /dev.
$ docker-compose logs i0
Attaching to systemd-debug_i0_1
i0_1 | Starting init.sh
i0_1 | Setup journalctl to copy logs to console
i0_1 | Starting /usr/lib/systemd/systemd
i0_1 | systemd 245.4-4ubuntu3.13 running in system mode. (+PAM +AUDIT +SELINUX +IMA +APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 +SECCOMP +BLKID +ELFUTILS +KMOD +IDN2 -IDN +PCRE2 default-hierarchy=hybrid)
i0_1 | Detected virtualization docker.
i0_1 | Detected architecture x86-64.
i0_1 |
i0_1 | Welcome to Ubuntu 20.04.2 LTS!
i0_1 |
i0_1 | Set hostname to <3695c98530d2>.
i0_1 | Couldn't move remaining userspace processes, ignoring: Input/output error
i0_1 | [ OK ] Created slice system-modprobe.slice.
i0_1 | [ OK ] Created slice User and Session Slice.
i0_1 | [ OK ] Started Dispatch Password ���ts to Console Directory Watch.
i0_1 | [ OK ] Started Forward Password R���uests to Wall Directory Watch.
i0_1 | [ OK ] Reached target Local Encrypted Volumes.
i0_1 | [ OK ] Reached target Paths.
i0_1 | [ OK ] Reached target Remote File Systems.
i0_1 | [ OK ] Reached target Slices.
i0_1 | [ OK ] Reached target Swap.
i0_1 | [ OK ] Listening on initctl Compatibility Named Pipe.
i0_1 | [ OK ] Listening on Journal Socket (/dev/log).
i0_1 | [ OK ] Listening on Journal Socket.
i0_1 | Mounting Huge Pages File System...
i0_1 | Starting Journal Service...
i0_1 | Starting Helper to synchronize boot up for ifupdown...
i0_1 | Mounting FUSE Control File System...
i0_1 | Starting Remount Root and Kernel File Systems...
i0_1 | systemd-remount-fs.service: Failed to attach to cgroup /system.slice/docker.service/system.slice/systemd-remount-fs.service: No such file or directory
i0_1 | [ OK ] Mounted Huge Pages File System.
i0_1 | [ OK ] Finished Helper to synchronize boot up for ifupdown.
i0_1 | [ OK ] Mounted FUSE Control File System.
i0_1 | systemd-remount-fs.service: Main process exited, code=exited, status=219/CGROUP
i0_1 | systemd-remount-fs.service: Failed with result 'exit-code'.
i0_1 | [FAILED] Failed to start Remount Root and Kernel File Systems.
i0_1 | See 'systemctl status systemd-remount-fs.service' for details.
i0_1 | Starting Create System Users...
i0_1 | [ OK ] Finished Create System Users.
i0_1 | [ OK ] Started Journal Service.
i0_1 | Starting Flush Journal to Persistent Storage...
i0_1 | Starting Create Static Device Nodes in /dev...
i0_1 | [ OK ] Finished Create Static Device Nodes in /dev.
i0_1 | [ OK ] Finished Flush Journal to Persistent Storage.
i0_1 | [ OK ] Reached target Local File Systems (Pre).
i0_1 | [ OK ] Reached target Local File Systems.
i0_1 | Starting Raise network interfaces...
i0_1 | Starting Create Volatile Files and Directories...
i0_1 | [ OK ] Finished Create Volatile Files and Directories.
i0_1 | Starting Network Name Resolution...
i0_1 | [ OK ] Reached target System Time Set.
i0_1 | [ OK ] Reached target System Time Synchronized.
i0_1 | Starting Update UTMP about System Boot/Shutdown...
i0_1 | [ OK ] Finished Update UTMP about System Boot/Shutdown. i0_1 | [ OK ] Reached target System Initialization.
i0_1 | [ OK ] Started Daily apt download activities.
i0_1 | [ OK ] Started Daily apt upgrade and clean activities.
i0_1 | [ OK ] Started Periodic ext4 Onli���ata Check for All Filesystems.
i0_1 | [ OK ] Started Message of the Day.
i0_1 | [ OK ] Started Daily Cleanup of Temporary Directories.
i0_1 | [ OK ] Reached target Timers.
i0_1 | [ OK ] Listening on D-Bus System Message Bus Socket.
i0_1 | [ OK ] Reached target Sockets.
i0_1 | [ OK ] Reached target Basic System.
i0_1 | [ OK ] Started D-Bus System Message Bus.
i0_1 | Starting Dispatcher daemon for systemd-networkd...
i0_1 | Starting Login Service...
i0_1 | [ OK ] Finished Raise network interfaces.
i0_1 | [ OK ] Started Dispatcher daemon for systemd-networkd.
i0_1 | [ OK ] Started Login Service.
i0_1 | [ OK ] Started Network Name Resolution.
i0_1 | [ OK ] Reached target Network.
i0_1 | [ OK ] Reached target Host and Network Name Lookups.
i0_1 | Starting /etc/rc.local Compatibility...
i0_1 | Starting Permit User Sessions...
i0_1 | [ OK ] Started /etc/rc.local Compatibility.
i0_1 | [ OK ] Finished Permit User Sessions.
i0_1 | [ OK ] Reached target Multi-User System.
i0_1 | Starting Update UTMP about System Runlevel Changes...
i0_1 | -- Logs begin at Tue 2021-10-05 14:14:17 UTC. --
i0_1 | Oct 05 14:14:17 3695c98530d2 systemd-journald[24]: Journal started
i0_1 | Oct 05 14:14:17 3695c98530d2 systemd-journald[24]: Runtime Journal (/run/log/journal/ebf552990276a47c4a507bad615c5c35) is 8.0M, max 635.3M, 627.3M free.
i0_1 | Oct 05 14:14:17 3695c98530d2 systemd[28]: systemd-remount-fs.service: Failed at step CGROUP spawning /lib/systemd/systemd-remount-fs: No such file or directory
i0_1 | Oct 05 14:14:17 3695c98530d2 systemd-sysusers[29]: Creating group systemd-coredump with gid 999.
i0_1 | Oct 05 14:14:17 3695c98530d2 systemd-sysusers[29]: Creating user systemd-coredump (systemd Core Dumper) with uid 999 and gid 999.
i0_1 | Oct 05 14:14:17 3695c98530d2 systemd[1]: Starting Flush Journal to Persistent Storage...
i0_1 | Oct 05 14:14:17 3695c98530d2 systemd[1]: Starting Create Static Device Nodes in /dev...
i0_1 | Oct 05 14:14:17 3695c98530d2 systemd-journald[24]: Time spent on flushing to /var/log/journal/ebf552990276a47c4a507bad615c5c35 is 1.752ms for 7 entries.
i0_1 | Oct 05 14:14:17 3695c98530d2 systemd-journald[24]: System Journal (/var/log/journal/ebf552990276a47c4a507bad615c5c35) is 8.0M, max 4.0G, 3.9G free.
i0_1 | Oct 05 14:14:17 3695c98530d2 systemd[1]: Finished Create Static Device Nodes in /dev.
i0_1 | Oct 05 14:14:17 3695c98530d2 systemd[1]: Finished Flush Journal to Persistent Storage.
i0_1 | Oct 05 14:14:17 3695c98530d2 systemd[1]: Reached target Local File Systems (Pre).
i0_1 | Oct 05 14:14:17 3695c98530d2 systemd[1]: Reached target Local File Systems.
i0_1 | Oct 05 14:14:17 3695c98530d2 systemd[1]: Starting Raise network interfaces...
i0_1 | Oct 05 14:14:17 3695c98530d2 systemd[1]: Condition check resulted in Store a System Token in an EFI Variable being skipped.
i0_1 | Oct 05 14:14:17 3695c98530d2 systemd[1]: Condition check resulted in Commit a transient machine-id on disk being skipped.
i0_1 | Oct 05 14:14:17 3695c98530d2 systemd[1]: Starting Create Volatile Files and Directories...
i0_1 | Oct 05 14:14:17 3695c98530d2 systemd[1]: Finished Create Volatile Files and Directories.
i0_1 | Oct 05 14:14:17 3695c98530d2 systemd[1]: Starting Network Name Resolution...
i0_1 | Oct 05 14:14:17 3695c98530d2 systemd[1]: Condition check resulted in Network Time Synchronization being skipped.
i0_1 | Oct 05 14:14:17 3695c98530d2 systemd[1]: Reached target System Time Set.
i0_1 | Oct 05 14:14:17 3695c98530d2 systemd[1]: Reached target System Time Synchronized.
i0_1 | Oct 05 14:14:17 3695c98530d2 systemd[1]: Starting Update UTMP about System Boot/Shutdown...
i0_1 | Oct 05 14:14:17 3695c98530d2 systemd[1]: Finished Update UTMP about System Boot/Shutdown.
i0_1 | Oct 05 14:14:17 3695c98530d2 systemd[1]: Reached target System Initialization.
i0_1 | Oct 05 14:14:17 3695c98530d2 systemd[1]: Started Daily apt download activities.
i0_1 | Oct 05 14:14:17 3695c98530d2 systemd[1]: Started Daily apt upgrade and clean activities.
i0_1 | Oct 05 14:14:17 3695c98530d2 systemd[1]: Started Periodic ext4 Online Metadata Check for All Filesystems.
i0_1 | Oct 05 14:14:17 3695c98530d2 systemd[1]: Condition check resulted in Discard unused blocks once a week being skipped.
i0_1 | Oct 05 14:14:17 3695c98530d2 systemd[1]: Started Message of the Day.
i0_1 | Oct 05 14:14:17 3695c98530d2 systemd[1]: Started Daily Cleanup of Temporary Directories.
i0_1 | Oct 05 14:14:17 3695c98530d2 systemd[1]: Reached target Timers.
i0_1 | Oct 05 14:14:17 3695c98530d2 systemd[1]: Listening on D-Bus System Message Bus Socket.
i0_1 | Oct 05 14:14:17 3695c98530d2 systemd[1]: Reached target Sockets.
i0_1 | Oct 05 14:14:17 3695c98530d2 systemd[1]: Reached target Basic System.
i0_1 | Oct 05 14:14:17 3695c98530d2 systemd[1]: Started D-Bus System Message Bus.
i0_1 | Oct 05 14:14:17 3695c98530d2 systemd[1]: Condition check resulted in Remove Stale Online ext4 Metadata Check Snapshots being skipped.
i0_1 | Oct 05 14:14:17 3695c98530d2 systemd[1]: Starting Dispatcher daemon for systemd-networkd...
i0_1 | Oct 05 14:14:17 3695c98530d2 systemd[1]: Condition check resulted in Set the CPU Frequency Scaling governor being skipped.
i0_1 | Oct 05 14:14:17 3695c98530d2 systemd[1]: Starting Login Service...
i0_1 | Oct 05 14:14:17 3695c98530d2 systemd[1]: Finished Raise network interfaces.
i0_1 | Oct 05 14:14:17 3695c98530d2 networkd-dispatcher[47]: No valid path found for iwconfig
i0_1 | Oct 05 14:14:17 3695c98530d2 networkd-dispatcher[47]: No valid path found for iw
i0_1 | Oct 05 14:14:17 3695c98530d2 networkd-dispatcher[51]: WARNING: systemd-networkd is not running, output will be incomplete.
i0_1 | Oct 05 14:14:17 3695c98530d2 systemd[1]: Started Dispatcher daemon for systemd-networkd.
i0_1 | Oct 05 14:14:17 3695c98530d2 systemd-logind[48]: New seat seat0.
i0_1 | Oct 05 14:14:17 3695c98530d2 systemd[1]: Started Login Service.
i0_1 | Oct 05 14:14:17 3695c98530d2 systemd-resolved[40]: Positive Trust Anchors:
i0_1 | Oct 05 14:14:17 3695c98530d2 systemd-resolved[40]: . IN DS 20326 8 2 e06d44b80b8f1d39a95c0b0d7c65d08458e880409bbc683457104237c7f8ec8d
i0_1 | Oct 05 14:14:17 3695c98530d2 systemd-resolved[40]: Negative trust anchors: 10.in-addr.arpa 16.172.in-addr.arpa 17.172.in-addr.arpa 18.172.in-addr.arpa 19.172.in-addr.arpa 20.172.in-addr.arpa 21.172.in-addr.arpa 22.172.in-addr.arpa 23.172.in-addr.arpa 24.172.in-addr.arpa 25.172.in-addr.arpa 26.172.in-addr.arpa
27.172.in-addr.arpa 28.172.in-addr.arpa 29.172.in-addr.arpa 30.172.in-addr.arpa 31.172.in-addr.arpa 168.192.in-addr.arpa d.f.ip6.arpa corp home internal intranet lan local private test
i0_1 | Oct 05 14:14:17 3695c98530d2 systemd-resolved[40]: Using system hostname '3695c98530d2'.
i0_1 | Oct 05 14:14:17 3695c98530d2 systemd[1]: Started Network Name Resolution.
i0_1 | Oct 05 14:14:17 3695c98530d2 systemd[1]: Reached target Network.
i0_1 | Oct 05 14:14:17 3695c98530d2 systemd[1]: Reached target Host and Network Name Lookups.
i0_1 | Oct 05 14:14:17 3695c98530d2 systemd[1]: Starting /etc/rc.local Compatibility...
i0_1 | Oct 05 14:14:17 3695c98530d2 systemd[1]: Starting Permit User Sessions...
i0_1 | Oct 05 14:14:17 3695c98530d2 systemd[1]: Started /etc/rc.local Compatibility.
i0_1 | Oct 05 14:14:17 3695c98530d2 systemd[1]: Finished Permit User Sessions.
i0_1 | Oct 05 14:14:17 3695c98530d2 systemd[1]: Reached target Multi-User System.
i0_1 | Oct 05 14:14:17 3695c98530d2 systemd[1]: Starting Update UTMP about System Runlevel Changes...
i0_1 | [ OK ] Finished Update UTMP about System Runlevel Changes.
i0_1 | Oct 05 14:14:17 3695c98530d2 systemd[1]: systemd-update-utmp-runlevel.service: Failed to kill control group /system.slice/docker.service/system.slice/systemd-update-utmp-runlevel.service, ignoring: Input/output error
i0_1 | Oct 05 14:14:17 3695c98530d2 systemd[1]: systemd-update-utmp-runlevel.service: Failed to kill control group /system.slice/docker.service/system.slice/systemd-update-utmp-runlevel.service, ignoring: Input/output error
i0_1 | Oct 05 14:14:17 3695c98530d2 systemd[1]: systemd-update-utmp-runlevel.service: Failed to kill control group /system.slice/docker.service/system.slice/systemd-update-utmp-runlevel.service, ignoring: Input/output error
i0_1 | Oct 05 14:14:17 3695c98530d2 systemd[1]: systemd-update-utmp-runlevel.service: Failed to kill control group /system.slice/docker.service/system.slice/systemd-update-utmp-runlevel.service, ignoring: Input/output error
i0_1 | Oct 05 14:14:17 3695c98530d2 systemd[1]: systemd-update-utmp-runlevel.service: Succeeded.
i0_1 | Oct 05 14:14:17 3695c98530d2 systemd[1]: Finished Update UTMP about System Runlevel Changes.
i0_1 | Oct 05 14:14:17 3695c98530d2 systemd[1]: Startup finished in 924ms.
$ docker-compose exec i0 systemctl status systemd-remount-fs.service
● systemd-remount-fs.service - Remount Root and Kernel File Systems
Loaded: loaded (/lib/systemd/system/systemd-remount-fs.service; enabled-runtime; vendor preset: enabled)
Active: failed (Result: exit-code) since Tue 2021-10-05 14:14:17 UTC; 3min 55s ago
Docs: man:systemd-remount-fs.service(8)
https://www.freedesktop.org/wiki/Software/systemd/APIFileSystems
Process: 28 ExecStart=/lib/systemd/systemd-remount-fs (code=exited, status=219/CGROUP)
Main PID: 28 (code=exited, status=219/CGROUP)
Warning: journal has been rotated since unit was started, output may be incomplete.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment