Description of problem: gvfs-udisks2-volume-monitor gobbles 100% CPU when my system is doing its weekly RAID check: top - 08:47:55 up 44 days, 16:45, 7 users, load average: 5.16, 5.16, 5.19 Tasks: 643 total, 2 running, 640 sleeping, 0 stopped, 1 zombie %Cpu(s): 7.0 us, 9.7 sy, 0.0 ni, 65.9 id, 17.1 wa, 0.2 hi, 0.1 si, 0.0 st KiB Mem : 32626844 total, 556228 free, 21471528 used, 10599088 buff/cache KiB Swap: 0 total, 0 free, 0 used. 8695992 avail Mem PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND 16460 paul 20 0 482324 68548 4120 R 106.0 0.2 604:44.10 gvfs-udisks2-vo 10936 paul 20 0 6415828 2.676g 138860 S 22.6 8.6 15230:37 firefox 5512 qemu 20 0 4308684 3.063g 7400 S 7.3 9.8 4656:23 qemu-system-x86 5355 qemu 20 0 5457992 3.906g 4596 S 6.0 12.6 4255:09 qemu-system-x86 29 root 20 0 0 0 0 S 2.0 0.0 33:33.35 rcuos/2 956 root 20 0 0 0 0 S 2.0 0.0 41:09.79 md123_raid1 3094 paul 9 -11 3718908 31916 25184 S 1.3 0.1 475:17.47 pulseaudio 15341 paul 20 0 2295656 291620 51048 S 1.0 0.9 614:51.68 chrome 3016 paul 20 0 3579680 869972 105736 S 0.7 2.7 261:02.84 gnome-shell 21393 root 20 0 0 0 0 D 0.7 0.0 1:29.50 md123_resync 469 root 0 -20 0 0 0 S 0.3 0.0 2:57.01 kworker/0:1H 1362 root 20 0 0 0 0 D 0.3 0.0 7:20.10 jbd2/dm-16-8 2359 gdm 20 0 1277716 15108 6232 S 0.3 0.0 9:11.07 gnome-settings- 5092 apache 20 0 299052 12972 7944 S 0.3 0.0 0:01.47 httpd 5275 paul 20 0 1603492 176464 29992 S 0.3 0.5 109:07.40 virt-manager 12662 root 20 0 539776 261180 4960 S 0.3 0.8 4:31.38 bacula-fd This really slows down my backup when /etc/cron.d/raid-check kicks off on Sunday mornings. It looks very similar to issues I (and others) used to have with gvfs-gdu-volume-monitor on older versions of Fedora/Ubuntu, e.g. https://bugzilla.redhat.com/show_bug.cgi?id=600592 https://bugs.launchpad.net/ubuntu/+source/gnome-disk-utility/+bug/890337 Version-Release number of selected component (if applicable): gvfs-1.30.4-1.fc25.x86_64 How reproducible: Happens every Sunday morning. Could probably trigger it manually using /usr/sbin/raid-check on a system with mdraid devices.
Thanks for your bug report. It produces probably too many events, which needs to be handled by the monitor... What events do you see using "udisksctl monitor" during the check? Are some events printed also by "gvfs-mount -o"?
Created attachment 1269348 [details] udisksctl monitor output (In reply to Ondrej Holy from comment #1) > Thanks for your bug report. It produces probably too many events, which > needs to be handled by the monitor... > > What events do you see using "udisksctl monitor" during the check? Are some > events printed also by "gvfs-mount -o"? No output from "gvfs-mount -o"; lots of activity from "udisksctl monitor" as per attachment.
Thanks. Hmm, GVfs rereads configuration of all mounts, volumes, and drives with each "changed" [1] signal for UDisksClient. So, it is a quite problem if something (i.e. raid-check) generates tons of changes. The docs said that it is rate limited, but obviously, it is not enough. Unfortunately, all those events are not interesting for GVfs, because there isn't any output from "gvfs-mount -o"... Vojtech, don't you have any idea what we can do with it? Maybe would be nice to have a way for configuring rate limiting, and interesting events... [1] https://udisks.freedesktop.org/docs/latest/UDisksClient.html#UDisksClient-changed
The "change" signal is emitted for every property change, but it sometimes doesn't make sense -- we emit the signal even for progress related changes (e.g. "SyncRemainingTime" here for the RAID check) and "job objects" (DBus objects representing the progress). We will fix this in udisks and emit the "change" signal only if the device/format is actually changed and not for these "progress" changes.
udisks2-2.6.5-1.fc26 has been submitted as an update to Fedora 26. https://bodhi.fedoraproject.org/updates/FEDORA-2017-b1fd799ba3
udisks2-2.6.5-1.fc26 has been pushed to the Fedora 26 testing repository. If problems still persist, please make note of it in this bug report. See https://fedoraproject.org/wiki/QA:Updates_Testing for instructions on how to install test updates. You can provide feedback for this update here: https://bodhi.fedoraproject.org/updates/FEDORA-2017-b1fd799ba3
udisks2-2.6.5-1.fc26 has been pushed to the Fedora 26 stable repository. If problems still persist, please make note of it in this bug report.
This is an F-25 bug: is there any plan of doing a fix there?
storaged-2.6.2-4.fc25 has been submitted as an update to Fedora 25. https://bodhi.fedoraproject.org/updates/FEDORA-2017-f18713a47e
Paul Howarth: F25 uses storaged. I've submitted new build with patch to fix this to bodhi.
storaged-2.6.2-4.fc25 has been pushed to the Fedora 25 testing repository. If problems still persist, please make note of it in this bug report. See https://fedoraproject.org/wiki/QA:Updates_Testing for instructions on how to install test updates. You can provide feedback for this update here: https://bodhi.fedoraproject.org/updates/FEDORA-2017-f18713a47e
storaged-2.6.2-4.fc25 has been pushed to the Fedora 25 stable repository. If problems still persist, please make note of it in this bug report.
The storaged update has certainly had a beneficial effect for me (following a reboot) - thanks!
Perhaps I commented too soon. This morning it's gobbling CPU again, though maybe not as much as before. I'm getting stuff like this from "udisksctl monitor": # udisksctl monitor Monitoring the udisks daemon. Press Ctrl+C to exit. 10:41:00.731: The udisks-daemon is running (name-owner :1.59). 10:41:01.610: /org/freedesktop/UDisks2/jobs/14: org.freedesktop.UDisks2.Job: Properties Changed ExpectedEndTime: 1496538943809595 Rate: 21525504 10:41:01.610: /org/freedesktop/UDisks2/mdraid/62e4a852_e89afb38_9e06909d_5c8f1dad: org.freedesktop.UDisks2.MDRaid: Properties Changed SyncRemainingTime: 4523707911 SyncRate: 21525504 10:41:02.610: /org/freedesktop/UDisks2/jobs/14: org.freedesktop.UDisks2.Job: Properties Changed ExpectedEndTime: 1496539013148962 Rate: 21182464 Progress: 0.39542758613949125 10:41:02.610: /org/freedesktop/UDisks2/mdraid/62e4a852_e89afb38_9e06909d_5c8f1dad: org.freedesktop.UDisks2.MDRaid: Properties Changed SyncRemainingTime: 4593047278 SyncRate: 21182464 SyncCompleted: 0.39542758613949125 10:41:03.610: /org/freedesktop/UDisks2/jobs/14: org.freedesktop.UDisks2.Job: Properties Changed ExpectedEndTime: 1496539068882190 Rate: 20928512 10:41:03.610: /org/freedesktop/UDisks2/mdraid/62e4a852_e89afb38_9e06909d_5c8f1dad: org.freedesktop.UDisks2.MDRaid: Properties Changed SyncRemainingTime: 4648780506 SyncRate: 20928512 10:41:04.610: /org/freedesktop/UDisks2/jobs/14: org.freedesktop.UDisks2.Job: Properties Changed ExpectedEndTime: 1496538981615726 Rate: 21328896 10:41:04.610: /org/freedesktop/UDisks2/mdraid/62e4a852_e89afb38_9e06909d_5c8f1dad: org.freedesktop.UDisks2.MDRaid: Properties Changed SyncRemainingTime: 4561514042 SyncRate: 21328896 10:41:05.610: /org/freedesktop/UDisks2/jobs/14: org.freedesktop.UDisks2.Job: Properties Changed ExpectedEndTime: 1496538977239964 Rate: 21349376 10:41:05.611: /org/freedesktop/UDisks2/mdraid/62e4a852_e89afb38_9e06909d_5c8f1dad: org.freedesktop.UDisks2.MDRaid: Properties Changed SyncRemainingTime: 4557138280 SyncRate: 21349376 10:41:06.610: /org/freedesktop/UDisks2/jobs/14: org.freedesktop.UDisks2.Job: Properties Changed ExpectedEndTime: 1496538887459968 Rate: 21778432 10:41:06.610: /org/freedesktop/UDisks2/mdraid/62e4a852_e89afb38_9e06909d_5c8f1dad: org.freedesktop.UDisks2.MDRaid: Properties Changed SyncRemainingTime: 4467358284 SyncRate: 21778432 10:41:07.609: /org/freedesktop/UDisks2/jobs/14: org.freedesktop.UDisks2.Job: Properties Changed ExpectedEndTime: 1496538977597529 Rate: 21322752 Progress: 0.39613414824854043 10:41:07.610: /org/freedesktop/UDisks2/mdraid/62e4a852_e89afb38_9e06909d_5c8f1dad: org.freedesktop.UDisks2.MDRaid: Properties Changed SyncRemainingTime: 4557495845 SyncRate: 21322752 SyncCompleted: 0.39613414824854043 10:41:08.610: /org/freedesktop/UDisks2/jobs/14: org.freedesktop.UDisks2.Job: Properties Changed ExpectedEndTime: 1496538822826620 Rate: 22072320 10:41:08.610: /org/freedesktop/UDisks2/mdraid/62e4a852_e89afb38_9e06909d_5c8f1dad: org.freedesktop.UDisks2.MDRaid: Properties Changed SyncRemainingTime: 4402724936 SyncRate: 22072320 10:41:09.611: /org/freedesktop/UDisks2/jobs/14: org.freedesktop.UDisks2.Job: Properties Changed ExpectedEndTime: 1496538768559162 Rate: 22347776 10:41:09.611: /org/freedesktop/UDisks2/mdraid/62e4a852_e89afb38_9e06909d_5c8f1dad: org.freedesktop.UDisks2.MDRaid: Properties Changed SyncRemainingTime: 4348457478 SyncRate: 22347776 10:41:10.610: /org/freedesktop/UDisks2/jobs/14: org.freedesktop.UDisks2.Job: Properties Changed ExpectedEndTime: 1496538915849279 Rate: 21615616 10:41:10.610: /org/freedesktop/UDisks2/mdraid/62e4a852_e89afb38_9e06909d_5c8f1dad: org.freedesktop.UDisks2.MDRaid: Properties Changed SyncRemainingTime: 4495747595 SyncRate: 21615616 10:41:11.610: /org/freedesktop/UDisks2/jobs/14: org.freedesktop.UDisks2.Job: Properties Changed ExpectedEndTime: 1496538867183970 Rate: 21852160 10:41:11.610: /org/freedesktop/UDisks2/mdraid/62e4a852_e89afb38_9e06909d_5c8f1dad: org.freedesktop.UDisks2.MDRaid: Properties Changed SyncRemainingTime: 4447082286 SyncRate: 21852160 10:41:12.610: /org/freedesktop/UDisks2/jobs/14: org.freedesktop.UDisks2.Job: Properties Changed ExpectedEndTime: 1496538938874025 Rate: 21473280 Progress: 0.39703822195579652 10:41:12.610: /org/freedesktop/UDisks2/mdraid/62e4a852_e89afb38_9e06909d_5c8f1dad: org.freedesktop.UDisks2.MDRaid: Properties Changed SyncRemainingTime: 4518772341 SyncRate: 21473280 SyncCompleted: 0.39703822195579652 10:41:13.610: /org/freedesktop/UDisks2/jobs/14: org.freedesktop.UDisks2.Job: Properties Changed ExpectedEndTime: 1496539154720251 Rate: 20494336 10:41:13.610: /org/freedesktop/UDisks2/mdraid/62e4a852_e89afb38_9e06909d_5c8f1dad: org.freedesktop.UDisks2.MDRaid: Properties Changed SyncRemainingTime: 4734618567 SyncRate: 20494336