Assertion 'a <= b' failed at src/libsystemd/sd-event/sd-event.c:2903, function sleep_between()

[mingtaoy]

systemd version the issue has been seen with
248.4
248.5
(Bisected to b1699fd2e0614c51bc08df49aad0b6e5f56eea68 in systemd-stable branches)
Unable to reproduce on main branch.

Used distribution
Fedora Workstation 34

Linux kernel version used (uname -a)
5.12.15-300.fc34.x86_64

CPU architecture issue was seen on
amd64

Expected behaviour you didn't see
systemd boots successfully with no crashes.

Unexpected behaviour you saw
systemd aborts with an assertion failure.

Jul 22 16:26:39 systemd-repro systemd[1]: Assertion 'a <= b' failed at src/libsystemd/sd-event/sd-event.c:2903, function sleep_between(). Aborting.
Jul 22 16:26:39 systemd-repro systemd-coredump[1031]: Due to PID 1 having crashed coredump collection will now be turned off.
Jul 22 16:26:39 systemd-repro systemd-coredump[1031]: Removed old coredump core.systemd.0.b9dffa442cbb4984a7f5093774fb2c9a.1022.1626996046000000.zst.
Jul 22 16:26:39 systemd-repro systemd-coredump[1031]: Process 1030 (systemd) of user 0 dumped core.
                                                      
                                                      Stack trace of thread 1030:
                                                      #0  0x00007f5f1973959b kill (libc.so.6 + 0x3d59b)
                                                      #1  0x000055af003f5bc8 crash (systemd + 0x45bc8)
                                                      #2  0x00007f5f198dea20 __restore_rt (libpthread.so.0 + 0x13a20)
                                                      #3  0x00007f5f197392a2 raise (libc.so.6 + 0x3d2a2)
                                                      #4  0x00007f5f197228a4 abort (libc.so.6 + 0x268a4)
                                                      #5  0x00007f5f19a8fa42 log_assert_failed.cold (libsystemd-shared-248.so + 0x78a42)
                                                      #6  0x00007f5f19c28d6f sleep_between (libsystemd-shared-248.so + 0x211d6f)
                                                      #7  0x00007f5f19c312b9 event_arm_timer (libsystemd-shared-248.so + 0x21a2b9)
                                                      #8  0x00007f5f19c31cf5 sd_event_prepare (libsystemd-shared-248.so + 0x21acf5)
                                                      #9  0x00007f5f19c34d50 sd_event_run (libsystemd-shared-248.so + 0x21dd50)
                                                      #10 0x000055af0043a7d4 manager_loop (systemd + 0x8a7d4)
                                                      #11 0x000055af003f2c5f main (systemd + 0x42c5f)
                                                      #12 0x00007f5f19723b75 __libc_start_main (libc.so.6 + 0x27b75)
                                                      #13 0x000055af003f577e _start (systemd + 0x4577e)

In gdb, I observe the following state in manager->event->monotonic. Below, I list the entries of the earliest and latest priority queues:

dumping sd_event monotonic earliest next= 21580465
num items: 39
0:  earliest_idx=0 latest_idx=1 type=SOURCE_TIME_MONOTONIC desc=0x55af00dbe5c0 "manager-jobs-in-progress" prio=0 enabled=-1 ratelimited=false ratelimit={ interval = 0, burst = 0, num = 0, begin = 0 } time_next=21546976 time_accuracy=250000
1:  earliest_idx=1 latest_idx=3 type=SOURCE_TIME_MONOTONIC desc=0x55af00d2db20 "service-timer" prio=0 enabled=-1 ratelimited=false ratelimit={ interval = 0, burst = 0, num = 0, begin = 0 } time_next=39539090 time_accuracy=250000
2:  earliest_idx=2 latest_idx=2 type=SOURCE_TIME_MONOTONIC desc=0x55af00c8cb10 "timer-monotonic" prio=0 enabled=-1 ratelimited=false ratelimit={ interval = 0, burst = 0, num = 0, begin = 0 } time_next=900000000 time_accuracy=60000000
3:  earliest_idx=3 latest_idx=18 type=SOURCE_TIME_MONOTONIC desc=0x55af00de36e0 "timer-monotonic" prio=0 enabled=-1 ratelimited=false ratelimit={ interval = 0, burst = 0, num = 0, begin = 0 } time_next=73435383 time_accuracy=60000000
4:  earliest_idx=4 latest_idx=4 type=SOURCE_TIME_MONOTONIC desc=0x55af00dea590 "service-timer" prio=0 enabled=-1 ratelimited=false ratelimit={ interval = 0, burst = 0, num = 0, begin = 0 } time_next=18446744073709551615 time_accuracy=250000
5:  earliest_idx=5 latest_idx=13 type=SOURCE_TIME_MONOTONIC desc=0x55af00dea970 "service-timer" prio=0 enabled=-1 ratelimited=false ratelimit={ interval = 0, burst = 0, num = 0, begin = 0 } time_next=18446744073709551615 time_accuracy=250000
6:  earliest_idx=6 latest_idx=6 type=SOURCE_TIME_MONOTONIC desc=0x55af00d17d20 "service-timer" prio=0 enabled=-1 ratelimited=false ratelimit={ interval = 0, burst = 0, num = 0, begin = 0 } time_next=18446744073709551615 time_accuracy=250000
7:  earliest_idx=7 latest_idx=7 type=SOURCE_TIME_MONOTONIC desc=0x55af00ca2ac0 "service-timer" prio=0 enabled=-1 ratelimited=false ratelimit={ interval = 0, burst = 0, num = 0, begin = 0 } time_next=18446744073709551615 time_accuracy=250000
8:  earliest_idx=8 latest_idx=8 type=SOURCE_TIME_MONOTONIC desc=0x55af00c34bc0 "service-timer" prio=0 enabled=-1 ratelimited=false ratelimit={ interval = 0, burst = 0, num = 0, begin = 0 } time_next=109500692 time_accuracy=250000
9:  earliest_idx=9 latest_idx=9 type=SOURCE_TIME_MONOTONIC desc=0x55af00dea130 "service-timer" prio=0 enabled=-1 ratelimited=false ratelimit={ interval = 0, burst = 0, num = 0, begin = 0 } time_next=18446744073709551615 time_accuracy=250000
10:  earliest_idx=10 latest_idx=10 type=SOURCE_TIME_MONOTONIC desc=0x55af00df29c0 "service-timer" prio=0 enabled=-1 ratelimited=false ratelimit={ interval = 0, burst = 0, num = 0, begin = 0 } time_next=18446744073709551615 time_accuracy=250000
11:  earliest_idx=11 latest_idx=5 type=SOURCE_TIME_MONOTONIC desc=0x55af00e17f20 "service-timer" prio=0 enabled=-1 ratelimited=false ratelimit={ interval = 0, burst = 0, num = 0, begin = 0 } time_next=18446744073709551615 time_accuracy=250000
12:  earliest_idx=12 latest_idx=12 type=SOURCE_TIME_MONOTONIC desc=0x55af00d17a60 "service-timer" prio=0 enabled=-1 ratelimited=false ratelimit={ interval = 0, burst = 0, num = 0, begin = 0 } time_next=18446744073709551615 time_accuracy=250000
13:  earliest_idx=13 latest_idx=14 type=SOURCE_TIME_MONOTONIC desc=0x55af00c8bae0 "service-timer" prio=0 enabled=-1 ratelimited=false ratelimit={ interval = 0, burst = 0, num = 0, begin = 0 } time_next=18446744073709551615 time_accuracy=250000
14:  earliest_idx=14 latest_idx=30 type=SOURCE_TIME_MONOTONIC desc=0x55af00d66f30 "service-timer" prio=0 enabled=-1 ratelimited=false ratelimit={ interval = 0, burst = 0, num = 0, begin = 0 } time_next=18446744073709551615 time_accuracy=250000
15:  earliest_idx=15 latest_idx=15 type=SOURCE_TIME_MONOTONIC desc=0x55af00de6ab0 "service-timer" prio=0 enabled=-1 ratelimited=false ratelimit={ interval = 0, burst = 0, num = 0, begin = 0 } time_next=18446744073709551615 time_accuracy=250000
16:  earliest_idx=16 latest_idx=16 type=SOURCE_TIME_MONOTONIC desc=0x55af00c29f50 "service-timer" prio=0 enabled=-1 ratelimited=false ratelimit={ interval = 0, burst = 0, num = 0, begin = 0 } time_next=18446744073709551615 time_accuracy=250000
17:  earliest_idx=17 latest_idx=17 type=SOURCE_TIME_MONOTONIC desc=0x55af00d9c310 "service-timer" prio=0 enabled=-1 ratelimited=false ratelimit={ interval = 0, burst = 0, num = 0, begin = 0 } time_next=18446744073709551615 time_accuracy=250000
18:  earliest_idx=18 latest_idx=38 type=SOURCE_TIME_MONOTONIC desc=0x55af00d5d370 "timer-monotonic" prio=0 enabled=-1 ratelimited=false ratelimit={ interval = 0, burst = 0, num = 0, begin = 0 } time_next=2940495181 time_accuracy=60000000
19:  earliest_idx=19 latest_idx=0 type=SOURCE_IO desc=0x55af00bf77d0 "mount-monitor-dispatch" prio=-10 enabled=1 ratelimited=true ratelimit={ interval = 1000000, burst = 5, num = 5, begin = 19492067 } time_next=4294967305 time_accuracy=1
20:  earliest_idx=20 latest_idx=20 type=SOURCE_TIME_MONOTONIC desc=0x55af00bf0db0 "service-timer" prio=0 enabled=-1 ratelimited=false ratelimit={ interval = 0, burst = 0, num = 0, begin = 0 } time_next=18446744073709551615 time_accuracy=250000
21:  earliest_idx=21 latest_idx=21 type=SOURCE_TIME_MONOTONIC desc=0x55af00de1290 "service-timer" prio=0 enabled=-1 ratelimited=false ratelimit={ interval = 0, burst = 0, num = 0, begin = 0 } time_next=18446744073709551615 time_accuracy=250000
22:  earliest_idx=22 latest_idx=22 type=SOURCE_TIME_MONOTONIC desc=0x55af00d1f0e0 "service-timer" prio=0 enabled=-1 ratelimited=false ratelimit={ interval = 0, burst = 0, num = 0, begin = 0 } time_next=18446744073709551615 time_accuracy=250000
23:  earliest_idx=23 latest_idx=11 type=SOURCE_TIME_MONOTONIC desc=0x55af00deb770 "service-timer" prio=0 enabled=-1 ratelimited=false ratelimit={ interval = 0, burst = 0, num = 0, begin = 0 } time_next=18446744073709551615 time_accuracy=250000
24:  earliest_idx=24 latest_idx=24 type=SOURCE_TIME_MONOTONIC desc=0x55af00d1e850 "varlink-time" prio=0 enabled=0 ratelimited=false ratelimit={ interval = 0, burst = 0, num = 0, begin = 0 } time_next=0 time_accuracy=250000
25:  earliest_idx=25 latest_idx=25 type=SOURCE_TIME_MONOTONIC desc=0x55af00d17bb0 "service-timer" prio=0 enabled=-1 ratelimited=false ratelimit={ interval = 0, burst = 0, num = 0, begin = 0 } time_next=18446744073709551615 time_accuracy=250000
26:  earliest_idx=26 latest_idx=26 type=SOURCE_TIME_MONOTONIC desc=0x55af00deaed0 "service-timer" prio=0 enabled=-1 ratelimited=false ratelimit={ interval = 0, burst = 0, num = 0, begin = 0 } time_next=18446744073709551615 time_accuracy=250000
27:  earliest_idx=27 latest_idx=23 type=SOURCE_TIME_MONOTONIC desc=0x55af00d18200 "bus-time" prio=0 enabled=0 ratelimited=false ratelimit={ interval = 0, burst = 0, num = 0, begin = 0 } time_next=0 time_accuracy=250000
28:  earliest_idx=28 latest_idx=27 type=SOURCE_TIME_MONOTONIC desc=0x55af00deb580 "service-timer" prio=0 enabled=-1 ratelimited=false ratelimit={ interval = 0, burst = 0, num = 0, begin = 0 } time_next=18446744073709551615 time_accuracy=250000
29:  earliest_idx=29 latest_idx=29 type=SOURCE_TIME_MONOTONIC desc=0x55af00d180a0 "service-timer" prio=0 enabled=-1 ratelimited=false ratelimit={ interval = 0, burst = 0, num = 0, begin = 0 } time_next=18446744073709551615 time_accuracy=250000
30:  earliest_idx=30 latest_idx=28 type=SOURCE_TIME_MONOTONIC desc=0x55af00d83380 "service-timer" prio=0 enabled=-1 ratelimited=false ratelimit={ interval = 0, burst = 0, num = 0, begin = 0 } time_next=18446744073709551615 time_accuracy=250000
31:  earliest_idx=31 latest_idx=31 type=SOURCE_TIME_MONOTONIC desc=0x55af00c79b20 "service-timer" prio=0 enabled=-1 ratelimited=false ratelimit={ interval = 0, burst = 0, num = 0, begin = 0 } time_next=18446744073709551615 time_accuracy=250000
32:  earliest_idx=32 latest_idx=32 type=SOURCE_TIME_MONOTONIC desc=0x55af00de1460 "service-timer" prio=0 enabled=-1 ratelimited=false ratelimit={ interval = 0, burst = 0, num = 0, begin = 0 } time_next=18446744073709551615 time_accuracy=250000
33:  earliest_idx=33 latest_idx=33 type=SOURCE_TIME_MONOTONIC desc=0x55af00ded6c0 "service-timer" prio=0 enabled=-1 ratelimited=false ratelimit={ interval = 0, burst = 0, num = 0, begin = 0 } time_next=18446744073709551615 time_accuracy=250000
34:  earliest_idx=34 latest_idx=34 type=SOURCE_TIME_MONOTONIC desc=0x55af00de71f0 "service-timer" prio=0 enabled=-1 ratelimited=false ratelimit={ interval = 0, burst = 0, num = 0, begin = 0 } time_next=18446744073709551615 time_accuracy=250000
35:  earliest_idx=35 latest_idx=35 type=SOURCE_TIME_MONOTONIC desc=0x55af00df2000 "service-timer" prio=0 enabled=-1 ratelimited=false ratelimit={ interval = 0, burst = 0, num = 0, begin = 0 } time_next=18446744073709551615 time_accuracy=250000
36:  earliest_idx=36 latest_idx=36 type=SOURCE_TIME_MONOTONIC desc=0x55af00ce5160 "service-timer" prio=0 enabled=-1 ratelimited=false ratelimit={ interval = 0, burst = 0, num = 0, begin = 0 } time_next=18446744073709551615 time_accuracy=250000
37:  earliest_idx=37 latest_idx=19 type=SOURCE_TIME_MONOTONIC desc=0x55af00de0b50 "service-timer" prio=0 enabled=-1 ratelimited=false ratelimit={ interval = 0, burst = 0, num = 0, begin = 0 } time_next=18446744073709551615 time_accuracy=250000
38:  earliest_idx=38 latest_idx=37 type=SOURCE_TIME_MONOTONIC desc=0x55af00de12b0 "service-timer" prio=0 enabled=-1 ratelimited=false ratelimit={ interval = 0, burst = 0, num = 0, begin = 0 } time_next=18446744073709551615 time_accuracy=250000
dumping sd_event monotonic latest next= 21580465
num items: 39
0:  earliest_idx=19 latest_idx=0 type=SOURCE_IO desc=0x55af00bf77d0 "mount-monitor-dispatch" prio=-10 enabled=1 ratelimited=true ratelimit={ interval = 1000000, burst = 5, num = 5, begin = 19492067 } time_next=4294967305 time_accuracy=1
1:  earliest_idx=0 latest_idx=1 type=SOURCE_TIME_MONOTONIC desc=0x55af00dbe5c0 "manager-jobs-in-progress" prio=0 enabled=-1 ratelimited=false ratelimit={ interval = 0, burst = 0, num = 0, begin = 0 } time_next=21546976 time_accuracy=250000
2:  earliest_idx=2 latest_idx=2 type=SOURCE_TIME_MONOTONIC desc=0x55af00c8cb10 "timer-monotonic" prio=0 enabled=-1 ratelimited=false ratelimit={ interval = 0, burst = 0, num = 0, begin = 0 } time_next=900000000 time_accuracy=60000000
3:  earliest_idx=1 latest_idx=3 type=SOURCE_TIME_MONOTONIC desc=0x55af00d2db20 "service-timer" prio=0 enabled=-1 ratelimited=false ratelimit={ interval = 0, burst = 0, num = 0, begin = 0 } time_next=39539090 time_accuracy=250000
4:  earliest_idx=4 latest_idx=4 type=SOURCE_TIME_MONOTONIC desc=0x55af00dea590 "service-timer" prio=0 enabled=-1 ratelimited=false ratelimit={ interval = 0, burst = 0, num = 0, begin = 0 } time_next=18446744073709551615 time_accuracy=250000
5:  earliest_idx=11 latest_idx=5 type=SOURCE_TIME_MONOTONIC desc=0x55af00e17f20 "service-timer" prio=0 enabled=-1 ratelimited=false ratelimit={ interval = 0, burst = 0, num = 0, begin = 0 } time_next=18446744073709551615 time_accuracy=250000
6:  earliest_idx=6 latest_idx=6 type=SOURCE_TIME_MONOTONIC desc=0x55af00d17d20 "service-timer" prio=0 enabled=-1 ratelimited=false ratelimit={ interval = 0, burst = 0, num = 0, begin = 0 } time_next=18446744073709551615 time_accuracy=250000
7:  earliest_idx=7 latest_idx=7 type=SOURCE_TIME_MONOTONIC desc=0x55af00ca2ac0 "service-timer" prio=0 enabled=-1 ratelimited=false ratelimit={ interval = 0, burst = 0, num = 0, begin = 0 } time_next=18446744073709551615 time_accuracy=250000
8:  earliest_idx=8 latest_idx=8 type=SOURCE_TIME_MONOTONIC desc=0x55af00c34bc0 "service-timer" prio=0 enabled=-1 ratelimited=false ratelimit={ interval = 0, burst = 0, num = 0, begin = 0 } time_next=109500692 time_accuracy=250000
9:  earliest_idx=9 latest_idx=9 type=SOURCE_TIME_MONOTONIC desc=0x55af00dea130 "service-timer" prio=0 enabled=-1 ratelimited=false ratelimit={ interval = 0, burst = 0, num = 0, begin = 0 } time_next=18446744073709551615 time_accuracy=250000
10:  earliest_idx=10 latest_idx=10 type=SOURCE_TIME_MONOTONIC desc=0x55af00df29c0 "service-timer" prio=0 enabled=-1 ratelimited=false ratelimit={ interval = 0, burst = 0, num = 0, begin = 0 } time_next=18446744073709551615 time_accuracy=250000
11:  earliest_idx=23 latest_idx=11 type=SOURCE_TIME_MONOTONIC desc=0x55af00deb770 "service-timer" prio=0 enabled=-1 ratelimited=false ratelimit={ interval = 0, burst = 0, num = 0, begin = 0 } time_next=18446744073709551615 time_accuracy=250000
12:  earliest_idx=12 latest_idx=12 type=SOURCE_TIME_MONOTONIC desc=0x55af00d17a60 "service-timer" prio=0 enabled=-1 ratelimited=false ratelimit={ interval = 0, burst = 0, num = 0, begin = 0 } time_next=18446744073709551615 time_accuracy=250000
13:  earliest_idx=5 latest_idx=13 type=SOURCE_TIME_MONOTONIC desc=0x55af00dea970 "service-timer" prio=0 enabled=-1 ratelimited=false ratelimit={ interval = 0, burst = 0, num = 0, begin = 0 } time_next=18446744073709551615 time_accuracy=250000
14:  earliest_idx=13 latest_idx=14 type=SOURCE_TIME_MONOTONIC desc=0x55af00c8bae0 "service-timer" prio=0 enabled=-1 ratelimited=false ratelimit={ interval = 0, burst = 0, num = 0, begin = 0 } time_next=18446744073709551615 time_accuracy=250000
15:  earliest_idx=15 latest_idx=15 type=SOURCE_TIME_MONOTONIC desc=0x55af00de6ab0 "service-timer" prio=0 enabled=-1 ratelimited=false ratelimit={ interval = 0, burst = 0, num = 0, begin = 0 } time_next=18446744073709551615 time_accuracy=250000
16:  earliest_idx=16 latest_idx=16 type=SOURCE_TIME_MONOTONIC desc=0x55af00c29f50 "service-timer" prio=0 enabled=-1 ratelimited=false ratelimit={ interval = 0, burst = 0, num = 0, begin = 0 } time_next=18446744073709551615 time_accuracy=250000
17:  earliest_idx=17 latest_idx=17 type=SOURCE_TIME_MONOTONIC desc=0x55af00d9c310 "service-timer" prio=0 enabled=-1 ratelimited=false ratelimit={ interval = 0, burst = 0, num = 0, begin = 0 } time_next=18446744073709551615 time_accuracy=250000
18:  earliest_idx=3 latest_idx=18 type=SOURCE_TIME_MONOTONIC desc=0x55af00de36e0 "timer-monotonic" prio=0 enabled=-1 ratelimited=false ratelimit={ interval = 0, burst = 0, num = 0, begin = 0 } time_next=73435383 time_accuracy=60000000
19:  earliest_idx=37 latest_idx=19 type=SOURCE_TIME_MONOTONIC desc=0x55af00de0b50 "service-timer" prio=0 enabled=-1 ratelimited=false ratelimit={ interval = 0, burst = 0, num = 0, begin = 0 } time_next=18446744073709551615 time_accuracy=250000
20:  earliest_idx=20 latest_idx=20 type=SOURCE_TIME_MONOTONIC desc=0x55af00bf0db0 "service-timer" prio=0 enabled=-1 ratelimited=false ratelimit={ interval = 0, burst = 0, num = 0, begin = 0 } time_next=18446744073709551615 time_accuracy=250000
21:  earliest_idx=21 latest_idx=21 type=SOURCE_TIME_MONOTONIC desc=0x55af00de1290 "service-timer" prio=0 enabled=-1 ratelimited=false ratelimit={ interval = 0, burst = 0, num = 0, begin = 0 } time_next=18446744073709551615 time_accuracy=250000
22:  earliest_idx=22 latest_idx=22 type=SOURCE_TIME_MONOTONIC desc=0x55af00d1f0e0 "service-timer" prio=0 enabled=-1 ratelimited=false ratelimit={ interval = 0, burst = 0, num = 0, begin = 0 } time_next=18446744073709551615 time_accuracy=250000
23:  earliest_idx=27 latest_idx=23 type=SOURCE_TIME_MONOTONIC desc=0x55af00d18200 "bus-time" prio=0 enabled=0 ratelimited=false ratelimit={ interval = 0, burst = 0, num = 0, begin = 0 } time_next=0 time_accuracy=250000
24:  earliest_idx=24 latest_idx=24 type=SOURCE_TIME_MONOTONIC desc=0x55af00d1e850 "varlink-time" prio=0 enabled=0 ratelimited=false ratelimit={ interval = 0, burst = 0, num = 0, begin = 0 } time_next=0 time_accuracy=250000
25:  earliest_idx=25 latest_idx=25 type=SOURCE_TIME_MONOTONIC desc=0x55af00d17bb0 "service-timer" prio=0 enabled=-1 ratelimited=false ratelimit={ interval = 0, burst = 0, num = 0, begin = 0 } time_next=18446744073709551615 time_accuracy=250000
26:  earliest_idx=26 latest_idx=26 type=SOURCE_TIME_MONOTONIC desc=0x55af00deaed0 "service-timer" prio=0 enabled=-1 ratelimited=false ratelimit={ interval = 0, burst = 0, num = 0, begin = 0 } time_next=18446744073709551615 time_accuracy=250000
27:  earliest_idx=28 latest_idx=27 type=SOURCE_TIME_MONOTONIC desc=0x55af00deb580 "service-timer" prio=0 enabled=-1 ratelimited=false ratelimit={ interval = 0, burst = 0, num = 0, begin = 0 } time_next=18446744073709551615 time_accuracy=250000
28:  earliest_idx=30 latest_idx=28 type=SOURCE_TIME_MONOTONIC desc=0x55af00d83380 "service-timer" prio=0 enabled=-1 ratelimited=false ratelimit={ interval = 0, burst = 0, num = 0, begin = 0 } time_next=18446744073709551615 time_accuracy=250000
29:  earliest_idx=29 latest_idx=29 type=SOURCE_TIME_MONOTONIC desc=0x55af00d180a0 "service-timer" prio=0 enabled=-1 ratelimited=false ratelimit={ interval = 0, burst = 0, num = 0, begin = 0 } time_next=18446744073709551615 time_accuracy=250000
30:  earliest_idx=14 latest_idx=30 type=SOURCE_TIME_MONOTONIC desc=0x55af00d66f30 "service-timer" prio=0 enabled=-1 ratelimited=false ratelimit={ interval = 0, burst = 0, num = 0, begin = 0 } time_next=18446744073709551615 time_accuracy=250000
31:  earliest_idx=31 latest_idx=31 type=SOURCE_TIME_MONOTONIC desc=0x55af00c79b20 "service-timer" prio=0 enabled=-1 ratelimited=false ratelimit={ interval = 0, burst = 0, num = 0, begin = 0 } time_next=18446744073709551615 time_accuracy=250000
32:  earliest_idx=32 latest_idx=32 type=SOURCE_TIME_MONOTONIC desc=0x55af00de1460 "service-timer" prio=0 enabled=-1 ratelimited=false ratelimit={ interval = 0, burst = 0, num = 0, begin = 0 } time_next=18446744073709551615 time_accuracy=250000
33:  earliest_idx=33 latest_idx=33 type=SOURCE_TIME_MONOTONIC desc=0x55af00ded6c0 "service-timer" prio=0 enabled=-1 ratelimited=false ratelimit={ interval = 0, burst = 0, num = 0, begin = 0 } time_next=18446744073709551615 time_accuracy=250000
34:  earliest_idx=34 latest_idx=34 type=SOURCE_TIME_MONOTONIC desc=0x55af00de71f0 "service-timer" prio=0 enabled=-1 ratelimited=false ratelimit={ interval = 0, burst = 0, num = 0, begin = 0 } time_next=18446744073709551615 time_accuracy=250000
35:  earliest_idx=35 latest_idx=35 type=SOURCE_TIME_MONOTONIC desc=0x55af00df2000 "service-timer" prio=0 enabled=-1 ratelimited=false ratelimit={ interval = 0, burst = 0, num = 0, begin = 0 } time_next=18446744073709551615 time_accuracy=250000
36:  earliest_idx=36 latest_idx=36 type=SOURCE_TIME_MONOTONIC desc=0x55af00ce5160 "service-timer" prio=0 enabled=-1 ratelimited=false ratelimit={ interval = 0, burst = 0, num = 0, begin = 0 } time_next=18446744073709551615 time_accuracy=250000
37:  earliest_idx=38 latest_idx=37 type=SOURCE_TIME_MONOTONIC desc=0x55af00de12b0 "service-timer" prio=0 enabled=-1 ratelimited=false ratelimit={ interval = 0, burst = 0, num = 0, begin = 0 } time_next=18446744073709551615 time_accuracy=250000
38:  earliest_idx=18 latest_idx=38 type=SOURCE_TIME_MONOTONIC desc=0x55af00d5d370 "timer-monotonic" prio=0 enabled=-1 ratelimited=false ratelimit={ interval = 0, burst = 0, num = 0, begin = 0 } time_next=2940495181 time_accuracy=60000000

Notably, when systemd tries to compute

        t = sleep_between(e, time_event_source_next(a), time_event_source_latest(b));

by using the earliest and latest priority queues stored in the event object, time_event_source_latest(b) selects a rate limited source corresponding to mount-monitor-dispatch which has a value that is less than the "earliest" entry which is not rate limited.

I've bisected this to b1699fd2e0614c51bc08df49aad0b6e5f56eea68 sd-event: change ordering of pending/ratelimited events, which was included in the v248.4 release that was released to Fedora 34 updates on 2021-07-14.

Steps to reproduce the problem
Unfortunately, I don't have a minimal repro to share at the moment. :( I bisected by booting a full copy of my workstation in QEMU multiple times. This issue does not happen 100% of the time, and I hypothesize that this has to do with the timing of when network-online.target completes (which triggers my NFS mounts) and when rate limiting occurs.

I'll update the bug report when I find a more minimal repro, but I figured I'd share my current findings in case the problem is obvious to those that are more familiar with systemd than I am.

Additional program output to the terminal or log subsystem illustrating the issue

• journalctl output of failing boot with systemd.log_level=debug
• corresponding /etc/fstab, since I think this timing issue has something to do with my mounts?

[keszybz]

The big question is whether this only happens in the stable branch (which would mean that there was some mishap during backporting), or also on main.

[keszybz]

Downstream bug report: https://bugzilla.redhat.com/show_bug.cgi?id=1984651.

[keszybz]

It seems I missed 2115b9b in the backport.

[mingtaoy]

I tried also cherry picking 2115b9b along with the other commits in that stack against v248-stable (here, but I am still seeing this issue. Will try on main per your suggestion.

[mingtaoy]

I was unable to reproduce on the main branch (on commit f571d9d) after 300 reboot cycles.

On the systemd-stable branch, I am able to reproduce usually within ~50 reboot cycles.

[mingtaoy]

I have ran 300 reboot cycles of systemd-248.6-1.fc34 which contains the additional patches mentioned by @keszybz, and now systemd boots successfully. Marking this issue as closed. Thanks for the quick response!