Hi Benjamin, I think Dan is onto something.
The following commit was merged in upstream 5.5-rc1, but was backported to 4.15.0-87-generic through upstream stable: commit 9fcc34b1a6dd4b8e5337e2b6ef45e428897eca6b Author: Coly Li <col...@suse.de> Date: Wed Nov 13 16:03:24 2019 +0800 Subject: bcache: at least try to shrink 1 node in bch_mca_scan() Link: https://github.com/torvalds/linux/commit/9fcc34b1a6dd4b8e5337e2b6ef45e428897eca6b It mentions in the description that: > If sc->nr_to_scan is smaller than c->btree_pages, after the above > calculation, variable 'nr' will be 0 and nothing will be shrunk. It is > frequeently observed that only 1 or 2 is set to sc->nr_to_scan and make > nr to be zero. Then bch_mca_scan() will do nothing more then acquiring > and releasing mutex c->bucket_lock. Spending a lot of idle time in bch_mca_scan() waiting on locks seems to be a key symptom from the logs you have gathered. I went and had a look through the commit history, and I think these three patches might solve the problem: commit 125d98edd11464c8e0ec9eaaba7d682d0f832686 Author: Coly Li <col...@suse.de> Date: Fri Jan 24 01:01:40 2020 +0800 Subject: bcache: remove member accessed from struct btree Link: https://github.com/torvalds/linux/commit/125d98edd11464c8e0ec9eaaba7d682d0f832686 commit d5c9c470b01177e4d90cdbf178b8c7f37f5b8795 Author: Coly Li <col...@suse.de> Date: Fri Jan 24 01:01:41 2020 +0800 Subject: bcache: reap c->btree_cache_freeable from the tail in bch_mca_scan() Link: https://github.com/torvalds/linux/commit/d5c9c470b01177e4d90cdbf178b8c7f37f5b8795 commit e3de04469a49ee09c89e80bf821508df458ccee6 Author: Coly Li <col...@suse.de> Date: Fri Jan 24 01:01:42 2020 +0800 Subject: bcache: reap from tail of c->btree_cache in bch_mca_scan() Link: Link: https://github.com/torvalds/linux/commit/e3de04469a49ee09c89e80bf821508df458ccee6 The first commit is a dependency of the other two. The first commit removes a "recently accessed" marker, used to indicate if a particular cache has been used recently, and if it has been, not consider it for cache eviction. The commit mentions that under heavy IO, all caches will end up being recently accessed, and nothing will ever be shrunk. The second commit changes a previous design decision of skipping the first 3 caches to shrink, since it is a common case to call bch_mca_scan() with nr being 1, or 2, just like 0 was common in the very first commit I mentioned. This time, if we land on 1 or 2, the loop exits and nothing happens, and we waste time waiting on locks, just like the very first commit I mentioned. The fix is to try shrink caches from the tail of the list, and not the beginning. The third commit fixes a minor issue where we don't want to re-arrange the linked list, which is what the second commit ended up doing, and instead, just shrink the cache at the end of the linked list, and not change the order. All three commits are clean cherry picks to 4.15.0-118-generic, and I have got a test kernel building for you in: https://launchpad.net/~mruffell/+archive/ubuntu/sf294907-test It should be ready in a few hours time. Make sure the build has finished before trying to install. Please note this package is NOT SUPPORTED by Canonical, and is for TESTING PURPOSES ONLY. ONLY Install in a dedicated test environment. Instructions to install (on a Bionic system): 1) sudo add-apt-repository ppa:mruffell/sf294907-test 2) sudo apt update 3) sudo apt install linux-image-unsigned-4.15.0-118-generic linux-modules-4.15.0-118-generic \ linux-modules-extra-4.15.0-118-generic linux-headers-4.15.0-118 linux-headers-4.15.0-118-generic 4) sudo reboot 5) uname -rv The uname string should be along the lines of 4.15.0-118.119+TEST294907v20201009b1. You may need to change your grub settings if you don't boot into the correct kernel. If you can, schedule some downtime and install the test kernel. Enable bcache shrinking and try reproduce the problem. Hopefully the test kernel is an improvement and fixes your issues. Let me know how the test kernel goes. Thanks, Matthew -- You received this bug notification because you are a member of Kernel Packages, which is subscribed to linux in Ubuntu. https://bugs.launchpad.net/bugs/1898786 Title: Issue with bcache bch_mca_scan causing huge IO wait Status in linux package in Ubuntu: Confirmed Status in linux source package in Bionic: New Bug description: Hello, In short, we faced an issue with a huge IO wait on a bionic Ubuntu 4.15.0-118.119-generic kernel. This is the full list of process and the kernel function they were stuck in [0]. The main issue can probably be summarized by this perf reports * first identify that the cpu are stuck in idle because of something[1] * second, see what kernel function seems to stuck the process kswapd0 and kswapd1 [2]. We could see that this seems to be the mutex_lock in the bch_mca_scan function [3]. After running the command: | sudo bash -c "echo 1 > /sys/fs/bcache/f1a1e8cb-3e6b-40ea-852e- 583c48d0c2b8/internal/btree_shrinker_disabled" The server started to respond normally and the IO wait dropped significantly Here is a trace of the bcache event related lock in the kernel obtained with some bpfcc-tools [4]. klockstat-bpfcc -c bch_ -i 5 -s 3 The trace has been run in parallel with the following command line echo "Shrinker disabled: $(date)"; sleep 60; echo "Enabling shrinker: $(date)"; echo 0 | sudo tee /sys/block/bcache0/bcache/cache/internal/btree_shrinker_disabled ; sleep 60; echo "Disabling shrinker: $(date)"; echo 1 | sudo tee /sys/block/bcache0/bcache/cache/internal/btree_shrinker_disabled; sleep 60; echo "End of test: $(date)" Trying to dig more, we reduced by 20 GB the memory allocated to a VM on the server. * The bcache btree size fluctuation seems "normal" [5] * I noticed that, when the shrinker was enabled,a lot of time was spent in the locks during "bch_btree_insert_node". [6] I decided to check if one of the function called during bch_btree_insert_node was taking longer than usual when the shrinker was enabled. I finally found the "funclatency" tool and tried do have the same approach I had with the klockstat [7]. However, that was inconclusive. I could see there that the bch_btree_insert_node was barely called during the whole duration of the test. Which made me think it's amount of time spent in lock is more due to another process acquiring the lock. I'm going to try to have another go with some perf/klockstat/funclatency focused on bch_mca_scan and the function called there. Also, here are some memory related metrics [8]. Now another perf stacktrace with the command used [9]. Strangely this one doesn't show any bch_mca_scan at all. I enabled the shrinker again, hoping to get more traces, but apparently the timeframe was not right. Not enough load to trigger the cliff resulting in a 1sec IOwait plateau. Which is interesting because that means that without the maximal workload, the kernel can cope with the shrinker. [0]: https://pastebin.ubuntu.com/p/QYXPdsMCWC/ [1]: https://pastebin.ubuntu.com/p/BFsvF7H54r/ [2]: https://pastebin.ubuntu.com/p/35qdsHYHf5/ [3]: https://git.launchpad.net/~ubuntu-kernel/ubuntu/+source/linux/+git/bionic/tree/drivers/md/bcache/btree.c?h=Ubuntu-4.15.0-118.119#n674 [4]: https://pastebin.ubuntu.com/p/qhyqP35fCw/ [5]: https://pastebin.ubuntu.com/p/McjxxqTVjn/ [6]: https://pastebin.ubuntu.com/p/KmrnW4Ng8F/ [7]: https://pastebin.ubuntu.com/p/fSX4c7tTFV/ [8]: https://pastebin.ubuntu.com/p/CZgXkgKhmJ/ [9]: https://pastebin.ubuntu.com/p/DzKCP8NGdf/ ==================== $ cat /proc/version_signature Ubuntu 4.15.0-118.119-generic 4.15.18 ProblemType: Bug DistroRelease: Ubuntu 18.04 Package: linux-image-4.15.0-118-generic 4.15.0-118.119 ProcVersionSignature: User Name 4.15.0-118.119-generic 4.15.18 Uname: Linux 4.15.0-118-generic x86_64 AlsaDevices: total 0 crw-rw---- 1 root audio 116, 1 Sep 29 10:04 seq crw-rw---- 1 root audio 116, 33 Sep 29 10:04 timer AplayDevices: Error: [Errno 2] No such file or directory: 'aplay': 'aplay' ApportVersion: 2.20.9-0ubuntu7.16 Architecture: amd64 ArecordDevices: Error: [Errno 2] No such file or directory: 'arecord': 'arecord' AudioDevicesInUse: Error: command ['fuser', '-v', '/dev/snd/seq', '/dev/snd/timer'] failed with exit code 1: Date: Tue Oct 6 20:36:18 2020 IwConfig: Error: [Errno 2] No such file or directory: 'iwconfig': 'iwconfig' MachineType: HP ProLiant DL380 G7 PciMultimedia: ProcFB: 0 radeondrmfb ProcKernelCmdLine: BOOT_IMAGE=/boot/vmlinuz-4.15.0-118-generic root=UUID=c6ad1629-a506-4043-a339-6d57f0708d12 ro console=ttyS1,115200 nosplash RelatedPackageVersions: linux-restricted-modules-4.15.0-118-generic N/A linux-backports-modules-4.15.0-118-generic N/A linux-firmware 1.173.18 RfKill: Error: [Errno 2] No such file or directory: 'rfkill': 'rfkill' SourcePackage: linux UpgradeStatus: Upgraded to bionic on 2019-09-27 (375 days ago) dmi.bios.date: 05/05/2011 dmi.bios.vendor: HP dmi.bios.version: P67 dmi.chassis.type: 23 dmi.chassis.vendor: HP dmi.modalias: dmi:bvnHP:bvrP67:bd05/05/2011:svnHP:pnProLiantDL380G7:pvr:cvnHP:ct23:cvr: dmi.product.family: ProLiant dmi.product.name: ProLiant DL380 G7 dmi.sys.vendor: HP To manage notifications about this bug go to: https://bugs.launchpad.net/ubuntu/+source/linux/+bug/1898786/+subscriptions -- Mailing list: https://launchpad.net/~kernel-packages Post to : kernel-packages@lists.launchpad.net Unsubscribe : https://launchpad.net/~kernel-packages More help : https://help.launchpad.net/ListHelp
