OSD read latency grows over time
Hello Ceph users, we see strange issue on last recent Ceph installation v17.6.2. We store data on HDD pool, index pool is on SSD. Each OSD store its wal on NVME partition. Benchmarks didn't expose any issues with cluster, but since we placed production load on it we see constantly growing OSD latency time (osd_read_latency) on SSD disks (where Index pool located). Latency is constantly growing day-by-day, but disks are not utilized even for 50%. Interesting, that when we move Index pool from SSD to NVME disks (disk space allows it for now) - osd latency drops to zero and start increasing from the ground. Also we noticed, that any change of pg_num for index pool (from 256 to 128 for instance) also drops latency to zero. And it starts its growth again (https://postimg.cc/5YHk9bby). From client perspective it looks like one operation takes longer and longer each other day and operation time drops each time when we do some change on index pool. I've enabled debug_optracker 10/0 and it shows, that OSD spend most time in `queued_for_pg` state, but physical disk utilization is about 10-20%. Also per logs I see, that longest operation is Listbucket, but it is strange, that with less than 100'000 items in bucket list even with 'max_keys=1' takes 3-40 seconds. If it matters client is Apache Flink doing checkpoints via S3 protocol. Here is an example of operation with debug_optracking logs: 2023-12-29T16:24:28.873353+0300, event: throttled, op: osd_op(client.1227774 .0:22575820 7.19 7.a84f1a59 (undecoded) ondisk+write+known_if_redirected+supports_pool_eio e83833) 2023-12-29T16:24:28.861549+0300, event: header_read, op: osd_op(client. 1227774.0:22575820 7.19 7.a84f1a59 (undecoded) ondisk+write+known_if_redirected+supports_pool_eio e83833) 2023-12-29T16:24:28.873358+0300, event: all_read, op: osd_op(client.1227774 .0:22575820 7.19 7.a84f1a59 (undecoded) ondisk+write+known_if_redirected+supports_pool_eio e83833) 2023-12-29T16:24:28.873359+0300, event: dispatched, op: osd_op(client. 1227774.0:22575820 7.19 7.a84f1a59 (undecoded) ondisk+write+known_if_redirected+supports_pool_eio e83833) 2023-12-29T16:24:28.873389+0300, event: queued_for_pg, op: osd_op(client. 1227774.0:22575820 7.19 7.a84f1a59 (undecoded) ondisk+write+known_if_redirected+supports_pool_eio e83833) 2023-12-29T16:24:38.077528+0300, event: reached_pg, op: osd_op(client. 1227774.0:22575820 7.19 7.a84f1a59 (undecoded) ondisk+write+known_if_redirected+supports_pool_eio e83833) 2023-12-29T16:24:38.077561+0300, event: started, op: osd_op(client.1227774 .0:22575820 7.19 7:9a58f215:::.dir.68960da3-1c98-45c1-a87a-9e6c39253d27. 9780498.1.83:head [stat,call rgw.guard_bucket_resharding in=36b,call rgw.bucket_prepare_op in=331b] snapc 0=[] ondisk+write+known_if_redirected+supports_pool_eio e83833) 2023-12-29T16:24:38.077714+0300, event: waiting for subops from 59,494, op: osd_op(client.1227774.0:22575820 7.19 7:9a58f215:::.dir.68960da3-1c98-45c1-a87a-9e6c39253d27.9780498.1.83:head [stat,call rgw.guard_bucket_resharding in=36b,call rgw.bucket_prepare_op in=331b] snapc 0=[] ondisk+write+known_if_redirected+supports_pool_eio e83833) 2023-12-29T16:24:38.146157+0300, event: sub_op_commit_rec, op: osd_op(client.1227774.0:22575820 7.19 7:9a58f215:::.dir.68960da3-1c98-45c1-a87a-9e6c39253d27.9780498.1.83:head [stat,call rgw.guard_bucket_resharding in=36b,call rgw.bucket_prepare_op in=331b] snapc 0=[] ondisk+write+known_if_redirected+supports_pool_eio e83833) 2023-12-29T16:24:38.146166+0300, event: op_commit, op: osd_op(client.1227774 .0:22575820 7.19 7:9a58f215:::.dir.68960da3-1c98-45c1-a87a-9e6c39253d27. 9780498.1.83:head [stat,call rgw.guard_bucket_resharding in=36b,call rgw.bucket_prepare_op in=331b] snapc 0=[] ondisk+write+known_if_redirected+supports_pool_eio e83833) 2023-12-29T16:24:38.146191+0300, event: sub_op_commit_rec, op: osd_op(client.1227774.0:22575820 7.19 7:9a58f215:::.dir.68960da3-1c98-45c1-a87a-9e6c39253d27.9780498.1.83:head [stat,call rgw.guard_bucket_resharding in=36b,call rgw.bucket_prepare_op in=331b] snapc 0=[] ondisk+write+known_if_redirected+supports_pool_eio e83833) 2023-12-29T16:24:38.146204+0300, event: commit_sent, op: osd_op(client. 1227774.0:22575820 7.19 7:9a58f215:::.dir.68960da3-1c98-45c1-a87a-9e6c39253d27.9780498.1.83:head [stat,call rgw.guard_bucket_resharding in=36b,call rgw.bucket_prepare_op in=331b] snapc 0=[] ondisk+write+known_if_redirected+supports_pool_eio e83833) 2023-12-29T16:24:38.146216+0300, event: done, op: osd_op(client.1227774.0:22575820 7.19 7:9a58f215:::.dir.68960da3-1c98-45c1-a87a-9e6c39253d27.9780498.1.83:head [stat,call rgw.guard_bucket_resharding in=36b,call rgw.bucket_prepare_op in=331b] snapc 0=[] ondisk+write+known_if_redirected+supports_pool_eio e83833) Does anybody faced with the same issue? I'd be very grateful for any idea because at this point I've got stuck with what to tune and where to look at. Cluster setup - replication 3x, 15 servers in 3 datacenters with datacenter as failure domain. 7x HDD (data), 2x SSD (index), 1x NVME (wal + OS). ceph config - https://pastebin.com/pCqxXhT3 OSD read latency graph - https://postimg.cc/5YHk9bby -- Thank you, Roman
Hi, I checked two production clusters which don't use RGW too heavily, both on Pacific though. There's no latency increase visible there. How is the data growth in your cluster? Is the pool size rather stable or is it constantly growing? Thanks, Eugen Zitat von Roman Pashin <romanpashin28@gmail.com>:
Hello Ceph users,
we see strange issue on last recent Ceph installation v17.6.2. We store data on HDD pool, index pool is on SSD. Each OSD store its wal on NVME partition. Benchmarks didn't expose any issues with cluster, but since we placed production load on it we see constantly growing OSD latency time (osd_read_latency) on SSD disks (where Index pool located). Latency is constantly growing day-by-day, but disks are not utilized even for 50%. Interesting, that when we move Index pool from SSD to NVME disks (disk space allows it for now) - osd latency drops to zero and start increasing from the ground. Also we noticed, that any change of pg_num for index pool (from 256 to 128 for instance) also drops latency to zero. And it starts its growth again (https://postimg.cc/5YHk9bby).
From client perspective it looks like one operation takes longer and longer each other day and operation time drops each time when we do some change on index pool. I've enabled debug_optracker 10/0 and it shows, that OSD spend most time in `queued_for_pg` state, but physical disk utilization is about 10-20%. Also per logs I see, that longest operation is Listbucket, but it is strange, that with less than 100'000 items in bucket list even with 'max_keys=1' takes 3-40 seconds.
If it matters client is Apache Flink doing checkpoints via S3 protocol.
Here is an example of operation with debug_optracking logs:
2023-12-29T16:24:28.873353+0300, event: throttled, op: osd_op(client.1227774 .0:22575820 7.19 7.a84f1a59 (undecoded) ondisk+write+known_if_redirected+supports_pool_eio e83833) 2023-12-29T16:24:28.861549+0300, event: header_read, op: osd_op(client. 1227774.0:22575820 7.19 7.a84f1a59 (undecoded) ondisk+write+known_if_redirected+supports_pool_eio e83833) 2023-12-29T16:24:28.873358+0300, event: all_read, op: osd_op(client.1227774 .0:22575820 7.19 7.a84f1a59 (undecoded) ondisk+write+known_if_redirected+supports_pool_eio e83833) 2023-12-29T16:24:28.873359+0300, event: dispatched, op: osd_op(client. 1227774.0:22575820 7.19 7.a84f1a59 (undecoded) ondisk+write+known_if_redirected+supports_pool_eio e83833) 2023-12-29T16:24:28.873389+0300, event: queued_for_pg, op: osd_op(client. 1227774.0:22575820 7.19 7.a84f1a59 (undecoded) ondisk+write+known_if_redirected+supports_pool_eio e83833) 2023-12-29T16:24:38.077528+0300, event: reached_pg, op: osd_op(client. 1227774.0:22575820 7.19 7.a84f1a59 (undecoded) ondisk+write+known_if_redirected+supports_pool_eio e83833) 2023-12-29T16:24:38.077561+0300, event: started, op: osd_op(client.1227774 .0:22575820 7.19 7:9a58f215:::.dir.68960da3-1c98-45c1-a87a-9e6c39253d27. 9780498.1.83:head [stat,call rgw.guard_bucket_resharding in=36b,call rgw.bucket_prepare_op in=331b] snapc 0=[] ondisk+write+known_if_redirected+supports_pool_eio e83833) 2023-12-29T16:24:38.077714+0300, event: waiting for subops from 59,494, op: osd_op(client.1227774.0:22575820 7.19 7:9a58f215:::.dir.68960da3-1c98-45c1-a87a-9e6c39253d27.9780498.1.83:head [stat,call rgw.guard_bucket_resharding in=36b,call rgw.bucket_prepare_op in=331b] snapc 0=[] ondisk+write+known_if_redirected+supports_pool_eio e83833) 2023-12-29T16:24:38.146157+0300, event: sub_op_commit_rec, op: osd_op(client.1227774.0:22575820 7.19 7:9a58f215:::.dir.68960da3-1c98-45c1-a87a-9e6c39253d27.9780498.1.83:head [stat,call rgw.guard_bucket_resharding in=36b,call rgw.bucket_prepare_op in=331b] snapc 0=[] ondisk+write+known_if_redirected+supports_pool_eio e83833) 2023-12-29T16:24:38.146166+0300, event: op_commit, op: osd_op(client.1227774 .0:22575820 7.19 7:9a58f215:::.dir.68960da3-1c98-45c1-a87a-9e6c39253d27. 9780498.1.83:head [stat,call rgw.guard_bucket_resharding in=36b,call rgw.bucket_prepare_op in=331b] snapc 0=[] ondisk+write+known_if_redirected+supports_pool_eio e83833) 2023-12-29T16:24:38.146191+0300, event: sub_op_commit_rec, op: osd_op(client.1227774.0:22575820 7.19 7:9a58f215:::.dir.68960da3-1c98-45c1-a87a-9e6c39253d27.9780498.1.83:head [stat,call rgw.guard_bucket_resharding in=36b,call rgw.bucket_prepare_op in=331b] snapc 0=[] ondisk+write+known_if_redirected+supports_pool_eio e83833) 2023-12-29T16:24:38.146204+0300, event: commit_sent, op: osd_op(client. 1227774.0:22575820 7.19 7:9a58f215:::.dir.68960da3-1c98-45c1-a87a-9e6c39253d27.9780498.1.83:head [stat,call rgw.guard_bucket_resharding in=36b,call rgw.bucket_prepare_op in=331b] snapc 0=[] ondisk+write+known_if_redirected+supports_pool_eio e83833) 2023-12-29T16:24:38.146216+0300, event: done, op: osd_op(client.1227774.0:22575820 7.19 7:9a58f215:::.dir.68960da3-1c98-45c1-a87a-9e6c39253d27.9780498.1.83:head [stat,call rgw.guard_bucket_resharding in=36b,call rgw.bucket_prepare_op in=331b] snapc 0=[] ondisk+write+known_if_redirected+supports_pool_eio e83833)
Does anybody faced with the same issue? I'd be very grateful for any idea because at this point I've got stuck with what to tune and where to look at.
Cluster setup - replication 3x, 15 servers in 3 datacenters with datacenter as failure domain. 7x HDD (data), 2x SSD (index), 1x NVME (wal + OS). ceph config - https://pastebin.com/pCqxXhT3 OSD read latency graph - https://postimg.cc/5YHk9bby -- Thank you, Roman _______________________________________________ ceph-users mailing list -- ceph-users@ceph.io To unsubscribe send an email to ceph-users-leave@ceph.io
Hi Eugen, How is the data growth in your cluster? Is the pool size rather stable or
is it constantly growing?
Pool size is fairly constant with tiny up trend. It's growth doesn't correlate with increase of OSD read latency. I've combined pool usage with OSD read latency on one graph to provide overall picture of what it looks like. Here is the graph - https://postimg.cc/p9ys3yX5 . Write latency btw doesn't have the same trend. It is more or less constant opposite to read latency. -- Thank you, Roman
On 16-01-2024 11:22, Roman Pashin wrote:
Hello Ceph users,
we see strange issue on last recent Ceph installation v17.6.2. We store data on HDD pool, index pool is on SSD. Each OSD store its wal on NVME partition.
Do you make use of a separate db partition as well? And if so, where is it stored? Benchmarks didn't expose any issues with cluster, but since we
placed production load on it we see constantly growing OSD latency time (osd_read_latency) on SSD disks (where Index pool located). Latency is constantly growing day-by-day, but disks are not utilized even for 50%. Interesting, that when we move Index pool from SSD to NVME disks (disk space allows it for now) - osd latency drops to zero and start increasing from the ground.
Do you only see latency increase in reads? And not writes? Not sure what metrics you are looking at, but remember that some metrics are "long running averages" (from the start of the daemon). If you restart the daemon it might look like things dramatically changed, while in real life this does need to be so. Gr. Stefan
Hi Stefan, Do you make use of a separate db partition as well? And if so, where is
it stored?
No, only WAL partition is on separate NVME partition. Not sure if ceph-ansible could install Ceph with db partition on separate device on v17.6.2 Do you only see latency increase in reads? And not writes?
Exactly, I see it on read only. Write latency looks pretty constant. Not sure what metrics you are looking at, but remember that some metrics
are "long running averages" (from the start of the daemon). If you restart the daemon it might look like things dramatically changed, while in real life this does need to be so.
Metrics are standard Ceph metrics: "ceph_osd_op_r_latency_sum" and "ceph_osd_op_r_latency_count" and graph shows "rate(latency_sum[1m]) / rate(latency_count[1m])" value. The thing is that not only metrics are growing, but also response time for clients are growing with it. But when we do any transformation with index pool (migration to other OSDs or changing pg_num) - it drops and start growing again. I've not catched yet what is causing this, but I see, that sometimes latency drops without any manual intervention and start raising again (like on this graph https://postimg.cc/p9ys3yX5). -- Thank you, Roman
HI Roman, The fact that changing the pg_num for the index pool drops the latency back down might be a clue. Do you have a lot of deletes happening on this cluster? If you have a lot of deletes and long pauses between writes, you could be accumulating tombstones that you have to keep iterating over during bucket listing. Those get cleaned up during compaction. If there are no writes, you might not be compacting the tombstones away enough. Just a theory, but when you rearrange the PG counts, Ceph does a bunch of writes to move the data around, triggering compaction, and deleting the tombstones. In v17.2.7 we enabled a feature that automatically performs a compaction if too many tombstones are present during iteration in RocksDB. It might be worth upgrading to see if it helps (you might have to try tweaking the settings if the defaults aren't helping enough). The PR is here: https://github.com/ceph/ceph/pull/50893 Mark On 1/16/24 04:22, Roman Pashin wrote:
Hello Ceph users,
we see strange issue on last recent Ceph installation v17.6.2. We store data on HDD pool, index pool is on SSD. Each OSD store its wal on NVME partition. Benchmarks didn't expose any issues with cluster, but since we placed production load on it we see constantly growing OSD latency time (osd_read_latency) on SSD disks (where Index pool located). Latency is constantly growing day-by-day, but disks are not utilized even for 50%. Interesting, that when we move Index pool from SSD to NVME disks (disk space allows it for now) - osd latency drops to zero and start increasing from the ground. Also we noticed, that any change of pg_num for index pool (from 256 to 128 for instance) also drops latency to zero. And it starts its growth again (https://postimg.cc/5YHk9bby).
From client perspective it looks like one operation takes longer and longer each other day and operation time drops each time when we do some change on index pool. I've enabled debug_optracker 10/0 and it shows, that OSD spend most time in `queued_for_pg` state, but physical disk utilization is about 10-20%. Also per logs I see, that longest operation is Listbucket, but it is strange, that with less than 100'000 items in bucket list even with 'max_keys=1' takes 3-40 seconds.
If it matters client is Apache Flink doing checkpoints via S3 protocol.
Here is an example of operation with debug_optracking logs:
2023-12-29T16:24:28.873353+0300, event: throttled, op: osd_op(client.1227774 .0:22575820 7.19 7.a84f1a59 (undecoded) ondisk+write+known_if_redirected+supports_pool_eio e83833) 2023-12-29T16:24:28.861549+0300, event: header_read, op: osd_op(client. 1227774.0:22575820 7.19 7.a84f1a59 (undecoded) ondisk+write+known_if_redirected+supports_pool_eio e83833) 2023-12-29T16:24:28.873358+0300, event: all_read, op: osd_op(client.1227774 .0:22575820 7.19 7.a84f1a59 (undecoded) ondisk+write+known_if_redirected+supports_pool_eio e83833) 2023-12-29T16:24:28.873359+0300, event: dispatched, op: osd_op(client. 1227774.0:22575820 7.19 7.a84f1a59 (undecoded) ondisk+write+known_if_redirected+supports_pool_eio e83833) 2023-12-29T16:24:28.873389+0300, event: queued_for_pg, op: osd_op(client. 1227774.0:22575820 7.19 7.a84f1a59 (undecoded) ondisk+write+known_if_redirected+supports_pool_eio e83833) 2023-12-29T16:24:38.077528+0300, event: reached_pg, op: osd_op(client. 1227774.0:22575820 7.19 7.a84f1a59 (undecoded) ondisk+write+known_if_redirected+supports_pool_eio e83833) 2023-12-29T16:24:38.077561+0300, event: started, op: osd_op(client.1227774 .0:22575820 7.19 7:9a58f215:::.dir.68960da3-1c98-45c1-a87a-9e6c39253d27. 9780498.1.83:head [stat,call rgw.guard_bucket_resharding in=36b,call rgw.bucket_prepare_op in=331b] snapc 0=[] ondisk+write+known_if_redirected+supports_pool_eio e83833) 2023-12-29T16:24:38.077714+0300, event: waiting for subops from 59,494, op: osd_op(client.1227774.0:22575820 7.19 7:9a58f215:::.dir.68960da3-1c98-45c1-a87a-9e6c39253d27.9780498.1.83:head [stat,call rgw.guard_bucket_resharding in=36b,call rgw.bucket_prepare_op in=331b] snapc 0=[] ondisk+write+known_if_redirected+supports_pool_eio e83833) 2023-12-29T16:24:38.146157+0300, event: sub_op_commit_rec, op: osd_op(client.1227774.0:22575820 7.19 7:9a58f215:::.dir.68960da3-1c98-45c1-a87a-9e6c39253d27.9780498.1.83:head [stat,call rgw.guard_bucket_resharding in=36b,call rgw.bucket_prepare_op in=331b] snapc 0=[] ondisk+write+known_if_redirected+supports_pool_eio e83833) 2023-12-29T16:24:38.146166+0300, event: op_commit, op: osd_op(client.1227774 .0:22575820 7.19 7:9a58f215:::.dir.68960da3-1c98-45c1-a87a-9e6c39253d27. 9780498.1.83:head [stat,call rgw.guard_bucket_resharding in=36b,call rgw.bucket_prepare_op in=331b] snapc 0=[] ondisk+write+known_if_redirected+supports_pool_eio e83833) 2023-12-29T16:24:38.146191+0300, event: sub_op_commit_rec, op: osd_op(client.1227774.0:22575820 7.19 7:9a58f215:::.dir.68960da3-1c98-45c1-a87a-9e6c39253d27.9780498.1.83:head [stat,call rgw.guard_bucket_resharding in=36b,call rgw.bucket_prepare_op in=331b] snapc 0=[] ondisk+write+known_if_redirected+supports_pool_eio e83833) 2023-12-29T16:24:38.146204+0300, event: commit_sent, op: osd_op(client. 1227774.0:22575820 7.19 7:9a58f215:::.dir.68960da3-1c98-45c1-a87a-9e6c39253d27.9780498.1.83:head [stat,call rgw.guard_bucket_resharding in=36b,call rgw.bucket_prepare_op in=331b] snapc 0=[] ondisk+write+known_if_redirected+supports_pool_eio e83833) 2023-12-29T16:24:38.146216+0300, event: done, op: osd_op(client.1227774.0:22575820 7.19 7:9a58f215:::.dir.68960da3-1c98-45c1-a87a-9e6c39253d27.9780498.1.83:head [stat,call rgw.guard_bucket_resharding in=36b,call rgw.bucket_prepare_op in=331b] snapc 0=[] ondisk+write+known_if_redirected+supports_pool_eio e83833)
Does anybody faced with the same issue? I'd be very grateful for any idea because at this point I've got stuck with what to tune and where to look at.
Cluster setup - replication 3x, 15 servers in 3 datacenters with datacenter as failure domain. 7x HDD (data), 2x SSD (index), 1x NVME (wal + OS). ceph config - https://pastebin.com/pCqxXhT3 OSD read latency graph - https://postimg.cc/5YHk9bby
-- Best Regards, Mark Nelson Head of Research and Development Clyso GmbH p: +49 89 21552391 12 | a: Minnesota, USA w: https://clyso.com | e: mark.nelson@clyso.com We are hiring: https://www.clyso.com/jobs/
Hi Mark, thank you for prompt answer.
The fact that changing the pg_num for the index pool drops the latency
back down might be a clue. Do you have a lot of deletes happening on this cluster? If you have a lot of deletes and long pauses between writes, you could be accumulating tombstones that you have to keep iterating over during bucket listing.
What you describe looks very close to our case of periodic creation of checkpoints. Now it sounds like it can be our issue. Those get cleaned up during
compaction. If there are no writes, you might not be compacting the tombstones away enough. Just a theory, but when you rearrange the PG counts, Ceph does a bunch of writes to move the data around, triggering compaction, and deleting the tombstones.
In v17.2.7 we enabled a feature that automatically performs a compaction if too many tombstones are present during iteration in RocksDB. It might be worth upgrading to see if it helps (you might have to try tweaking the settings if the defaults aren't helping enough). The PR is here:
https://github.com/ceph/ceph/pull/50893
Thank you very much for this idea! We'll upgrade cluster to v17.2.7 and will check if it helped. If not - we'll try to tune options you are referring to. Anyway I'll update the thread with result.
Thank you once again for well-explained suggestion, Mark! -- Thank you, Roman
Hi Mark, In v17.2.7 we enabled a feature that automatically performs a compaction
if too many tombstones are present during iteration in RocksDB. It might be worth upgrading to see if it helps (you might have to try tweaking the settings if the defaults aren't helping enough). The PR is here:
we've upgraded Ceph to v17.2.7 yesterday. Unfortunately I still see growing latency on OSDs hosting index pool. Will try to tune rocksdb_cf_compact_on_deletion options as you suggested. I've started with decreasing deletion_trigger from 16384 to 512 with: # ceph tell 'osd.*' injectargs '--rocksdb_cf_compact_on_deletion_trigger 512' At first glance - nothing has changed per OSD latency graphs. I've tried to decrease it to 32 deletions per window on a single OSD where I see increasing latency to force compactions, but per graphs nothing has changed after approx 40 minutes. # ceph tell 'osd.435' injectargs '--rocksdb_cf_compact_on_deletion_trigger 32' Didn't touch rocksdb_cf_compact_on_deletion_sliding_window yet, it is set with default 32768 entries. Do you know if it rocksdb_cf_compact_on_deletion_trigger and rocksdb_cf_compact_on_deletion_sliding_window can be changed in runtime without OSD restart? -- Thank you, Roman
Do you know if it rocksdb_cf_compact_on_deletion_trigger and rocksdb_cf_compact_on_deletion_sliding_window can be changed in runtime without OSD restart?
Unfortunately they cannot. You'll want to set them in centralized conf and then restart OSDs for them to take effect. Josh On Fri, Jan 26, 2024 at 2:54 AM Roman Pashin <romanpashin28@gmail.com> wrote:
Hi Mark,
In v17.2.7 we enabled a feature that automatically performs a compaction
if too many tombstones are present during iteration in RocksDB. It might be worth upgrading to see if it helps (you might have to try tweaking the settings if the defaults aren't helping enough). The PR is here:
we've upgraded Ceph to v17.2.7 yesterday. Unfortunately I still see growing latency on OSDs hosting index pool. Will try to tune rocksdb_cf_compact_on_deletion options as you suggested.
I've started with decreasing deletion_trigger from 16384 to 512 with:
# ceph tell 'osd.*' injectargs '--rocksdb_cf_compact_on_deletion_trigger 512'
At first glance - nothing has changed per OSD latency graphs. I've tried to decrease it to 32 deletions per window on a single OSD where I see increasing latency to force compactions, but per graphs nothing has changed after approx 40 minutes.
# ceph tell 'osd.435' injectargs '--rocksdb_cf_compact_on_deletion_trigger 32'
Didn't touch rocksdb_cf_compact_on_deletion_sliding_window yet, it is set with default 32768 entries.
Do you know if it rocksdb_cf_compact_on_deletion_trigger and rocksdb_cf_compact_on_deletion_sliding_window can be changed in runtime without OSD restart?
-- Thank you, Roman _______________________________________________ ceph-users mailing list -- ceph-users@ceph.io To unsubscribe send an email to ceph-users-leave@ceph.io
Unfortunately they cannot. You'll want to set them in centralized conf and then restart OSDs for them to take effect.
Got it. Thank you Josh! WIll put it to config of affected OSDs and restart them. Just curious, can decreasing rocksdb_cf_compact_on_deletion_trigger 16384 > 4096 hurt performance of HDD OSDs in any way? I have no growing latency on HDD OSD, where data is stored, but it would be easier to set it to [osd] section without cherry picking only SSD/NVME OSDs, but for all at once. -- Thank you, Roman
Just curious, can decreasing rocksdb_cf_compact_on_deletion_trigger 16384 > 4096 hurt performance of HDD OSDs in any way? I have no growing latency on HDD OSD, where data is stored, but it would be easier to set it to [osd] section without cherry picking only SSD/NVME OSDs, but for all at once.
I think that depends on your workload, but I'm not certain. If you don't override the OSD classes, you should be able to do something like "ceph config set osd/class:ssd rocksdb_cf_compact_on_deletion_trigger 4096". Josh On Fri, Jan 26, 2024 at 10:27 AM Roman Pashin <romanpashin28@gmail.com> wrote:
Unfortunately they cannot. You'll want to set them in centralized conf and then restart OSDs for them to take effect.
Got it. Thank you Josh! WIll put it to config of affected OSDs and restart them.
Just curious, can decreasing rocksdb_cf_compact_on_deletion_trigger 16384 > 4096 hurt performance of HDD OSDs in any way? I have no growing latency on HDD OSD, where data is stored, but it would be easier to set it to [osd] section without cherry picking only SSD/NVME OSDs, but for all at once.
-- Thank you, Roman _______________________________________________ ceph-users mailing list -- ceph-users@ceph.io To unsubscribe send an email to ceph-users-leave@ceph.io
On 1/26/24 11:26, Roman Pashin wrote:
Unfortunately they cannot. You'll want to set them in centralized conf and then restart OSDs for them to take effect.
Got it. Thank you Josh! WIll put it to config of affected OSDs and restart them.
Just curious, can decreasing rocksdb_cf_compact_on_deletion_trigger 16384 > 4096 hurt performance of HDD OSDs in any way? I have no growing latency on HDD OSD, where data is stored, but it would be easier to set it to [osd] section without cherry picking only SSD/NVME OSDs, but for all at once.
Potentially if you set the trigger too low, you could force constant compactions. Say if you set it to trigger compaction every time a tombstone is encountered. You really want to find the sweet spot where iterating over tombstones (possibly multiple times) is more expensive than doing a compaction. The defaults are basically just tuned to avoid the worst case scenario where OSDs become laggy or even go into heartbeat timeout (and we're not 100% sure we got those right). I believe we've got a couple of big users that tune it more aggressively, though I'll let them speak up if they are able. Mark
-- Thank you, Roman _______________________________________________ ceph-users mailing list -- ceph-users@ceph.io To unsubscribe send an email to ceph-users-leave@ceph.io
Shiming in here, just so that it’s indexed in archives. We’ve have a lot of issues with tombstones when running RGW usage logging and when we trim those the Ceph OSD hosting that usage.X object will basically kill the OSD performance due to the tombstones being so many, restarting the OSD solves it. We are not yet on Quincy but when we are will look into optimizing rocksdb_cf_compact_on_deletion_trigger so that we don’t have to locate the objects, trim, restart OSDs everytime we want to clean them. Unfortunately the message on Ceph Slack is lost since it was a while back I wrote more details on that investigation, but IIRC the issue is that the "radosgw-admin usage trim” does SingleDelete() in the RocksDB layer when deleting objects that could be bulk deleted (RangeDelete?) due to them having the same prefix (name + date). Best regards
On 26 Jan 2024, at 23:18, Mark Nelson <mark.a.nelson@gmail.com> wrote:
On 1/26/24 11:26, Roman Pashin wrote:
Unfortunately they cannot. You'll want to set them in centralized conf and then restart OSDs for them to take effect.
Got it. Thank you Josh! WIll put it to config of affected OSDs and restart them.
Just curious, can decreasing rocksdb_cf_compact_on_deletion_trigger 16384 > 4096 hurt performance of HDD OSDs in any way? I have no growing latency on HDD OSD, where data is stored, but it would be easier to set it to [osd] section without cherry picking only SSD/NVME OSDs, but for all at once.
Potentially if you set the trigger too low, you could force constant compactions. Say if you set it to trigger compaction every time a tombstone is encountered. You really want to find the sweet spot where iterating over tombstones (possibly multiple times) is more expensive than doing a compaction. The defaults are basically just tuned to avoid the worst case scenario where OSDs become laggy or even go into heartbeat timeout (and we're not 100% sure we got those right). I believe we've got a couple of big users that tune it more aggressively, though I'll let them speak up if they are able.
Mark
-- Thank you, Roman _______________________________________________ ceph-users mailing list -- ceph-users@ceph.io To unsubscribe send an email to ceph-users-leave@ceph.io
ceph-users mailing list -- ceph-users@ceph.io To unsubscribe send an email to ceph-users-leave@ceph.io
I found the internal note I made about it, see below. When we trim thousands of OMAP keys in RocksDB this calls SingleDelete() in the RocksDBStore in Ceph, this causes tombstones in the RocksDB database. These thousands of tombstones that each needs to be iterated over when for example reading data from the database causes the latency to become super high. If the OSD is restarted the issue disappears, I assume this is because RocksDB or the RocksDBStore in Ceph creates a new iterator or does compaction internally upon startup. I don't see any straight forward solution without having to rebuild internal logic in the usage trim code. More specifically that would be investigating in the usage trim code to use `cls_cxx_map_remove_range()` which would call `RocksDBStore::RocksDBTransactionImpl::rm_range_keys()` internally instead when doing a usage trim for an epoch (—start-date and —end-date only, and no user or bucket). The problem there though is that the `rocksdb_delete_range_threshold` config option defaults to 1_M which is way more than the amount we are deleting and still causing issue, that function calls `DeleteRange()` instead of `SingleDelete()` in RocksDB which would cause one tombstone for all entries instead of one tombstone for every single OMAP key. Even better for above would be calling `rmkeys_by_prefix()` and not having to specify start and end but there is no OSD op in PrimaryLogPG for that which means even more work that might not be backportable. Our best bet right now without touching radosgw-admin is upgrading to >=16.2.14 which introduces https://github.com/ceph/ceph/pull/50894 that will do compaction if a threshold of tombstones is hit within a sliding window during iteration. Best regards
On 2 Feb 2024, at 11:29, Tobias Urdin <tobias.urdin@binero.com> wrote:
Shiming in here, just so that it’s indexed in archives.
We’ve have a lot of issues with tombstones when running RGW usage logging and when we trim those the Ceph OSD hosting that usage.X object will basically kill the OSD performance due to the tombstones being so many, restarting the OSD solves it.
We are not yet on Quincy but when we are will look into optimizing rocksdb_cf_compact_on_deletion_trigger so that we don’t have to locate the objects, trim, restart OSDs everytime we want to clean them.
Unfortunately the message on Ceph Slack is lost since it was a while back I wrote more details on that investigation, but IIRC the issue is that the "radosgw-admin usage trim” does SingleDelete() in the RocksDB layer when deleting objects that could be bulk deleted (RangeDelete?) due to them having the same prefix (name + date).
Best regards
On 26 Jan 2024, at 23:18, Mark Nelson <mark.a.nelson@gmail.com> wrote:
On 1/26/24 11:26, Roman Pashin wrote:
Unfortunately they cannot. You'll want to set them in centralized conf and then restart OSDs for them to take effect.
Got it. Thank you Josh! WIll put it to config of affected OSDs and restart them.
Just curious, can decreasing rocksdb_cf_compact_on_deletion_trigger 16384 > 4096 hurt performance of HDD OSDs in any way? I have no growing latency on HDD OSD, where data is stored, but it would be easier to set it to [osd] section without cherry picking only SSD/NVME OSDs, but for all at once.
Potentially if you set the trigger too low, you could force constant compactions. Say if you set it to trigger compaction every time a tombstone is encountered. You really want to find the sweet spot where iterating over tombstones (possibly multiple times) is more expensive than doing a compaction. The defaults are basically just tuned to avoid the worst case scenario where OSDs become laggy or even go into heartbeat timeout (and we're not 100% sure we got those right). I believe we've got a couple of big users that tune it more aggressively, though I'll let them speak up if they are able.
Mark
-- Thank you, Roman _______________________________________________ ceph-users mailing list -- ceph-users@ceph.io To unsubscribe send an email to ceph-users-leave@ceph.io
ceph-users mailing list -- ceph-users@ceph.io To unsubscribe send an email to ceph-users-leave@ceph.io
We've seen issues with high index OSD latencies in multiple scenarios over the past couple of years. The issues related to rocksdb tombstones could certainly be relevant, but compact on deletion has been very effective for us in that regard. Recently, we experienced a similar issue at a higher level with the RGW bucket index deletion markers on versioned buckets. Do you happen to have versioned buckets in your cluster? If you do and the clients of those buckets are doing a bunch of deletes that leave behind S3 delete markers, the CLS code may be doing a lot of work to filter relevant entries during bucket listing ops. Another thing that we've found is that rocksdb can become quite slow if it doesn't have enough memory for internal caches. As our cluster usage has grown, we've needed to increase OSD memory in accordance with bucket index pool usage. One one cluster, we found that increasing OSD memory improved rocksdb latencies by over 10x. Hope this helps! Cory Snyder From: Tobias Urdin <tobias.urdin@binero.com> Sent: Friday, February 2, 2024 5:41 AM To: ceph-users <ceph-users@ceph.io> Subject: [ceph-users] Re: OSD read latency grows over time I found the internal note I made about it, see below. When we trim thousands of OMAP keys in RocksDB this calls SingleDelete() in the RocksDBStore in Ceph, this causes tombstones in the RocksDB database. These thousands of tombstones that each ZjQcmQRYFpfptBannerStart This Message Is From an Untrusted Sender You have not previously corresponded with this sender. Report Suspicious ZjQcmQRYFpfptBannerEnd I found the internal note I made about it, see below. When we trim thousands of OMAP keys in RocksDB this calls SingleDelete() in the RocksDBStore in Ceph, this causes tombstones in the RocksDB database. These thousands of tombstones that each needs to be iterated over when for example reading data from the database causes the latency to become super high. If the OSD is restarted the issue disappears, I assume this is because RocksDB or the RocksDBStore in Ceph creates a new iterator or does compaction internally upon startup. I don't see any straight forward solution without having to rebuild internal logic in the usage trim code. More specifically that would be investigating in the usage trim code to use `cls_cxx_map_remove_range()` which would call `RocksDBStore::RocksDBTransactionImpl::rm_range_keys()` internally instead when doing a usage trim for an epoch (—start-date and —end-date only, and no user or bucket). The problem there though is that the `rocksdb_delete_range_threshold` config option defaults to 1_M which is way more than the amount we are deleting and still causing issue, that function calls `DeleteRange()` instead of `SingleDelete()` in RocksDB which would cause one tombstone for all entries instead of one tombstone for every single OMAP key. Even better for above would be calling `rmkeys_by_prefix()` and not having to specify start and end but there is no OSD op in PrimaryLogPG for that which means even more work that might not be backportable. Our best bet right now without touching radosgw-admin is upgrading to >=16.2.14 which introduces https://urldefense.com/v3/__https://github.com/ceph/ceph/pull/50894__;!!J0dt... that will do compaction if a threshold of tombstones is hit within a sliding window during iteration. Best regards
On 2 Feb 2024, at 11:29, Tobias Urdin <tobias.urdin@binero.com> wrote:
Shiming in here, just so that it’s indexed in archives.
We’ve have a lot of issues with tombstones when running RGW usage logging and when we trim those the Ceph OSD hosting that usage.X object will basically kill the OSD performance due to the tombstones being so many, restarting the OSD solves it.
We are not yet on Quincy but when we are will look into optimizing rocksdb_cf_compact_on_deletion_trigger so that we don’t have to locate the objects, trim, restart OSDs everytime we want to clean them.
Unfortunately the message on Ceph Slack is lost since it was a while back I wrote more details on that investigation, but IIRC the issue is that the "radosgw-admin usage trim” does SingleDelete() in the RocksDB layer when deleting objects that could be bulk deleted (RangeDelete?) due to them having the same prefix (name + date).
Best regards
On 26 Jan 2024, at 23:18, Mark Nelson <mark.a.nelson@gmail.com> wrote:
On 1/26/24 11:26, Roman Pashin wrote:
Unfortunately they cannot. You'll want to set them in centralized conf and then restart OSDs for them to take effect.
Got it. Thank you Josh! WIll put it to config of affected OSDs and restart them.
Just curious, can decreasing rocksdb_cf_compact_on_deletion_trigger 16384 > 4096 hurt performance of HDD OSDs in any way? I have no growing latency on HDD OSD, where data is stored, but it would be easier to set it to [osd] section without cherry picking only SSD/NVME OSDs, but for all at once.
Potentially if you set the trigger too low, you could force constant compactions. Say if you set it to trigger compaction every time a tombstone is encountered. You really want to find the sweet spot where iterating over tombstones (possibly multiple times) is more expensive than doing a compaction. The defaults are basically just tuned to avoid the worst case scenario where OSDs become laggy or even go into heartbeat timeout (and we're not 100% sure we got those right). I believe we've got a couple of big users that tune it more aggressively, though I'll let them speak up if they are able.
Mark
-- Thank you, Roman _______________________________________________ ceph-users mailing list -- ceph-users@ceph.io To unsubscribe send an email to ceph-users-leave@ceph.io
ceph-users mailing list -- ceph-users@ceph.io To unsubscribe send an email to ceph-users-leave@ceph.io
_______________________________________________ ceph-users mailing list -- ceph-users@ceph.io To unsubscribe send an email to ceph-users-leave@ceph.io
You adjusted osd_memory_target? Higher than the default 4GB?
Another thing that we've found is that rocksdb can become quite slow if it doesn't have enough memory for internal caches. As our cluster usage has grown, we've needed to increase OSD memory in accordance with bucket index pool usage. One one cluster, we found that increasing OSD memory improved rocksdb latencies by over 10x.
Yes, we changed osd_memory_target to 10 GB on just our index OSDs. These OSDs have over 300 GB of lz4 compressed bucket index omap data. Here is a graph showing the latencies before/after that single change: https://pasteboard.co/IMCUWa1t3Uau.png Cory Snyder From: Anthony D'Atri <anthony.datri@gmail.com> Sent: Friday, February 2, 2024 2:15 PM To: Cory Snyder <csnyder@1111systems.com> Cc: ceph-users <ceph-users@ceph.io> Subject: Re: [ceph-users] OSD read latency grows over time You adjusted osd_memory_target? Higher than the default 4GB? Another thing that we've found is that rocksdb can become quite slow if it doesn't have enough memory for internal caches. As our cluster usage has grown, we've needed to increase ZjQcmQRYFpfptBannerStart This Message Is From an External Sender This message came from outside your organization. Report Suspicious ZjQcmQRYFpfptBannerEnd You adjusted osd_memory_target? Higher than the default 4GB? Another thing that we've found is that rocksdb can become quite slow if it doesn't have enough memory for internal caches. As our cluster usage has grown, we've needed to increase OSD memory in accordance with bucket index pool usage. One one cluster, we found that increasing OSD memory improved rocksdb latencies by over 10x.
Hi Cory, Thanks for the excellent information here! I'm super curious how much the kv cache is using in this case. If you happen to have a dump from the perf counters that includes the prioritycache subsystem that would be ideal. By default, onode (meta) and rocksdb (except for onodes stored in rocksdb) each get a first shot at 45% of the available cache memory at high priority, but how much they actually request depends on the relative ages of the items in each cache. The age bins are defined in seconds. By default: kv: "1 2 6 24 120 720 0 0 0 0" kv_onode: "0 0 0 0 0 0 0 0 0 720" meta: "1 2 6 24 120 720 0 0 0 0" data: "1 2 6 24 120 720 0 0 0 0" and the ratios: kv: 45% kv_onode: 4% meta: 45% data: 6% (implicit) This means that items from the kv cache, meta cache, and data caches that are less than 1 second old will all be competing with each other for memory during the first round. kv and meta cache can each get up to 45% of the available memory and meta/data get up to 4% and 6% respectively. Since kv_onode doesn't actually compete at the first priority level though, it won't actually request any memory. Whatever memory is left after the first round (assuming there is any) will be divided up based on the ratios to the remaining caches that are still requesting memory until either there are no requests or no memory left. After that, the PriorityCache proceeds to the next round and does the same thing, this time for cache items that are between 1 and 2 seconds old. Then between 2 and 6 seconds old, etc. This approach lets us have different caches compete at different intervals. For instance we could have the first age-bin be 0-1 seconds for onodes, but 0-5 seconds for kv. We could also make the ratios different. IE the first bin might be for onodes that are 0-1 seconds, but we give them a first shot at 60% of the memory. kv entries that are 0-5 seconds old might all be put in the first priority bin with the 0-1 second onodes, but we could give them say only a 30% iniital shot at available memory (but they would still all be cached with higher priority than onodes that are 1-2 seconds old). Ultimately, we might find that there are better defaults for the bins and ratios when the index gets big, however typically we really want to cache onodes, so if we are seeing that the kv cache is fully utilizing it's default ratio, increasing the amount of memory may indeed be warranted. Mark On 2/2/24 12:50, Cory Snyder wrote:
We've seen issues with high index OSD latencies in multiple scenarios over the past couple of years. The issues related to rocksdb tombstones could certainly be relevant, but compact on deletion has been very effective for us in that regard. Recently, we experienced a similar issue at a higher level with the RGW bucket index deletion markers on versioned buckets. Do you happen to have versioned buckets in your cluster? If you do and the clients of those buckets are doing a bunch of deletes that leave behind S3 delete markers, the CLS code may be doing a lot of work to filter relevant entries during bucket listing ops.
Another thing that we've found is that rocksdb can become quite slow if it doesn't have enough memory for internal caches. As our cluster usage has grown, we've needed to increase OSD memory in accordance with bucket index pool usage. One one cluster, we found that increasing OSD memory improved rocksdb latencies by over 10x.
Hope this helps!
Cory Snyder
From: Tobias Urdin <tobias.urdin@binero.com> Sent: Friday, February 2, 2024 5:41 AM To: ceph-users <ceph-users@ceph.io> Subject: [ceph-users] Re: OSD read latency grows over time
I found the internal note I made about it, see below. When we trim thousands of OMAP keys in RocksDB this calls SingleDelete() in the RocksDBStore in Ceph, this causes tombstones in the RocksDB database. These thousands of tombstones that each ZjQcmQRYFpfptBannerStart This Message Is From an Untrusted Sender You have not previously corresponded with this sender. Report Suspicious
ZjQcmQRYFpfptBannerEnd I found the internal note I made about it, see below.
When we trim thousands of OMAP keys in RocksDB this calls SingleDelete() in the RocksDBStore in Ceph, this causes tombstones in the RocksDB database.
These thousands of tombstones that each needs to be iterated over when for example reading data from the database causes the latency to become super high. If the OSD is restarted the issue disappears, I assume this is because RocksDB or the RocksDBStore in Ceph creates a new iterator or does compaction internally upon startup.
I don't see any straight forward solution without having to rebuild internal logic in the usage trim code. More specifically that would be investigating in the usage trim code to use `cls_cxx_map_remove_range()` which would call `RocksDBStore::RocksDBTransactionImpl::rm_range_keys()` internally instead when doing a usage trim for an epoch (—start-date and —end-date only, and no user or bucket).
The problem there though is that the `rocksdb_delete_range_threshold` config option defaults to 1_M which is way more than the amount we are deleting and still causing issue, that function calls `DeleteRange()` instead of `SingleDelete()` in RocksDB which would cause one tombstone for all entries instead of one tombstone for every single OMAP key.
Even better for above would be calling `rmkeys_by_prefix()` and not having to specify start and end but there is no OSD op in PrimaryLogPG for that which means even more work that might not be backportable.
Our best bet right now without touching radosgw-admin is upgrading to >=16.2.14 which introduces https://urldefense.com/v3/__https://github.com/ceph/ceph/pull/50894__;!!J0dt... that will do compaction if a threshold of tombstones is hit within a sliding window during iteration.
Best regards
On 2 Feb 2024, at 11:29, Tobias Urdin <tobias.urdin@binero.com> wrote:
Shiming in here, just so that it’s indexed in archives.
We’ve have a lot of issues with tombstones when running RGW usage logging and when we trim those the Ceph OSD hosting that usage.X object will basically kill the OSD performance due to the tombstones being so many, restarting the OSD solves it.
We are not yet on Quincy but when we are will look into optimizing rocksdb_cf_compact_on_deletion_trigger so that we don’t have to locate the objects, trim, restart OSDs everytime we want to clean them.
Unfortunately the message on Ceph Slack is lost since it was a while back I wrote more details on that investigation, but IIRC the issue is that the "radosgw-admin usage trim” does SingleDelete() in the RocksDB layer when deleting objects that could be bulk deleted (RangeDelete?) due to them having the same prefix (name + date).
Best regards
On 26 Jan 2024, at 23:18, Mark Nelson <mark.a.nelson@gmail.com> wrote:
On 1/26/24 11:26, Roman Pashin wrote:
Unfortunately they cannot. You'll want to set them in centralized conf and then restart OSDs for them to take effect.
Got it. Thank you Josh! WIll put it to config of affected OSDs and restart them.
Just curious, can decreasing rocksdb_cf_compact_on_deletion_trigger 16384 > 4096 hurt performance of HDD OSDs in any way? I have no growing latency on HDD OSD, where data is stored, but it would be easier to set it to [osd] section without cherry picking only SSD/NVME OSDs, but for all at once.
Potentially if you set the trigger too low, you could force constant compactions. Say if you set it to trigger compaction every time a tombstone is encountered. You really want to find the sweet spot where iterating over tombstones (possibly multiple times) is more expensive than doing a compaction. The defaults are basically just tuned to avoid the worst case scenario where OSDs become laggy or even go into heartbeat timeout (and we're not 100% sure we got those right). I believe we've got a couple of big users that tune it more aggressively, though I'll let them speak up if they are able.
Mark
-- Thank you, Roman _______________________________________________ ceph-users mailing list -- ceph-users@ceph.io To unsubscribe send an email to ceph-users-leave@ceph.io
ceph-users mailing list -- ceph-users@ceph.io To unsubscribe send an email to ceph-users-leave@ceph.io
ceph-users mailing list -- ceph-users@ceph.io To unsubscribe send an email to ceph-users-leave@ceph.io _______________________________________________ ceph-users mailing list -- ceph-users@ceph.io To unsubscribe send an email to ceph-users-leave@ceph.io
-- Best Regards, Mark Nelson Head of Research and Development Clyso GmbH p: +49 89 21552391 12 | a: Minnesota, USA w: https://clyso.com | e: mark.nelson@clyso.com We are hiring: https://www.clyso.com/jobs/
participants (9)
-
Anthony D'Atri
-
Cory Snyder
-
Eugen Block
-
Josh Baergen
-
Mark Nelson
-
Mark Nelson
-
Roman Pashin
-
Stefan Kooman
-
Tobias Urdin