Re: RBD with PWL cache shows poor performance compared to cache device
On Wed, 28 Jun 2023 at 22:44, Ilya Dryomov <idryomov@redhat.com> wrote:
** TL;DR
In testing, the write latency performance of a PWL-cache backed RBD disk was 2 orders of magnitude worse than the disk holding the PWL cache.
** Summary
I was hoping that PWL cache might be a good solution to the problem of write latency requirements of etcd when running a kubernetes control plane on ceph. Etcd is extremely write latency sensitive and becomes unstable if write latency is too high. The etcd workload can be characterised by very small (~4k) writes with a queue depth of 1. Throughput, even on a busy system, is normally very low. As etcd is distributed and can safely handle the loss of un-flushed data from a single node, a local ssd PWL cache for etcd looked like an ideal solution.
Right, this is exactly the use case that the PWL cache is supposed to address.
Good to know!
My expectation was that adding a PWL cache on a local SSD to an RBD-backed would improve write latency to something approaching the write latency performance of the local SSD. However, in my testing adding a PWL cache to an rbd-backed VM increased write latency by approximately 4x over not using a PWL cache. This was over 100x more than the write latency performance of the underlying SSD.
My expectation was based on the documentation here: https://docs.ceph.com/en/quincy/rbd/rbd-persistent-write-log-cache/
“The cache provides two different persistence modes. In persistent-on-write mode, the writes are completed only when they are persisted to the cache device and will be readable after a crash. In persistent-on-flush mode, the writes are completed as soon as it no longer needs the caller’s data buffer to complete the writes, but does not guarantee that writes will be readable after a crash. The data is persisted to the cache device when a flush request is received.”
** Method
2 systems, 1 running single-node Ceph Quincy (17.2.6), the other running libvirt and mounting a VM’s disk with librbd (also 17.2.6) from the first node.
All performance testing is from the libvirt system. I tested write latency performance:
* Inside the VM without a PWL cache * Of the PWL device directly from the host (direct to filesystem, no VM) * Inside the VM with a PWL cache
I am testing with fio. Specifically I am running a containerised test, executed with: podman run --volume .:/var/lib/etcd:Z quay.io/openshift-scale/etcd-perf
This container runs: fio --rw=write --ioengine=sync --fdatasync=1 --directory=/var/lib/etcd --size=100m --bs=8000 --name=etcd_perf --output-format=json --runtime=60 --time_based=1
And extracts sync.lat_ns.percentile["99.000000"]
Matthew, do you have the rest of the fio output captured? It would be interesting to see if it's just the 99th percentile that is bad or the PWL cache is worse in general.
Sure. With PWL cache: https://paste.openstack.org/show/820504/ Without PWL cache: https://paste.openstack.org/show/b35e71zAwtYR2hjmSRtR/ With PWL cache, 'rbd_cache'=false: https://paste.openstack.org/show/byp8ZITPzb3r9bb06cPf/
** Results
All results were stable across multiple runs within a small margin of error.
* rbd no cache: 1417216 ns * pwl cache device: 44288 ns * rbd with pwl cache: 5210112 ns
Note that by adding a PWL cache we increase write latency by approximately 4x, which is more than 100x than the underlying device.
** Hardware
2 x Dell R640s, each with Xeon Silver 4216 CPU @ 2.10GHz and 192G RAM Storage under test: 2 x SAMSUNG MZ7KH480HAHQ0D3 SSDs attached to PERC H730P Mini (Embedded)
OS installed on rotational disks
N.B. Linux incorrectly detects these disks as rotational, which I assume relates to weird behaviour by the PERC controller. I remembered to manually correct this on the ‘client’ machine for the PWL cache, but at OSD configuration time ceph would have detected them as rotational. They are not rotational.
** Ceph Configuration
CentOS Stream 9
# ceph version ceph version 17.2.6 (d7ff0d10654d2280e08f1ab989c7cdf3064446a5) quincy (stable)
Single node installation with cephadm. 2 OSDs, one on each SSD. 1 pool with size 2
** Client Configuration
Fedora 38 Librbd1-17.2.6-3.fc38.x86_64
PWL cache is XFS filesystem with 4k block size, matching the underlying device. The filesystem uses the whole block device. There is no other load on the system.
** RBD Configuration
# rbd config image list libvirt-pool/pwl-test | grep cache rbd_cache true
I wonder if rbd_cache should have been set to false here to disable the default volatile cache. Other than that, I don't see anything obviously wrong with the configuration at first sight.
I added some full output for this above.
-- Ilya
config rbd_cache_block_writes_upfront false config rbd_cache_max_dirty 25165824 config rbd_cache_max_dirty_age 1.000000 config rbd_cache_max_dirty_object 0 config rbd_cache_policy writeback pool rbd_cache_size 33554432 config rbd_cache_target_dirty 16777216 config rbd_cache_writethrough_until_flush true pool rbd_parent_cache_enabled false config rbd_persistent_cache_mode ssd pool rbd_persistent_cache_path /var/lib/libvirt/images/pwl pool rbd_persistent_cache_size 1073741824 config rbd_plugins pwl_cache pool
# rbd status libvirt-pool/pwl-test Watchers: watcher=10.1.240.27:0/1406459716 client.14475 cookie=140282423200720 Persistent cache state: host: dell-r640-050 path: /var/lib/libvirt/images/pwl/rbd-pwl.libvirt-pool.37e947fd216b.pool size: 1 GiB mode: ssd stats_timestamp: Mon Jun 26 11:29:21 2023 present: true empty: false clean: true allocated: 180 MiB cached: 135 MiB dirty: 0 B free: 844 MiB hits_full: 1 / 0% hits_partial: 3 / 0% misses: 21952 hit_bytes: 6 KiB / 0% miss_bytes: 349 MiB
-- Matthew Booth
Hi Matthew! On 6/29/23 06:23, Matthew Booth wrote:
On Wed, 28 Jun 2023 at 22:44, Ilya Dryomov <idryomov@redhat.com> wrote:
** TL;DR
In testing, the write latency performance of a PWL-cache backed RBD disk was 2 orders of magnitude worse than the disk holding the PWL cache.
** Summary
I was hoping that PWL cache might be a good solution to the problem of write latency requirements of etcd when running a kubernetes control plane on ceph. Etcd is extremely write latency sensitive and becomes unstable if write latency is too high. The etcd workload can be characterised by very small (~4k) writes with a queue depth of 1. Throughput, even on a busy system, is normally very low. As etcd is distributed and can safely handle the loss of un-flushed data from a single node, a local ssd PWL cache for etcd looked like an ideal solution.
Right, this is exactly the use case that the PWL cache is supposed to address. Good to know!
My expectation was that adding a PWL cache on a local SSD to an RBD-backed would improve write latency to something approaching the write latency performance of the local SSD. However, in my testing adding a PWL cache to an rbd-backed VM increased write latency by approximately 4x over not using a PWL cache. This was over 100x more than the write latency performance of the underlying SSD.
My expectation was based on the documentation here: https://docs.ceph.com/en/quincy/rbd/rbd-persistent-write-log-cache/
“The cache provides two different persistence modes. In persistent-on-write mode, the writes are completed only when they are persisted to the cache device and will be readable after a crash. In persistent-on-flush mode, the writes are completed as soon as it no longer needs the caller’s data buffer to complete the writes, but does not guarantee that writes will be readable after a crash. The data is persisted to the cache device when a flush request is received.”
** Method
2 systems, 1 running single-node Ceph Quincy (17.2.6), the other running libvirt and mounting a VM’s disk with librbd (also 17.2.6) from the first node.
All performance testing is from the libvirt system. I tested write latency performance:
* Inside the VM without a PWL cache * Of the PWL device directly from the host (direct to filesystem, no VM) * Inside the VM with a PWL cache
I am testing with fio. Specifically I am running a containerised test, executed with: podman run --volume .:/var/lib/etcd:Z quay.io/openshift-scale/etcd-perf
This container runs: fio --rw=write --ioengine=sync --fdatasync=1 --directory=/var/lib/etcd --size=100m --bs=8000 --name=etcd_perf --output-format=json --runtime=60 --time_based=1
And extracts sync.lat_ns.percentile["99.000000"]
Matthew, do you have the rest of the fio output captured? It would be interesting to see if it's just the 99th percentile that is bad or the PWL cache is worse in general. Sure.
With PWL cache: https://paste.openstack.org/show/820504/ Without PWL cache: https://paste.openstack.org/show/b35e71zAwtYR2hjmSRtR/ With PWL cache, 'rbd_cache'=false: https://paste.openstack.org/show/byp8ZITPzb3r9bb06cPf/
Also, how's the CPU usage client side? I would be very curious to see if unwindpmp shows anything useful (especially lock contention): https://github.com/markhpc/uwpmp Just attach it to the client-side process and start out with something like 100 samples (more are better but take longer). You can run it like: ./unwindpmp -n 100 -p <pid> Mark
** Results
All results were stable across multiple runs within a small margin of error.
* rbd no cache: 1417216 ns * pwl cache device: 44288 ns * rbd with pwl cache: 5210112 ns
Note that by adding a PWL cache we increase write latency by approximately 4x, which is more than 100x than the underlying device.
** Hardware
2 x Dell R640s, each with Xeon Silver 4216 CPU @ 2.10GHz and 192G RAM Storage under test: 2 x SAMSUNG MZ7KH480HAHQ0D3 SSDs attached to PERC H730P Mini (Embedded)
OS installed on rotational disks
N.B. Linux incorrectly detects these disks as rotational, which I assume relates to weird behaviour by the PERC controller. I remembered to manually correct this on the ‘client’ machine for the PWL cache, but at OSD configuration time ceph would have detected them as rotational. They are not rotational.
** Ceph Configuration
CentOS Stream 9
# ceph version ceph version 17.2.6 (d7ff0d10654d2280e08f1ab989c7cdf3064446a5) quincy (stable)
Single node installation with cephadm. 2 OSDs, one on each SSD. 1 pool with size 2
** Client Configuration
Fedora 38 Librbd1-17.2.6-3.fc38.x86_64
PWL cache is XFS filesystem with 4k block size, matching the underlying device. The filesystem uses the whole block device. There is no other load on the system.
** RBD Configuration
# rbd config image list libvirt-pool/pwl-test | grep cache rbd_cache true
I wonder if rbd_cache should have been set to false here to disable the default volatile cache. Other than that, I don't see anything obviously wrong with the configuration at first sight. I added some full output for this above.
-- Ilya
config rbd_cache_block_writes_upfront false config rbd_cache_max_dirty 25165824 config rbd_cache_max_dirty_age 1.000000 config rbd_cache_max_dirty_object 0 config rbd_cache_policy writeback pool rbd_cache_size 33554432 config rbd_cache_target_dirty 16777216 config rbd_cache_writethrough_until_flush true pool rbd_parent_cache_enabled false config rbd_persistent_cache_mode ssd pool rbd_persistent_cache_path /var/lib/libvirt/images/pwl pool rbd_persistent_cache_size 1073741824 config rbd_plugins pwl_cache pool
# rbd status libvirt-pool/pwl-test Watchers: watcher=10.1.240.27:0/1406459716 client.14475 cookie=140282423200720 Persistent cache state: host: dell-r640-050 path: /var/lib/libvirt/images/pwl/rbd-pwl.libvirt-pool.37e947fd216b.pool size: 1 GiB mode: ssd stats_timestamp: Mon Jun 26 11:29:21 2023 present: true empty: false clean: true allocated: 180 MiB cached: 135 MiB dirty: 0 B free: 844 MiB hits_full: 1 / 0% hits_partial: 3 / 0% misses: 21952 hit_bytes: 6 KiB / 0% miss_bytes: 349 MiB
-- Best Regards, Mark Nelson Head of R&D (USA) Clyso GmbH p: +49 89 21552391 12 a: Loristraße 8 | 80335 München | Germany w: https://clyso.com | e: mark.nelson@clyso.com We are hiring: https://www.clyso.com/jobs/
On Thu, 29 Jun 2023 at 14:11, Mark Nelson <mark.nelson@clyso.com> wrote:
This container runs: fio --rw=write --ioengine=sync --fdatasync=1 --directory=/var/lib/etcd --size=100m --bs=8000 --name=etcd_perf --output-format=json --runtime=60 --time_based=1
And extracts sync.lat_ns.percentile["99.000000"]
Matthew, do you have the rest of the fio output captured? It would be interesting to see if it's just the 99th percentile that is bad or the PWL cache is worse in general. Sure.
With PWL cache: https://paste.openstack.org/show/820504/ Without PWL cache: https://paste.openstack.org/show/b35e71zAwtYR2hjmSRtR/ With PWL cache, 'rbd_cache'=false: https://paste.openstack.org/show/byp8ZITPzb3r9bb06cPf/
Also, how's the CPU usage client side? I would be very curious to see if unwindpmp shows anything useful (especially lock contention):
https://github.com/markhpc/uwpmp
Just attach it to the client-side process and start out with something like 100 samples (more are better but take longer). You can run it like:
./unwindpmp -n 100 -p <pid>
I've included the output in this gist: https://gist.github.com/mdbooth/2d68b7e081a37e27b78fe396d771427d That gist contains 4 runs: 2 with PWL enabled and 2 without, and also a markdown file explaining the collection method. Matt -- Matthew Booth
On 7/3/23 04:53, Matthew Booth wrote:
On Thu, 29 Jun 2023 at 14:11, Mark Nelson <mark.nelson@clyso.com> wrote:
This container runs: fio --rw=write --ioengine=sync --fdatasync=1 --directory=/var/lib/etcd --size=100m --bs=8000 --name=etcd_perf --output-format=json --runtime=60 --time_based=1
And extracts sync.lat_ns.percentile["99.000000"] Matthew, do you have the rest of the fio output captured? It would be interesting to see if it's just the 99th percentile that is bad or the PWL cache is worse in general. Sure.
With PWL cache: https://paste.openstack.org/show/820504/ Without PWL cache: https://paste.openstack.org/show/b35e71zAwtYR2hjmSRtR/ With PWL cache, 'rbd_cache'=false: https://paste.openstack.org/show/byp8ZITPzb3r9bb06cPf/
Also, how's the CPU usage client side? I would be very curious to see if unwindpmp shows anything useful (especially lock contention):
https://github.com/markhpc/uwpmp
Just attach it to the client-side process and start out with something like 100 samples (more are better but take longer). You can run it like:
./unwindpmp -n 100 -p <pid> I've included the output in this gist: https://gist.github.com/mdbooth/2d68b7e081a37e27b78fe396d771427d
That gist contains 4 runs: 2 with PWL enabled and 2 without, and also a markdown file explaining the collection method.
Matt
Thanks Matt! I looked through the output. Looks like the symbols might have gotten mangled. I'm not an expert on the RBD client, but I don't think we would really be calling into rbd_group_snap_rollback_with_progress from librbd::cache::pwl::ssd::WriteLogEntry::writeback_bl. Was it possible you used the libdw backend for unwindpmp? libdw sometimes gives strange/mangled callgraphs, but I haven't seen it before with libunwind. Hopefully Congmin Yin or Ilya can confirm if it's garbage. So with that said, assuming we can trust these callgraphs at all, it looks like it might be worth looking at the latency of the AbstractWriteLog, librbd::cache::pwl::ssd::WriteLogEntry::writeback_bl, and possibly usage of librados::v14_2_0::IoCtx::object_list. On the QEMU side, possibly the latency of rbd_aio_flush in both cases. Also it's possible we might have md_config_t get_val/set_val in the hot path somewhere though it looks minor. If the rbd_group_snap_rollback_with_progress usage is real, it's significantly more prevalent in the PWL callgraphs. Without knowing more about how the PWL cache works, I'm not sure if any of this is meaningful or not though. Mark Best Regards, Mark Nelson Head of R&D (USA) Clyso GmbH p: +49 89 21552391 12 a: Loristraße 8 | 80335 München | Germany w: https://clyso.com | e: mark.nelson@clyso.com We are hiring: https://www.clyso.com/jobs/
On Mon, Jul 3, 2023 at 6:58 PM Mark Nelson <mark.nelson@clyso.com> wrote:
On 7/3/23 04:53, Matthew Booth wrote:
On Thu, 29 Jun 2023 at 14:11, Mark Nelson <mark.nelson@clyso.com> wrote:
This container runs: fio --rw=write --ioengine=sync --fdatasync=1 --directory=/var/lib/etcd --size=100m --bs=8000 --name=etcd_perf --output-format=json --runtime=60 --time_based=1
And extracts sync.lat_ns.percentile["99.000000"] Matthew, do you have the rest of the fio output captured? It would be interesting to see if it's just the 99th percentile that is bad or the PWL cache is worse in general. Sure.
With PWL cache: https://paste.openstack.org/show/820504/ Without PWL cache: https://paste.openstack.org/show/b35e71zAwtYR2hjmSRtR/ With PWL cache, 'rbd_cache'=false: https://paste.openstack.org/show/byp8ZITPzb3r9bb06cPf/
Also, how's the CPU usage client side? I would be very curious to see if unwindpmp shows anything useful (especially lock contention):
https://github.com/markhpc/uwpmp
Just attach it to the client-side process and start out with something like 100 samples (more are better but take longer). You can run it like:
./unwindpmp -n 100 -p <pid> I've included the output in this gist: https://gist.github.com/mdbooth/2d68b7e081a37e27b78fe396d771427d
That gist contains 4 runs: 2 with PWL enabled and 2 without, and also a markdown file explaining the collection method.
Matt
Thanks Matt! I looked through the output. Looks like the symbols might have gotten mangled. I'm not an expert on the RBD client, but I don't think we would really be calling into rbd_group_snap_rollback_with_progress from librbd::cache::pwl::ssd::WriteLogEntry::writeback_bl. Was it possible you used the libdw backend for unwindpmp? libdw sometimes gives strange/mangled callgraphs, but I haven't seen it before with libunwind. Hopefully Congmin Yin or Ilya can confirm if it's garbage.
So with that said, assuming we can trust these callgraphs at all, it looks like it might be worth looking at the latency of the AbstractWriteLog, librbd::cache::pwl::ssd::WriteLogEntry::writeback_bl, and possibly usage of librados::v14_2_0::IoCtx::object_list. On the
Hi Mark, Both rbd_group_snap_rollback_with_progress and librados::v14_2_0::IoCtx::object_list entries don't make sense to me, so I'd say it's garbage. Thanks, Ilya
On Mon, 3 Jul 2023 at 18:33, Ilya Dryomov <idryomov@gmail.com> wrote:
On Mon, Jul 3, 2023 at 6:58 PM Mark Nelson <mark.nelson@clyso.com> wrote:
On 7/3/23 04:53, Matthew Booth wrote:
On Thu, 29 Jun 2023 at 14:11, Mark Nelson <mark.nelson@clyso.com> wrote:
> This container runs: > fio --rw=write --ioengine=sync --fdatasync=1 > --directory=/var/lib/etcd --size=100m --bs=8000 --name=etcd_perf > --output-format=json --runtime=60 --time_based=1 > > And extracts sync.lat_ns.percentile["99.000000"] Matthew, do you have the rest of the fio output captured? It would be interesting to see if it's just the 99th percentile that is bad or the PWL cache is worse in general. Sure.
With PWL cache: https://paste.openstack.org/show/820504/ Without PWL cache: https://paste.openstack.org/show/b35e71zAwtYR2hjmSRtR/ With PWL cache, 'rbd_cache'=false: https://paste.openstack.org/show/byp8ZITPzb3r9bb06cPf/
Also, how's the CPU usage client side? I would be very curious to see if unwindpmp shows anything useful (especially lock contention):
https://github.com/markhpc/uwpmp
Just attach it to the client-side process and start out with something like 100 samples (more are better but take longer). You can run it like:
./unwindpmp -n 100 -p <pid> I've included the output in this gist: https://gist.github.com/mdbooth/2d68b7e081a37e27b78fe396d771427d
That gist contains 4 runs: 2 with PWL enabled and 2 without, and also a markdown file explaining the collection method.
Matt
Thanks Matt! I looked through the output. Looks like the symbols might have gotten mangled. I'm not an expert on the RBD client, but I don't think we would really be calling into rbd_group_snap_rollback_with_progress from librbd::cache::pwl::ssd::WriteLogEntry::writeback_bl. Was it possible you used the libdw backend for unwindpmp? libdw sometimes gives strange/mangled callgraphs, but I haven't seen it before with libunwind. Hopefully Congmin Yin or Ilya can confirm if it's garbage.
So with that said, assuming we can trust these callgraphs at all, it looks like it might be worth looking at the latency of the AbstractWriteLog, librbd::cache::pwl::ssd::WriteLogEntry::writeback_bl, and possibly usage of librados::v14_2_0::IoCtx::object_list. On the
Hi Mark,
Both rbd_group_snap_rollback_with_progress and librados::v14_2_0::IoCtx::object_list entries don't make sense to me, so I'd say it's garbage.
Unfortunately I'm not at all familiar with this tool. Do you know how it obtains its symbols? I didn't install any debuginfo packages, so I was a bit surprised to see any symbols at all. Matt -- Matthew Booth
On Tue, 4 Jul 2023 at 10:00, Matthew Booth <mbooth@redhat.com> wrote:
On Mon, 3 Jul 2023 at 18:33, Ilya Dryomov <idryomov@gmail.com> wrote:
On Mon, Jul 3, 2023 at 6:58 PM Mark Nelson <mark.nelson@clyso.com> wrote:
On 7/3/23 04:53, Matthew Booth wrote:
On Thu, 29 Jun 2023 at 14:11, Mark Nelson <mark.nelson@clyso.com> wrote:
>> This container runs: >> fio --rw=write --ioengine=sync --fdatasync=1 >> --directory=/var/lib/etcd --size=100m --bs=8000 --name=etcd_perf >> --output-format=json --runtime=60 --time_based=1 >> >> And extracts sync.lat_ns.percentile["99.000000"] > Matthew, do you have the rest of the fio output captured? It would be interesting to see if it's just the 99th percentile that is bad or the PWL cache is worse in general. Sure.
With PWL cache: https://paste.openstack.org/show/820504/ Without PWL cache: https://paste.openstack.org/show/b35e71zAwtYR2hjmSRtR/ With PWL cache, 'rbd_cache'=false: https://paste.openstack.org/show/byp8ZITPzb3r9bb06cPf/
Also, how's the CPU usage client side? I would be very curious to see if unwindpmp shows anything useful (especially lock contention):
https://github.com/markhpc/uwpmp
Just attach it to the client-side process and start out with something like 100 samples (more are better but take longer). You can run it like:
./unwindpmp -n 100 -p <pid> I've included the output in this gist: https://gist.github.com/mdbooth/2d68b7e081a37e27b78fe396d771427d
That gist contains 4 runs: 2 with PWL enabled and 2 without, and also a markdown file explaining the collection method.
Matt
Thanks Matt! I looked through the output. Looks like the symbols might have gotten mangled. I'm not an expert on the RBD client, but I don't think we would really be calling into rbd_group_snap_rollback_with_progress from librbd::cache::pwl::ssd::WriteLogEntry::writeback_bl. Was it possible you used the libdw backend for unwindpmp? libdw sometimes gives strange/mangled callgraphs, but I haven't seen it before with libunwind. Hopefully Congmin Yin or Ilya can confirm if it's garbage.
So with that said, assuming we can trust these callgraphs at all, it looks like it might be worth looking at the latency of the AbstractWriteLog, librbd::cache::pwl::ssd::WriteLogEntry::writeback_bl, and possibly usage of librados::v14_2_0::IoCtx::object_list. On the
Hi Mark,
Both rbd_group_snap_rollback_with_progress and librados::v14_2_0::IoCtx::object_list entries don't make sense to me, so I'd say it's garbage.
Unfortunately I'm not at all familiar with this tool. Do you know how it obtains its symbols? I didn't install any debuginfo packages, so I was a bit surprised to see any symbols at all.
I installed the following debuginfo packages and re-ran the tests: elfutils-debuginfod-client-0.189-2.fc38.x86_64 elfutils-debuginfod-client-devel-0.189-2.fc38.x86_64 ceph-debuginfo-17.2.6-3.fc38.x86_64 librbd1-debuginfo-17.2.6-3.fc38.x86_64 librados2-debuginfo-17.2.6-3.fc38.x86_64 qemu-debuginfo-7.2.1-2.fc38.x86_64 qemu-system-x86-core-debuginfo-7.2.1-2.fc38.x86_64 boost-debuginfo-1.78.0-11.fc38.x86_64 Note that unwindpmp now runs considerably slower (because it re-reads debug symbols for each sample?), so I had to reduce the number of samples to 500. I have updated the gist with the new results: https://gist.github.com/mdbooth/2d68b7e081a37e27b78fe396d771427d Thanks, Matt -- Matthew Booth
On 7/4/23 10:39, Matthew Booth wrote:
On Mon, 3 Jul 2023 at 18:33, Ilya Dryomov <idryomov@gmail.com> wrote:
On Mon, Jul 3, 2023 at 6:58 PM Mark Nelson <mark.nelson@clyso.com> wrote:
On 7/3/23 04:53, Matthew Booth wrote:
On Thu, 29 Jun 2023 at 14:11, Mark Nelson <mark.nelson@clyso.com> wrote:
>>> This container runs: >>> fio --rw=write --ioengine=sync --fdatasync=1 >>> --directory=/var/lib/etcd --size=100m --bs=8000 --name=etcd_perf >>> --output-format=json --runtime=60 --time_based=1 >>> >>> And extracts sync.lat_ns.percentile["99.000000"] >> Matthew, do you have the rest of the fio output captured? It would be interesting to see if it's just the 99th percentile that is bad or the PWL cache is worse in general. > Sure. > > With PWL cache: https://paste.openstack.org/show/820504/ > Without PWL cache: https://paste.openstack.org/show/b35e71zAwtYR2hjmSRtR/ > With PWL cache, 'rbd_cache'=false: > https://paste.openstack.org/show/byp8ZITPzb3r9bb06cPf/ Also, how's the CPU usage client side? I would be very curious to see if unwindpmp shows anything useful (especially lock contention):
https://github.com/markhpc/uwpmp
Just attach it to the client-side process and start out with something like 100 samples (more are better but take longer). You can run it like:
./unwindpmp -n 100 -p <pid> I've included the output in this gist: https://gist.github.com/mdbooth/2d68b7e081a37e27b78fe396d771427d
That gist contains 4 runs: 2 with PWL enabled and 2 without, and also a markdown file explaining the collection method.
Matt
Thanks Matt! I looked through the output. Looks like the symbols might have gotten mangled. I'm not an expert on the RBD client, but I don't think we would really be calling into rbd_group_snap_rollback_with_progress from librbd::cache::pwl::ssd::WriteLogEntry::writeback_bl. Was it possible you used the libdw backend for unwindpmp? libdw sometimes gives strange/mangled callgraphs, but I haven't seen it before with libunwind. Hopefully Congmin Yin or Ilya can confirm if it's garbage. So with that said, assuming we can trust these callgraphs at all, it looks like it might be worth looking at the latency of the AbstractWriteLog, librbd::cache::pwl::ssd::WriteLogEntry::writeback_bl, and possibly usage of librados::v14_2_0::IoCtx::object_list. On the
Hi Mark,
Both rbd_group_snap_rollback_with_progress and librados::v14_2_0::IoCtx::object_list entries don't make sense to me, so I'd say it's garbage. Unfortunately I'm not at all familiar with this tool. Do you know how it obtains its symbols? I didn't install any debuginfo packages, so I was a bit surprised to see any symbols at all. I installed the following debuginfo packages and re-ran the tests: elfutils-debuginfod-client-0.189-2.fc38.x86_64 elfutils-debuginfod-client-devel-0.189-2.fc38.x86_64 ceph-debuginfo-17.2.6-3.fc38.x86_64
On Tue, 4 Jul 2023 at 10:00, Matthew Booth <mbooth@redhat.com> wrote: librbd1-debuginfo-17.2.6-3.fc38.x86_64 librados2-debuginfo-17.2.6-3.fc38.x86_64 qemu-debuginfo-7.2.1-2.fc38.x86_64 qemu-system-x86-core-debuginfo-7.2.1-2.fc38.x86_64 boost-debuginfo-1.78.0-11.fc38.x86_64
Note that unwindpmp now runs considerably slower (because it re-reads debug symbols for each sample?), so I had to reduce the number of samples to 500.
It basically just uses libunwind or libdw to unwind the stack over and over and then unwindpmp turns the resulting samples into a forward or reverse call graph. The libunwind backend code is here: https://github.com/markhpc/uwpmp/blob/master/src/tracer/unwind_tracer.cc I'm sort of amazed that it gave you symbols without the debuginfo packages installed. I'll need to figure out a way to prevent that. Having said that, your new traces look more accurate to me. The thing that sticks out to me is the (slight?) amount of contention on the PWL m_lock in dispatch_deferred_writes, update_root_scheduled_ops, append_ops, append_sync_point(), etc. I don't know if the contention around the m_lock is enough to cause an increase in 99% tail latency from 1.4ms to 5.2ms, but it's the first thing that jumps out at me. There appears to be a large number of threads (each tp_pwl thread, the io_context_pool threads, the qemu thread, and the bstore_aio thread) that all appear to have potential to contend on that lock. You could try dropping the number of tp_pwl threads from 4 to 1 and see if that changes anything. Mark
I have updated the gist with the new results: https://gist.github.com/mdbooth/2d68b7e081a37e27b78fe396d771427d
Thanks, Matt
-- Best Regards, Mark Nelson Head of R&D (USA) Clyso GmbH p: +49 89 21552391 12 a: Loristraße 8 | 80335 München | Germany w: https://clyso.com | e: mark.nelson@clyso.com We are hiring: https://www.clyso.com/jobs/
On Wed, 5 Jul 2023 at 15:18, Mark Nelson <mark.nelson@clyso.com> wrote:
I'm sort of amazed that it gave you symbols without the debuginfo packages installed. I'll need to figure out a way to prevent that. Having said that, your new traces look more accurate to me. The thing that sticks out to me is the (slight?) amount of contention on the PWL m_lock in dispatch_deferred_writes, update_root_scheduled_ops, append_ops, append_sync_point(), etc.
I don't know if the contention around the m_lock is enough to cause an increase in 99% tail latency from 1.4ms to 5.2ms, but it's the first thing that jumps out at me. There appears to be a large number of threads (each tp_pwl thread, the io_context_pool threads, the qemu thread, and the bstore_aio thread) that all appear to have potential to contend on that lock. You could try dropping the number of tp_pwl threads from 4 to 1 and see if that changes anything.
Will do. Any idea how to do that? I don't see an obvious rbd config option. Thanks for looking into this, Matt -- Matthew Booth
On 7/6/23 06:02, Matthew Booth wrote:
On Wed, 5 Jul 2023 at 15:18, Mark Nelson <mark.nelson@clyso.com> wrote:
I'm sort of amazed that it gave you symbols without the debuginfo packages installed. I'll need to figure out a way to prevent that. Having said that, your new traces look more accurate to me. The thing that sticks out to me is the (slight?) amount of contention on the PWL m_lock in dispatch_deferred_writes, update_root_scheduled_ops, append_ops, append_sync_point(), etc.
I don't know if the contention around the m_lock is enough to cause an increase in 99% tail latency from 1.4ms to 5.2ms, but it's the first thing that jumps out at me. There appears to be a large number of threads (each tp_pwl thread, the io_context_pool threads, the qemu thread, and the bstore_aio thread) that all appear to have potential to contend on that lock. You could try dropping the number of tp_pwl threads from 4 to 1 and see if that changes anything. Will do. Any idea how to do that? I don't see an obvious rbd config option.
Thanks for looking into this, Matt
you thanked me too soon...it appears to be hard-coded in, so you'll have to do a custom build. :D https://github.com/ceph/ceph/blob/main/src/librbd/cache/pwl/AbstractWriteLog... Mark -- Best Regards, Mark Nelson Head of R&D (USA) Clyso GmbH p: +49 89 21552391 12 a: Loristraße 8 | 80335 München | Germany w: https://clyso.com | e: mark.nelson@clyso.com We are hiring: https://www.clyso.com/jobs/
On Thu, 6 Jul 2023 at 12:54, Mark Nelson <mark.nelson@clyso.com> wrote:
On 7/6/23 06:02, Matthew Booth wrote:
On Wed, 5 Jul 2023 at 15:18, Mark Nelson <mark.nelson@clyso.com> wrote:
I'm sort of amazed that it gave you symbols without the debuginfo packages installed. I'll need to figure out a way to prevent that. Having said that, your new traces look more accurate to me. The thing that sticks out to me is the (slight?) amount of contention on the PWL m_lock in dispatch_deferred_writes, update_root_scheduled_ops, append_ops, append_sync_point(), etc.
I don't know if the contention around the m_lock is enough to cause an increase in 99% tail latency from 1.4ms to 5.2ms, but it's the first thing that jumps out at me. There appears to be a large number of threads (each tp_pwl thread, the io_context_pool threads, the qemu thread, and the bstore_aio thread) that all appear to have potential to contend on that lock. You could try dropping the number of tp_pwl threads from 4 to 1 and see if that changes anything. Will do. Any idea how to do that? I don't see an obvious rbd config option.
Thanks for looking into this, Matt
you thanked me too soon...it appears to be hard-coded in, so you'll have to do a custom build. :D
https://github.com/ceph/ceph/blob/main/src/librbd/cache/pwl/AbstractWriteLog...
Just to update: I have managed to test this today and it made no difference :( In general, though, unless it's something egregious are we really looking for something CPU-bound? Writes are 2 orders of magnitude slower than the underlying local disk. This has to be caused by something wildly inefficient. I have had a thought: the guest filesystem has 512 byte blocks, but the pwl filesystem has 4k blocks (on a 4k disk). Given that the test is of small writes, is there any chance that we're multiplying the number of physical writes in some pathological manner? Matt -- Matthew Booth
On 7/10/23 11:19 AM, Matthew Booth wrote:
On Thu, 6 Jul 2023 at 12:54, Mark Nelson <mark.nelson@clyso.com> wrote:
On 7/6/23 06:02, Matthew Booth wrote:
On Wed, 5 Jul 2023 at 15:18, Mark Nelson <mark.nelson@clyso.com> wrote:
I'm sort of amazed that it gave you symbols without the debuginfo packages installed. I'll need to figure out a way to prevent that. Having said that, your new traces look more accurate to me. The thing that sticks out to me is the (slight?) amount of contention on the PWL m_lock in dispatch_deferred_writes, update_root_scheduled_ops, append_ops, append_sync_point(), etc.
I don't know if the contention around the m_lock is enough to cause an increase in 99% tail latency from 1.4ms to 5.2ms, but it's the first thing that jumps out at me. There appears to be a large number of threads (each tp_pwl thread, the io_context_pool threads, the qemu thread, and the bstore_aio thread) that all appear to have potential to contend on that lock. You could try dropping the number of tp_pwl threads from 4 to 1 and see if that changes anything. Will do. Any idea how to do that? I don't see an obvious rbd config option.
Thanks for looking into this, Matt you thanked me too soon...it appears to be hard-coded in, so you'll have to do a custom build. :D
https://github.com/ceph/ceph/blob/main/src/librbd/cache/pwl/AbstractWriteLog...
Just to update: I have managed to test this today and it made no difference :(
Sorry for the late reply, just saw I had written this email but never actually sent it. So... Nuts. I was hoping for at least a little gain if you dropped it to 1.
In general, though, unless it's something egregious are we really looking for something CPU-bound? Writes are 2 orders of magnitude slower than the underlying local disk. This has to be caused by something wildly inefficient.
In this case I would expect to be entirely latency bound. It didn't look like PWL was working particularly hard, but to the extent that it was doing anything, it looked like it was spending a surprising amount of time dealing with that lock. I still suspect that if your goal is to reduce 99% latency, you'll need to figure out what's causing little micro-stalls.
I have had a thought: the guest filesystem has 512 byte blocks, but the pwl filesystem has 4k blocks (on a 4k disk). Given that the test is of small writes, is there any chance that we're multiplying the number of physical writes in some pathological manner?
Matt
-- Best Regards, Mark Nelson Head of R&D (USA) Clyso GmbH p: +49 89 21552391 12 a: Loristraße 8 | 80335 München | Germany w: https://clyso.com | e: mark.nelson@clyso.com We are hiring: https://www.clyso.com/jobs/
Hi Matthew, Due to the latency of rbd layers, the write latency of the pwl cache is more than ten times that of the Raw device. I replied directly below the 2 questions. Best regards. Congmin Yin -----Original Message----- From: Matthew Booth <mbooth@redhat.com> Sent: Thursday, June 29, 2023 7:23 PM To: Ilya Dryomov <idryomov@redhat.com> Cc: Giulio Fidente <gfidente@redhat.com>; Yin, Congmin <congmin.yin@intel.com>; Tang, Guifeng <guifeng.tang@intel.com>; Vikhyat Umrao <vumrao@redhat.com>; Jdurgin <Jdurgin@redhat.com>; John Fulton <johfulto@redhat.com>; Francesco Pantano <fpantano@redhat.com>; ceph-users@ceph.io Subject: Re: [ceph-users] RBD with PWL cache shows poor performance compared to cache device On Wed, 28 Jun 2023 at 22:44, Ilya Dryomov <idryomov@redhat.com> wrote:
** TL;DR
In testing, the write latency performance of a PWL-cache backed RBD disk was 2 orders of magnitude worse than the disk holding the PWL cache.
PWL cache can use pmem or SSD as cache devices. Using PMEM, based on my test environment at that time, I can give specific data as follows: the write latency of the pmem Raw device is about 10+us, the write latency of the pwl cache is about 100us+(from the latency of the rbd layers), and the write latency of the ceph cluster is about 1000+us(from messengers and network). But for SSDs, there are many types, and I cannot provide a specific value, but it will definitely be worse than pmem. So, for a phenomenon that is 2 orders of magnitude lower, it is worse than expected. Can you provide detailed values of the three for analysis. (SSD, pwl cache, ceph cluster) ==============================================================
** Summary
I was hoping that PWL cache might be a good solution to the problem of write latency requirements of etcd when running a kubernetes control plane on ceph. Etcd is extremely write latency sensitive and becomes unstable if write latency is too high. The etcd workload can be characterised by very small (~4k) writes with a queue depth of 1. Throughput, even on a busy system, is normally very low. As etcd is distributed and can safely handle the loss of un-flushed data from a single node, a local ssd PWL cache for etcd looked like an ideal solution.
Right, this is exactly the use case that the PWL cache is supposed to address.
Good to know!
My expectation was that adding a PWL cache on a local SSD to an RBD-backed would improve write latency to something approaching the write latency performance of the local SSD. However, in my testing adding a PWL cache to an rbd-backed VM increased write latency by approximately 4x over not using a PWL cache. This was over 100x more than the write latency performance of the underlying SSD.
When using image as the VM's disk, you may have used commands like the following. In many cases, using parameters such as writeback will force the start of rbd cache, which is a memory cache. It is normal for pwl cache to be several times slower than it. Please confirm. There is currently no parameter support for using only pwl cache instead of rbd cache. I have tested the latency of using pwl cache (pmem) by modifying the code myself, which is about twice as high as using rbd cache. qemu -m 1024 -drive format=raw,file=rbd:data/squeeze:rbd_cache=true,cache=writeback ==============================================================
My expectation was based on the documentation here: https://docs.ceph.com/en/quincy/rbd/rbd-persistent-write-log-cache/
“The cache provides two different persistence modes. In persistent-on-write mode, the writes are completed only when they are persisted to the cache device and will be readable after a crash. In persistent-on-flush mode, the writes are completed as soon as it no longer needs the caller’s data buffer to complete the writes, but does not guarantee that writes will be readable after a crash. The data is persisted to the cache device when a flush request is received.”
** Method
2 systems, 1 running single-node Ceph Quincy (17.2.6), the other running libvirt and mounting a VM’s disk with librbd (also 17.2.6) from the first node.
All performance testing is from the libvirt system. I tested write latency performance:
* Inside the VM without a PWL cache * Of the PWL device directly from the host (direct to filesystem, no VM) * Inside the VM with a PWL cache
I am testing with fio. Specifically I am running a containerised test, executed with: podman run --volume .:/var/lib/etcd:Z quay.io/openshift-scale/etcd-perf
This container runs: fio --rw=write --ioengine=sync --fdatasync=1 --directory=/var/lib/etcd --size=100m --bs=8000 --name=etcd_perf --output-format=json --runtime=60 --time_based=1
And extracts sync.lat_ns.percentile["99.000000"]
Matthew, do you have the rest of the fio output captured? It would be interesting to see if it's just the 99th percentile that is bad or the PWL cache is worse in general.
Sure. With PWL cache: https://paste.openstack.org/show/820504/ Without PWL cache: https://paste.openstack.org/show/b35e71zAwtYR2hjmSRtR/ With PWL cache, 'rbd_cache'=false: https://paste.openstack.org/show/byp8ZITPzb3r9bb06cPf/
** Results
All results were stable across multiple runs within a small margin of error.
* rbd no cache: 1417216 ns * pwl cache device: 44288 ns * rbd with pwl cache: 5210112 ns
Note that by adding a PWL cache we increase write latency by approximately 4x, which is more than 100x than the underlying device.
** Hardware
2 x Dell R640s, each with Xeon Silver 4216 CPU @ 2.10GHz and 192G RAM Storage under test: 2 x SAMSUNG MZ7KH480HAHQ0D3 SSDs attached to PERC H730P Mini (Embedded)
OS installed on rotational disks
N.B. Linux incorrectly detects these disks as rotational, which I assume relates to weird behaviour by the PERC controller. I remembered to manually correct this on the ‘client’ machine for the PWL cache, but at OSD configuration time ceph would have detected them as rotational. They are not rotational.
** Ceph Configuration
CentOS Stream 9
# ceph version ceph version 17.2.6 (d7ff0d10654d2280e08f1ab989c7cdf3064446a5) quincy (stable)
Single node installation with cephadm. 2 OSDs, one on each SSD. 1 pool with size 2
** Client Configuration
Fedora 38 Librbd1-17.2.6-3.fc38.x86_64
PWL cache is XFS filesystem with 4k block size, matching the underlying device. The filesystem uses the whole block device. There is no other load on the system.
** RBD Configuration
# rbd config image list libvirt-pool/pwl-test | grep cache rbd_cache true
I wonder if rbd_cache should have been set to false here to disable the default volatile cache. Other than that, I don't see anything obviously wrong with the configuration at first sight.
I added some full output for this above.
-- Ilya
config rbd_cache_block_writes_upfront false config rbd_cache_max_dirty 25165824 config rbd_cache_max_dirty_age 1.000000 config rbd_cache_max_dirty_object 0 config rbd_cache_policy writeback pool rbd_cache_size 33554432 config rbd_cache_target_dirty 16777216 config rbd_cache_writethrough_until_flush true pool rbd_parent_cache_enabled false config rbd_persistent_cache_mode ssd pool rbd_persistent_cache_path /var/lib/libvirt/images/pwl pool rbd_persistent_cache_size 1073741824 config rbd_plugins pwl_cache pool
# rbd status libvirt-pool/pwl-test Watchers: watcher=10.1.240.27:0/1406459716 client.14475 cookie=140282423200720 Persistent cache state: host: dell-r640-050 path: /var/lib/libvirt/images/pwl/rbd-pwl.libvirt-pool.37e947fd216b.pool size: 1 GiB mode: ssd stats_timestamp: Mon Jun 26 11:29:21 2023 present: true empty: false clean: true allocated: 180 MiB cached: 135 MiB dirty: 0 B free: 844 MiB hits_full: 1 / 0% hits_partial: 3 / 0% misses: 21952 hit_bytes: 6 KiB / 0% miss_bytes: 349 MiB
-- Matthew Booth
On Fri, 30 Jun 2023 at 08:50, Yin, Congmin <congmin.yin@intel.com> wrote:
Hi Matthew,
Due to the latency of rbd layers, the write latency of the pwl cache is more than ten times that of the Raw device. I replied directly below the 2 questions.
Best regards. Congmin Yin
-----Original Message----- From: Matthew Booth <mbooth@redhat.com> Sent: Thursday, June 29, 2023 7:23 PM To: Ilya Dryomov <idryomov@redhat.com> Cc: Giulio Fidente <gfidente@redhat.com>; Yin, Congmin <congmin.yin@intel.com>; Tang, Guifeng <guifeng.tang@intel.com>; Vikhyat Umrao <vumrao@redhat.com>; Jdurgin <Jdurgin@redhat.com>; John Fulton <johfulto@redhat.com>; Francesco Pantano <fpantano@redhat.com>; ceph-users@ceph.io Subject: Re: [ceph-users] RBD with PWL cache shows poor performance compared to cache device
On Wed, 28 Jun 2023 at 22:44, Ilya Dryomov <idryomov@redhat.com> wrote:
** TL;DR
In testing, the write latency performance of a PWL-cache backed RBD disk was 2 orders of magnitude worse than the disk holding the PWL cache.
PWL cache can use pmem or SSD as cache devices. Using PMEM, based on my test environment at that time, I can give specific data as follows: the write latency of the pmem Raw device is about 10+us, the write latency of the pwl cache is about 100us+(from the latency of the rbd layers), and the write latency of the ceph cluster is about 1000+us(from messengers and network). But for SSDs, there are many types, and I cannot provide a specific value, but it will definitely be worse than pmem. So, for a phenomenon that is 2 orders of magnitude lower, it is worse than expected. Can you provide detailed values of the three for analysis. (SSD, pwl cache, ceph cluster)
I'm not entirely sure what you're asking for. Which values are you looking for? I did provide 3 sets of test results below, is that what you mean? * rbd no cache: 1417216 ns * pwl cache device: 44288 ns * rbd with pwl cache: 5210112 ns These are all outputs from the benchmarking test. The first is executing in the VM writing to a ceph RBD disk *without* PWL. The second is executing on the host writing directly to the SSD which is being used for the PWL cache. The third is execuing in the VM writing to the same ceph RBD disk, but this time *with* PWL. Incidentally, the client and server machines are identical, and the SSD used by the client for PWL is the same model used on the server as the OSDs. The SSDs are SAMSUNG MZ7KH480HAHQ0D3 SSDs attached to PERC H730P Mini (Embedded).
==============================================================
** Summary
I was hoping that PWL cache might be a good solution to the problem of write latency requirements of etcd when running a kubernetes control plane on ceph. Etcd is extremely write latency sensitive and becomes unstable if write latency is too high. The etcd workload can be characterised by very small (~4k) writes with a queue depth of 1. Throughput, even on a busy system, is normally very low. As etcd is distributed and can safely handle the loss of un-flushed data from a single node, a local ssd PWL cache for etcd looked like an ideal solution.
Right, this is exactly the use case that the PWL cache is supposed to address.
Good to know!
My expectation was that adding a PWL cache on a local SSD to an RBD-backed would improve write latency to something approaching the write latency performance of the local SSD. However, in my testing adding a PWL cache to an rbd-backed VM increased write latency by approximately 4x over not using a PWL cache. This was over 100x more than the write latency performance of the underlying SSD.
When using image as the VM's disk, you may have used commands like the following. In many cases, using parameters such as writeback will force the start of rbd cache, which is a memory cache. It is normal for pwl cache to be several times slower than it. Please confirm. There is currently no parameter support for using only pwl cache instead of rbd cache. I have tested the latency of using pwl cache (pmem) by modifying the code myself, which is about twice as high as using rbd cache.
qemu -m 1024 -drive format=raw,file=rbd:data/squeeze:rbd_cache=true,cache=writeback
I created the rbd disk by first installing the VM on a local qcow2 file, then copying the data from the qcow2 to rbd, converting to raw. The command I used was: `qemu-img convert -f qcow2 -O raw /var/lib/libvirt/images/pwl-test.qcow2 rbd:libvirt-pool/pwl-test:id=libvirt` I am configuring rbd options from the server by setting options on the pool. I have been confirming that options are being set correctly with `rbd status libvirt-pool/pwl-test` on the server. The latest set of profiling data requested by Mark were generated entirely with `rbd_cache=false`: https://gist.github.com/mdbooth/2d68b7e081a37e27b78fe396d771427d -- Matthew Booth
Hi , Matthew I see "rbd with pwl cache: 5210112 ns", This latency is beyond my expectations and I believe it is unlikely to occur. In theory, this value should be around a few hundred microseconds. But I'm not sure what went wrong in your steps. Can you use perf for latency analysis. Hi @Ilya Dryomov , do you have any suggestions? Perf, some command: admin_socket = /mnt/pmem/cache.asok ceph --admin-daemon /mnt/pmem/cache.asok perf reset all ceph --admin-daemon /mnt/pmem/cache.asok perf dump -----Original Message----- From: Matthew Booth <mbooth@redhat.com> Sent: Monday, July 3, 2023 6:09 PM To: Yin, Congmin <congmin.yin@intel.com> Cc: Ilya Dryomov <idryomov@redhat.com>; Giulio Fidente <gfidente@redhat.com>; Tang, Guifeng <guifeng.tang@intel.com>; Vikhyat Umrao <vumrao@redhat.com>; Jdurgin <Jdurgin@redhat.com>; John Fulton <johfulto@redhat.com>; Francesco Pantano <fpantano@redhat.com>; ceph-users@ceph.io Subject: Re: [ceph-users] RBD with PWL cache shows poor performance compared to cache device On Fri, 30 Jun 2023 at 08:50, Yin, Congmin <congmin.yin@intel.com> wrote:
Hi Matthew,
Due to the latency of rbd layers, the write latency of the pwl cache is more than ten times that of the Raw device. I replied directly below the 2 questions.
Best regards. Congmin Yin
-----Original Message----- From: Matthew Booth <mbooth@redhat.com> Sent: Thursday, June 29, 2023 7:23 PM To: Ilya Dryomov <idryomov@redhat.com> Cc: Giulio Fidente <gfidente@redhat.com>; Yin, Congmin <congmin.yin@intel.com>; Tang, Guifeng <guifeng.tang@intel.com>; Vikhyat Umrao <vumrao@redhat.com>; Jdurgin <Jdurgin@redhat.com>; John Fulton <johfulto@redhat.com>; Francesco Pantano <fpantano@redhat.com>; ceph-users@ceph.io Subject: Re: [ceph-users] RBD with PWL cache shows poor performance compared to cache device
On Wed, 28 Jun 2023 at 22:44, Ilya Dryomov <idryomov@redhat.com> wrote:
** TL;DR
In testing, the write latency performance of a PWL-cache backed RBD disk was 2 orders of magnitude worse than the disk holding the PWL cache.
PWL cache can use pmem or SSD as cache devices. Using PMEM, based on my test environment at that time, I can give specific data as follows: the write latency of the pmem Raw device is about 10+us, the write latency of the pwl cache is about 100us+(from the latency of the rbd layers), and the write latency of the ceph cluster is about 1000+us(from messengers and network). But for SSDs, there are many types, and I cannot provide a specific value, but it will definitely be worse than pmem. So, for a phenomenon that is 2 orders of magnitude lower, it is worse than expected. Can you provide detailed values of the three for analysis. (SSD, pwl cache, ceph cluster)
I'm not entirely sure what you're asking for. Which values are you looking for? I did provide 3 sets of test results below, is that what you mean? * rbd no cache: 1417216 ns * pwl cache device: 44288 ns * rbd with pwl cache: 5210112 ns These are all outputs from the benchmarking test. The first is executing in the VM writing to a ceph RBD disk *without* PWL. The second is executing on the host writing directly to the SSD which is being used for the PWL cache. The third is execuing in the VM writing to the same ceph RBD disk, but this time *with* PWL. Incidentally, the client and server machines are identical, and the SSD used by the client for PWL is the same model used on the server as the OSDs. The SSDs are SAMSUNG MZ7KH480HAHQ0D3 SSDs attached to PERC H730P Mini (Embedded).
==============================================================
** Summary
I was hoping that PWL cache might be a good solution to the problem of write latency requirements of etcd when running a kubernetes control plane on ceph. Etcd is extremely write latency sensitive and becomes unstable if write latency is too high. The etcd workload can be characterised by very small (~4k) writes with a queue depth of 1. Throughput, even on a busy system, is normally very low. As etcd is distributed and can safely handle the loss of un-flushed data from a single node, a local ssd PWL cache for etcd looked like an ideal solution.
Right, this is exactly the use case that the PWL cache is supposed to address.
Good to know!
My expectation was that adding a PWL cache on a local SSD to an RBD-backed would improve write latency to something approaching the write latency performance of the local SSD. However, in my testing adding a PWL cache to an rbd-backed VM increased write latency by approximately 4x over not using a PWL cache. This was over 100x more than the write latency performance of the underlying SSD.
When using image as the VM's disk, you may have used commands like the following. In many cases, using parameters such as writeback will force the start of rbd cache, which is a memory cache. It is normal for pwl cache to be several times slower than it. Please confirm. There is currently no parameter support for using only pwl cache instead of rbd cache. I have tested the latency of using pwl cache (pmem) by modifying the code myself, which is about twice as high as using rbd cache.
qemu -m 1024 -drive format=raw,file=rbd:data/squeeze:rbd_cache=true,cache=writeback
I created the rbd disk by first installing the VM on a local qcow2 file, then copying the data from the qcow2 to rbd, converting to raw. The command I used was: `qemu-img convert -f qcow2 -O raw /var/lib/libvirt/images/pwl-test.qcow2 rbd:libvirt-pool/pwl-test:id=libvirt` I am configuring rbd options from the server by setting options on the pool. I have been confirming that options are being set correctly with `rbd status libvirt-pool/pwl-test` on the server. The latest set of profiling data requested by Mark were generated entirely with `rbd_cache=false`: https://gist.github.com/mdbooth/2d68b7e081a37e27b78fe396d771427d -- Matthew Booth
On Tue, 4 Jul 2023 at 10:45, Yin, Congmin <congmin.yin@intel.com> wrote:
Hi , Matthew
I see "rbd with pwl cache: 5210112 ns", This latency is beyond my expectations and I believe it is unlikely to occur. In theory, this value should be around a few hundred microseconds. But I'm not sure what went wrong in your steps. Can you use perf for latency analysis. Hi @Ilya Dryomov , do you have any suggestions?
I don't think the absolute value is interesting to you: it's the output of a specific benchmarking test (described in detail below) which likely has multiple additional layers involved. It's also a 99th percentile value so most likely includes jitter from other subsystems, although note that it is very reproducible and the test system has no other load. The interesting thing here is the difference between 'rbd with pwl' and 'pwl cache device'. Why is the latency performance of 'rbd with pwl' so much worse than the device which is holding the pwl cache?
Perf, some command: admin_socket = /mnt/pmem/cache.asok ceph --admin-daemon /mnt/pmem/cache.asok perf reset all ceph --admin-daemon /mnt/pmem/cache.asok perf dump
I assume these are to be run on the client with the admin socket hosted on the pwl device? Is anything supposed to be connected to that socket? Incidentally, note that I'm using SSD not pmem. Thanks, Matt
-----Original Message----- From: Matthew Booth <mbooth@redhat.com> Sent: Monday, July 3, 2023 6:09 PM To: Yin, Congmin <congmin.yin@intel.com> Cc: Ilya Dryomov <idryomov@redhat.com>; Giulio Fidente <gfidente@redhat.com>; Tang, Guifeng <guifeng.tang@intel.com>; Vikhyat Umrao <vumrao@redhat.com>; Jdurgin <Jdurgin@redhat.com>; John Fulton <johfulto@redhat.com>; Francesco Pantano <fpantano@redhat.com>; ceph-users@ceph.io Subject: Re: [ceph-users] RBD with PWL cache shows poor performance compared to cache device
On Fri, 30 Jun 2023 at 08:50, Yin, Congmin <congmin.yin@intel.com> wrote:
Hi Matthew,
Due to the latency of rbd layers, the write latency of the pwl cache is more than ten times that of the Raw device. I replied directly below the 2 questions.
Best regards. Congmin Yin
-----Original Message----- From: Matthew Booth <mbooth@redhat.com> Sent: Thursday, June 29, 2023 7:23 PM To: Ilya Dryomov <idryomov@redhat.com> Cc: Giulio Fidente <gfidente@redhat.com>; Yin, Congmin <congmin.yin@intel.com>; Tang, Guifeng <guifeng.tang@intel.com>; Vikhyat Umrao <vumrao@redhat.com>; Jdurgin <Jdurgin@redhat.com>; John Fulton <johfulto@redhat.com>; Francesco Pantano <fpantano@redhat.com>; ceph-users@ceph.io Subject: Re: [ceph-users] RBD with PWL cache shows poor performance compared to cache device
On Wed, 28 Jun 2023 at 22:44, Ilya Dryomov <idryomov@redhat.com> wrote:
** TL;DR
In testing, the write latency performance of a PWL-cache backed RBD disk was 2 orders of magnitude worse than the disk holding the PWL cache.
PWL cache can use pmem or SSD as cache devices. Using PMEM, based on my test environment at that time, I can give specific data as follows: the write latency of the pmem Raw device is about 10+us, the write latency of the pwl cache is about 100us+(from the latency of the rbd layers), and the write latency of the ceph cluster is about 1000+us(from messengers and network). But for SSDs, there are many types, and I cannot provide a specific value, but it will definitely be worse than pmem. So, for a phenomenon that is 2 orders of magnitude lower, it is worse than expected. Can you provide detailed values of the three for analysis. (SSD, pwl cache, ceph cluster)
I'm not entirely sure what you're asking for. Which values are you looking for?
I did provide 3 sets of test results below, is that what you mean? * rbd no cache: 1417216 ns * pwl cache device: 44288 ns * rbd with pwl cache: 5210112 ns
These are all outputs from the benchmarking test. The first is executing in the VM writing to a ceph RBD disk *without* PWL. The second is executing on the host writing directly to the SSD which is being used for the PWL cache. The third is execuing in the VM writing to the same ceph RBD disk, but this time *with* PWL.
Incidentally, the client and server machines are identical, and the SSD used by the client for PWL is the same model used on the server as the OSDs. The SSDs are SAMSUNG MZ7KH480HAHQ0D3 SSDs attached to PERC H730P Mini (Embedded).
==============================================================
** Summary
I was hoping that PWL cache might be a good solution to the problem of write latency requirements of etcd when running a kubernetes control plane on ceph. Etcd is extremely write latency sensitive and becomes unstable if write latency is too high. The etcd workload can be characterised by very small (~4k) writes with a queue depth of 1. Throughput, even on a busy system, is normally very low. As etcd is distributed and can safely handle the loss of un-flushed data from a single node, a local ssd PWL cache for etcd looked like an ideal solution.
Right, this is exactly the use case that the PWL cache is supposed to address.
Good to know!
My expectation was that adding a PWL cache on a local SSD to an RBD-backed would improve write latency to something approaching the write latency performance of the local SSD. However, in my testing adding a PWL cache to an rbd-backed VM increased write latency by approximately 4x over not using a PWL cache. This was over 100x more than the write latency performance of the underlying SSD.
When using image as the VM's disk, you may have used commands like the following. In many cases, using parameters such as writeback will force the start of rbd cache, which is a memory cache. It is normal for pwl cache to be several times slower than it. Please confirm. There is currently no parameter support for using only pwl cache instead of rbd cache. I have tested the latency of using pwl cache (pmem) by modifying the code myself, which is about twice as high as using rbd cache.
qemu -m 1024 -drive format=raw,file=rbd:data/squeeze:rbd_cache=true,cache=writeback
I created the rbd disk by first installing the VM on a local qcow2 file, then copying the data from the qcow2 to rbd, converting to raw. The command I used was:
`qemu-img convert -f qcow2 -O raw /var/lib/libvirt/images/pwl-test.qcow2 rbd:libvirt-pool/pwl-test:id=libvirt`
I am configuring rbd options from the server by setting options on the pool. I have been confirming that options are being set correctly with `rbd status libvirt-pool/pwl-test` on the server.
The latest set of profiling data requested by Mark were generated entirely with `rbd_cache=false`: https://gist.github.com/mdbooth/2d68b7e081a37e27b78fe396d771427d -- Matthew Booth
-- Matthew Booth
On Tue, 4 Jul 2023 at 14:24, Matthew Booth <mbooth@redhat.com> wrote:
On Tue, 4 Jul 2023 at 10:45, Yin, Congmin <congmin.yin@intel.com> wrote:
Hi , Matthew
I see "rbd with pwl cache: 5210112 ns", This latency is beyond my expectations and I believe it is unlikely to occur. In theory, this value should be around a few hundred microseconds. But I'm not sure what went wrong in your steps. Can you use perf for latency analysis. Hi @Ilya Dryomov , do you have any suggestions?
I don't think the absolute value is interesting to you: it's the output of a specific benchmarking test (described in detail below) which likely has multiple additional layers involved. It's also a 99th percentile value so most likely includes jitter from other subsystems, although note that it is very reproducible and the test system has no other load. The interesting thing here is the difference between 'rbd with pwl' and 'pwl cache device'. Why is the latency performance of 'rbd with pwl' so much worse than the device which is holding the pwl cache?
Perf, some command: admin_socket = /mnt/pmem/cache.asok ceph --admin-daemon /mnt/pmem/cache.asok perf reset all ceph --admin-daemon /mnt/pmem/cache.asok perf dump
To give you an idea of my confusion, here's what I'm running on the client, which is not running any ceph daemons: # admin_socket=/var/lib/libvirt/images/pwl/cache.sock # ceph --admin-daemon ${admin_socket} perf reset all admin_socket: exception getting command descriptions: [Errno 2] No such file or directory What should be listening on that socket? Do you have a link to any documentation which would help me get this up and running? Thanks, Matt -- Matthew Booth
participants (4)
-
Ilya Dryomov
-
Mark Nelson
-
Matthew Booth
-
Yin, Congmin