18 Jun
2020
18 Jun
'20
8:24 a.m.
Hi,
we're using Ceph as S3-compatible storage to serve static files (mostly
css/js/images + some videos) and I've noticed that there seem to be
huge read amplification for index pool.
Incoming traffic magniture is of around 15k req/sec (mostly sub 1MB
request but index pool is getting hammered:
pool pl-war1.rgw.buckets.index id 10
client io 632 MiB/s rd, 277 KiB/s wr, 129.92k op/s rd, 415 op/s wr
pool pl-war1.rgw.buckets.data id 11
client io 4.5 MiB/s rd, 6.8 MiB/s wr, 640 op/s rd, 1.65k op/s wr
and is getting order of magnitude more requests
running 15.2.3, nothing special in terms of tunning aside from
disabling some logging as to not overflow the logs.
We've had similar test cluster on 12.x (and way slower hardware)
getting similar traffic and haven't observed that magnitude of
difference.
when enabling debug on affected OSD I only get spam of
2020-06-17T12:35:05.700+0200 7f80694c4700 10 bluestore(/var/lib/ceph/osd/ceph-20)
omap_get_header 10.51_head oid
#10:8b1a34d8:::.dir.88d4f221-0da5-444d-81a8-517771278350.454759.8.214:head# = 0
2020-06-17T12:35:05.700+0200 7f80694c4700 10 bluestore(/var/lib/ceph/osd/ceph-20)
get_omap_iterator 10.51_head
#10:8b1a34d8:::.dir.88d4f221-0da5-444d-81a8-517771278350.454759.8.214:head#
2020-06-17T12:35:05.700+0200 7f80694c4700 10 bluestore(/var/lib/ceph/osd/ceph-20)
get_omap_iterator 10.51_head
#10:8b1a34d8:::.dir.88d4f221-0da5-444d-81a8-517771278350.454759.8.214:head#
2020-06-17T12:35:05.700+0200 7f80694c4700 10 bluestore(/var/lib/ceph/osd/ceph-20)
get_omap_iterator 10.51_head
#10:8b1a34d8:::.dir.88d4f221-0da5-444d-81a8-517771278350.454759.8.214:head#
2020-06-17T12:35:05.700+0200 7f80694c4700 10 bluestore(/var/lib/ceph/osd/ceph-20)
get_omap_iterator 10.51_head
#10:8b1a34d8:::.dir.88d4f221-0da5-444d-81a8-517771278350.454759.8.214:head#
2020-06-17T12:35:05.704+0200 7f80694c4700 10 bluestore(/var/lib/ceph/osd/ceph-20)
get_omap_iterator 10.51_head
#10:8b1a34d8:::.dir.88d4f221-0da5-444d-81a8-517771278350.454759.8.214:head#
2020-06-17T12:35:05.704+0200 7f80694c4700 10 bluestore(/var/lib/ceph/osd/ceph-20)
get_omap_iterator 10.51_head
#10:8b1a34d8:::.dir.88d4f221-0da5-444d-81a8-517771278350.454759.8.214:head#
2020-06-17T12:35:05.704+0200 7f80694c4700 10 bluestore(/var/lib/ceph/osd/ceph-20)
get_omap_iterator 10.51_head
#10:8b1a34d8:::.dir.88d4f221-0da5-444d-81a8-517771278350.454759.8.214:head#
2020-06-17T12:35:05.704+0200 7f80694c4700 10 bluestore(/var/lib/ceph/osd/ceph-20)
get_omap_iterator 10.51_head
#10:8b1a34d8:::.dir.88d4f221-0da5-444d-81a8-517771278350.454759.8.214:head#
2020-06-17T12:35:05.704+0200 7f80694c4700 10 bluestore(/var/lib/ceph/osd/ceph-20)
omap_get_header 10.51_head oid
#10:8b0d75b0:::.dir.88d4f221-0da5-444d-81a8-517771278350.454759.8.222:head# = 0
2020-06-17T12:35:05.704+0200 7f80694c4700 10 bluestore(/var/lib/ceph/osd/ceph-20)
get_omap_iterator 10.51_head
#10:8b0d75b0:::.dir.88d4f221-0da5-444d-81a8-517771278350.454759.8.222:head#
2020-06-17T12:35:05.704+0200 7f80694c4700 10 bluestore(/var/lib/ceph/osd/ceph-20)
get_omap_iterator 10.51_head
#10:8b0d75b0:::.dir.88d4f221-0da5-444d-81a8-517771278350.454759.8.222:head#
2020-06-17T12:35:05.704+0200 7f80694c4700 10 bluestore(/var/lib/ceph/osd/ceph-20)
get_omap_iterator 10.51_head
#10:8b0d75b0:::.dir.88d4f221-0da5-444d-81a8-517771278350.454759.8.222:head#
2020-06-17T12:35:05.704+0200 7f80694c4700 10 bluestore(/var/lib/ceph/osd/ceph-20)
get_omap_iterator 10.51_head
#10:8b0d75b0:::.dir.88d4f221-0da5-444d-81a8-517771278350.454759.8.222:head#
2020-06-17T12:35:05.704+0200 7f80694c4700 10 bluestore(/var/lib/ceph/osd/ceph-20)
get_omap_iterator 10.51_head
#10:8b0d75b0:::.dir.88d4f221-0da5-444d-81a8-517771278350.454759.8.222:head#
2020-06-17T12:35:05.704+0200 7f80694c4700 10 bluestore(/var/lib/ceph/osd/ceph-20)
get_omap_iterator 10.51_head
#10:8b0d75b0:::.dir.88d4f221-0da5-444d-81a8-517771278350.454759.8.222:head#
2020-06-17T12:35:05.708+0200 7f80694c4700 10 bluestore(/var/lib/ceph/osd/ceph-20)
get_omap_iterator 10.51_head
#10:8b0d75b0:::.dir.88d4f221-0da5-444d-81a8-517771278350.454759.8.222:head#
2020-06-17T12:35:05.708+0200 7f80694c4700 10 bluestore(/var/lib/ceph/osd/ceph-20)
get_omap_iterator 10.51_head
#10:8b0d75b0:::.dir.88d4f221-0da5-444d-81a8-517771278350.454759.8.222:head#
2020-06-17T12:35:05.716+0200 7f806d4cc700 10 bluestore(/var/lib/ceph/osd/ceph-20)
omap_get_header 10.51_head oid
#10:8b5ed205:::.dir.88d4f221-0da5-444d-81a8-517771278350.454759.8.151:head# = 0
2020-06-17T12:35:05.716+0200 7f806d4cc700 10 bluestore(/var/lib/ceph/osd/ceph-20)
get_omap_iterator 10.51_head
#10:8b5ed205:::.dir.88d4f221-0da5-444d-81a8-517771278350.454759.8.151:head#
2020-06-17T12:35:05.716+0200 7f806d4cc700 10 bluestore(/var/lib/ceph/osd/ceph-20)
get_omap_iterator 10.51_head
#10:8b5ed205:::.dir.88d4f221-0da5-444d-81a8-517771278350.454759.8.151:head#
2020-06-17T12:35:05.720+0200 7f806d4cc700 10 bluestore(/var/lib/ceph/osd/ceph-20)
get_omap_iterator 10.51_head
#10:8b5ed205:::.dir.88d4f221-0da5-444d-81a8-517771278350.454759.8.151:head#
2020-06-17T12:35:05.720+0200 7f806d4cc700 10 bluestore(/var/lib/ceph/osd/ceph-20)
get_omap_iterator 10.51_head
#10:8b5ed205:::.dir.88d4f221-0da5-444d-81a8-517771278350.454759.8.151:head#
2020-06-17T12:35:05.720+0200 7f806d4cc700 10 bluestore(/var/lib/ceph/osd/ceph-20)
get_omap_iterator 10.51_head
#10:8b5ed205:::.dir.88d4f221-0da5-444d-81a8-517771278350.454759.8.151:head#
2020-06-17T12:35:05.720+0200 7f806d4cc700 10 bluestore(/var/lib/ceph/osd/ceph-20)
get_omap_iterator 10.51_head
#10:8b5ed205:::.dir.88d4f221-0da5-444d-81a8-517771278350.454759.8.151:head#
2020-06-17T12:35:05.720+0200 7f806d4cc700 10 bluestore(/var/lib/ceph/osd/ceph-20)
get_omap_iterator 10.51_head
#10:8b5ed205:::.dir.88d4f221-0da5-444d-81a8-517771278350.454759.8.151:head#
2020-06-17T12:35:05.720+0200 7f806d4cc700 10 bluestore(/var/lib/ceph/osd/ceph-20)
get_omap_iterator 10.51_head
#10:8b5ed205:::.dir.88d4f221-0da5-444d-81a8-517771278350.454759.8.151:head#
--
Mariusz Gronczewski (XANi) <xani666(a)gmail.com>
GnuPG: 0xEA8ACE64
http://devrandom.pl
18 Jun
18 Jun
9:51 a.m.
Dear Mariusz,
we're using Ceph as S3-compatible storage to serve
static files (mostly
css/js/images + some videos) and I've noticed that there seem to be
huge read amplification for index pool.
we have observed that too, under Nautilus (14.2.4-14.2.8).
Incoming traffic magniture is of around 15k req/sec
(mostly sub 1MB
request but index pool is getting hammered:
pool pl-war1.rgw.buckets.index id 10
client io 632 MiB/s rd, 277 KiB/s wr, 129.92k op/s rd, 415 op/s wr
pool pl-war1.rgw.buckets.data id 11
client io 4.5 MiB/s rd, 6.8 MiB/s wr, 640 op/s rd, 1.65k op/s wr
and is getting order of magnitude more requests
Our hypothesis is that this is due to the way that RadosGW maps bucket
index queries (ListObjects/ListObjectsV2) to Rados-level operations
against a *sharded* index.
For certain types of S3 index queries, the response must be collected
from multiple (potentially all) shards of the index.
S3 index queries are always "bounded" by the response limitation (1000
keys by default). But when your index is distributed over, let's say,
2000 shards, RadosGW must collect some data from those 2000 shards, then
throw away most of what it gets, and return the next 1000 keys. This
could explain the kind of read amplification that you are seeing.
(In practice, S3 index queries often use "prefix" and "delimiter" to
emulate a hierarchical directory structure. A recently merged change,
https://github.com/ceph/ceph/pull/30272 , should make such queries much
more efficient in RadosGW (note that the change contains some extensions
to the OSD-side Rados protocol). But if I read it correctly, that
change is already in the version you are using.)
Paul Emmerich has written about performance issues with large buckets on
this list, see
https://lists.ceph.io/hyperkitty/list/dev@ceph.io/thread/36P62BOOCJBVVJCVUX…
Let's say that there are opportunities for further improvements.
You could look for the specific queries that cause the high read load in
your system. Maybe there's something that can be done on the client
side. This could also provide input for Ceph development as to what
kinds of index operations are used by applications "in the wild". Those
might be worth optimizing first :-)
running 15.2.3, nothing special in terms of tunning
aside from
disabling some logging as to not overflow the logs.
We've had similar test cluster on 12.x (and way
slower hardware)
getting similar traffic and haven't observed that magnitude of
difference.
Was your bucket index sharded in 12.x?
when enabling debug on affected OSD I only get spam of
2020-06-17T12:35:05.700+0200 7f80694c4700 10
bluestore(/var/lib/ceph/osd/ceph-20) omap_get_header 10.51_head oid
#10:8b1a34d8:::.dir.88d4f221-0da5-444d-81a8-517771278350.454759.8.214:head# = 0
2020-06-17T12:35:05.700+0200 7f80694c4700 10 bluestore(/var/lib/ceph/osd/ceph-20)
get_omap_iterator 10.51_head
#10:8b1a34d8:::.dir.88d4f221-0da5-444d-81a8-517771278350.454759.8.214:head#
2020-06-17T12:35:05.700+0200 7f80694c4700 10 bluestore(/var/lib/ceph/osd/ceph-20)
get_omap_iterator 10.51_head
#10:8b1a34d8:::.dir.88d4f221-0da5-444d-81a8-517771278350.454759.8.214:head#
2020-06-17T12:35:05.700+0200 7f80694c4700 10 bluestore(/var/lib/ceph/osd/ceph-20)
get_omap_iterator 10.51_head
#10:8b1a34d8:::.dir.88d4f221-0da5-444d-81a8-517771278350.454759.8.214:head#
2020-06-17T12:35:05.700+0200 7f80694c4700 10 bluestore(/var/lib/ceph/osd/ceph-20)
get_omap_iterator 10.51_head
#10:8b1a34d8:::.dir.88d4f221-0da5-444d-81a8-517771278350.454759.8.214:head#
2020-06-17T12:35:05.704+0200 7f80694c4700 10 bluestore(/var/lib/ceph/osd/ceph-20)
get_omap_iterator 10.51_head
#10:8b1a34d8:::.dir.88d4f221-0da5-444d-81a8-517771278350.454759.8.214:head#
2020-06-17T12:35:05.704+0200 7f80694c4700 10 bluestore(/var/lib/ceph/osd/ceph-20)
get_omap_iterator 10.51_head
#10:8b1a34d8:::.dir.88d4f221-0da5-444d-81a8-517771278350.454759.8.214:head#
2020-06-17T12:35:05.704+0200 7f80694c4700 10 bluestore(/var/lib/ceph/osd/ceph-20)
get_omap_iterator 10.51_head
#10:8b1a34d8:::.dir.88d4f221-0da5-444d-81a8-517771278350.454759.8.214:head#
2020-06-17T12:35:05.704+0200 7f80694c4700 10 bluestore(/var/lib/ceph/osd/ceph-20)
get_omap_iterator 10.51_head
#10:8b1a34d8:::.dir.88d4f221-0da5-444d-81a8-517771278350.454759.8.214:head#
2020-06-17T12:35:05.704+0200 7f80694c4700 10 bluestore(/var/lib/ceph/osd/ceph-20)
omap_get_header 10.51_head oid
#10:8b0d75b0:::.dir.88d4f221-0da5-444d-81a8-517771278350.454759.8.222:head# = 0
2020-06-17T12:35:05.704+0200 7f80694c4700 10 bluestore(/var/lib/ceph/osd/ceph-20)
get_omap_iterator 10.51_head
#10:8b0d75b0:::.dir.88d4f221-0da5-444d-81a8-517771278350.454759.8.222:head#
2020-06-17T12:35:05.704+0200 7f80694c4700 10 bluestore(/var/lib/ceph/osd/ceph-20)
get_omap_iterator 10.51_head
#10:8b0d75b0:::.dir.88d4f221-0da5-444d-81a8-517771278350.454759.8.222:head#
2020-06-17T12:35:05.704+0200 7f80694c4700 10 bluestore(/var/lib/ceph/osd/ceph-20)
get_omap_iterator 10.51_head
#10:8b0d75b0:::.dir.88d4f221-0da5-444d-81a8-517771278350.454759.8.222:head#
2020-06-17T12:35:05.704+0200 7f80694c4700 10 bluestore(/var/lib/ceph/osd/ceph-20)
get_omap_iterator 10.51_head
#10:8b0d75b0:::.dir.88d4f221-0da5-444d-81a8-517771278350.454759.8.222:head#
2020-06-17T12:35:05.704+0200 7f80694c4700 10 bluestore(/var/lib/ceph/osd/ceph-20)
get_omap_iterator 10.51_head
#10:8b0d75b0:::.dir.88d4f221-0da5-444d-81a8-517771278350.454759.8.222:head#
2020-06-17T12:35:05.704+0200 7f80694c4700 10 bluestore(/var/lib/ceph/osd/ceph-20)
get_omap_iterator 10.51_head
#10:8b0d75b0:::.dir.88d4f221-0da5-444d-81a8-517771278350.454759.8.222:head#
2020-06-17T12:35:05.708+0200 7f80694c4700 10 bluestore(/var/lib/ceph/osd/ceph-20)
get_omap_iterator 10.51_head
#10:8b0d75b0:::.dir.88d4f221-0da5-444d-81a8-517771278350.454759.8.222:head#
2020-06-17T12:35:05.708+0200 7f80694c4700 10 bluestore(/var/lib/ceph/osd/ceph-20)
get_omap_iterator 10.51_head
#10:8b0d75b0:::.dir.88d4f221-0da5-444d-81a8-517771278350.454759.8.222:head#
2020-06-17T12:35:05.716+0200 7f806d4cc700 10 bluestore(/var/lib/ceph/osd/ceph-20)
omap_get_header 10.51_head oid
#10:8b5ed205:::.dir.88d4f221-0da5-444d-81a8-517771278350.454759.8.151:head# = 0
2020-06-17T12:35:05.716+0200 7f806d4cc700 10 bluestore(/var/lib/ceph/osd/ceph-20)
get_omap_iterator 10.51_head
#10:8b5ed205:::.dir.88d4f221-0da5-444d-81a8-517771278350.454759.8.151:head#
2020-06-17T12:35:05.716+0200 7f806d4cc700 10 bluestore(/var/lib/ceph/osd/ceph-20)
get_omap_iterator 10.51_head
#10:8b5ed205:::.dir.88d4f221-0da5-444d-81a8-517771278350.454759.8.151:head#
2020-06-17T12:35:05.720+0200 7f806d4cc700 10 bluestore(/var/lib/ceph/osd/ceph-20)
get_omap_iterator 10.51_head
#10:8b5ed205:::.dir.88d4f221-0da5-444d-81a8-517771278350.454759.8.151:head#
2020-06-17T12:35:05.720+0200 7f806d4cc700 10 bluestore(/var/lib/ceph/osd/ceph-20)
get_omap_iterator 10.51_head
#10:8b5ed205:::.dir.88d4f221-0da5-444d-81a8-517771278350.454759.8.151:head#
2020-06-17T12:35:05.720+0200 7f806d4cc700 10 bluestore(/var/lib/ceph/osd/ceph-20)
get_omap_iterator 10.51_head
#10:8b5ed205:::.dir.88d4f221-0da5-444d-81a8-517771278350.454759.8.151:head#
2020-06-17T12:35:05.720+0200 7f806d4cc700 10 bluestore(/var/lib/ceph/osd/ceph-20)
get_omap_iterator 10.51_head
#10:8b5ed205:::.dir.88d4f221-0da5-444d-81a8-517771278350.454759.8.151:head#
2020-06-17T12:35:05.720+0200 7f806d4cc700 10 bluestore(/var/lib/ceph/osd/ceph-20)
get_omap_iterator 10.51_head
#10:8b5ed205:::.dir.88d4f221-0da5-444d-81a8-517771278350.454759.8.151:head#
2020-06-17T12:35:05.720+0200 7f806d4cc700 10 bluestore(/var/lib/ceph/osd/ceph-20)
get_omap_iterator 10.51_head
#10:8b5ed205:::.dir.88d4f221-0da5-444d-81a8-517771278350.454759.8.151:head#
Hm, I don't understand enough about the operations that this represents,
but maybe one of the RadosGW developers can explain why a single OSD
would perform so many similar requests in such a short timeframe.
Cheers,
--
Simon.
10:22 a.m.
Dnia 2020-06-18, o godz. 10:51:31
Simon Leinen <simon.leinen(a)switch.ch> napisał(a):
we didn't touch default settings so I assume not ? "radosgw-admin
metadata get" and "radosgw-admin bucket stat" doesn't say anything
about shards on old cluster, while on new cluster there is from 11 to
few hundred on the biggest buckets.
I'm getting similar logs on any osd/pg that takes part in the .index
Cheers
--
Mariusz Gronczewski (XANi) <xani666(a)gmail.com>
GnuPG: 0xEA8ACE64
http://devrandom.pl
Dear Mariusz,
listing itself is bugged in version
I'm running: https://tracker.ceph.com/issues/45955
But yes, our structure is generally /bucket/prefix/prefix/file so there
is not many big directories (we're migrating from GFS where that was a
problem)
we're using Ceph as S3-compatible storage to
serve static files
(mostly css/js/images + some videos) and I've noticed that there
seem to be huge read amplification for index pool.
we have observed that too, under Nautilus (14.2.4-14.2.8).
Incoming traffic magniture is of around 15k
req/sec (mostly sub 1MB
request but index pool is getting hammered:
pool pl-war1.rgw.buckets.index id 10
client io 632 MiB/s rd, 277 KiB/s wr, 129.92k op/s rd, 415 op/s
wr
pool pl-war1.rgw.buckets.data id 11
client io 4.5 MiB/s rd, 6.8 MiB/s wr, 640 op/s rd, 1.65k op/s wr
and is getting order of magnitude more requests
Our hypothesis is that this is due to the way that RadosGW maps bucket
index queries (ListObjects/ListObjectsV2) to Rados-level operations
against a *sharded* index.
For certain types of S3 index queries, the response must be collected
from multiple (potentially all) shards of the index.
S3 index queries are always "bounded" by the response limitation (1000
keys by default). But when your index is distributed over, let's say,
2000 shards, RadosGW must collect some data from those 2000 shards,
then throw away most of what it gets, and return the next 1000 keys.
This could explain the kind of read amplification that you are seeing.
(In practice, S3 index queries often use "prefix" and "delimiter" to
emulate a hierarchical directory structure. A recently merged change,
https://github.com/ceph/ceph/pull/30272 , should make such queries
much more efficient in RadosGW (note that the change contains some
extensions to the OSD-side Rados protocol). But if I read it
correctly, that change is already in the version you are using.) Paul Emmerich has written about performance issues
with large buckets
on this list, see
https://lists.ceph.io/hyperkitty/list/dev@ceph.io/thread/36P62BOOCJBVVJCVUX…
Let's say that there are opportunities for further improvements.
You could look for the specific queries that cause the high read load
in your system. Maybe there's something that can be done on the
client side. This could also provide input for Ceph development as
to what kinds of index operations are used by applications "in the
wild". Those might be worth optimizing first :-)
Is there a way to debug which query exactly is causing that ?
Currently there is a lot of incoming traffic (mostly from aws cli sync)
as we're migrating data over but that's at most hundreds of requests
per sec.
running 15.2.3, nothing special in terms of
tunning aside from
disabling some logging as to not overflow the logs.
We've had similar test cluster on 12.x (and
way slower hardware)
getting similar traffic and haven't observed that magnitude of
difference.
Was your bucket index sharded in 12.x? when enabling debug on affected OSD I only get
spam of
2020-06-17T12:35:05.700+0200 7f80694c4700 10
bluestore(/var/lib/ceph/osd/ceph-20) omap_get_header 10.51_head oid
#10:8b1a34d8:::.dir.88d4f221-0da5-444d-81a8-517771278350.454759.8.214:head#
= 0 2020-06-17T12:35:05.700+0200 7f80694c4700 10
bluestore(/var/lib/ceph/osd/ceph-20) get_omap_iterator 10.51_head
#10:8b1a34d8:::.dir.88d4f221-0da5-444d-81a8-517771278350.454759.8.214:head#
2020-06-17T12:35:05.700+0200 7f80694c4700 10
bluestore(/var/lib/ceph/osd/ceph-20) get_omap_iterator 10.51_head
#10:8b1a34d8:::.dir.88d4f221-0da5-444d-81a8-517771278350.454759.8.214:head#
2020-06-17T12:35:05.700+0200 7f80694c4700 10
bluestore(/var/lib/ceph/osd/ceph-20) get_omap_iterator 10.51_head
#10:8b1a34d8:::.dir.88d4f221-0da5-444d-81a8-517771278350.454759.8.214:head#
2020-06-17T12:35:05.700+0200 7f80694c4700 10
bluestore(/var/lib/ceph/osd/ceph-20) get_omap_iterator 10.51_head
#10:8b1a34d8:::.dir.88d4f221-0da5-444d-81a8-517771278350.454759.8.214:head#
2020-06-17T12:35:05.704+0200 7f80694c4700 10
bluestore(/var/lib/ceph/osd/ceph-20) get_omap_iterator 10.51_head
#10:8b1a34d8:::.dir.88d4f221-0da5-444d-81a8-517771278350.454759.8.214:head#
2020-06-17T12:35:05.704+0200 7f80694c4700 10
bluestore(/var/lib/ceph/osd/ceph-20) get_omap_iterator 10.51_head
#10:8b1a34d8:::.dir.88d4f221-0da5-444d-81a8-517771278350.454759.8.214:head#
2020-06-17T12:35:05.704+0200 7f80694c4700 10
bluestore(/var/lib/ceph/osd/ceph-20) get_omap_iterator 10.51_head
#10:8b1a34d8:::.dir.88d4f221-0da5-444d-81a8-517771278350.454759.8.214:head#
2020-06-17T12:35:05.704+0200 7f80694c4700 10
bluestore(/var/lib/ceph/osd/ceph-20) get_omap_iterator 10.51_head
#10:8b1a34d8:::.dir.88d4f221-0da5-444d-81a8-517771278350.454759.8.214:head#
2020-06-17T12:35:05.704+0200 7f80694c4700 10
bluestore(/var/lib/ceph/osd/ceph-20) omap_get_header 10.51_head oid
#10:8b0d75b0:::.dir.88d4f221-0da5-444d-81a8-517771278350.454759.8.222:head#
= 0 2020-06-17T12:35:05.704+0200 7f80694c4700 10
bluestore(/var/lib/ceph/osd/ceph-20) get_omap_iterator 10.51_head
#10:8b0d75b0:::.dir.88d4f221-0da5-444d-81a8-517771278350.454759.8.222:head#
2020-06-17T12:35:05.704+0200 7f80694c4700 10
bluestore(/var/lib/ceph/osd/ceph-20) get_omap_iterator 10.51_head
#10:8b0d75b0:::.dir.88d4f221-0da5-444d-81a8-517771278350.454759.8.222:head#
2020-06-17T12:35:05.704+0200 7f80694c4700 10
bluestore(/var/lib/ceph/osd/ceph-20) get_omap_iterator 10.51_head
#10:8b0d75b0:::.dir.88d4f221-0da5-444d-81a8-517771278350.454759.8.222:head#
2020-06-17T12:35:05.704+0200 7f80694c4700 10
bluestore(/var/lib/ceph/osd/ceph-20) get_omap_iterator 10.51_head
#10:8b0d75b0:::.dir.88d4f221-0da5-444d-81a8-517771278350.454759.8.222:head#
2020-06-17T12:35:05.704+0200 7f80694c4700 10
bluestore(/var/lib/ceph/osd/ceph-20) get_omap_iterator 10.51_head
#10:8b0d75b0:::.dir.88d4f221-0da5-444d-81a8-517771278350.454759.8.222:head#
2020-06-17T12:35:05.704+0200 7f80694c4700 10
bluestore(/var/lib/ceph/osd/ceph-20) get_omap_iterator 10.51_head
#10:8b0d75b0:::.dir.88d4f221-0da5-444d-81a8-517771278350.454759.8.222:head#
2020-06-17T12:35:05.708+0200 7f80694c4700 10
bluestore(/var/lib/ceph/osd/ceph-20) get_omap_iterator 10.51_head
#10:8b0d75b0:::.dir.88d4f221-0da5-444d-81a8-517771278350.454759.8.222:head#
2020-06-17T12:35:05.708+0200 7f80694c4700 10
bluestore(/var/lib/ceph/osd/ceph-20) get_omap_iterator 10.51_head
#10:8b0d75b0:::.dir.88d4f221-0da5-444d-81a8-517771278350.454759.8.222:head#
2020-06-17T12:35:05.716+0200 7f806d4cc700 10
bluestore(/var/lib/ceph/osd/ceph-20) omap_get_header 10.51_head oid
#10:8b5ed205:::.dir.88d4f221-0da5-444d-81a8-517771278350.454759.8.151:head#
= 0 2020-06-17T12:35:05.716+0200 7f806d4cc700 10
bluestore(/var/lib/ceph/osd/ceph-20) get_omap_iterator 10.51_head
#10:8b5ed205:::.dir.88d4f221-0da5-444d-81a8-517771278350.454759.8.151:head#
2020-06-17T12:35:05.716+0200 7f806d4cc700 10
bluestore(/var/lib/ceph/osd/ceph-20) get_omap_iterator 10.51_head
#10:8b5ed205:::.dir.88d4f221-0da5-444d-81a8-517771278350.454759.8.151:head#
2020-06-17T12:35:05.720+0200 7f806d4cc700 10
bluestore(/var/lib/ceph/osd/ceph-20) get_omap_iterator 10.51_head
#10:8b5ed205:::.dir.88d4f221-0da5-444d-81a8-517771278350.454759.8.151:head#
2020-06-17T12:35:05.720+0200 7f806d4cc700 10
bluestore(/var/lib/ceph/osd/ceph-20) get_omap_iterator 10.51_head
#10:8b5ed205:::.dir.88d4f221-0da5-444d-81a8-517771278350.454759.8.151:head#
2020-06-17T12:35:05.720+0200 7f806d4cc700 10
bluestore(/var/lib/ceph/osd/ceph-20) get_omap_iterator 10.51_head
#10:8b5ed205:::.dir.88d4f221-0da5-444d-81a8-517771278350.454759.8.151:head#
2020-06-17T12:35:05.720+0200 7f806d4cc700 10
bluestore(/var/lib/ceph/osd/ceph-20) get_omap_iterator 10.51_head
#10:8b5ed205:::.dir.88d4f221-0da5-444d-81a8-517771278350.454759.8.151:head#
2020-06-17T12:35:05.720+0200 7f806d4cc700 10
bluestore(/var/lib/ceph/osd/ceph-20) get_omap_iterator 10.51_head
#10:8b5ed205:::.dir.88d4f221-0da5-444d-81a8-517771278350.454759.8.151:head#
2020-06-17T12:35:05.720+0200 7f806d4cc700 10
bluestore(/var/lib/ceph/osd/ceph-20) get_omap_iterator 10.51_head
#10:8b5ed205:::.dir.88d4f221-0da5-444d-81a8-517771278350.454759.8.151:head#
Hm, I don't understand enough about the operations that this
represents, but maybe one of the RadosGW developers can explain why a
single OSD would perform so many similar requests in such a short
timeframe.
9:18 p.m.
Mariusz Gronczewski writes:
listing itself is bugged in version
I'm running: https://tracker.ceph.com/issues/45955
Ouch! Are your OSDs all running the same version as your RadosGW? The
message looks a bit as if your RadosGW might be a newer version than the
OSDs, and the new optimized bucket list operation was missing the new
extensions to the client<->OSD protocol.
But yes, our structure is generally
/bucket/prefix/prefix/file so there
is not many big directories (we're migrating from GFS where that was a
problem)
> Paul Emmerich has written about performance issues
with large buckets
> on this list, see
>
https://lists.ceph.io/hyperkitty/list/dev@ceph.io/thread/36P62BOOCJBVVJCVUX…
>
> Let's say that there are opportunities for further improvements.
>
> You could look for the specific queries that cause the high read load
> in your system. Maybe there's something that can be done on the
> client side. This could also provide input for Ceph development as
> to what kinds of index operations are used by applications "in the
> wild". Those might be worth optimizing first :-)
Is there a way to debug which query exactly is causing
that ?
What I usually do is grep through the HTTP request logs of the front-end
proxy/load balancer (Nginx in our case), and look for GET requests on a
bucket that have a long duration. It's a bit crude, I know. (If
someone knows better techniques for this, I'd also be interested! Maybe
something based on something like Jaeger/OpenTracing, or clever log
correlation?)
Currently there is a lot of incoming traffic (mostly
from aws cli sync)
as we're migrating data over but that's at most hundreds of requests
per sec.
>
> > running 15.2.3, nothing special in terms of tunning aside from
> > disabling some logging as to not overflow the logs.
>
> > We've had similar test cluster on 12.x (and way slower hardware)
> > getting similar traffic and haven't observed that magnitude of
> > difference.
>
> Was your bucket index sharded in 12.x?
we didn't touch default settings so I assume not ?
"radosgw-admin
metadata get" and "radosgw-admin bucket stat" doesn't say anything
about shards on old cluster, while on new cluster there is from 11 to
few hundred on the biggest buckets.
Yes, I think it's the sharding that causes the read amplification.
> Hm, I don't understand enough about the
operations that this
> represents, but maybe one of the RadosGW developers can explain why a
> single OSD would perform so many similar requests in such a short
> timeframe.
I'm getting similar logs on any osd/pg that takes
part in the .index
Right, that's what I thought. Again, I can't tell whether these log
messages are to be expected... the repetitions look a bit odd.
Best regards,
--
Simon.
19 Jun
19 Jun
10:12 a.m.
Dnia 2020-06-18, o godz. 22:18:08
Simon Leinen <simon.leinen(a)switch.ch> napisał(a):
I did some looking and it appears most of our indexing traffic were
developers doing some cleaning and monitoring the progress by basically
ls-ing over and over again so at least the problem should subsist once
migration is over.
AFAIK there isn't really any way to "mark request for tracing" in Ceph
so sadly any tracing kinda ends at radosgw
Well, it is same requests over and over again so without/with too small
cache that's to be expected. I guess I'll just wait for next release.
Cheers
--
Mariusz Gronczewski, Administrator
Efigence S. A.
ul. Wołoska 9a, 02-583 Warszawa
T: [+48] 22 380 13 13
NOC: [+48] 22 380 10 20
E: admin(a)efigence.com
Mariusz Gronczewski writes:
Versions are same on every node. Is there a command that is required to
enable new extensions?
It was clean install of octopus from upstream ceph repos (not
upgrade) but the feature level appears to be stuck at luminous ?
ceph features
...
"client": [
{
"features": "0x3f01cfb8ffadffff",
"release": "luminous",
"num": 16
}
],
...
dunno if that's something expected or a problem.
listing itself is bugged in version
I'm running: https://tracker.ceph.com/issues/45955
Ouch! Are your OSDs all running the same version as your RadosGW? The
message looks a bit as if your RadosGW might be a newer version than
the OSDs, and the new optimized bucket list operation was missing the
new extensions to the client<->OSD protocol.
But yes, our
structure is generally /bucket/prefix/prefix/file so
there is not many big directories (we're migrating from GFS where
that was a problem)
> Paul Emmerich has written about performance
issues with large
> buckets on this list, see
>
https://lists.ceph.io/hyperkitty/list/dev@ceph.io/thread/36P62BOOCJBVVJCVUX…
>
> Let's say that there are opportunities for further improvements.
>
> You could look for the specific queries that cause the high read
> load in your system. Maybe there's something that can be done on
> the client side. This could also provide input for Ceph
> development as to what kinds of index operations are used by
> applications "in the wild". Those might be worth optimizing first
> :-)
Is there a way to debug which query exactly is
causing that ?
What I usually do is grep through the HTTP request logs of the
front-end proxy/load balancer (Nginx in our case), and look for GET
requests on a bucket that have a long duration. It's a bit crude, I
know. (If someone knows better techniques for this, I'd also be
interested! Maybe something based on something like
Jaeger/OpenTracing, or clever log correlation?)
Currently
there is a lot of incoming traffic (mostly from aws cli
sync) as we're migrating data over but that's at most hundreds of
requests per sec.
>
> > running 15.2.3, nothing special in terms of tunning aside from
> > disabling some logging as to not overflow the logs.
>
> > We've had similar test cluster on 12.x (and way slower hardware)
> > getting similar traffic and haven't observed that magnitude of
> > difference.
>
> Was your bucket index sharded in 12.x?
we didn't touch default settings so I assume
not ? "radosgw-admin
metadata get" and "radosgw-admin bucket stat" doesn't say anything
about shards on old cluster, while on new cluster there is from 11
to few hundred on the biggest buckets.
Yes, I think it's the sharding that causes the read amplification.
> Hm, I don't understand enough about the
operations that this
> represents, but maybe one of the RadosGW developers can explain
> why a single OSD would perform so many similar requests in such a
> short timeframe.
I'm getting similar logs on any osd/pg that
takes part in the
.index
Right, that's what I thought. Again, I can't tell whether these log
messages are to be expected... the repetitions look a bit odd.
Best regards, 
1:34 p.m.
Hi,
huge read amplification for index buckets is unfortunately normal,
complexity of a read request is O(n) where n is the number of objects in
that bucket.
I've worked on many clusters with huge buckets and having 10 gbit/s of
network traffic between the OSDs and radosgw is unfortunately not unusual
when running a lot of listing requests.
The problem is that it needs to read *all* shards for each list request and
the number of shards is the number of objects divided by 100k by default.
It's a little bit better in Octopus, but still not great for huge buckets.
My experiences with building rgw setups for huge (> 200 million) buckets
can be summed up as:
* use *good* NVMe disks for the index bucket (very good experiences with
Samsung 1725a, seen these things do > 50k iops during recovieres)
* it can be beneficial to have a larger number of OSDs handling the load as
huge rocksdb sizes can be a problem; that means it can be better to use the
NVMe disks as DB device for HDDs and put the index pool here than to run a
dedicated NVMe-only pool on very few OSDs
* go for larger shards on large buckets, shard sizes of 300k - 600k are
perfectly fine on fast NVMes (the trade-off here is recovery speed/locked
objects vs. read amplification)
I think the formula shards = bucket_size / 100k shouldn't apply for buckets
with >= 100 million objects; shards should become bigger as the bucket size
increases.
Paul
--
Paul Emmerich
Looking for help with your Ceph cluster? Contact us at https://croit.io
croit GmbH
Freseniusstr. 31h
81247 München
www.croit.io
Tel: +49 89 1896585 90
On Thu, Jun 18, 2020 at 9:25 AM Mariusz Gronczewski <
mariusz.gronczewski(a)efigence.com> wrote:
Hi,
we're using Ceph as S3-compatible storage to serve static files (mostly
css/js/images + some videos) and I've noticed that there seem to be
huge read amplification for index pool.
Incoming traffic magniture is of around 15k req/sec (mostly sub 1MB
request but index pool is getting hammered:
pool pl-war1.rgw.buckets.index id 10
client io 632 MiB/s rd, 277 KiB/s wr, 129.92k op/s rd, 415 op/s wr
pool pl-war1.rgw.buckets.data id 11
client io 4.5 MiB/s rd, 6.8 MiB/s wr, 640 op/s rd, 1.65k op/s wr
and is getting order of magnitude more requests
running 15.2.3, nothing special in terms of tunning aside from
disabling some logging as to not overflow the logs.
We've had similar test cluster on 12.x (and way slower hardware)
getting similar traffic and haven't observed that magnitude of
difference.
when enabling debug on affected OSD I only get spam of
2020-06-17T12:35:05.700+0200 7f80694c4700 10
bluestore(/var/lib/ceph/osd/ceph-20) omap_get_header 10.51_head oid
#10:8b1a34d8:::.dir.88d4f221-0da5-444d-81a8-517771278350.454759.8.214:head#
= 0
2020-06-17T12:35:05.700+0200 7f80694c4700 10
bluestore(/var/lib/ceph/osd/ceph-20) get_omap_iterator 10.51_head
#10:8b1a34d8:::.dir.88d4f221-0da5-444d-81a8-517771278350.454759.8.214:head#
2020-06-17T12:35:05.700+0200 7f80694c4700 10
bluestore(/var/lib/ceph/osd/ceph-20) get_omap_iterator 10.51_head
#10:8b1a34d8:::.dir.88d4f221-0da5-444d-81a8-517771278350.454759.8.214:head#
2020-06-17T12:35:05.700+0200 7f80694c4700 10
bluestore(/var/lib/ceph/osd/ceph-20) get_omap_iterator 10.51_head
#10:8b1a34d8:::.dir.88d4f221-0da5-444d-81a8-517771278350.454759.8.214:head#
2020-06-17T12:35:05.700+0200 7f80694c4700 10
bluestore(/var/lib/ceph/osd/ceph-20) get_omap_iterator 10.51_head
#10:8b1a34d8:::.dir.88d4f221-0da5-444d-81a8-517771278350.454759.8.214:head#
2020-06-17T12:35:05.704+0200 7f80694c4700 10
bluestore(/var/lib/ceph/osd/ceph-20) get_omap_iterator 10.51_head
#10:8b1a34d8:::.dir.88d4f221-0da5-444d-81a8-517771278350.454759.8.214:head#
2020-06-17T12:35:05.704+0200 7f80694c4700 10
bluestore(/var/lib/ceph/osd/ceph-20) get_omap_iterator 10.51_head
#10:8b1a34d8:::.dir.88d4f221-0da5-444d-81a8-517771278350.454759.8.214:head#
2020-06-17T12:35:05.704+0200 7f80694c4700 10
bluestore(/var/lib/ceph/osd/ceph-20) get_omap_iterator 10.51_head
#10:8b1a34d8:::.dir.88d4f221-0da5-444d-81a8-517771278350.454759.8.214:head#
2020-06-17T12:35:05.704+0200 7f80694c4700 10
bluestore(/var/lib/ceph/osd/ceph-20) get_omap_iterator 10.51_head
#10:8b1a34d8:::.dir.88d4f221-0da5-444d-81a8-517771278350.454759.8.214:head#
2020-06-17T12:35:05.704+0200 7f80694c4700 10
bluestore(/var/lib/ceph/osd/ceph-20) omap_get_header 10.51_head oid
#10:8b0d75b0:::.dir.88d4f221-0da5-444d-81a8-517771278350.454759.8.222:head#
= 0
2020-06-17T12:35:05.704+0200 7f80694c4700 10
bluestore(/var/lib/ceph/osd/ceph-20) get_omap_iterator 10.51_head
#10:8b0d75b0:::.dir.88d4f221-0da5-444d-81a8-517771278350.454759.8.222:head#
2020-06-17T12:35:05.704+0200 7f80694c4700 10
bluestore(/var/lib/ceph/osd/ceph-20) get_omap_iterator 10.51_head
#10:8b0d75b0:::.dir.88d4f221-0da5-444d-81a8-517771278350.454759.8.222:head#
2020-06-17T12:35:05.704+0200 7f80694c4700 10
bluestore(/var/lib/ceph/osd/ceph-20) get_omap_iterator 10.51_head
#10:8b0d75b0:::.dir.88d4f221-0da5-444d-81a8-517771278350.454759.8.222:head#
2020-06-17T12:35:05.704+0200 7f80694c4700 10
bluestore(/var/lib/ceph/osd/ceph-20) get_omap_iterator 10.51_head
#10:8b0d75b0:::.dir.88d4f221-0da5-444d-81a8-517771278350.454759.8.222:head#
2020-06-17T12:35:05.704+0200 7f80694c4700 10
bluestore(/var/lib/ceph/osd/ceph-20) get_omap_iterator 10.51_head
#10:8b0d75b0:::.dir.88d4f221-0da5-444d-81a8-517771278350.454759.8.222:head#
2020-06-17T12:35:05.704+0200 7f80694c4700 10
bluestore(/var/lib/ceph/osd/ceph-20) get_omap_iterator 10.51_head
#10:8b0d75b0:::.dir.88d4f221-0da5-444d-81a8-517771278350.454759.8.222:head#
2020-06-17T12:35:05.708+0200 7f80694c4700 10
bluestore(/var/lib/ceph/osd/ceph-20) get_omap_iterator 10.51_head
#10:8b0d75b0:::.dir.88d4f221-0da5-444d-81a8-517771278350.454759.8.222:head#
2020-06-17T12:35:05.708+0200 7f80694c4700 10
bluestore(/var/lib/ceph/osd/ceph-20) get_omap_iterator 10.51_head
#10:8b0d75b0:::.dir.88d4f221-0da5-444d-81a8-517771278350.454759.8.222:head#
2020-06-17T12:35:05.716+0200 7f806d4cc700 10
bluestore(/var/lib/ceph/osd/ceph-20) omap_get_header 10.51_head oid
#10:8b5ed205:::.dir.88d4f221-0da5-444d-81a8-517771278350.454759.8.151:head#
= 0
2020-06-17T12:35:05.716+0200 7f806d4cc700 10
bluestore(/var/lib/ceph/osd/ceph-20) get_omap_iterator 10.51_head
#10:8b5ed205:::.dir.88d4f221-0da5-444d-81a8-517771278350.454759.8.151:head#
2020-06-17T12:35:05.716+0200 7f806d4cc700 10
bluestore(/var/lib/ceph/osd/ceph-20) get_omap_iterator 10.51_head
#10:8b5ed205:::.dir.88d4f221-0da5-444d-81a8-517771278350.454759.8.151:head#
2020-06-17T12:35:05.720+0200 7f806d4cc700 10
bluestore(/var/lib/ceph/osd/ceph-20) get_omap_iterator 10.51_head
#10:8b5ed205:::.dir.88d4f221-0da5-444d-81a8-517771278350.454759.8.151:head#
2020-06-17T12:35:05.720+0200 7f806d4cc700 10
bluestore(/var/lib/ceph/osd/ceph-20) get_omap_iterator 10.51_head
#10:8b5ed205:::.dir.88d4f221-0da5-444d-81a8-517771278350.454759.8.151:head#
2020-06-17T12:35:05.720+0200 7f806d4cc700 10
bluestore(/var/lib/ceph/osd/ceph-20) get_omap_iterator 10.51_head
#10:8b5ed205:::.dir.88d4f221-0da5-444d-81a8-517771278350.454759.8.151:head#
2020-06-17T12:35:05.720+0200 7f806d4cc700 10
bluestore(/var/lib/ceph/osd/ceph-20) get_omap_iterator 10.51_head
#10:8b5ed205:::.dir.88d4f221-0da5-444d-81a8-517771278350.454759.8.151:head#
2020-06-17T12:35:05.720+0200 7f806d4cc700 10
bluestore(/var/lib/ceph/osd/ceph-20) get_omap_iterator 10.51_head
#10:8b5ed205:::.dir.88d4f221-0da5-444d-81a8-517771278350.454759.8.151:head#
2020-06-17T12:35:05.720+0200 7f806d4cc700 10
bluestore(/var/lib/ceph/osd/ceph-20) get_omap_iterator 10.51_head
#10:8b5ed205:::.dir.88d4f221-0da5-444d-81a8-517771278350.454759.8.151:head#
--
Mariusz Gronczewski (XANi) <xani666(a)gmail.com>
GnuPG: 0xEA8ACE64
http://devrandom.pl
_______________________________________________
ceph-users mailing list -- ceph-users(a)ceph.io
To unsubscribe send an email to ceph-users-leave(a)ceph.io
1429
days inactive
1430
days old
5 comments
3 participants
participants (3)
-
Mariusz Gronczewski -
Paul Emmerich -
Simon Leinen