Note: This bug is displayed in read-only format because
the product is no longer active in Red Hat Bugzilla.
RHEL Engineering is moving the tracking of its product development work on RHEL 6 through RHEL 9 to Red Hat Jira (issues.redhat.com). If you're a Red Hat customer, please continue to file support cases via the Red Hat customer portal. If you're not, please head to the "RHEL project" in Red Hat Jira and file new tickets here. Individual Bugzilla bugs in the statuses "NEW", "ASSIGNED", and "POST" are being migrated throughout September 2023. Bugs of Red Hat partners with an assigned Engineering Partner Manager (EPM) are migrated in late September as per pre-agreed dates. Bugs against components "kernel", "kernel-rt", and "kpatch" are only migrated if still in "NEW" or "ASSIGNED". If you cannot log in to RH Jira, please consult article #7032570. That failing, please send an e-mail to the RH Jira admins at rh-issues@redhat.com to troubleshoot your issue as a user management inquiry. The email creates a ServiceNow ticket with Red Hat. Individual Bugzilla bugs that are migrated will be moved to status "CLOSED", resolution "MIGRATED", and set with "MigratedToJIRA" in "Keywords". The link to the successor Jira issue will be found under "Links", have a little "two-footprint" icon next to it, and direct you to the "RHEL project" in Red Hat Jira (issue links are of type "https://issues.redhat.com/browse/RHEL-XXXX", where "X" is a digit). This same link will be available in a blue banner at the top of the page informing you that that bug has been migrated.
I'm trying to determine a significant boot-time regression when using an initramfs generated with 219-62.el7.
The short version of the referenced bug is that after upgrading systemd and regenerating the initramfs, we see significantly slower boot times.
There isn't that much different between the two initramfs images; the diff is http://paste.openstack.org/show/743145/
Booting with systemd debugging turned on, I think that the hotplug rules introduced with [1] (which references #1614686) are a very likely suspect. The slow-boot logs show a flood of stuff like
---
...
Jan 23 23:01:14 localhost systemd-udevd[254]: PROGRAM '/bin/uname -p' /usr/lib/udev/rules.d/40-redhat.rules:8
Jan 23 23:01:14 localhost systemd-udevd[257]: seq 741 running
Jan 23 23:01:14 localhost systemd-udevd[239]: '/bin/uname -p'(out) 'x86_64'
Jan 23 23:01:14 localhost systemd-udevd[239]: '/bin/uname -p' [250] exit with return code 0
Jan 23 23:01:14 localhost systemd-udevd[239]: PROGRAM '/bin/systemd-detect-virt' /usr/lib/udev/rules.d/40-redhat.rules:11
Jan 23 23:01:14 localhost systemd-udevd[224]: seq 742 queued, 'add' 'bus'
Jan 23 23:01:14 localhost systemd-udevd[224]: maximum number (10) of children reached
Jan 23 23:01:14 localhost systemd-udevd[224]: seq 743 queued, 'add' 'bus'
Jan 23 23:01:14 localhost systemd-udevd[224]: maximum number (10) of children reached
Jan 23 23:01:14 localhost systemd-udevd[224]: maximum number (10) of children reached
...
---
grepping for the "systemd-detect-virt" invocations shows it runs *a lot*
---
cat boot-slow-trunc.log | grep systemd-detect-virt | grep qemu | wc -l
143
---
In the "fast" boot logs, I don't see anything at all seemingly related to memory hotplug coming up.
The rule is quite short
---
# Memory hotadd request
-SUBSYSTEM=="memory", ACTION=="add", PROGRAM="/bin/uname -p", RESULT!="s390*", ATTR{state}=="offline", ATTR{state}="online"
+SUBSYSTEM!="memory", ACTION!="add", GOTO="memory_hotplug_end"
+PROGRAM="/bin/uname -p", RESULT=="s390*", GOTO="memory_hotplug_end"
+
+ENV{.state}="online"
+PROGRAM="/bin/systemd-detect-virt", RESULT=="none", ENV{.state}="online_movable"
+ATTR{state}=="offline", ATTR{state}="$env{.state}"
+
+LABEL="memory_hotplug_end"
---
I'm not sure I can see anything wrong with this as such, it seems like this would correctly skip any events it wasn't interested in. Maybe there's just way more memory events than anticipated?
This is running in a binary-translation qemu, which is essentially what is happening in the CI jobs where we noticed this. The slower boot times started making jobs time out.
[1] https://git.centos.org/blob/rpms!systemd.git/c7/SOURCES!0659-rules-implement-new-memory-hotplug-policy.patch
Actually, no looking at it, the rule is subtly wrong (thanks to Jens Harbott for pointing me in this direction :) -- this should not trigger on something like a block device
---
# udevadm test /block/sr0
calling: test
version 219
...
rules contain 24576 bytes tokens (2048 * 12 bytes), 12369 bytes strings
1853 strings (23179 bytes), 1230 de-duplicated (11434 bytes), 624 trie nodes used
PROGRAM '/bin/uname -p' /usr/lib/udev/rules.d/40-redhat.rules:8
starting '/bin/uname -p'
'/bin/uname -p'(out) 'x86_64'
'/bin/uname -p' [5462] exit with return code 0
PROGRAM '/bin/systemd-detect-virt' /usr/lib/udev/rules.d/40-redhat.rules:11
starting '/bin/systemd-detect-virt'
'/bin/systemd-detect-virt'(out) 'qemu'
'/bin/systemd-detect-virt' [5463] exit with return code 0
...
ACTION=add
SUBSYSTEM=block
---
The new rule is:
SUBSYSTEM!="memory", ACTION!="add", GOTO="memory_hotplug_end"
so when "SUBSYSTEM=block, ACTION=add" we get "True, False" and don't take the GOTO ...
This explains the initial symptoms reported in [1] very well; a large regression in the boot phase where it's going through adding devices, due to the extra overheads of the forks in here.
[1] https://etherpad.openstack.org/p/dib-centos-slow