Bug 1793527

Summary: systemd sends tons of useless PropertiesChanged messages when a mount happens [rhel-7.9.z]
Product: Red Hat Enterprise Linux 7 Reporter: Renaud Métrich <rmetrich>
Component: systemdAssignee: Michal Sekletar <msekleta>
Status: CLOSED ERRATA QA Contact: Frantisek Sumsal <fsumsal>
Severity: urgent Docs Contact:
Priority: urgent    
Version: 7.7CC: akaiser, ckoep, dchong, fhirtz, ikent, jamacku, jreznik, lnykryn, mmatsuya, mrobson, msekleta, ovasik, qguo, sbroz, sfu, subhat, systemd-maint-list, vhernand
Target Milestone: rcKeywords: Patch, ZStream
Target Release: ---   
Hardware: All   
OS: Linux   
Whiteboard:
Fixed In Version: Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of:
: 1917516 1920502 (view as bug list) Environment:
Last Closed: 2020-11-10 12:58:04 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Bug Depends On: 1793533    
Bug Blocks: 1801675, 1917516, 1920502    

Description Renaud Métrich 2020-01-21 14:15:28 UTC
Description of problem:

This is kinda a continuation of BZ #1769928, this time focused on optimizing DBus messages being sent.
It appears that a single "mount" operation on a single file system (including a "mount -o remount") makes systemd send 2 PropertiesChanged message per mount point seen on the system (even if the mount point is not touched).
This creates a huge systemd load, and potentially a huge load on DBus.

The root cause behind this is an absence of caching of the /proc/1/mountinfo table.


Version-Release number of selected component (if applicable):

systemd-219 AND systemd-239 (RHEL8)


How reproducible:

Always


Steps to Reproduce:
1. Set up a system with 200 mount points on a "data" volume group

  # vgcreate data /dev/sdb
  # for i in $(seq 1 200); do lvcreate -n lv$i -L 10M data; mkfs.ext4 /dev/data/lv$i; echo "/dev/mapper/data-lv$i /data/lv$i ext4 defaults 0 0" >> /etc/fstab; mkdir -p /data/lv$i; done
  # systemctl daemon-reload
  # mount -a

2. Monitor systemd's "sendmsg" while performing 100 remounts of /data/lv1

  In a terminal:
  # timeout 1m strace -ttTvyy -o /tmp/systemd.strace -s 1024 -e sendmsg -p 1

  In another terminal:
  # for i in $(seq 1 100); do mount -o remount /data/lv1; sleep 0.1; done

3. Count the number of PropertiesChanged messages sent

  # grep -c PropertiesChanged /tmp/systemd.strace

Actual results:

40600


Expected results:

100 (ideally) or 200 (observed with a patch because there is a PropertiesChanged message for "/" seen, holding "/data/lv1")


Additional info:

The load is due to systemd parsing the whole /proc/1/mountinfo table and UDEV database to construct "description" field of corresponding Device units, requiring tons of malloc().
Finally all this gets sent through DBus "blindly" (no one cares about these messages).

A simple optimization (count dropping to 200) is to only send data when "description" field changes.

A better optimization would be to cache the content of /proc/1/mountinfo and only recompute the "description" field based on UDEV database for the modified mount points, but it's harder to do.

Comment 11 Lukáš Nykrýn 2020-08-11 16:02:59 UTC
fix merged to github rhel-7.9 branch -> https://github.com/systemd-rhel/rhel-7/pull/119

Comment 52 errata-xmlrpc 2020-11-10 12:58:04 UTC
Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory (systemd bug fix and enhancement update), and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://access.redhat.com/errata/RHBA-2020:5007