23 Aug
2019
23 Aug
'19
5:30 p.m.
I need to harden our ceph cluster to satisfy the following properties:
Assuming all hardware is functioning properly,
1) Cluster health has highest priority. Heartbeats have priority over client requests.
2) The cluster does not accept more IO than the OSDs can handle. The only exception might
be a configurable burst option.
3) Client IO is accepted as long as it does not compromise 1.
4) Ideally, there is fair sharing of the cluster's IO budget between clients (like
deadline or completely fair scheduling). Rogue clients should not get priority just
because they push a lot.
Unfortunately, with default settings our (any?) cluster prefers client IO over cluster
health, which opens up for a simple but serious non-privileged client attack on cluster
health:
I observed a serious issue on our cluster when running a simple fio test that does 4K
random writes on 100GB files (see details below). What I observe is that within a few
seconds the cluster goes to health_warn with the MDS reporting slow meta data IO and
behind on trimming. What is not shown in ceph health detail is, that all OSDs report
thousands of slow ops and the counter increases really fast (I include some snippets
below). This goes rapidly to the point where OSDs start missing heartbeats and start
flapping, some PGs become inactive+degraded and start peering regularly. CPU load, memory
and even network load were rather low (one-figure % CPU load). Nothing out of the
ordinary. The mons had no issues.
After the fio test completed, the OSDs slowly crunched through the backlog and managed to
complete all OPS. The complete processing of the ops of a 30 second fio test took ca. 10
minutes. However, even then the cluster did not come back healthy as essential messages
between daemons seem to have been lost. It is not a long stretch to assume that one can
destroy a ceph fs beyond repair when running this test or an application performing the
same IO pattern from multiple clients for several hours. We have a 500 node cluster as
clients and I'm afraid that even ordinary IO might trigger this scenario in unlucky
circumstances.
Since our cluster is only half-trusted (we have root access to clients, but no control
over user IO patterns), we are in need to harden our cluster against such destructive IO
patterns as much as possible.
To me it looks like the cluster is accepting way more IO than the OSDs can handle.
Ideally, what I would like to do is configure effective rate limiting on (rogue) clients
depending on how much OPS they have in flight already. I would expect that there are
tunables for MDS/OSD daemons that control how much IO requests a client can submit/OSD
will accept before throttling IO. In particular, I would like to prioritize heartbeats to
prevent load-induced OSD flapping. How can I tune the cluster to satisfy the conditions
outlined at the top of this e-mail?
There were recent threads with similar topics, in particular, "MDS failing under load
with large cache sizes" and others reporting unstable MDS daemons under load.
However, I believe they were mostly related to cache trimming issues due to large amounts
of files created. This is not the case here, its just 4 files with lots of random IO from
a single client.
A bit of information about our cluster and observations:
The cluster is bluestore-only with 8+2 EC fs data pool on spinning disks and an 3(2)
replicated fs meta data pool on SSD. We have 8 OSD hosts with 2 shards per host. Each host
has 4SSDs and 12 10TB HDDs SAS 12GB with 4k block size. Network is 2x10G bonded for client
and 2x10G bonded for replication. The replication network will be extended to 4x10G soon.
We are aware that currently the network bandwidth greatly exceeds what the spinning disks
can handle. It is dimensioned for adding more disks in the future.
The fio job script is:
[global]
name=fio-rand-write
directory=/home/fio # /home is on ceph fs
filename_format=tmp/fio-$jobname-${HOSTNAME}-$jobnum-$filenum
rw=randwrite
bs=4K
numjobs=4
time_based=1
runtime=30
[file1]
size=100G
ioengine=sync
Its one of the examples in the fio source repo with small modifications (file pattern, run
time). Shortly after starting this fio job from a client connected with single 10G line,
all OSDs start reporting slow ops. Picking one, the log messages look like this:
Aug 22 12:06:22 ceph-09 ceph-osd: 2019-08-22 10:06:22.151 7f399d1bd700 -1 osd.125 3778
get_health_metrics reporting 146 slow ops, oldest is osd_op(client.1178165.0:1670940
5.3fs0 5:fcc65fe3:::10000f403bc.0000063e:head [write 307200~4096,write 315392~8192,write
380928~12288,write 405504~12288,write 421888~4096,write 458752~4096,write
466944~4096,write 475136~4096,write 487424~8192,write 512000~4096,write 524288~4096,write
565248~4096,write 589824~8192,write 622592~4096,write 651264~4096,write 724992~12288]
snapc 12e=[] ondisk+write+known_if_redirected e3778)
...
Aug 22 12:06:49 ceph-09 journal: 2019-08-22 10:06:49.415 7f399d1bd700 -1 osd.125 3779
get_health_metrics reporting 4595 slow ops, olde
st is osd_op(client.1178165.0:1686216 5.acs0 5:354e96d5:::10000f403bc.00000bc1:head [write
2359296~4096,write 2375680~4096,write 23838
72~4096,write 2404352~4096,write 2428928~8192,write 2469888~4096,write 2490368~8192,write
2514944~4096,write 2527232~4096,write 253542
4~4096,write 2588672~4096,write 2600960~4096,write 2621440~8192,write 2658304~4096,write
2715648~8192,write 2727936~4096] snapc 12e=[]
ondisk+write+known_if_redirected e3778)
...
Aug 22 12:12:57 ceph-09 journal: 2019-08-22 10:12:57.650 7f399d1bd700 -1 osd.125 3839
get_health_metrics reporting 8419 slow ops, oldest is osd_op(client.1178165.0:2009417
5.3fs0 5:fcdcf2bd:::10000f47e2d.00001501:head [write 2236416~4096,write 2256896~4096,write
2265088~4096,write 2301952~4096,write 2322432~4096,write 2355200~4096,write
2371584~4096,write 2387968~4096,write 2449408~4096,write 2486272~4096,write
2547712~8192,write 2617344~4096,write 2809856~4096,write 3018752~4096,write
3194880~4096,write 3223552~4096] snapc 12e=[] ondisk+write+known_if_redirected e3839)
Aug 22 12:12:58 ceph-09 ceph-osd: 2019-08-22 10:12:58.681 7f399d1bd700 -1 osd.125 3839
get_health_metrics reporting 8862 slow ops, oldest is osd_op(mds.0.16909:69577511 5.ees0
5.992388ee (undecoded) ondisk+write+known_if_redirected+full_force e3839)
...
Aug 22 12:13:27 ceph-09 journal: 2019-08-22 10:13:27.691 7f399d1bd700 -1 osd.125 3839
get_health_metrics reporting 13795 slow ops, oldest is osd_op(mds.0.16909:69577573 5.e6s0
5.d8994de6 (undecoded) ondisk+write+known_if_redirected+full_force e3839)
...
Aug 22 12:13:59 ceph-09 ceph-osd: 2019-08-22 10:13:59.762 7f399d1bd700 -1 osd.125 3900
get_health_metrics reporting 12 slow ops, oldest is osd_op(mds.0.16909:69577511 5.ees0
5.992388ee (undecoded) ondisk+retry+write+known_if_redirected+full_force e3875)
...
Aug 22 12:14:46 ceph-09 journal: 2019-08-22 10:14:46.569 7f399d1bd700 -1 osd.125 3916
get_health_metrics reporting 969 slow ops, oldes
t is osd_op(mds.0.16909:69577511 5.ees0 5.992388ee (undecoded)
ondisk+retry+write+known_if_redirected+full_force e3875)
Aug 22 12:14:47 ceph-09 ceph-osd: 2019-08-22 10:14:47.617 7f399d1bd700 -1 osd.125 3935
get_health_metrics reporting 1 slow ops, oldest
is osd_op(mds.0.16909:69577511 5.ees0 5:7711c499:::10000f4798b.00000000:head
[create,setxattr parent (289),setxattr layout (30)] snap
c 0=[] RETRY=2 ondisk+retry+write+known_if_redirected+full_force e3875)
...
Aug 22 12:14:53 ceph-09 journal: 2019-08-22 10:14:53.675 7f399d1bd700 -1 osd.125 3939
get_health_metrics reporting 1 slow ops, oldest is osd_op(mds.0.16909:69577511 5.ees0
5:7711c499:::10000f4798b.00000000:head [create,setxattr parent (289),setxattr layout (30)]
snapc 0=[] RETRY=2 ondisk+retry+write+known_if_redirected+full_force e3875)
This is the last log message, the OSD seems to have executed all OPS at this point or
shortly after. The cluster state went to health_ok - at least shortly.
At about 12:45 (yes, lunch break) we looked at the cluster again and it was back in
health_warn with the following status output:
[root@ceph-01 ~]# ceph status
cluster:
id: e4ece518-f2cb-4708-b00f-b6bf511e91d9
health: HEALTH_WARN
1 MDSs report slow metadata IOs
2 MDSs behind on trimming
services:
mon: 3 daemons, quorum ceph-01,ceph-02,ceph-03
mgr: ceph-01(active), standbys: ceph-02, ceph-03
mds: con-fs-1/1/1 up {0=ceph-08=up:active}, 1 up:standby-replay
osd: 192 osds: 192 up, 192 in
data:
pools: 7 pools, 790 pgs
objects: 9.01 M objects, 16 TiB
usage: 20 TiB used, 1.3 PiB / 1.3 PiB avail
pgs: 790 active+clean
io:
client: 1.9 MiB/s rd, 21 MiB/s wr, 60 op/s rd, 721 op/s wr
[root@ceph-01 ~]# ceph health detail
HEALTH_WARN 1 MDSs report slow metadata IOs; 2 MDSs behind on trimming
MDS_SLOW_METADATA_IO 1 MDSs report slow metadata IOs
mdsceph-08(mds.0): 2 slow metadata IOs are blocked > 30 secs, oldest blocked for
3275 secs
MDS_TRIM 2 MDSs behind on trimming
mdsceph-08(mds.0): Behind on trimming (1778/128) max_segments: 128, num_segments:
1778
mdsceph-12(mds.0): Behind on trimming (1780/128) max_segments: 128, num_segments:
1780
Num_segments was increasing constantly. Apparently, an operation got stuck and never
completed. We hunted a little bit and found
[root@ceph-mds:ceph-08 /]# ceph daemon mds.ceph-08 objecter_requests
{
"ops": [
{
"tid": 71206302,
"pg": "4.952611b7",
"osd": 19,
"object_id": "200.0001be74",
"object_locator": "@4",
"target_object_id": "200.0001be74",
"target_object_locator": "@4",
"paused": 0,
"used_replica": 0,
"precalc_pgid": 0,
"last_sent": "268516s",
"attempts": 1,
"snapid": "head",
"snap_context": "0=[]",
"mtime": "2019-08-22 11:12:41.0.565912s",
"osd_ops": [
"write 890478~1923"
]
},
{
"tid": 71206303,
"pg": "4.952611b7",
"osd": 19,
"object_id": "200.0001be74",
"object_locator": "@4",
"target_object_id": "200.0001be74",
"target_object_locator": "@4",
"paused": 0,
"used_replica": 0,
"precalc_pgid": 0,
"last_sent": "268516s",
"attempts": 1,
"snapid": "head",
"snap_context": "0=[]",
"mtime": "2019-08-22 11:12:41.0.566236s",
"osd_ops": [
"write 892401~1931"
]
},
{
"tid": 71206301,
"pg": "5.eeb918c6",
"osd": 67,
"object_id": "10000f26f67.00000000",
"object_locator": "@5",
"target_object_id": "10000f26f67.00000000",
"target_object_locator": "@5",
"paused": 0,
"used_replica": 0,
"precalc_pgid": 0,
"last_sent": "268516s",
"attempts": 1,
"snapid": "head",
"snap_context": "12e=[]",
"mtime": "1970-01-01 00:00:00.000000s",
"osd_ops": [
"trimtrunc 81854@573"
]
},
{
"tid": 69577573,
"pg": "5.d8994de6",
"osd": 125,
"object_id": "10000f479c9.00000000",
"object_locator": "@5",
"target_object_id": "10000f479c9.00000000",
"target_object_locator": "@5",
"paused": 0,
"used_replica": 0,
"precalc_pgid": 0,
"last_sent": "265042s",
"attempts": 5,
"snapid": "head",
"snap_context": "0=[]",
"mtime": "2019-08-22 10:12:05.0.256058s",
"osd_ops": [
"create",
"setxattr parent (319)",
"setxattr layout (30)"
]
},
{
"tid": 69577598,
"pg": "5.deb003e6",
"osd": 125,
"object_id": "10000f479da.00000000",
"object_locator": "@5",
"target_object_id": "10000f479da.00000000",
"target_object_locator": "@5",
"paused": 0,
"used_replica": 0,
"precalc_pgid": 0,
"last_sent": "265042s",
"attempts": 5,
"snapid": "head",
"snap_context": "0=[]",
"mtime": "2019-08-22 10:12:05.0.258824s",
"osd_ops": [
"create",
"setxattr parent (288)",
"setxattr layout (30)"
]
},
{
"tid": 71206300,
"pg": "5.5cd5b20b",
"osd": 163,
"object_id": "10000f01396.00000000",
"object_locator": "@5",
"target_object_id": "10000f01396.00000000",
"target_object_locator": "@5",
"paused": 0,
"used_replica": 0,
"precalc_pgid": 0,
"last_sent": "268516s",
"attempts": 1,
"snapid": "head",
"snap_context": "12e=[]",
"mtime": "1970-01-01 00:00:00.000000s",
"osd_ops": [
"trimtrunc 208782@573"
]
}
],
"linger_ops": [],
"pool_ops": [],
"pool_stat_ops": [],
"statfs_ops": [],
"command_ops": []
}
Notice the ops from the 1970's. Checking ops and dump_blocked_ops on osd.19 showed
that these lists were empty. So, we decided to restart osd.19 and it cleared out most of
the stuck requests, but did not clear the health warnings:
[root@ceph-mds:ceph-08 /]# ceph daemon mds.ceph-08 objecter_requests
{
"ops": [
{
"tid": 69577573,
"pg": "5.d8994de6",
"osd": 125,
"object_id": "10000f479c9.00000000",
"object_locator": "@5",
"target_object_id": "10000f479c9.00000000",
"target_object_locator": "@5",
"paused": 0,
"used_replica": 0,
"precalc_pgid": 0,
"last_sent": "265042s",
"attempts": 5,
"snapid": "head",
"snap_context": "0=[]",
"mtime": "2019-08-22 10:12:05.0.256058s",
"osd_ops": [
"create",
"setxattr parent (319)",
"setxattr layout (30)"
]
},
{
"tid": 69577598,
"pg": "5.deb003e6",
"osd": 125,
"object_id": "10000f479da.00000000",
"object_locator": "@5",
"target_object_id": "10000f479da.00000000",
"target_object_locator": "@5",
"paused": 0,
"used_replica": 0,
"precalc_pgid": 0,
"last_sent": "265042s",
"attempts": 5,
"snapid": "head",
"snap_context": "0=[]",
"mtime": "2019-08-22 10:12:05.0.258824s",
"osd_ops": [
"create",
"setxattr parent (288)",
"setxattr layout (30)"
]
}
],
"linger_ops": [],
"pool_ops": [],
"pool_stat_ops": [],
"statfs_ops": [],
"command_ops": []
}
Restarting osd.125 finally resolved the health issues. However, the client I run fio on
had lost connection to ceph due to this incident, which is really annoying. This client is
the head node of our HPC cluster and it was not possible to restore ceph fs access without
reboot. This is an additional bad fallout as all users will loose access to our HPC
cluster when this happens (/home is on the ceph fs).
I dumped the dump_historic_slow_ops of osd.125 in case anyone can use this information.
I might be able to repeat this experiment, but cannot promise anything.
Best regards,
=================
Frank Schilder
AIT Risø Campus
Bygning 109, rum S14
23 Aug
23 Aug
8:58 p.m.
The WPQ scheduler may help your clients back off when things get busy.
Put this in your ceph.conf and restart your OSDs.
osd op queue = wpq
osd op queue cut off = high
----------------
Robert LeBlanc
PGP Fingerprint 79A2 9CA4 6CC4 45DD A904 C70E E654 3BB2 FA62 B9F1
On Fri, Aug 23, 2019 at 5:03 AM Frank Schilder <frans(a)dtu.dk> wrote:
I need to harden our ceph cluster to satisfy the
following properties:
Assuming all hardware is functioning properly,
1) Cluster health has highest priority. Heartbeats have priority over
client requests.
2) The cluster does not accept more IO than the OSDs can handle. The only
exception might be a configurable burst option.
3) Client IO is accepted as long as it does not compromise 1.
4) Ideally, there is fair sharing of the cluster's IO budget between
clients (like deadline or completely fair scheduling). Rogue clients should
not get priority just because they push a lot.
Unfortunately, with default settings our (any?) cluster prefers client IO
over cluster health, which opens up for a simple but serious non-privileged
client attack on cluster health:
I observed a serious issue on our cluster when running a simple fio test
that does 4K random writes on 100GB files (see details below). What I
observe is that within a few seconds the cluster goes to health_warn with
the MDS reporting slow meta data IO and behind on trimming. What is not
shown in ceph health detail is, that all OSDs report thousands of slow ops
and the counter increases really fast (I include some snippets below). This
goes rapidly to the point where OSDs start missing heartbeats and start
flapping, some PGs become inactive+degraded and start peering regularly.
CPU load, memory and even network load were rather low (one-figure % CPU
load). Nothing out of the ordinary. The mons had no issues.
After the fio test completed, the OSDs slowly crunched through the backlog
and managed to complete all OPS. The complete processing of the ops of a 30
second fio test took ca. 10 minutes. However, even then the cluster did not
come back healthy as essential messages between daemons seem to have been
lost. It is not a long stretch to assume that one can destroy a ceph fs
beyond repair when running this test or an application performing the same
IO pattern from multiple clients for several hours. We have a 500 node
cluster as clients and I'm afraid that even ordinary IO might trigger this
scenario in unlucky circumstances.
Since our cluster is only half-trusted (we have root access to clients,
but no control over user IO patterns), we are in need to harden our cluster
against such destructive IO patterns as much as possible.
To me it looks like the cluster is accepting way more IO than the OSDs can
handle. Ideally, what I would like to do is configure effective rate
limiting on (rogue) clients depending on how much OPS they have in flight
already. I would expect that there are tunables for MDS/OSD daemons that
control how much IO requests a client can submit/OSD will accept before
throttling IO. In particular, I would like to prioritize heartbeats to
prevent load-induced OSD flapping. How can I tune the cluster to satisfy
the conditions outlined at the top of this e-mail?
There were recent threads with similar topics, in particular, "MDS failing
under load with large cache sizes" and others reporting unstable MDS
daemons under load. However, I believe they were mostly related to cache
trimming issues due to large amounts of files created. This is not the case
here, its just 4 files with lots of random IO from a single client.
A bit of information about our cluster and observations:
The cluster is bluestore-only with 8+2 EC fs data pool on spinning disks
and an 3(2) replicated fs meta data pool on SSD. We have 8 OSD hosts with 2
shards per host. Each host has 4SSDs and 12 10TB HDDs SAS 12GB with 4k
block size. Network is 2x10G bonded for client and 2x10G bonded for
replication. The replication network will be extended to 4x10G soon. We are
aware that currently the network bandwidth greatly exceeds what the
spinning disks can handle. It is dimensioned for adding more disks in the
future.
The fio job script is:
[global]
name=fio-rand-write
directory=/home/fio # /home is on ceph fs
filename_format=tmp/fio-$jobname-${HOSTNAME}-$jobnum-$filenum
rw=randwrite
bs=4K
numjobs=4
time_based=1
runtime=30
[file1]
size=100G
ioengine=sync
Its one of the examples in the fio source repo with small modifications
(file pattern, run time). Shortly after starting this fio job from a client
connected with single 10G line, all OSDs start reporting slow ops. Picking
one, the log messages look like this:
Aug 22 12:06:22 ceph-09 ceph-osd: 2019-08-22 10:06:22.151 7f399d1bd700 -1
osd.125 3778 get_health_metrics reporting 146 slow ops, oldest is
osd_op(client.1178165.0:1670940 5.3fs0
5:fcc65fe3:::10000f403bc.0000063e:head [write 307200~4096,write
315392~8192,write 380928~12288,write 405504~12288,write 421888~4096,write
458752~4096,write 466944~4096,write 475136~4096,write 487424~8192,write
512000~4096,write 524288~4096,write 565248~4096,write 589824~8192,write
622592~4096,write 651264~4096,write 724992~12288] snapc 12e=[]
ondisk+write+known_if_redirected e3778)
...
Aug 22 12:06:49 ceph-09 journal: 2019-08-22 10:06:49.415 7f399d1bd700 -1
osd.125 3779 get_health_metrics reporting 4595 slow ops, olde
st is osd_op(client.1178165.0:1686216 5.acs0
5:354e96d5:::10000f403bc.00000bc1:head [write 2359296~4096,write
2375680~4096,write 23838
72~4096,write 2404352~4096,write 2428928~8192,write 2469888~4096,write
2490368~8192,write 2514944~4096,write 2527232~4096,write 253542
4~4096,write 2588672~4096,write 2600960~4096,write 2621440~8192,write
2658304~4096,write 2715648~8192,write 2727936~4096] snapc 12e=[]
ondisk+write+known_if_redirected e3778)
...
Aug 22 12:12:57 ceph-09 journal: 2019-08-22 10:12:57.650 7f399d1bd700 -1
osd.125 3839 get_health_metrics reporting 8419 slow ops, oldest is
osd_op(client.1178165.0:2009417 5.3fs0
5:fcdcf2bd:::10000f47e2d.00001501:head [write 2236416~4096,write
2256896~4096,write 2265088~4096,write 2301952~4096,write 2322432~4096,write
2355200~4096,write 2371584~4096,write 2387968~4096,write 2449408~4096,write
2486272~4096,write 2547712~8192,write 2617344~4096,write 2809856~4096,write
3018752~4096,write 3194880~4096,write 3223552~4096] snapc 12e=[]
ondisk+write+known_if_redirected e3839)
Aug 22 12:12:58 ceph-09 ceph-osd: 2019-08-22 10:12:58.681 7f399d1bd700 -1
osd.125 3839 get_health_metrics reporting 8862 slow ops, oldest is
osd_op(mds.0.16909:69577511 5.ees0 5.992388ee (undecoded)
ondisk+write+known_if_redirected+full_force e3839)
...
Aug 22 12:13:27 ceph-09 journal: 2019-08-22 10:13:27.691 7f399d1bd700 -1
osd.125 3839 get_health_metrics reporting 13795 slow ops, oldest is
osd_op(mds.0.16909:69577573 5.e6s0 5.d8994de6 (undecoded)
ondisk+write+known_if_redirected+full_force e3839)
...
Aug 22 12:13:59 ceph-09 ceph-osd: 2019-08-22 10:13:59.762 7f399d1bd700 -1
osd.125 3900 get_health_metrics reporting 12 slow ops, oldest is
osd_op(mds.0.16909:69577511 5.ees0 5.992388ee (undecoded)
ondisk+retry+write+known_if_redirected+full_force e3875)
...
Aug 22 12:14:46 ceph-09 journal: 2019-08-22 10:14:46.569 7f399d1bd700 -1
osd.125 3916 get_health_metrics reporting 969 slow ops, oldes
t is osd_op(mds.0.16909:69577511 5.ees0 5.992388ee (undecoded)
ondisk+retry+write+known_if_redirected+full_force e3875)
Aug 22 12:14:47 ceph-09 ceph-osd: 2019-08-22 10:14:47.617 7f399d1bd700 -1
osd.125 3935 get_health_metrics reporting 1 slow ops, oldest
is osd_op(mds.0.16909:69577511 5.ees0
5:7711c499:::10000f4798b.00000000:head [create,setxattr parent
(289),setxattr layout (30)] snap
c 0=[] RETRY=2 ondisk+retry+write+known_if_redirected+full_force e3875)
...
Aug 22 12:14:53 ceph-09 journal: 2019-08-22 10:14:53.675 7f399d1bd700 -1
osd.125 3939 get_health_metrics reporting 1 slow ops, oldest is
osd_op(mds.0.16909:69577511 5.ees0 5:7711c499:::10000f4798b.00000000:head
[create,setxattr parent (289),setxattr layout (30)] snapc 0=[] RETRY=2
ondisk+retry+write+known_if_redirected+full_force e3875)
This is the last log message, the OSD seems to have executed all OPS at
this point or shortly after. The cluster state went to health_ok - at least
shortly.
At about 12:45 (yes, lunch break) we looked at the cluster again and it
was back in health_warn with the following status output:
[root@ceph-01 ~]# ceph status
cluster:
id: e4ece518-f2cb-4708-b00f-b6bf511e91d9
health: HEALTH_WARN
1 MDSs report slow metadata IOs
2 MDSs behind on trimming
services:
mon: 3 daemons, quorum ceph-01,ceph-02,ceph-03
mgr: ceph-01(active), standbys: ceph-02, ceph-03
mds: con-fs-1/1/1 up {0=ceph-08=up:active}, 1 up:standby-replay
osd: 192 osds: 192 up, 192 in
data:
pools: 7 pools, 790 pgs
objects: 9.01 M objects, 16 TiB
usage: 20 TiB used, 1.3 PiB / 1.3 PiB avail
pgs: 790 active+clean
io:
client: 1.9 MiB/s rd, 21 MiB/s wr, 60 op/s rd, 721 op/s wr
[root@ceph-01 ~]# ceph health detail
HEALTH_WARN 1 MDSs report slow metadata IOs; 2 MDSs behind on trimming
MDS_SLOW_METADATA_IO 1 MDSs report slow metadata IOs
mdsceph-08(mds.0): 2 slow metadata IOs are blocked > 30 secs, oldest
blocked for 3275 secs
MDS_TRIM 2 MDSs behind on trimming
mdsceph-08(mds.0): Behind on trimming (1778/128) max_segments: 128,
num_segments: 1778
mdsceph-12(mds.0): Behind on trimming (1780/128) max_segments: 128,
num_segments: 1780
Num_segments was increasing constantly. Apparently, an operation got stuck
and never completed. We hunted a little bit and found
[root@ceph-mds:ceph-08 /]# ceph daemon mds.ceph-08 objecter_requests
{
"ops": [
{
"tid": 71206302,
"pg": "4.952611b7",
"osd": 19,
"object_id": "200.0001be74",
"object_locator": "@4",
"target_object_id": "200.0001be74",
"target_object_locator": "@4",
"paused": 0,
"used_replica": 0,
"precalc_pgid": 0,
"last_sent": "268516s",
"attempts": 1,
"snapid": "head",
"snap_context": "0=[]",
"mtime": "2019-08-22 11:12:41.0.565912s",
"osd_ops": [
"write 890478~1923"
]
},
{
"tid": 71206303,
"pg": "4.952611b7",
"osd": 19,
"object_id": "200.0001be74",
"object_locator": "@4",
"target_object_id": "200.0001be74",
"target_object_locator": "@4",
"paused": 0,
"used_replica": 0,
"precalc_pgid": 0,
"last_sent": "268516s",
"attempts": 1,
"snapid": "head",
"snap_context": "0=[]",
"mtime": "2019-08-22 11:12:41.0.566236s",
"osd_ops": [
"write 892401~1931"
]
},
{
"tid": 71206301,
"pg": "5.eeb918c6",
"osd": 67,
"object_id": "10000f26f67.00000000",
"object_locator": "@5",
"target_object_id": "10000f26f67.00000000",
"target_object_locator": "@5",
"paused": 0,
"used_replica": 0,
"precalc_pgid": 0,
"last_sent": "268516s",
"attempts": 1,
"snapid": "head",
"snap_context": "12e=[]",
"mtime": "1970-01-01 00:00:00.000000s",
"osd_ops": [
"trimtrunc 81854@573"
]
},
{
"tid": 69577573,
"pg": "5.d8994de6",
"osd": 125,
"object_id": "10000f479c9.00000000",
"object_locator": "@5",
"target_object_id": "10000f479c9.00000000",
"target_object_locator": "@5",
"paused": 0,
"used_replica": 0,
"precalc_pgid": 0,
"last_sent": "265042s",
"attempts": 5,
"snapid": "head",
"snap_context": "0=[]",
"mtime": "2019-08-22 10:12:05.0.256058s",
"osd_ops": [
"create",
"setxattr parent (319)",
"setxattr layout (30)"
]
},
{
"tid": 69577598,
"pg": "5.deb003e6",
"osd": 125,
"object_id": "10000f479da.00000000",
"object_locator": "@5",
"target_object_id": "10000f479da.00000000",
"target_object_locator": "@5",
"paused": 0,
"used_replica": 0,
"precalc_pgid": 0,
"last_sent": "265042s",
"attempts": 5,
"snapid": "head",
"snap_context": "0=[]",
"mtime": "2019-08-22 10:12:05.0.258824s",
"osd_ops": [
"create",
"setxattr parent (288)",
"setxattr layout (30)"
]
},
{
"tid": 71206300,
"pg": "5.5cd5b20b",
"osd": 163,
"object_id": "10000f01396.00000000",
"object_locator": "@5",
"target_object_id": "10000f01396.00000000",
"target_object_locator": "@5",
"paused": 0,
"used_replica": 0,
"precalc_pgid": 0,
"last_sent": "268516s",
"attempts": 1,
"snapid": "head",
"snap_context": "12e=[]",
"mtime": "1970-01-01 00:00:00.000000s",
"osd_ops": [
"trimtrunc 208782@573"
]
}
],
"linger_ops": [],
"pool_ops": [],
"pool_stat_ops": [],
"statfs_ops": [],
"command_ops": []
}
Notice the ops from the 1970's. Checking ops and dump_blocked_ops on
osd.19 showed that these lists were empty. So, we decided to restart osd.19
and it cleared out most of the stuck requests, but did not clear the health
warnings:
[root@ceph-mds:ceph-08 /]# ceph daemon mds.ceph-08 objecter_requests
{
"ops": [
{
"tid": 69577573,
"pg": "5.d8994de6",
"osd": 125,
"object_id": "10000f479c9.00000000",
"object_locator": "@5",
"target_object_id": "10000f479c9.00000000",
"target_object_locator": "@5",
"paused": 0,
"used_replica": 0,
"precalc_pgid": 0,
"last_sent": "265042s",
"attempts": 5,
"snapid": "head",
"snap_context": "0=[]",
"mtime": "2019-08-22 10:12:05.0.256058s",
"osd_ops": [
"create",
"setxattr parent (319)",
"setxattr layout (30)"
]
},
{
"tid": 69577598,
"pg": "5.deb003e6",
"osd": 125,
"object_id": "10000f479da.00000000",
"object_locator": "@5",
"target_object_id": "10000f479da.00000000",
"target_object_locator": "@5",
"paused": 0,
"used_replica": 0,
"precalc_pgid": 0,
"last_sent": "265042s",
"attempts": 5,
"snapid": "head",
"snap_context": "0=[]",
"mtime": "2019-08-22 10:12:05.0.258824s",
"osd_ops": [
"create",
"setxattr parent (288)",
"setxattr layout (30)"
]
}
],
"linger_ops": [],
"pool_ops": [],
"pool_stat_ops": [],
"statfs_ops": [],
"command_ops": []
}
Restarting osd.125 finally resolved the health issues. However, the client
I run fio on had lost connection to ceph due to this incident, which is
really annoying. This client is the head node of our HPC cluster and it was
not possible to restore ceph fs access without reboot. This is an
additional bad fallout as all users will loose access to our HPC cluster
when this happens (/home is on the ceph fs).
I dumped the dump_historic_slow_ops of osd.125 in case anyone can use this
information.
I might be able to repeat this experiment, but cannot promise anything.
Best regards,
=================
Frank Schilder
AIT Risø Campus
Bygning 109, rum S14
_______________________________________________
ceph-users mailing list -- ceph-users(a)ceph.io
To unsubscribe send an email to ceph-users-leave(a)ceph.io
24 Aug
24 Aug
1:56 a.m.
Frank;
Just out of curiosity; do you use a dedicated cluster network, or do you run a single
network?
Thank you,
Dominic L. Hilsbos, MBA
Director – Information Technology
Perform Air International Inc.
DHilsbos(a)PerformAir.com
www.PerformAir.com
From: Robert LeBlanc [mailto:robert@leblancnet.us]
Sent: Friday, August 23, 2019 8:29 AM
To: Frank Schilder
Cc: ceph-users
Subject: [ceph-users] Re: ceph fs crashes on simple fio test
The WPQ scheduler may help your clients back off when things get busy.
Put this in your ceph.conf and restart your OSDs.
osd op queue = wpq
osd op queue cut off = high
----------------
Robert LeBlanc
PGP Fingerprint 79A2 9CA4 6CC4 45DD A904 C70E E654 3BB2 FA62 B9F1
On Fri, Aug 23, 2019 at 5:03 AM Frank Schilder <frans(a)dtu.dk> wrote:
I need to harden our ceph cluster to satisfy the following properties:
Assuming all hardware is functioning properly,
1) Cluster health has highest priority. Heartbeats have priority over client requests.
2) The cluster does not accept more IO than the OSDs can handle. The only exception might
be a configurable burst option.
3) Client IO is accepted as long as it does not compromise 1.
4) Ideally, there is fair sharing of the cluster's IO budget between clients (like
deadline or completely fair scheduling). Rogue clients should not get priority just
because they push a lot.
Unfortunately, with default settings our (any?) cluster prefers client IO over cluster
health, which opens up for a simple but serious non-privileged client attack on cluster
health:
I observed a serious issue on our cluster when running a simple fio test that does 4K
random writes on 100GB files (see details below). What I observe is that within a few
seconds the cluster goes to health_warn with the MDS reporting slow meta data IO and
behind on trimming. What is not shown in ceph health detail is, that all OSDs report
thousands of slow ops and the counter increases really fast (I include some snippets
below). This goes rapidly to the point where OSDs start missing heartbeats and start
flapping, some PGs become inactive+degraded and start peering regularly. CPU load, memory
and even network load were rather low (one-figure % CPU load). Nothing out of the
ordinary. The mons had no issues.
After the fio test completed, the OSDs slowly crunched through the backlog and managed to
complete all OPS. The complete processing of the ops of a 30 second fio test took ca. 10
minutes. However, even then the cluster did not come back healthy as essential messages
between daemons seem to have been lost. It is not a long stretch to assume that one can
destroy a ceph fs beyond repair when running this test or an application performing the
same IO pattern from multiple clients for several hours. We have a 500 node cluster as
clients and I'm afraid that even ordinary IO might trigger this scenario in unlucky
circumstances.
Since our cluster is only half-trusted (we have root access to clients, but no control
over user IO patterns), we are in need to harden our cluster against such destructive IO
patterns as much as possible.
To me it looks like the cluster is accepting way more IO than the OSDs can handle.
Ideally, what I would like to do is configure effective rate limiting on (rogue) clients
depending on how much OPS they have in flight already. I would expect that there are
tunables for MDS/OSD daemons that control how much IO requests a client can submit/OSD
will accept before throttling IO. In particular, I would like to prioritize heartbeats to
prevent load-induced OSD flapping. How can I tune the cluster to satisfy the conditions
outlined at the top of this e-mail?
There were recent threads with similar topics, in particular, "MDS failing under load
with large cache sizes" and others reporting unstable MDS daemons under load.
However, I believe they were mostly related to cache trimming issues due to large amounts
of files created. This is not the case here, its just 4 files with lots of random IO from
a single client.
A bit of information about our cluster and observations:
The cluster is bluestore-only with 8+2 EC fs data pool on spinning disks and an 3(2)
replicated fs meta data pool on SSD. We have 8 OSD hosts with 2 shards per host. Each host
has 4SSDs and 12 10TB HDDs SAS 12GB with 4k block size. Network is 2x10G bonded for client
and 2x10G bonded for replication. The replication network will be extended to 4x10G soon.
We are aware that currently the network bandwidth greatly exceeds what the spinning disks
can handle. It is dimensioned for adding more disks in the future.
The fio job script is:
[global]
name=fio-rand-write
directory=/home/fio # /home is on ceph fs
filename_format=tmp/fio-$jobname-${HOSTNAME}-$jobnum-$filenum
rw=randwrite
bs=4K
numjobs=4
time_based=1
runtime=30
[file1]
size=100G
ioengine=sync
Its one of the examples in the fio source repo with small modifications (file pattern, run
time). Shortly after starting this fio job from a client connected with single 10G line,
all OSDs start reporting slow ops. Picking one, the log messages look like this:
Aug 22 12:06:22 ceph-09 ceph-osd: 2019-08-22 10:06:22.151 7f399d1bd700 -1 osd.125 3778
get_health_metrics reporting 146 slow ops, oldest is osd_op(client.1178165.0:1670940
5.3fs0 5:fcc65fe3:::10000f403bc.0000063e:head [write 307200~4096,write 315392~8192,write
380928~12288,write 405504~12288,write 421888~4096,write 458752~4096,write
466944~4096,write 475136~4096,write 487424~8192,write 512000~4096,write 524288~4096,write
565248~4096,write 589824~8192,write 622592~4096,write 651264~4096,write 724992~12288]
snapc 12e=[] ondisk+write+known_if_redirected e3778)
...
Aug 22 12:06:49 ceph-09 journal: 2019-08-22 10:06:49.415 7f399d1bd700 -1 osd.125 3779
get_health_metrics reporting 4595 slow ops, olde
st is osd_op(client.1178165.0:1686216 5.acs0 5:354e96d5:::10000f403bc.00000bc1:head [write
2359296~4096,write 2375680~4096,write 23838
72~4096,write 2404352~4096,write 2428928~8192,write 2469888~4096,write 2490368~8192,write
2514944~4096,write 2527232~4096,write 253542
4~4096,write 2588672~4096,write 2600960~4096,write 2621440~8192,write 2658304~4096,write
2715648~8192,write 2727936~4096] snapc 12e=[]
ondisk+write+known_if_redirected e3778)
...
Aug 22 12:12:57 ceph-09 journal: 2019-08-22 10:12:57.650 7f399d1bd700 -1 osd.125 3839
get_health_metrics reporting 8419 slow ops, oldest is osd_op(client.1178165.0:2009417
5.3fs0 5:fcdcf2bd:::10000f47e2d.00001501:head [write 2236416~4096,write 2256896~4096,write
2265088~4096,write 2301952~4096,write 2322432~4096,write 2355200~4096,write
2371584~4096,write 2387968~4096,write 2449408~4096,write 2486272~4096,write
2547712~8192,write 2617344~4096,write 2809856~4096,write 3018752~4096,write
3194880~4096,write 3223552~4096] snapc 12e=[] ondisk+write+known_if_redirected e3839)
Aug 22 12:12:58 ceph-09 ceph-osd: 2019-08-22 10:12:58.681 7f399d1bd700 -1 osd.125 3839
get_health_metrics reporting 8862 slow ops, oldest is osd_op(mds.0.16909:69577511 5.ees0
5.992388ee (undecoded) ondisk+write+known_if_redirected+full_force e3839)
...
Aug 22 12:13:27 ceph-09 journal: 2019-08-22 10:13:27.691 7f399d1bd700 -1 osd.125 3839
get_health_metrics reporting 13795 slow ops, oldest is osd_op(mds.0.16909:69577573 5.e6s0
5.d8994de6 (undecoded) ondisk+write+known_if_redirected+full_force e3839)
...
Aug 22 12:13:59 ceph-09 ceph-osd: 2019-08-22 10:13:59.762 7f399d1bd700 -1 osd.125 3900
get_health_metrics reporting 12 slow ops, oldest is osd_op(mds.0.16909:69577511 5.ees0
5.992388ee (undecoded) ondisk+retry+write+known_if_redirected+full_force e3875)
...
Aug 22 12:14:46 ceph-09 journal: 2019-08-22 10:14:46.569 7f399d1bd700 -1 osd.125 3916
get_health_metrics reporting 969 slow ops, oldes
t is osd_op(mds.0.16909:69577511 5.ees0 5.992388ee (undecoded)
ondisk+retry+write+known_if_redirected+full_force e3875)
Aug 22 12:14:47 ceph-09 ceph-osd: 2019-08-22 10:14:47.617 7f399d1bd700 -1 osd.125 3935
get_health_metrics reporting 1 slow ops, oldest
is osd_op(mds.0.16909:69577511 5.ees0 5:7711c499:::10000f4798b.00000000:head
[create,setxattr parent (289),setxattr layout (30)] snap
c 0=[] RETRY=2 ondisk+retry+write+known_if_redirected+full_force e3875)
...
Aug 22 12:14:53 ceph-09 journal: 2019-08-22 10:14:53.675 7f399d1bd700 -1 osd.125 3939
get_health_metrics reporting 1 slow ops, oldest is osd_op(mds.0.16909:69577511 5.ees0
5:7711c499:::10000f4798b.00000000:head [create,setxattr parent (289),setxattr layout (30)]
snapc 0=[] RETRY=2 ondisk+retry+write+known_if_redirected+full_force e3875)
This is the last log message, the OSD seems to have executed all OPS at this point or
shortly after. The cluster state went to health_ok - at least shortly.
At about 12:45 (yes, lunch break) we looked at the cluster again and it was back in
health_warn with the following status output:
[root@ceph-01 ~]# ceph status
cluster:
id: e4ece518-f2cb-4708-b00f-b6bf511e91d9
health: HEALTH_WARN
1 MDSs report slow metadata IOs
2 MDSs behind on trimming
services:
mon: 3 daemons, quorum ceph-01,ceph-02,ceph-03
mgr: ceph-01(active), standbys: ceph-02, ceph-03
mds: con-fs-1/1/1 up {0=ceph-08=up:active}, 1 up:standby-replay
osd: 192 osds: 192 up, 192 in
data:
pools: 7 pools, 790 pgs
objects: 9.01 M objects, 16 TiB
usage: 20 TiB used, 1.3 PiB / 1.3 PiB avail
pgs: 790 active+clean
io:
client: 1.9 MiB/s rd, 21 MiB/s wr, 60 op/s rd, 721 op/s wr
[root@ceph-01 ~]# ceph health detail
HEALTH_WARN 1 MDSs report slow metadata IOs; 2 MDSs behind on trimming
MDS_SLOW_METADATA_IO 1 MDSs report slow metadata IOs
mdsceph-08(mds.0): 2 slow metadata IOs are blocked > 30 secs, oldest blocked for
3275 secs
MDS_TRIM 2 MDSs behind on trimming
mdsceph-08(mds.0): Behind on trimming (1778/128) max_segments: 128, num_segments:
1778
mdsceph-12(mds.0): Behind on trimming (1780/128) max_segments: 128, num_segments:
1780
Num_segments was increasing constantly. Apparently, an operation got stuck and never
completed. We hunted a little bit and found
[root@ceph-mds:ceph-08 /]# ceph daemon mds.ceph-08 objecter_requests
{
"ops": [
{
"tid": 71206302,
"pg": "4.952611b7",
"osd": 19,
"object_id": "200.0001be74",
"object_locator": "@4",
"target_object_id": "200.0001be74",
"target_object_locator": "@4",
"paused": 0,
"used_replica": 0,
"precalc_pgid": 0,
"last_sent": "268516s",
"attempts": 1,
"snapid": "head",
"snap_context": "0=[]",
"mtime": "2019-08-22 11:12:41.0.565912s",
"osd_ops": [
"write 890478~1923"
]
},
{
"tid": 71206303,
"pg": "4.952611b7",
"osd": 19,
"object_id": "200.0001be74",
"object_locator": "@4",
"target_object_id": "200.0001be74",
"target_object_locator": "@4",
"paused": 0,
"used_replica": 0,
"precalc_pgid": 0,
"last_sent": "268516s",
"attempts": 1,
"snapid": "head",
"snap_context": "0=[]",
"mtime": "2019-08-22 11:12:41.0.566236s",
"osd_ops": [
"write 892401~1931"
]
},
{
"tid": 71206301,
"pg": "5.eeb918c6",
"osd": 67,
"object_id": "10000f26f67.00000000",
"object_locator": "@5",
"target_object_id": "10000f26f67.00000000",
"target_object_locator": "@5",
"paused": 0,
"used_replica": 0,
"precalc_pgid": 0,
"last_sent": "268516s",
"attempts": 1,
"snapid": "head",
"snap_context": "12e=[]",
"mtime": "1970-01-01 00:00:00.000000s",
"osd_ops": [
"trimtrunc 81854@573"
]
},
{
"tid": 69577573,
"pg": "5.d8994de6",
"osd": 125,
"object_id": "10000f479c9.00000000",
"object_locator": "@5",
"target_object_id": "10000f479c9.00000000",
"target_object_locator": "@5",
"paused": 0,
"used_replica": 0,
"precalc_pgid": 0,
"last_sent": "265042s",
"attempts": 5,
"snapid": "head",
"snap_context": "0=[]",
"mtime": "2019-08-22 10:12:05.0.256058s",
"osd_ops": [
"create",
"setxattr parent (319)",
"setxattr layout (30)"
]
},
{
"tid": 69577598,
"pg": "5.deb003e6",
"osd": 125,
"object_id": "10000f479da.00000000",
"object_locator": "@5",
"target_object_id": "10000f479da.00000000",
"target_object_locator": "@5",
"paused": 0,
"used_replica": 0,
"precalc_pgid": 0,
"last_sent": "265042s",
"attempts": 5,
"snapid": "head",
"snap_context": "0=[]",
"mtime": "2019-08-22 10:12:05.0.258824s",
"osd_ops": [
"create",
"setxattr parent (288)",
"setxattr layout (30)"
]
},
{
"tid": 71206300,
"pg": "5.5cd5b20b",
"osd": 163,
"object_id": "10000f01396.00000000",
"object_locator": "@5",
"target_object_id": "10000f01396.00000000",
"target_object_locator": "@5",
"paused": 0,
"used_replica": 0,
"precalc_pgid": 0,
"last_sent": "268516s",
"attempts": 1,
"snapid": "head",
"snap_context": "12e=[]",
"mtime": "1970-01-01 00:00:00.000000s",
"osd_ops": [
"trimtrunc 208782@573"
]
}
],
"linger_ops": [],
"pool_ops": [],
"pool_stat_ops": [],
"statfs_ops": [],
"command_ops": []
}
Notice the ops from the 1970's. Checking ops and dump_blocked_ops on osd.19 showed
that these lists were empty. So, we decided to restart osd.19 and it cleared out most of
the stuck requests, but did not clear the health warnings:
[root@ceph-mds:ceph-08 /]# ceph daemon mds.ceph-08 objecter_requests
{
"ops": [
{
"tid": 69577573,
"pg": "5.d8994de6",
"osd": 125,
"object_id": "10000f479c9.00000000",
"object_locator": "@5",
"target_object_id": "10000f479c9.00000000",
"target_object_locator": "@5",
"paused": 0,
"used_replica": 0,
"precalc_pgid": 0,
"last_sent": "265042s",
"attempts": 5,
"snapid": "head",
"snap_context": "0=[]",
"mtime": "2019-08-22 10:12:05.0.256058s",
"osd_ops": [
"create",
"setxattr parent (319)",
"setxattr layout (30)"
]
},
{
"tid": 69577598,
"pg": "5.deb003e6",
"osd": 125,
"object_id": "10000f479da.00000000",
"object_locator": "@5",
"target_object_id": "10000f479da.00000000",
"target_object_locator": "@5",
"paused": 0,
"used_replica": 0,
"precalc_pgid": 0,
"last_sent": "265042s",
"attempts": 5,
"snapid": "head",
"snap_context": "0=[]",
"mtime": "2019-08-22 10:12:05.0.258824s",
"osd_ops": [
"create",
"setxattr parent (288)",
"setxattr layout (30)"
]
}
],
"linger_ops": [],
"pool_ops": [],
"pool_stat_ops": [],
"statfs_ops": [],
"command_ops": []
}
Restarting osd.125 finally resolved the health issues. However, the client I run fio on
had lost connection to ceph due to this incident, which is really annoying. This client is
the head node of our HPC cluster and it was not possible to restore ceph fs access without
reboot. This is an additional bad fallout as all users will loose access to our HPC
cluster when this happens (/home is on the ceph fs).
I dumped the dump_historic_slow_ops of osd.125 in case anyone can use this information.
I might be able to repeat this experiment, but cannot promise anything.
Best regards,
=================
Frank Schilder
AIT Risø Campus
Bygning 109, rum S14
_______________________________________________
ceph-users mailing list -- ceph-users(a)ceph.io
To unsubscribe send an email to ceph-users-leave(a)ceph.io
5:01 a.m.
We have separate public and cluster networks, but on the same physical
switches with different VLANs.
----------------
Robert LeBlanc
PGP Fingerprint 79A2 9CA4 6CC4 45DD A904 C70E E654 3BB2 FA62 B9F1
On Fri, Aug 23, 2019 at 1:29 PM <DHilsbos(a)performair.com> wrote:
Frank;
Just out of curiosity; do you use a dedicated cluster network, or do you
run a single network?
Thank you,
Dominic L. Hilsbos, MBA
Director – Information Technology
Perform Air International Inc.
DHilsbos(a)PerformAir.com
www.PerformAir.com
From: Robert LeBlanc [mailto:robert@leblancnet.us]
Sent: Friday, August 23, 2019 8:29 AM
To: Frank Schilder
Cc: ceph-users
Subject: [ceph-users] Re: ceph fs crashes on simple fio test
The WPQ scheduler may help your clients back off when things get busy.
Put this in your ceph.conf and restart your OSDs.
osd op queue = wpq
osd op queue cut off = high
----------------
Robert LeBlanc
PGP Fingerprint 79A2 9CA4 6CC4 45DD A904 C70E E654 3BB2 FA62 B9F1
On Fri, Aug 23, 2019 at 5:03 AM Frank Schilder <frans(a)dtu.dk> wrote:
I need to harden our ceph cluster to satisfy the following properties:
Assuming all hardware is functioning properly,
1) Cluster health has highest priority. Heartbeats have priority over
client requests.
2) The cluster does not accept more IO than the OSDs can handle. The only
exception might be a configurable burst option.
3) Client IO is accepted as long as it does not compromise 1.
4) Ideally, there is fair sharing of the cluster's IO budget between
clients (like deadline or completely fair scheduling). Rogue clients should
not get priority just because they push a lot.
Unfortunately, with default settings our (any?) cluster prefers client IO
over cluster health, which opens up for a simple but serious non-privileged
client attack on cluster health:
I observed a serious issue on our cluster when running a simple fio test
that does 4K random writes on 100GB files (see details below). What I
observe is that within a few seconds the cluster goes to health_warn with
the MDS reporting slow meta data IO and behind on trimming. What is not
shown in ceph health detail is, that all OSDs report thousands of slow ops
and the counter increases really fast (I include some snippets below). This
goes rapidly to the point where OSDs start missing heartbeats and start
flapping, some PGs become inactive+degraded and start peering regularly.
CPU load, memory and even network load were rather low (one-figure % CPU
load). Nothing out of the ordinary. The mons had no issues.
After the fio test completed, the OSDs slowly crunched through the backlog
and managed to complete all OPS. The complete processing of the ops of a 30
second fio test took ca. 10 minutes. However, even then the cluster did not
come back healthy as essential messages between daemons seem to have been
lost. It is not a long stretch to assume that one can destroy a ceph fs
beyond repair when running this test or an application performing the same
IO pattern from multiple clients for several hours. We have a 500 node
cluster as clients and I'm afraid that even ordinary IO might trigger this
scenario in unlucky circumstances.
Since our cluster is only half-trusted (we have root access to clients,
but no control over user IO patterns), we are in need to harden our cluster
against such destructive IO patterns as much as possible.
To me it looks like the cluster is accepting way more IO than the OSDs can
handle. Ideally, what I would like to do is configure effective rate
limiting on (rogue) clients depending on how much OPS they have in flight
already. I would expect that there are tunables for MDS/OSD daemons that
control how much IO requests a client can submit/OSD will accept before
throttling IO. In particular, I would like to prioritize heartbeats to
prevent load-induced OSD flapping. How can I tune the cluster to satisfy
the conditions outlined at the top of this e-mail?
There were recent threads with similar topics, in particular, "MDS failing
under load with large cache sizes" and others reporting unstable MDS
daemons under load. However, I believe they were mostly related to cache
trimming issues due to large amounts of files created. This is not the case
here, its just 4 files with lots of random IO from a single client.
A bit of information about our cluster and observations:
The cluster is bluestore-only with 8+2 EC fs data pool on spinning disks
and an 3(2) replicated fs meta data pool on SSD. We have 8 OSD hosts with 2
shards per host. Each host has 4SSDs and 12 10TB HDDs SAS 12GB with 4k
block size. Network is 2x10G bonded for client and 2x10G bonded for
replication. The replication network will be extended to 4x10G soon. We are
aware that currently the network bandwidth greatly exceeds what the
spinning disks can handle. It is dimensioned for adding more disks in the
future.
The fio job script is:
[global]
name=fio-rand-write
directory=/home/fio # /home is on ceph fs
filename_format=tmp/fio-$jobname-${HOSTNAME}-$jobnum-$filenum
rw=randwrite
bs=4K
numjobs=4
time_based=1
runtime=30
[file1]
size=100G
ioengine=sync
Its one of the examples in the fio source repo with small modifications
(file pattern, run time). Shortly after starting this fio job from a client
connected with single 10G line, all OSDs start reporting slow ops. Picking
one, the log messages look like this:
Aug 22 12:06:22 ceph-09 ceph-osd: 2019-08-22 10:06:22.151 7f399d1bd700 -1
osd.125 3778 get_health_metrics reporting 146 slow ops, oldest is
osd_op(client.1178165.0:1670940 5.3fs0
5:fcc65fe3:::10000f403bc.0000063e:head [write 307200~4096,write
315392~8192,write 380928~12288,write 405504~12288,write 421888~4096,write
458752~4096,write 466944~4096,write 475136~4096,write 487424~8192,write
512000~4096,write 524288~4096,write 565248~4096,write 589824~8192,write
622592~4096,write 651264~4096,write 724992~12288] snapc 12e=[]
ondisk+write+known_if_redirected e3778)
...
Aug 22 12:06:49 ceph-09 journal: 2019-08-22 10:06:49.415 7f399d1bd700 -1
osd.125 3779 get_health_metrics reporting 4595 slow ops, olde
st is osd_op(client.1178165.0:1686216 5.acs0
5:354e96d5:::10000f403bc.00000bc1:head [write 2359296~4096,write
2375680~4096,write 23838
72~4096,write 2404352~4096,write 2428928~8192,write 2469888~4096,write
2490368~8192,write 2514944~4096,write 2527232~4096,write 253542
4~4096,write 2588672~4096,write 2600960~4096,write 2621440~8192,write
2658304~4096,write 2715648~8192,write 2727936~4096] snapc 12e=[]
ondisk+write+known_if_redirected e3778)
...
Aug 22 12:12:57 ceph-09 journal: 2019-08-22 10:12:57.650 7f399d1bd700 -1
osd.125 3839 get_health_metrics reporting 8419 slow ops, oldest is
osd_op(client.1178165.0:2009417 5.3fs0
5:fcdcf2bd:::10000f47e2d.00001501:head [write 2236416~4096,write
2256896~4096,write 2265088~4096,write 2301952~4096,write 2322432~4096,write
2355200~4096,write 2371584~4096,write 2387968~4096,write 2449408~4096,write
2486272~4096,write 2547712~8192,write 2617344~4096,write 2809856~4096,write
3018752~4096,write 3194880~4096,write 3223552~4096] snapc 12e=[]
ondisk+write+known_if_redirected e3839)
Aug 22 12:12:58 ceph-09 ceph-osd: 2019-08-22 10:12:58.681 7f399d1bd700 -1
osd.125 3839 get_health_metrics reporting 8862 slow ops, oldest is
osd_op(mds.0.16909:69577511 5.ees0 5.992388ee (undecoded)
ondisk+write+known_if_redirected+full_force e3839)
...
Aug 22 12:13:27 ceph-09 journal: 2019-08-22 10:13:27.691 7f399d1bd700 -1
osd.125 3839 get_health_metrics reporting 13795 slow ops, oldest is
osd_op(mds.0.16909:69577573 5.e6s0 5.d8994de6 (undecoded)
ondisk+write+known_if_redirected+full_force e3839)
...
Aug 22 12:13:59 ceph-09 ceph-osd: 2019-08-22 10:13:59.762 7f399d1bd700 -1
osd.125 3900 get_health_metrics reporting 12 slow ops, oldest is
osd_op(mds.0.16909:69577511 5.ees0 5.992388ee (undecoded)
ondisk+retry+write+known_if_redirected+full_force e3875)
...
Aug 22 12:14:46 ceph-09 journal: 2019-08-22 10:14:46.569 7f399d1bd700 -1
osd.125 3916 get_health_metrics reporting 969 slow ops, oldes
t is osd_op(mds.0.16909:69577511 5.ees0 5.992388ee (undecoded)
ondisk+retry+write+known_if_redirected+full_force e3875)
Aug 22 12:14:47 ceph-09 ceph-osd: 2019-08-22 10:14:47.617 7f399d1bd700 -1
osd.125 3935 get_health_metrics reporting 1 slow ops, oldest
is osd_op(mds.0.16909:69577511 5.ees0
5:7711c499:::10000f4798b.00000000:head [create,setxattr parent
(289),setxattr layout (30)] snap
c 0=[] RETRY=2 ondisk+retry+write+known_if_redirected+full_force e3875)
...
Aug 22 12:14:53 ceph-09 journal: 2019-08-22 10:14:53.675 7f399d1bd700 -1
osd.125 3939 get_health_metrics reporting 1 slow ops, oldest is
osd_op(mds.0.16909:69577511 5.ees0 5:7711c499:::10000f4798b.00000000:head
[create,setxattr parent (289),setxattr layout (30)] snapc 0=[] RETRY=2
ondisk+retry+write+known_if_redirected+full_force e3875)
This is the last log message, the OSD seems to have executed all OPS at
this point or shortly after. The cluster state went to health_ok - at least
shortly.
At about 12:45 (yes, lunch break) we looked at the cluster again and it
was back in health_warn with the following status output:
[root@ceph-01 ~]# ceph status
cluster:
id: e4ece518-f2cb-4708-b00f-b6bf511e91d9
health: HEALTH_WARN
1 MDSs report slow metadata IOs
2 MDSs behind on trimming
services:
mon: 3 daemons, quorum ceph-01,ceph-02,ceph-03
mgr: ceph-01(active), standbys: ceph-02, ceph-03
mds: con-fs-1/1/1 up {0=ceph-08=up:active}, 1 up:standby-replay
osd: 192 osds: 192 up, 192 in
data:
pools: 7 pools, 790 pgs
objects: 9.01 M objects, 16 TiB
usage: 20 TiB used, 1.3 PiB / 1.3 PiB avail
pgs: 790 active+clean
io:
client: 1.9 MiB/s rd, 21 MiB/s wr, 60 op/s rd, 721 op/s wr
[root@ceph-01 ~]# ceph health detail
HEALTH_WARN 1 MDSs report slow metadata IOs; 2 MDSs behind on trimming
MDS_SLOW_METADATA_IO 1 MDSs report slow metadata IOs
mdsceph-08(mds.0): 2 slow metadata IOs are blocked > 30 secs, oldest
blocked for 3275 secs
MDS_TRIM 2 MDSs behind on trimming
mdsceph-08(mds.0): Behind on trimming (1778/128) max_segments: 128,
num_segments: 1778
mdsceph-12(mds.0): Behind on trimming (1780/128) max_segments: 128,
num_segments: 1780
Num_segments was increasing constantly. Apparently, an operation got stuck
and never completed. We hunted a little bit and found
[root@ceph-mds:ceph-08 /]# ceph daemon mds.ceph-08 objecter_requests
{
"ops": [
{
"tid": 71206302,
"pg": "4.952611b7",
"osd": 19,
"object_id": "200.0001be74",
"object_locator": "@4",
"target_object_id": "200.0001be74",
"target_object_locator": "@4",
"paused": 0,
"used_replica": 0,
"precalc_pgid": 0,
"last_sent": "268516s",
"attempts": 1,
"snapid": "head",
"snap_context": "0=[]",
"mtime": "2019-08-22 11:12:41.0.565912s",
"osd_ops": [
"write 890478~1923"
]
},
{
"tid": 71206303,
"pg": "4.952611b7",
"osd": 19,
"object_id": "200.0001be74",
"object_locator": "@4",
"target_object_id": "200.0001be74",
"target_object_locator": "@4",
"paused": 0,
"used_replica": 0,
"precalc_pgid": 0,
"last_sent": "268516s",
"attempts": 1,
"snapid": "head",
"snap_context": "0=[]",
"mtime": "2019-08-22 11:12:41.0.566236s",
"osd_ops": [
"write 892401~1931"
]
},
{
"tid": 71206301,
"pg": "5.eeb918c6",
"osd": 67,
"object_id": "10000f26f67.00000000",
"object_locator": "@5",
"target_object_id": "10000f26f67.00000000",
"target_object_locator": "@5",
"paused": 0,
"used_replica": 0,
"precalc_pgid": 0,
"last_sent": "268516s",
"attempts": 1,
"snapid": "head",
"snap_context": "12e=[]",
"mtime": "1970-01-01 00:00:00.000000s",
"osd_ops": [
"trimtrunc 81854@573"
]
},
{
"tid": 69577573,
"pg": "5.d8994de6",
"osd": 125,
"object_id": "10000f479c9.00000000",
"object_locator": "@5",
"target_object_id": "10000f479c9.00000000",
"target_object_locator": "@5",
"paused": 0,
"used_replica": 0,
"precalc_pgid": 0,
"last_sent": "265042s",
"attempts": 5,
"snapid": "head",
"snap_context": "0=[]",
"mtime": "2019-08-22 10:12:05.0.256058s",
"osd_ops": [
"create",
"setxattr parent (319)",
"setxattr layout (30)"
]
},
{
"tid": 69577598,
"pg": "5.deb003e6",
"osd": 125,
"object_id": "10000f479da.00000000",
"object_locator": "@5",
"target_object_id": "10000f479da.00000000",
"target_object_locator": "@5",
"paused": 0,
"used_replica": 0,
"precalc_pgid": 0,
"last_sent": "265042s",
"attempts": 5,
"snapid": "head",
"snap_context": "0=[]",
"mtime": "2019-08-22 10:12:05.0.258824s",
"osd_ops": [
"create",
"setxattr parent (288)",
"setxattr layout (30)"
]
},
{
"tid": 71206300,
"pg": "5.5cd5b20b",
"osd": 163,
"object_id": "10000f01396.00000000",
"object_locator": "@5",
"target_object_id": "10000f01396.00000000",
"target_object_locator": "@5",
"paused": 0,
"used_replica": 0,
"precalc_pgid": 0,
"last_sent": "268516s",
"attempts": 1,
"snapid": "head",
"snap_context": "12e=[]",
"mtime": "1970-01-01 00:00:00.000000s",
"osd_ops": [
"trimtrunc 208782@573"
]
}
],
"linger_ops": [],
"pool_ops": [],
"pool_stat_ops": [],
"statfs_ops": [],
"command_ops": []
}
Notice the ops from the 1970's. Checking ops and dump_blocked_ops on
osd.19 showed that these lists were empty. So, we decided to restart osd.19
and it cleared out most of the stuck requests, but did not clear the health
warnings:
[root@ceph-mds:ceph-08 /]# ceph daemon mds.ceph-08 objecter_requests
{
"ops": [
{
"tid": 69577573,
"pg": "5.d8994de6",
"osd": 125,
"object_id": "10000f479c9.00000000",
"object_locator": "@5",
"target_object_id": "10000f479c9.00000000",
"target_object_locator": "@5",
"paused": 0,
"used_replica": 0,
"precalc_pgid": 0,
"last_sent": "265042s",
"attempts": 5,
"snapid": "head",
"snap_context": "0=[]",
"mtime": "2019-08-22 10:12:05.0.256058s",
"osd_ops": [
"create",
"setxattr parent (319)",
"setxattr layout (30)"
]
},
{
"tid": 69577598,
"pg": "5.deb003e6",
"osd": 125,
"object_id": "10000f479da.00000000",
"object_locator": "@5",
"target_object_id": "10000f479da.00000000",
"target_object_locator": "@5",
"paused": 0,
"used_replica": 0,
"precalc_pgid": 0,
"last_sent": "265042s",
"attempts": 5,
"snapid": "head",
"snap_context": "0=[]",
"mtime": "2019-08-22 10:12:05.0.258824s",
"osd_ops": [
"create",
"setxattr parent (288)",
"setxattr layout (30)"
]
}
],
"linger_ops": [],
"pool_ops": [],
"pool_stat_ops": [],
"statfs_ops": [],
"command_ops": []
}
Restarting osd.125 finally resolved the health issues. However, the client
I run fio on had lost connection to ceph due to this incident, which is
really annoying. This client is the head node of our HPC cluster and it was
not possible to restore ceph fs access without reboot. This is an
additional bad fallout as all users will loose access to our HPC cluster
when this happens (/home is on the ceph fs).
I dumped the dump_historic_slow_ops of osd.125 in case anyone can use this
information.
I might be able to repeat this experiment, but cannot promise anything.
Best regards,
=================
Frank Schilder
AIT Risø Campus
Bygning 109, rum S14
_______________________________________________
ceph-users mailing list -- ceph-users(a)ceph.io
To unsubscribe send an email to ceph-users-leave(a)ceph.io
_______________________________________________
ceph-users mailing list -- ceph-users(a)ceph.io
To unsubscribe send an email to ceph-users-leave(a)ceph.io
2:18 p.m.
Same set-up as Robert. Two different VLANs for front and back network on same switch. We
did load tests before and the switches have no problems routing the traffic.
Best regards,
=================
Frank Schilder
AIT Risø Campus
Bygning 109, rum S14
________________________________________
From: Robert LeBlanc <robert(a)leblancnet.us>
Sent: 24 August 2019 01:31
To: DHilsbos(a)performair.com
Cc: Frank Schilder; ceph-users(a)ceph.io
Subject: Re: [ceph-users] Re: ceph fs crashes on simple fio test
We have separate public and cluster networks, but on the same physical switches with
different VLANs.
----------------
Robert LeBlanc
PGP Fingerprint 79A2 9CA4 6CC4 45DD A904 C70E E654 3BB2 FA62 B9F1
On Fri, Aug 23, 2019 at 1:29 PM
<DHilsbos@performair.com<mailto:DHilsbos@performair.com>> wrote:
Frank;
Just out of curiosity; do you use a dedicated cluster network, or do you run a single
network?
Thank you,
Dominic L. Hilsbos, MBA
Director – Information Technology
Perform Air International Inc.
DHilsbos(a)PerformAir.com
www.PerformAir.com<http://www.PerformAir.com>
2:38 p.m.
Hi Robert,
thanks for your reply. These are actually settings I found in cases I referred to with
"other cases" in my mail. These settings could be a first step. Looking at the
documentation, solving the overload problem might require some QoS settings I found below
the description of "osd op queue"
https://docs.ceph.com/docs/master/rados/configuration/osd-config-ref/#opera… .
I see some possibilities, but I'm not sure how to use these settings to enforce load
dependent rate limiting on clients. As far as I can see, IOPs QoS does not take backlog
into account, which would be important for distinguishing a burst from a sustained
overload. In addition, this requires mClock, which is labelled experimental.
If anyone could shed some light on what possibilities currently exist beyond playing with
"osd op queue" and "osd op queue cut off" that would be great. Also if
there is some experience out there about this problem.
For example, would reducing "osd client op priority" have any effect? As far as
I can see, this is only for weighting between recovery and client IO, not for priority of
IO already in flight versus new client OPS.
Best regards,
=================
Frank Schilder
AIT Risø Campus
Bygning 109, rum S14
________________________________________
From: Robert LeBlanc <robert(a)leblancnet.us>
Sent: 23 August 2019 17:28
To: Frank Schilder
Cc: ceph-users
Subject: Re: [ceph-users] ceph fs crashes on simple fio test
The WPQ scheduler may help your clients back off when things get busy.
Put this in your ceph.conf and restart your OSDs.
osd op queue = wpq
osd op queue cut off = high
----------------
Robert LeBlanc
PGP Fingerprint 79A2 9CA4 6CC4 45DD A904 C70E E654 3BB2 FA62 B9F1
26 Aug
26 Aug
9:49 p.m.
Frank,
I wrote the wpq and the cut off code because the only scheduler at the time
was not servicing other priorities under extreme load. The default op
scheduler prioritized replication ops in the strict queue which meant as
long as there were any ops from other OSDs for replication, no client or
backfill ops would be serviced. Once the strict queue was empty then it
would start dequeing client ops, but the way the token bucket code worked
it would drain the client queue quickly and then start running
backfill/recovery ops which didn't drain that bucket as fast. This did not
sit well with our VMs with heavy write loads.
I wrote WPQ to dequeue each op priority based on the weight of the op
rather than token bucket queue and showed that it proportionally dequeued
ops based on the priority. It meant that sometimes higher priority ops
would be blocked to run a lower priority op but no queue was ever starved
from dequeunig an op like before. An op that had twice the priority of
another op had twice the probability of being dequed. The op scheduler in
Ceph actually consists of two queues, a strict priority queue and a TB/WPQ
queue. The cut off refers to the op priority number that separates the
strict priority queue from the WPQ or default token bucket. By setting it
to high, you are telling Ceph to include the replication ops in the token
bucket or WPQ rather than the strict queue and only allows very small ops
that don't require disk access to be in the strict priority queue
(heartbeats, Mon messages, OSD messages, etc) so that all the slow work is
prioritized by the WPQ/TB queue.
With this, we found that we didn't need QoS as all client now got a fair
share of I/O instead of some clients being 'lucky' to land on a non-busy
OSD and send many rep ops to a busy OSD who could only service replication
ops and never any client ops. I also found that op priorities worked as
expected. We could raise the number of backfill operations on an OSD and it
would negligibly impact clients as it started using only idle capacity to
do the backfill and prioritize client traffic. I assume that if you change
the op priority of the different classes of ops, that it would work more
predictably with WPQ, but I don't think that you can change it on the fly
and would require an OSD reboot which I could not do at the time I tried.
The WPQ did not prevent all blocked I/O, but what it did was prevent any
single client from being blocked indefinitely. I saw latencies become very
tight across all clients, instead of some clients having very good latency
and other extremely poor latency, each client had statistically the same
latency. No longer was the cluster limited by the slowest drive in the
cluster, the OSD with the slow drive would now execute client ops sending
rep ops to other OSD and helping to generate more load on a less loaded OSD
which would then possibly reduce the load on the overloaded OSD (because
now the idle OSD had other work to do other than just servicing client
ops). This allowed the cluster to appropriately throttle clients by
increasing latency on all clients in a more uniform manner. It allows the
cluster to achieve 100% utilization at the same time.
WPQ was planned to be the default scheduler, but I left the company I was
working for shortly after getting it merged and my new company wasn't doing
object storage so I wasn't there to see it become the default. I'm at a new
company and again working with Ceph and have made it the default on our two
large production clusters with great success. The client latencies and
backfill pain that my co-workers experienced on a daily basis have been all
alleviated since moving to WPQ.
Honestly, WPQ may do what you need without having to try to configure QoS.
----------------
Robert LeBlanc
PGP Fingerprint 79A2 9CA4 6CC4 45DD A904 C70E E654 3BB2 FA62 B9F1
On Sat, Aug 24, 2019 at 2:08 AM Frank Schilder <frans(a)dtu.dk> wrote:
Hi Robert,
thanks for your reply. These are actually settings I found in cases I
referred to with "other cases" in my mail. These settings could be a first
step. Looking at the documentation, solving the overload problem might
require some QoS settings I found below the description of "osd op queue"
https://docs.ceph.com/docs/master/rados/configuration/osd-config-ref/#opera…
.
I see some possibilities, but I'm not sure how to use these settings to
enforce load dependent rate limiting on clients. As far as I can see, IOPs
QoS does not take backlog into account, which would be important for
distinguishing a burst from a sustained overload. In addition, this
requires mClock, which is labelled experimental.
If anyone could shed some light on what possibilities currently exist
beyond playing with "osd op queue" and "osd op queue cut off" that
would be
great. Also if there is some experience out there about this problem.
For example, would reducing "osd client op priority" have any effect? As
far as I can see, this is only for weighting between recovery and client
IO, not for priority of IO already in flight versus new client OPS.
Best regards,
=================
Frank Schilder
AIT Risø Campus
Bygning 109, rum S14
________________________________________
From: Robert LeBlanc <robert(a)leblancnet.us>
Sent: 23 August 2019 17:28
To: Frank Schilder
Cc: ceph-users
Subject: Re: [ceph-users] ceph fs crashes on simple fio test
The WPQ scheduler may help your clients back off when things get busy.
Put this in your ceph.conf and restart your OSDs.
osd op queue = wpq
osd op queue cut off = high
----------------
Robert LeBlanc
PGP Fingerprint 79A2 9CA4 6CC4 45DD A904 C70E E654 3BB2 FA62 B9F1
11:14 p.m.
WPQ has been the default queue for quite some time now (Luminous?).
However, the default cut off is low. I remember changing this in some
early jewel (or kraken?) version to high and it helped a lot with the
only cluster we had back then.
We've been running all of our clusters with cut off high since then,
any reason why this isn't the default?
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 Mon, Aug 26, 2019 at 6:21 PM Robert LeBlanc <robert(a)leblancnet.us> wrote:
>
> Frank,
>
> I wrote the wpq and the cut off code because the only scheduler at the time was not
servicing other priorities under extreme load. The default op scheduler prioritized
replication ops in the strict queue which meant as long as there were any ops from other
OSDs for replication, no client or backfill ops would be serviced. Once the strict queue
was empty then it would start dequeing client ops, but the way the token bucket code
worked it would drain the client queue quickly and then start running backfill/recovery
ops which didn't drain that bucket as fast. This did not sit well with our VMs with
heavy write loads.
>
> I wrote WPQ to dequeue each op priority based on the weight of the op rather than
token bucket queue and showed that it proportionally dequeued ops based on the priority.
It meant that sometimes higher priority ops would be blocked to run a lower priority op
but no queue was ever starved from dequeunig an op like before. An op that had twice the
priority of another op had twice the probability of being dequed. The op scheduler in Ceph
actually consists of two queues, a strict priority queue and a TB/WPQ queue. The cut off
refers to the op priority number that separates the strict priority queue from the WPQ or
default token bucket. By setting it to high, you are telling Ceph to include the
replication ops in the token bucket or WPQ rather than the strict queue and only allows
very small ops that don't require disk access to be in the strict priority queue
(heartbeats, Mon messages, OSD messages, etc) so that all the slow work is prioritized by
the WPQ/TB queue.
>
> With this, we found that we didn't need QoS as all client now got a fair share of
I/O instead of some clients being 'lucky' to land on a non-busy OSD and send many
rep ops to a busy OSD who could only service replication ops and never any client ops. I
also found that op priorities worked as expected. We could raise the number of backfill
operations on an OSD and it would negligibly impact clients as it started using only idle
capacity to do the backfill and prioritize client traffic. I assume that if you change the
op priority of the different classes of ops, that it would work more predictably with WPQ,
but I don't think that you can change it on the fly and would require an OSD reboot
which I could not do at the time I tried.
>
> The WPQ did not prevent all blocked I/O, but what it did was prevent any single
client from being blocked indefinitely. I saw latencies become very tight across all
clients, instead of some clients having very good latency and other extremely poor
latency, each client had statistically the same latency. No longer was the cluster limited
by the slowest drive in the cluster, the OSD with the slow drive would now execute client
ops sending rep ops to other OSD and helping to generate more load on a less loaded OSD
which would then possibly reduce the load on the overloaded OSD (because now the idle OSD
had other work to do other than just servicing client ops). This allowed the cluster to
appropriately throttle clients by increasing latency on all clients in a more uniform
manner. It allows the cluster to achieve 100% utilization at the same time.
>
> WPQ was planned to be the default scheduler, but I left the company I was working for
shortly after getting it merged and my new company wasn't doing object storage so I
wasn't there to see it become the default. I'm at a new company and again working
with Ceph and have made it the default on our two large production clusters with great
success. The client latencies and backfill pain that my co-workers experienced on a daily
basis have been all alleviated since moving to WPQ.
>
> Honestly, WPQ may do what you need without having to try to configure QoS.
>
> ----------------
> Robert LeBlanc
> PGP Fingerprint 79A2 9CA4 6CC4 45DD A904 C70E E654 3BB2 FA62 B9F1
>
>
> On Sat, Aug 24, 2019 at 2:08 AM Frank Schilder <frans(a)dtu.dk> wrote:
>>
>> Hi Robert,
>>
>> thanks for your reply. These are actually settings I found in cases I referred to
with "other cases" in my mail. These settings could be a first step. Looking at
the documentation, solving the overload problem might require some QoS settings I found
below the description of "osd op queue"
https://docs.ceph.com/docs/master/rados/configuration/osd-config-ref/#opera… .
>>
>> I see some possibilities, but I'm not sure how to use these settings to
enforce load dependent rate limiting on clients. As far as I can see, IOPs QoS does not
take backlog into account, which would be important for distinguishing a burst from a
sustained overload. In addition, this requires mClock, which is labelled experimental.
>>
>> If anyone could shed some light on what possibilities currently exist beyond
playing with "osd op queue" and "osd op queue cut off" that would be
great. Also if there is some experience out there about this problem.
>>
>> For example, would reducing "osd client op priority" have any effect?
As far as I can see, this is only for weighting between recovery and client IO, not for
priority of IO already in flight versus new client OPS.
>>
>> Best regards,
>>
>> =================
>> Frank Schilder
>> AIT Risø Campus
>> Bygning 109, rum S14
>>
>> ________________________________________
>> From: Robert LeBlanc <robert(a)leblancnet.us>
>> Sent: 23 August 2019 17:28
>> To: Frank Schilder
>> Cc: ceph-users
>> Subject: Re: [ceph-users] ceph fs crashes on simple fio test
>>
>> The WPQ scheduler may help your clients back off when things get busy.
>>
>> Put this in your ceph.conf and restart your OSDs.
>> osd op queue = wpq
>> osd op queue cut off = high
>> ----------------
>> Robert LeBlanc
>> PGP Fingerprint 79A2 9CA4 6CC4 45DD A904 C70E E654 3BB2 FA62 B9F1
>
> _______________________________________________
> ceph-users mailing list -- ceph-users(a)ceph.io
> To unsubscribe send an email to ceph-users-leave(a)ceph.io
27 Aug
27 Aug
1:52 a.m.
High should be the default with WPQ.
----------------
Robert LeBlanc
PGP Fingerprint 79A2 9CA4 6CC4 45DD A904 C70E E654 3BB2 FA62 B9F1
On Mon, Aug 26, 2019 at 10:44 AM Paul Emmerich <paul.emmerich(a)croit.io>
wrote:
WPQ has been the default queue for quite some time now
(Luminous?).
However, the default cut off is low. I remember changing this in some
early jewel (or kraken?) version to high and it helped a lot with the
only cluster we had back then.
We've been running all of our clusters with cut off high since then,
any reason why this isn't the default?
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 Mon, Aug 26, 2019 at 6:21 PM Robert LeBlanc <robert(a)leblancnet.us>
wrote:
Frank,
I wrote the wpq and the cut off code because the only scheduler at the
time was
not servicing other priorities under extreme load. The default op
scheduler prioritized replication ops in the strict queue which meant as
long as there were any ops from other OSDs for replication, no client or
backfill ops would be serviced. Once the strict queue was empty then it
would start dequeing client ops, but the way the token bucket code worked
it would drain the client queue quickly and then start running
backfill/recovery ops which didn't drain that bucket as fast. This did not
sit well with our VMs with heavy write loads.
I wrote WPQ to dequeue each op priority based on the weight of the op
rather than
token bucket queue and showed that it proportionally dequeued
ops based on the priority. It meant that sometimes higher priority ops
would be blocked to run a lower priority op but no queue was ever starved
from dequeunig an op like before. An op that had twice the priority of
another op had twice the probability of being dequed. The op scheduler in
Ceph actually consists of two queues, a strict priority queue and a TB/WPQ
queue. The cut off refers to the op priority number that separates the
strict priority queue from the WPQ or default token bucket. By setting it
to high, you are telling Ceph to include the replication ops in the token
bucket or WPQ rather than the strict queue and only allows very small ops
that don't require disk access to be in the strict priority queue
(heartbeats, Mon messages, OSD messages, etc) so that all the slow work is
prioritized by the WPQ/TB queue.
With this, we found that we didn't need QoS as all client now got a fair
share
of I/O instead of some clients being 'lucky' to land on a non-busy
OSD and send many rep ops to a busy OSD who could only service replication
ops and never any client ops. I also found that op priorities worked as
expected. We could raise the number of backfill operations on an OSD and it
would negligibly impact clients as it started using only idle capacity to
do the backfill and prioritize client traffic. I assume that if you change
the op priority of the different classes of ops, that it would work more
predictably with WPQ, but I don't think that you can change it on the fly
and would require an OSD reboot which I could not do at the time I tried.
The WPQ did not prevent all blocked I/O, but what it did was prevent any
single
client from being blocked indefinitely. I saw latencies become very
tight across all clients, instead of some clients having very good latency
and other extremely poor latency, each client had statistically the same
latency. No longer was the cluster limited by the slowest drive in the
cluster, the OSD with the slow drive would now execute client ops sending
rep ops to other OSD and helping to generate more load on a less loaded OSD
which would then possibly reduce the load on the overloaded OSD (because
now the idle OSD had other work to do other than just servicing client
ops). This allowed the cluster to appropriately throttle clients by
increasing latency on all clients in a more uniform manner. It allows the
cluster to achieve 100% utilization at the same time.
WPQ was planned to be the default scheduler, but I left the company I
was working
for shortly after getting it merged and my new company wasn't
doing object storage so I wasn't there to see it become the default. I'm at
a new company and again working with Ceph and have made it the default on
our two large production clusters with great success. The client latencies
and backfill pain that my co-workers experienced on a daily basis have been
all alleviated since moving to WPQ.
Honestly, WPQ may do what you need without having to try to configure
QoS.
----------------
Robert LeBlanc
PGP Fingerprint 79A2 9CA4 6CC4 45DD A904 C70E E654 3BB2 FA62 B9F1
On Sat, Aug 24, 2019 at 2:08 AM Frank Schilder <frans(a)dtu.dk> wrote:
>
> Hi Robert,
>
> thanks for your reply. These are actually settings I found in cases I
referred
to with "other cases" in my mail. These settings could be a first
step. Looking at the documentation, solving the overload problem might
require some QoS settings I found below the description of "osd op queue"
https://docs.ceph.com/docs/master/rados/configuration/osd-config-ref/#opera…
.
>
> I see some possibilities, but I'm not sure how to use these settings to
enforce load dependent rate limiting on clients. As far as I can see, IOPs
QoS does not take backlog into account, which would be important for
distinguishing a burst from a sustained overload. In addition, this
requires mClock, which is labelled experimental.
>
> If anyone could shed some light on what possibilities currently exist
beyond
playing with "osd op queue" and "osd op queue cut off" that would be
great. Also if there is some experience out there about this problem.
>
> For example, would reducing "osd client op priority" have any effect?
As far as I can see, this is only for weighting between recovery and client
IO, not for priority of IO already in flight versus new client OPS.
Best regards,
=================
Frank Schilder
AIT Risø Campus
Bygning 109, rum S14
________________________________________
From: Robert LeBlanc <robert(a)leblancnet.us>
Sent: 23 August 2019 17:28
To: Frank Schilder
Cc: ceph-users
Subject: Re: [ceph-users] ceph fs crashes on simple fio test
The WPQ scheduler may help your clients back off when things get busy.
Put this in your ceph.conf and restart your OSDs.
osd op queue = wpq
osd op queue cut off = high
----------------
Robert LeBlanc
PGP Fingerprint 79A2 9CA4 6CC4 45DD A904 C70E E654 3BB2 FA62 B9F1
_______________________________________________
ceph-users mailing list -- ceph-users(a)ceph.io
To unsubscribe send an email to ceph-users-leave(a)ceph.io
1:54 a.m.
If it is the default, then the documentation should be updated. [0]
[0]
https://docs.ceph.com/docs/master/rados/configuration/osd-config-ref/?highl…
----------------
Robert LeBlanc
PGP Fingerprint 79A2 9CA4 6CC4 45DD A904 C70E E654 3BB2 FA62 B9F1
On Mon, Aug 26, 2019 at 1:22 PM Robert LeBlanc <robert(a)leblancnet.us> wrote:
High should be the default with WPQ.
----------------
Robert LeBlanc
PGP Fingerprint 79A2 9CA4 6CC4 45DD A904 C70E E654 3BB2 FA62 B9F1
On Mon, Aug 26, 2019 at 10:44 AM Paul Emmerich <paul.emmerich(a)croit.io>
wrote:
WPQ has been the default queue for quite some
time now (Luminous?).
However, the default cut off is low. I remember changing this in some
early jewel (or kraken?) version to high and it helped a lot with the
only cluster we had back then.
We've been running all of our clusters with cut off high since then,
any reason why this isn't the default?
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 Mon, Aug 26, 2019 at 6:21 PM Robert LeBlanc <robert(a)leblancnet.us>
wrote:
Frank,
I wrote the wpq and the cut off code because the only scheduler at the
time was
not servicing other priorities under extreme load. The default op
scheduler prioritized replication ops in the strict queue which meant as
long as there were any ops from other OSDs for replication, no client or
backfill ops would be serviced. Once the strict queue was empty then it
would start dequeing client ops, but the way the token bucket code worked
it would drain the client queue quickly and then start running
backfill/recovery ops which didn't drain that bucket as fast. This did not
sit well with our VMs with heavy write loads.
I wrote WPQ to dequeue each op priority based on the weight of the op
rather than
token bucket queue and showed that it proportionally dequeued
ops based on the priority. It meant that sometimes higher priority ops
would be blocked to run a lower priority op but no queue was ever starved
from dequeunig an op like before. An op that had twice the priority of
another op had twice the probability of being dequed. The op scheduler in
Ceph actually consists of two queues, a strict priority queue and a TB/WPQ
queue. The cut off refers to the op priority number that separates the
strict priority queue from the WPQ or default token bucket. By setting it
to high, you are telling Ceph to include the replication ops in the token
bucket or WPQ rather than the strict queue and only allows very small ops
that don't require disk access to be in the strict priority queue
(heartbeats, Mon messages, OSD messages, etc) so that all the slow work is
prioritized by the WPQ/TB queue.
With this, we found that we didn't need QoS as all client now got a
fair share
of I/O instead of some clients being 'lucky' to land on a
non-busy OSD and send many rep ops to a busy OSD who could only service
replication ops and never any client ops. I also found that op priorities
worked as expected. We could raise the number of backfill operations on an
OSD and it would negligibly impact clients as it started using only idle
capacity to do the backfill and prioritize client traffic. I assume that if
you change the op priority of the different classes of ops, that it would
work more predictably with WPQ, but I don't think that you can change it on
the fly and would require an OSD reboot which I could not do at the time I
tried.
The WPQ did not prevent all blocked I/O, but what it did was prevent
any single
client from being blocked indefinitely. I saw latencies become
very tight across all clients, instead of some clients having very good
latency and other extremely poor latency, each client had statistically the
same latency. No longer was the cluster limited by the slowest drive in the
cluster, the OSD with the slow drive would now execute client ops sending
rep ops to other OSD and helping to generate more load on a less loaded OSD
which would then possibly reduce the load on the overloaded OSD (because
now the idle OSD had other work to do other than just servicing client
ops). This allowed the cluster to appropriately throttle clients by
increasing latency on all clients in a more uniform manner. It allows the
cluster to achieve 100% utilization at the same time.
WPQ was planned to be the default scheduler, but I left the company I
was working
for shortly after getting it merged and my new company wasn't
doing object storage so I wasn't there to see it become the default. I'm at
a new company and again working with Ceph and have made it the default on
our two large production clusters with great success. The client latencies
and backfill pain that my co-workers experienced on a daily basis have been
all alleviated since moving to WPQ.
Honestly, WPQ may do what you need without having to try to configure
QoS.
----------------
Robert LeBlanc
PGP Fingerprint 79A2 9CA4 6CC4 45DD A904 C70E E654 3BB2 FA62 B9F1
On Sat, Aug 24, 2019 at 2:08 AM Frank Schilder <frans(a)dtu.dk> wrote:
>
> Hi Robert,
>
> thanks for your reply. These are actually settings I found in cases I
referred
to with "other cases" in my mail. These settings could be a first
step. Looking at the documentation, solving the overload problem might
require some QoS settings I found below the description of "osd op queue"
https://docs.ceph.com/docs/master/rados/configuration/osd-config-ref/#opera…
.
>
> I see some possibilities, but I'm not sure how to use these settings
to
enforce load dependent rate limiting on clients. As far as I can see,
IOPs QoS does not take backlog into account, which would be important for
distinguishing a burst from a sustained overload. In addition, this
requires mClock, which is labelled experimental.
>
> If anyone could shed some light on what possibilities currently exist
beyond
playing with "osd op queue" and "osd op queue cut off" that would be
great. Also if there is some experience out there about this problem.
>
> For example, would reducing "osd client op priority" have any effect?
As far as I can see, this is only for weighting between recovery and client
IO, not for priority of IO already in flight versus new client OPS.
Best regards,
=================
Frank Schilder
AIT Risø Campus
Bygning 109, rum S14
________________________________________
From: Robert LeBlanc <robert(a)leblancnet.us>
Sent: 23 August 2019 17:28
To: Frank Schilder
Cc: ceph-users
Subject: Re: [ceph-users] ceph fs crashes on simple fio test
The WPQ scheduler may help your clients back off when things get busy.
Put this in your ceph.conf and restart your OSDs.
osd op queue = wpq
osd op queue cut off = high
----------------
Robert LeBlanc
PGP Fingerprint 79A2 9CA4 6CC4 45DD A904 C70E E654 3BB2 FA62 B9F1
_______________________________________________
ceph-users mailing list -- ceph-users(a)ceph.io
To unsubscribe send an email to ceph-users-leave(a)ceph.io
2:21 a.m.
Hi Robert and Paul,
I checked today and the default scheduler is WPQ with cut off low (I was using the
defaults). I changed cut off to high in the config data base, but still need to restart
all OSDs to apply the change.
I'm not sure how much it will help though. Maybe heartbeats will get through despite
the mess, which will be a plus in any case.
My observation was, that not some but *all* OSDs were heavily overloaded by just one
client doing aggressive IO. Following your explanations, I'm not yet convinced that
the changed cut-off will limit the rate of client OPs accepted by the cluster. Well, I
will try again after OSD restart and report back.
Thanks for your help!
Best regards,
=================
Frank Schilder
AIT Risø Campus
Bygning 109, rum S14
________________________________________
From: Robert LeBlanc <robert(a)leblancnet.us>
Sent: 26 August 2019 22:24
To: Paul Emmerich
Cc: Frank Schilder; ceph-users
Subject: Re: [ceph-users] Re: ceph fs crashes on simple fio test
If it is the default, then the documentation should be updated. [0]
[0]
https://docs.ceph.com/docs/master/rados/configuration/osd-config-ref/?highl…
----------------
Robert LeBlanc
PGP Fingerprint 79A2 9CA4 6CC4 45DD A904 C70E E654 3BB2 FA62 B9F1
On Mon, Aug 26, 2019 at 1:22 PM Robert LeBlanc
<robert@leblancnet.us<mailto:robert@leblancnet.us>> wrote:
High should be the default with WPQ.
----------------
Robert LeBlanc
PGP Fingerprint 79A2 9CA4 6CC4 45DD A904 C70E E654 3BB2 FA62 B9F1
On Mon, Aug 26, 2019 at 10:44 AM Paul Emmerich
<paul.emmerich@croit.io<mailto:paul.emmerich@croit.io>> wrote:
WPQ has been the default queue for quite some time now (Luminous?).
However, the default cut off is low. I remember changing this in some
early jewel (or kraken?) version to high and it helped a lot with the
only cluster we had back then.
We've been running all of our clusters with cut off high since then,
any reason why this isn't the default?
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<http://www.croit.io>
Tel: +49 89 1896585 90
On Mon, Aug 26, 2019 at 6:21 PM Robert LeBlanc
<robert@leblancnet.us<mailto:robert@leblancnet.us>> wrote:
>
> Frank,
>
> I wrote the wpq and the cut off code because the only scheduler at the time was not
servicing other priorities under extreme load. The default op scheduler prioritized
replication ops in the strict queue which meant as long as there were any ops from other
OSDs for replication, no client or backfill ops would be serviced. Once the strict queue
was empty then it would start dequeing client ops, but the way the token bucket code
worked it would drain the client queue quickly and then start running backfill/recovery
ops which didn't drain that bucket as fast. This did not sit well with our VMs with
heavy write loads.
>
> I wrote WPQ to dequeue each op priority based on the weight of the op rather than
token bucket queue and showed that it proportionally dequeued ops based on the priority.
It meant that sometimes higher priority ops would be blocked to run a lower priority op
but no queue was ever starved from dequeunig an op like before. An op that had twice the
priority of another op had twice the probability of being dequed. The op scheduler in Ceph
actually consists of two queues, a strict priority queue and a TB/WPQ queue. The cut off
refers to the op priority number that separates the strict priority queue from the WPQ or
default token bucket. By setting it to high, you are telling Ceph to include the
replication ops in the token bucket or WPQ rather than the strict queue and only allows
very small ops that don't require disk access to be in the strict priority queue
(heartbeats, Mon messages, OSD messages, etc) so that all the slow work is prioritized by
the WPQ/TB queue.
>
> With this, we found that we didn't need QoS as all client now got a fair share of
I/O instead of some clients being 'lucky' to land on a non-busy OSD and send many
rep ops to a busy OSD who could only service replication ops and never any client ops. I
also found that op priorities worked as expected. We could raise the number of backfill
operations on an OSD and it would negligibly impact clients as it started using only idle
capacity to do the backfill and prioritize client traffic. I assume that if you change the
op priority of the different classes of ops, that it would work more predictably with WPQ,
but I don't think that you can change it on the fly and would require an OSD reboot
which I could not do at the time I tried.
>
> The WPQ did not prevent all blocked I/O, but what it did was prevent any single
client from being blocked indefinitely. I saw latencies become very tight across all
clients, instead of some clients having very good latency and other extremely poor
latency, each client had statistically the same latency. No longer was the cluster limited
by the slowest drive in the cluster, the OSD with the slow drive would now execute client
ops sending rep ops to other OSD and helping to generate more load on a less loaded OSD
which would then possibly reduce the load on the overloaded OSD (because now the idle OSD
had other work to do other than just servicing client ops). This allowed the cluster to
appropriately throttle clients by increasing latency on all clients in a more uniform
manner. It allows the cluster to achieve 100% utilization at the same time.
>
> WPQ was planned to be the default scheduler, but I left the company I was working for
shortly after getting it merged and my new company wasn't doing object storage so I
wasn't there to see it become the default. I'm at a new company and again working
with Ceph and have made it the default on our two large production clusters with great
success. The client latencies and backfill pain that my co-workers experienced on a daily
basis have been all alleviated since moving to WPQ.
>
> Honestly, WPQ may do what you need without having to try to configure QoS.
>
> ----------------
> Robert LeBlanc
> PGP Fingerprint 79A2 9CA4 6CC4 45DD A904 C70E E654 3BB2 FA62 B9F1
>
>
> On Sat, Aug 24, 2019 at 2:08 AM Frank Schilder
<frans@dtu.dk<mailto:frans@dtu.dk>> wrote:
>>
>> Hi Robert,
>>
>> thanks for your reply. These are actually settings I found in cases I referred to
with "other cases" in my mail. These settings could be a first step. Looking at
the documentation, solving the overload problem might require some QoS settings I found
below the description of "osd op queue"
https://docs.ceph.com/docs/master/rados/configuration/osd-config-ref/#opera… .
>>
>> I see some possibilities, but I'm not sure how to use these settings to
enforce load dependent rate limiting on clients. As far as I can see, IOPs QoS does not
take backlog into account, which would be important for distinguishing a burst from a
sustained overload. In addition, this requires mClock, which is labelled experimental.
>>
>> If anyone could shed some light on what possibilities currently exist beyond
playing with "osd op queue" and "osd op queue cut off" that would be
great. Also if there is some experience out there about this problem.
>>
>> For example, would reducing "osd client op priority" have any effect?
As far as I can see, this is only for weighting between recovery and client IO, not for
priority of IO already in flight versus new client OPS.
>>
>> Best regards,
>>
>> =================
>> Frank Schilder
>> AIT Risø Campus
>> Bygning 109, rum S14
>>
>> ________________________________________
>> From: Robert LeBlanc
<robert@leblancnet.us<mailto:robert@leblancnet.us>>
>> Sent: 23 August 2019 17:28
>> To: Frank Schilder
>> Cc: ceph-users
>> Subject: Re: [ceph-users] ceph fs crashes on simple fio test
>>
>> The WPQ scheduler may help your clients back off when things get busy.
>>
>> Put this in your ceph.conf and restart your OSDs.
>> osd op queue = wpq
>> osd op queue cut off = high
>> ----------------
>> Robert LeBlanc
>> PGP Fingerprint 79A2 9CA4 6CC4 45DD A904 C70E E654 3BB2 FA62 B9F1
>
> _______________________________________________
> ceph-users mailing list -- ceph-users@ceph.io<mailto:ceph-users@ceph.io>
> To unsubscribe send an email to
ceph-users-leave@ceph.io<mailto:ceph-users-leave@ceph.io>
30 Aug
30 Aug
4:26 p.m.
Hi Robert and Paul,
a quick update. I restarted all OSDs today to activate osd_op_queue_cut_off=high. I run
into a serious problem right after that. The standby-replay MDS daemons started missing
mon beacons and were killed by the mons:
ceph-01 journal: debug [...] log [INF] Standby daemon mds.ceph-12 is not responding,
dropping it
Apparently, one also needs to set this on the MDSes:
ceph config set mds osd_op_queue_cut_off high
This also requires a restart to become active. After that, everything seems to work again.
The question that remains is:
Do I need to change this for any other daemon?
I will repeat the performance tests later and post results. On observation is, that an MDS
fail-over was a factor of 5-10 faster with the cut-off set to high.
Best regards,
=================
Frank Schilder
AIT Risø Campus
Bygning 109, rum S14
4 Sep
4 Sep
12:03 a.m.
Hi Robert and Paul,
sad news. I did a 5 seconds single thread test after setting osd_op_queue_cut_off=high on
all OSDs and MDSs. Here the current settings:
[root@ceph-01 ~]# ceph config show osd.0
NAME VALUE SOURCE OVERRIDES IGNORES
bluestore_compression_min_blob_size_hdd 262144 file
bluestore_compression_mode aggressive file
cluster_addr 192.168.16.68:0/0 override
cluster_network 192.168.16.0/20 file
crush_location host=c-04-A file
daemonize false override
err_to_syslog true file
keyring $osd_data/keyring default
leveldb_log default
mgr_initial_modules balancer dashboard file
mon_allow_pool_delete false file
mon_pool_quota_crit_threshold 90 file
mon_pool_quota_warn_threshold 70 file
osd_journal_size 4096 file
osd_max_backfills 3 mon
osd_op_queue_cut_off high mon
osd_pool_default_flag_nodelete true file
osd_recovery_max_active 8 mon
osd_recovery_sleep 0.050000 mon
public_addr 192.168.32.68:0/0 override
public_network 192.168.32.0/19 file
rbd_default_features 61 default
setgroup disk cmdline
setuser ceph cmdline
[root@ceph-01 ~]# ceph config get osd.0 osd_op_queue
wpq
Unfortunately, the problem is not resolved. The fio job script is:
=====================
[global]
name=fio-rand-write
filename_format=fio-$jobname-${HOSTNAME}-$jobnum-$filenum
rw=randwrite
bs=4K
numjobs=1
time_based=1
runtime=5
[file1]
size=100G
ioengine=sync
=====================
That's a random write test on a 100G file with write size 4K. Note that fio uses
"direct=0" by default. Using "direct=1" is absolutely fine.
Running this short burst of load, I already get the cluster unhealthy:
cluster log:
2019-09-03 20:00:00.000160 [INF] overall HEALTH_OK
2019-09-03 20:08:36.450527 [WRN] Health check failed: 1 MDSs report slow metadata IOs
(MDS_SLOW_METADATA_IO)
2019-09-03 20:08:59.867124 [INF] MDS health message cleared (mds.0): 2 slow metadata IOs
are blocked > 30 secs, oldest blocked for 49 secs
2019-09-03 20:09:00.373050 [INF] Health check cleared: MDS_SLOW_METADATA_IO (was: 1 MDSs
report slow metadata IOs)
2019-09-03 20:09:00.373094 [INF] Cluster is now healthy
/var/log/messages: loads of these (all OSDs!)
Sep 3 20:08:39 ceph-09 journal: 2019-09-03 20:08:39.269 7f6a3d63c700 -1 osd.161 10411
get_health_metrics reporting 354 slow ops, oldest is osd_op(client.4497435.0:38244 5.f7s0
5:ef9f1be4:::100010ed9bd.0000390c:head [write 8192~4096,write 32768~4096,write
139264~4096,write 172032~4096,write 270336~4096,write 512000~4096,write 688128~4096,write
876544~4096,write 1048576~4096,write 1257472~4096,write 1425408~4096,write
1445888~4096,write 1503232~4096,write 1552384~4096,write 1716224~4096,write 1765376~4096]
snapc 12e=[] ondisk+write+known_if_redirected e10411)
It looks like the MDS is pushing waaaayyy too many requests onto the HDDs instead of
throttling the client.
An ordinary user should not have so much power in his hands. This makes it trivial to
destroy a ceph cluster.
This very short fio test is probably sufficient to reproduce the issue on any test
cluster. Should I open an issue?
Best regards,
=================
Frank Schilder
AIT Risø Campus
Bygning 109, rum S14
________________________________________
From: Frank Schilder <frans(a)dtu.dk>
Sent: 30 August 2019 12:56
To: Robert LeBlanc; Paul Emmerich
Cc: ceph-users
Subject: [ceph-users] Re: ceph fs crashes on simple fio test
Hi Robert and Paul,
a quick update. I restarted all OSDs today to activate osd_op_queue_cut_off=high. I run
into a serious problem right after that. The standby-replay MDS daemons started missing
mon beacons and were killed by the mons:
ceph-01 journal: debug [...] log [INF] Standby daemon mds.ceph-12 is not responding,
dropping it
Apparently, one also needs to set this on the MDSes:
ceph config set mds osd_op_queue_cut_off high
This also requires a restart to become active. After that, everything seems to work again.
The question that remains is:
Do I need to change this for any other daemon?
I will repeat the performance tests later and post results. On observation is, that an MDS
fail-over was a factor of 5-10 faster with the cut-off set to high.
Best regards,
=================
Frank Schilder
AIT Risø Campus
Bygning 109, rum S14
_______________________________________________
ceph-users mailing list -- ceph-users(a)ceph.io
To unsubscribe send an email to ceph-users-leave(a)ceph.io
5 Sep
5 Sep
8:53 p.m.
On Tue, Sep 3, 2019 at 11:33 AM Frank Schilder <frans(a)dtu.dk> wrote:
Hi Robert and Paul,
sad news. I did a 5 seconds single thread test after setting
osd_op_queue_cut_off=high on all OSDs and MDSs. Here the current settings:
[root@ceph-01 ~]# ceph config show osd.0
NAME VALUE SOURCE
OVERRIDES IGNORES
bluestore_compression_min_blob_size_hdd 262144 file
bluestore_compression_mode aggressive file
cluster_addr 192.168.16.68:0/0 override
cluster_network 192.168.16.0/20 file
crush_location host=c-04-A file
daemonize false override
err_to_syslog true file
keyring $osd_data/keyring default
leveldb_log default
mgr_initial_modules balancer dashboard file
mon_allow_pool_delete false file
mon_pool_quota_crit_threshold 90 file
mon_pool_quota_warn_threshold 70 file
osd_journal_size 4096 file
osd_max_backfills 3 mon
osd_op_queue_cut_off high mon
osd_pool_default_flag_nodelete true file
osd_recovery_max_active 8 mon
osd_recovery_sleep 0.050000 mon
public_addr 192.168.32.68:0/0 override
public_network 192.168.32.0/19 file
rbd_default_features 61 default
setgroup disk cmdline
setuser ceph cmdline
[root@ceph-01 ~]# ceph config get osd.0 osd_op_queue
wpq
Unfortunately, the problem is not resolved. The fio job script is:
=====================
[global]
name=fio-rand-write
filename_format=fio-$jobname-${HOSTNAME}-$jobnum-$filenum
rw=randwrite
bs=4K
numjobs=1
time_based=1
runtime=5
[file1]
size=100G
ioengine=sync
=====================
That's a random write test on a 100G file with write size 4K. Note that
fio uses "direct=0" by default. Using "direct=1" is absolutely fine.
Running this short burst of load, I already get the cluster unhealthy:
cluster log:
2019-09-03 20:00:00.000160 [INF] overall HEALTH_OK
2019-09-03 20:08:36.450527 [WRN] Health check failed: 1 MDSs report slow
metadata IOs (MDS_SLOW_METADATA_IO)
2019-09-03 20:08:59.867124 [INF] MDS health message cleared (mds.0): 2
slow metadata IOs are blocked > 30 secs, oldest blocked for 49 secs
2019-09-03 20:09:00.373050 [INF] Health check cleared:
MDS_SLOW_METADATA_IO (was: 1 MDSs report slow metadata IOs)
2019-09-03 20:09:00.373094 [INF] Cluster is now healthy
/var/log/messages: loads of these (all OSDs!)
Sep 3 20:08:39 ceph-09 journal: 2019-09-03 20:08:39.269 7f6a3d63c700 -1
osd.161 10411 get_health_metrics reporting 354 slow ops, oldest is
osd_op(client.4497435.0:38244 5.f7s0 5:ef9f1be4:::100010ed9bd.0000390c:head
[write 8192~4096,write 32768~4096,write 139264~4096,write 172032~4096,write
270336~4096,write 512000~4096,write 688128~4096,write 876544~4096,write
1048576~4096,write 1257472~4096,write 1425408~4096,write 1445888~4096,write
1503232~4096,write 1552384~4096,write 1716224~4096,write 1765376~4096]
snapc 12e=[] ondisk+write+known_if_redirected e10411)
It looks like the MDS is pushing waaaayyy too many requests onto the HDDs
instead of throttling the client.
An ordinary user should not have so much power in his hands. This makes it
trivial to destroy a ceph cluster.
This very short fio test is probably sufficient to reproduce the issue on
any test cluster. Should I open an issue?
Best regards,
Are your metadata pools on SSD, or HDD? Usually for us, as long as the
blocked I/O fluctuates and goes up and down, the cluster run fine even with
the warnings. Usually on an idle cluster a client will send a bunch of data
which fills up the queues, then the HDDs have to work through them, at that
point the client realizes that the storage is 'slow' and starts throttling
the traffic and will then match the speed at which the HDDs can perform the
work. If you run the job for a long time, are you still seeing the trimming
errors, or just a steady rise in blocked IO on the OSDs without any drops
in count? What about the client, does it have a fairly even distribution of
latencies, or does it have a lot that are just really long?
----------------
Robert LeBlanc
PGP Fingerprint 79A2 9CA4 6CC4 45DD A904 C70E E654 3BB2 FA62 B9F1
29 Aug
29 Aug
1:58 p.m.
Thanks for this thread -- I'd forgotten all about high/low.
On one congested rbd cluster it just dropped our 4kB object write
latency from ~150ms to ~40ms :-)
Who wants to send the PR? -- sounds like an easy way to get on the next t-shirt.
-- dan
On Mon, Aug 26, 2019 at 10:24 PM Robert LeBlanc <robert(a)leblancnet.us> wrote:
>
> High should be the default with WPQ.
> ----------------
> Robert LeBlanc
> PGP Fingerprint 79A2 9CA4 6CC4 45DD A904 C70E E654 3BB2 FA62 B9F1
>
>
> On Mon, Aug 26, 2019 at 10:44 AM Paul Emmerich <paul.emmerich(a)croit.io> wrote:
>>
>> WPQ has been the default queue for quite some time now (Luminous?).
>>
>> However, the default cut off is low. I remember changing this in some
>> early jewel (or kraken?) version to high and it helped a lot with the
>> only cluster we had back then.
>> We've been running all of our clusters with cut off high since then,
>> any reason why this isn't the default?
>>
>>
>> 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 Mon, Aug 26, 2019 at 6:21 PM Robert LeBlanc <robert(a)leblancnet.us>
wrote:
>> >
>> > Frank,
>> >
>> > I wrote the wpq and the cut off code because the only scheduler at the time
was not servicing other priorities under extreme load. The default op scheduler
prioritized replication ops in the strict queue which meant as long as there were any ops
from other OSDs for replication, no client or backfill ops would be serviced. Once the
strict queue was empty then it would start dequeing client ops, but the way the token
bucket code worked it would drain the client queue quickly and then start running
backfill/recovery ops which didn't drain that bucket as fast. This did not sit well
with our VMs with heavy write loads.
>> >
>> > I wrote WPQ to dequeue each op priority based on the weight of the op rather
than token bucket queue and showed that it proportionally dequeued ops based on the
priority. It meant that sometimes higher priority ops would be blocked to run a lower
priority op but no queue was ever starved from dequeunig an op like before. An op that had
twice the priority of another op had twice the probability of being dequed. The op
scheduler in Ceph actually consists of two queues, a strict priority queue and a TB/WPQ
queue. The cut off refers to the op priority number that separates the strict priority
queue from the WPQ or default token bucket. By setting it to high, you are telling Ceph to
include the replication ops in the token bucket or WPQ rather than the strict queue and
only allows very small ops that don't require disk access to be in the strict priority
queue (heartbeats, Mon messages, OSD messages, etc) so that all the slow work is
prioritized by the WPQ/TB queue.
>> >
>> > With this, we found that we didn't need QoS as all client now got a fair
share of I/O instead of some clients being 'lucky' to land on a non-busy OSD and
send many rep ops to a busy OSD who could only service replication ops and never any
client ops. I also found that op priorities worked as expected. We could raise the number
of backfill operations on an OSD and it would negligibly impact clients as it started
using only idle capacity to do the backfill and prioritize client traffic. I assume that
if you change the op priority of the different classes of ops, that it would work more
predictably with WPQ, but I don't think that you can change it on the fly and would
require an OSD reboot which I could not do at the time I tried.
>> >
>> > The WPQ did not prevent all blocked I/O, but what it did was prevent any
single client from being blocked indefinitely. I saw latencies become very tight across
all clients, instead of some clients having very good latency and other extremely poor
latency, each client had statistically the same latency. No longer was the cluster limited
by the slowest drive in the cluster, the OSD with the slow drive would now execute client
ops sending rep ops to other OSD and helping to generate more load on a less loaded OSD
which would then possibly reduce the load on the overloaded OSD (because now the idle OSD
had other work to do other than just servicing client ops). This allowed the cluster to
appropriately throttle clients by increasing latency on all clients in a more uniform
manner. It allows the cluster to achieve 100% utilization at the same time.
>> >
>> > WPQ was planned to be the default scheduler, but I left the company I was
working for shortly after getting it merged and my new company wasn't doing object
storage so I wasn't there to see it become the default. I'm at a new company and
again working with Ceph and have made it the default on our two large production clusters
with great success. The client latencies and backfill pain that my co-workers experienced
on a daily basis have been all alleviated since moving to WPQ.
>> >
>> > Honestly, WPQ may do what you need without having to try to configure QoS.
>> >
>> > ----------------
>> > Robert LeBlanc
>> > PGP Fingerprint 79A2 9CA4 6CC4 45DD A904 C70E E654 3BB2 FA62 B9F1
>> >
>> >
>> > On Sat, Aug 24, 2019 at 2:08 AM Frank Schilder <frans(a)dtu.dk> wrote:
>> >>
>> >> Hi Robert,
>> >>
>> >> thanks for your reply. These are actually settings I found in cases I
referred to with "other cases" in my mail. These settings could be a first
step. Looking at the documentation, solving the overload problem might require some QoS
settings I found below the description of "osd op queue"
https://docs.ceph.com/docs/master/rados/configuration/osd-config-ref/#opera… .
>> >>
>> >> I see some possibilities, but I'm not sure how to use these settings
to enforce load dependent rate limiting on clients. As far as I can see, IOPs QoS does not
take backlog into account, which would be important for distinguishing a burst from a
sustained overload. In addition, this requires mClock, which is labelled experimental.
>> >>
>> >> If anyone could shed some light on what possibilities currently exist
beyond playing with "osd op queue" and "osd op queue cut off" that
would be great. Also if there is some experience out there about this problem.
>> >>
>> >> For example, would reducing "osd client op priority" have any
effect? As far as I can see, this is only for weighting between recovery and client IO,
not for priority of IO already in flight versus new client OPS.
>> >>
>> >> Best regards,
>> >>
>> >> =================
>> >> Frank Schilder
>> >> AIT Risø Campus
>> >> Bygning 109, rum S14
>> >>
>> >> ________________________________________
>> >> From: Robert LeBlanc <robert(a)leblancnet.us>
>> >> Sent: 23 August 2019 17:28
>> >> To: Frank Schilder
>> >> Cc: ceph-users
>> >> Subject: Re: [ceph-users] ceph fs crashes on simple fio test
>> >>
>> >> The WPQ scheduler may help your clients back off when things get busy.
>> >>
>> >> Put this in your ceph.conf and restart your OSDs.
>> >> osd op queue = wpq
>> >> osd op queue cut off = high
>> >> ----------------
>> >> Robert LeBlanc
>> >> PGP Fingerprint 79A2 9CA4 6CC4 45DD A904 C70E E654 3BB2 FA62 B9F1
>> >
>> > _______________________________________________
>> > ceph-users mailing list -- ceph-users(a)ceph.io
>> > To unsubscribe send an email to ceph-users-leave(a)ceph.io
>
> _______________________________________________
> ceph-users mailing list -- ceph-users(a)ceph.io
> To unsubscribe send an email to ceph-users-leave(a)ceph.io
1695
days inactive
1708
days old
14 comments
5 participants
participants (5)
-
Dan van der Ster -
DHilsbos＠performair.com -
Frank Schilder -
Paul Emmerich -
Robert LeBlanc