performance degredation every 30 seconds
I have a new 3 node octopus cluster, set up on SSDs. I'm running fio to benchmark the setup, with fio --filename=/dev/rbd0 --direct=1 --rw=randrw --bs=4k --ioengine=libaio --iodepth=256 --numjobs=1 --time_based --group_reporting --name=iops-test-job --runtime=120 --eta-newline=1 However, I notice that, approximately every 30 seconds, performance tanks for a bit. Any ideas on why, and better yet, how to get rid of the problem? Sample debug output below. Notice the transitions at [eta 01m:27s] and [eta 00m:49s] It happens again at [00m:09], but figured I didnt need to redundantly post that. Jobs: 1 (f=1): [m(1)][2.5%][r=43.4MiB/s,w=43.3MiB/s][r=11.1k,w=11.1k IOPS][eta 01m:58s] Jobs: 1 (f=1): [m(1)][4.1%][r=47.3MiB/s,w=47.8MiB/s][r=12.1k,w=12.2k IOPS][eta 01m:56s] Jobs: 1 (f=1): [m(1)][5.8%][r=48.6MiB/s,w=49.3MiB/s][r=12.5k,w=12.6k IOPS][eta 01m:54s] Jobs: 1 (f=1): [m(1)][7.4%][r=52.4MiB/s,w=53.1MiB/s][r=13.4k,w=13.6k IOPS][eta 01m:52s] Jobs: 1 (f=1): [m(1)][9.1%][r=54.7MiB/s,w=54.1MiB/s][r=13.0k,w=13.8k IOPS][eta 01m:50s] Jobs: 1 (f=1): [m(1)][10.7%][r=41.5MiB/s,w=42.6MiB/s][r=10.6k,w=10.9k IOPS][eta 01m:48s] Jobs: 1 (f=1): [m(1)][12.4%][r=51.5MiB/s,w=50.6MiB/s][r=13.2k,w=12.0k IOPS][eta 01m:46s] Jobs: 1 (f=1): [m(1)][14.0%][r=16.6MiB/s,w=16.0MiB/s][r=4248,w=4098 IOPS][eta 01m:44s] Jobs: 1 (f=1): [m(1)][14.9%][r=33.3MiB/s,w=33.5MiB/s][r=8526,w=8579 IOPS][eta 01m:43s] Jobs: 1 (f=1): [m(1)][16.5%][r=47.1MiB/s,w=47.4MiB/s][r=12.1k,w=12.1k IOPS][eta 01m:41s] Jobs: 1 (f=1): [m(1)][18.2%][r=49.6MiB/s,w=49.0MiB/s][r=12.7k,w=12.8k IOPS][eta 01m:39s] Jobs: 1 (f=1): [m(1)][19.8%][r=50.3MiB/s,w=51.4MiB/s][r=12.9k,w=13.1k IOPS][eta 01m:37s] Jobs: 1 (f=1): [m(1)][21.5%][r=53.5MiB/s,w=52.9MiB/s][r=13.7k,w=13.5k IOPS][eta 01m:35s] Jobs: 1 (f=1): [m(1)][23.1%][r=52.7MiB/s,w=52.1MiB/s][r=13.5k,w=13.3k IOPS][eta 01m:33s] Jobs: 1 (f=1): [m(1)][24.8%][r=55.3MiB/s,w=54.9MiB/s][r=14.1k,w=14.1k IOPS][eta 01m:31s] Jobs: 1 (f=1): [m(1)][26.4%][r=44.0MiB/s,w=45.2MiB/s][r=11.5k,w=11.6k IOPS][eta 01m:29s] Jobs: 1 (f=1): [m(1)][28.1%][r=12.1MiB/s,w=11.8MiB/s][r=3105,w=3011 IOPS][eta 01m:27s] Jobs: 1 (f=1): [m(1)][29.8%][r=16.6MiB/s,w=17.3MiB/s][r=4238,w=4422 IOPS][eta 01m:25s] Jobs: 1 (f=1): [m(1)][31.4%][r=9820KiB/s,w=9516KiB/s][r=2455,w=2379 IOPS][eta 01m:23s] Jobs: 1 (f=1): [m(1)][33.1%][r=6974KiB/s,w=7099KiB/s][r=1743,w=1774 IOPS][eta 01m:21s] Jobs: 1 (f=1): [m(1)][34.7%][r=49.5MiB/s,w=49.2MiB/s][r=12.7k,w=12.6k IOPS][eta 01m:19s] Jobs: 1 (f=1): [m(1)][36.4%][r=49.3MiB/s,w=49.8MiB/s][r=12.6k,w=12.8k IOPS][eta 01m:17s] Jobs: 1 (f=1): [m(1)][38.0%][r=36.4MiB/s,w=35.9MiB/s][r=9326,w=9200 IOPS][eta 01m:15s] Jobs: 1 (f=1): [m(1)][39.7%][r=43.4MiB/s,w=43.3MiB/s][r=11.1k,w=11.1k IOPS][eta 01m:13s] Jobs: 1 (f=1): [m(1)][41.3%][r=47.1MiB/s,w=47.1MiB/s][r=12.1k,w=12.1k IOPS][eta 01m:11s] Jobs: 1 (f=1): [m(1)][43.0%][r=47.9MiB/s,w=48.0MiB/s][r=12.3k,w=12.5k IOPS][eta 01m:09s] Jobs: 1 (f=1): [m(1)][44.6%][r=49.9MiB/s,w=48.8MiB/s][r=12.8k,w=12.5k IOPS][eta 01m:07s] Jobs: 1 (f=1): [m(1)][46.3%][r=46.4MiB/s,w=46.9MiB/s][r=11.9k,w=11.0k IOPS][eta 01m:05s] Jobs: 1 (f=1): [m(1)][47.9%][r=46.7MiB/s,w=46.4MiB/s][r=11.0k,w=11.9k IOPS][eta 01m:03s] Jobs: 1 (f=1): [m(1)][49.6%][r=55.3MiB/s,w=55.3MiB/s][r=14.1k,w=14.2k IOPS][eta 01m:01s] Jobs: 1 (f=1): [m(1)][51.2%][r=54.1MiB/s,w=53.2MiB/s][r=13.8k,w=13.6k IOPS][eta 00m:59s] Jobs: 1 (f=1): [m(1)][52.9%][r=53.4MiB/s,w=52.9MiB/s][r=13.7k,w=13.6k IOPS][eta 00m:57s] Jobs: 1 (f=1): [m(1)][54.5%][r=58.8MiB/s,w=58.0MiB/s][r=15.1k,w=15.1k IOPS][eta 00m:55s] Jobs: 1 (f=1): [m(1)][56.2%][r=60.0MiB/s,w=58.6MiB/s][r=15.4k,w=15.0k IOPS][eta 00m:53s] Jobs: 1 (f=1): [m(1)][57.9%][r=57.7MiB/s,w=58.1MiB/s][r=14.8k,w=14.9k IOPS][eta 00m:51s] Jobs: 1 (f=1): [m(1)][59.5%][r=14.0MiB/s,w=14.3MiB/s][r=3592,w=3651 IOPS][eta 00m:49s] Jobs: 1 (f=1): [m(1)][61.2%][r=17.4MiB/s,w=17.4MiB/s][r=4443,w=4457 IOPS][eta 00m:47s] Jobs: 1 (f=1): [m(1)][62.8%][r=18.1MiB/s,w=18.7MiB/s][r=4640,w=4783 IOPS][eta 00m:45s] Jobs: 1 (f=1): [m(1)][64.5%][r=7896KiB/s,w=8300KiB/s][r=1974,w=2075 IOPS][eta 00m:43s] Jobs: 1 (f=1): [m(1)][66.1%][r=47.8MiB/s,w=47.3MiB/s][r=12.2k,w=12.1k IOPS][eta 00m:41s] -- Philip Brown| Sr. Linux System Administrator | Medata, Inc. 5 Peters Canyon Rd Suite 250 Irvine CA 92606 Office 714.918.1310| Fax 714.918.1325 pbrown@medata.com| www.medata.com
On Mon, Dec 14, 2020 at 11:28 AM Philip Brown <pbrown@medata.com> wrote:
I have a new 3 node octopus cluster, set up on SSDs.
I'm running fio to benchmark the setup, with
fio --filename=/dev/rbd0 --direct=1 --rw=randrw --bs=4k --ioengine=libaio --iodepth=256 --numjobs=1 --time_based --group_reporting --name=iops-test-job --runtime=120 --eta-newline=1
However, I notice that, approximately every 30 seconds, performance tanks for a bit.
Any ideas on why, and better yet, how to get rid of the problem?
Does the same issue appear when running a direct rados bench? What brand are your SSDs (i.e. are they data center grade)?
Sample debug output below. Notice the transitions at [eta 01m:27s] and [eta 00m:49s] It happens again at [00m:09], but figured I didnt need to redundantly post that.
Jobs: 1 (f=1): [m(1)][2.5%][r=43.4MiB/s,w=43.3MiB/s][r=11.1k,w=11.1k IOPS][eta 01m:58s] Jobs: 1 (f=1): [m(1)][4.1%][r=47.3MiB/s,w=47.8MiB/s][r=12.1k,w=12.2k IOPS][eta 01m:56s] Jobs: 1 (f=1): [m(1)][5.8%][r=48.6MiB/s,w=49.3MiB/s][r=12.5k,w=12.6k IOPS][eta 01m:54s] Jobs: 1 (f=1): [m(1)][7.4%][r=52.4MiB/s,w=53.1MiB/s][r=13.4k,w=13.6k IOPS][eta 01m:52s] Jobs: 1 (f=1): [m(1)][9.1%][r=54.7MiB/s,w=54.1MiB/s][r=13.0k,w=13.8k IOPS][eta 01m:50s] Jobs: 1 (f=1): [m(1)][10.7%][r=41.5MiB/s,w=42.6MiB/s][r=10.6k,w=10.9k IOPS][eta 01m:48s] Jobs: 1 (f=1): [m(1)][12.4%][r=51.5MiB/s,w=50.6MiB/s][r=13.2k,w=12.0k IOPS][eta 01m:46s] Jobs: 1 (f=1): [m(1)][14.0%][r=16.6MiB/s,w=16.0MiB/s][r=4248,w=4098 IOPS][eta 01m:44s] Jobs: 1 (f=1): [m(1)][14.9%][r=33.3MiB/s,w=33.5MiB/s][r=8526,w=8579 IOPS][eta 01m:43s] Jobs: 1 (f=1): [m(1)][16.5%][r=47.1MiB/s,w=47.4MiB/s][r=12.1k,w=12.1k IOPS][eta 01m:41s] Jobs: 1 (f=1): [m(1)][18.2%][r=49.6MiB/s,w=49.0MiB/s][r=12.7k,w=12.8k IOPS][eta 01m:39s] Jobs: 1 (f=1): [m(1)][19.8%][r=50.3MiB/s,w=51.4MiB/s][r=12.9k,w=13.1k IOPS][eta 01m:37s] Jobs: 1 (f=1): [m(1)][21.5%][r=53.5MiB/s,w=52.9MiB/s][r=13.7k,w=13.5k IOPS][eta 01m:35s] Jobs: 1 (f=1): [m(1)][23.1%][r=52.7MiB/s,w=52.1MiB/s][r=13.5k,w=13.3k IOPS][eta 01m:33s] Jobs: 1 (f=1): [m(1)][24.8%][r=55.3MiB/s,w=54.9MiB/s][r=14.1k,w=14.1k IOPS][eta 01m:31s] Jobs: 1 (f=1): [m(1)][26.4%][r=44.0MiB/s,w=45.2MiB/s][r=11.5k,w=11.6k IOPS][eta 01m:29s] Jobs: 1 (f=1): [m(1)][28.1%][r=12.1MiB/s,w=11.8MiB/s][r=3105,w=3011 IOPS][eta 01m:27s] Jobs: 1 (f=1): [m(1)][29.8%][r=16.6MiB/s,w=17.3MiB/s][r=4238,w=4422 IOPS][eta 01m:25s] Jobs: 1 (f=1): [m(1)][31.4%][r=9820KiB/s,w=9516KiB/s][r=2455,w=2379 IOPS][eta 01m:23s] Jobs: 1 (f=1): [m(1)][33.1%][r=6974KiB/s,w=7099KiB/s][r=1743,w=1774 IOPS][eta 01m:21s] Jobs: 1 (f=1): [m(1)][34.7%][r=49.5MiB/s,w=49.2MiB/s][r=12.7k,w=12.6k IOPS][eta 01m:19s] Jobs: 1 (f=1): [m(1)][36.4%][r=49.3MiB/s,w=49.8MiB/s][r=12.6k,w=12.8k IOPS][eta 01m:17s] Jobs: 1 (f=1): [m(1)][38.0%][r=36.4MiB/s,w=35.9MiB/s][r=9326,w=9200 IOPS][eta 01m:15s] Jobs: 1 (f=1): [m(1)][39.7%][r=43.4MiB/s,w=43.3MiB/s][r=11.1k,w=11.1k IOPS][eta 01m:13s] Jobs: 1 (f=1): [m(1)][41.3%][r=47.1MiB/s,w=47.1MiB/s][r=12.1k,w=12.1k IOPS][eta 01m:11s] Jobs: 1 (f=1): [m(1)][43.0%][r=47.9MiB/s,w=48.0MiB/s][r=12.3k,w=12.5k IOPS][eta 01m:09s] Jobs: 1 (f=1): [m(1)][44.6%][r=49.9MiB/s,w=48.8MiB/s][r=12.8k,w=12.5k IOPS][eta 01m:07s] Jobs: 1 (f=1): [m(1)][46.3%][r=46.4MiB/s,w=46.9MiB/s][r=11.9k,w=11.0k IOPS][eta 01m:05s] Jobs: 1 (f=1): [m(1)][47.9%][r=46.7MiB/s,w=46.4MiB/s][r=11.0k,w=11.9k IOPS][eta 01m:03s] Jobs: 1 (f=1): [m(1)][49.6%][r=55.3MiB/s,w=55.3MiB/s][r=14.1k,w=14.2k IOPS][eta 01m:01s] Jobs: 1 (f=1): [m(1)][51.2%][r=54.1MiB/s,w=53.2MiB/s][r=13.8k,w=13.6k IOPS][eta 00m:59s] Jobs: 1 (f=1): [m(1)][52.9%][r=53.4MiB/s,w=52.9MiB/s][r=13.7k,w=13.6k IOPS][eta 00m:57s] Jobs: 1 (f=1): [m(1)][54.5%][r=58.8MiB/s,w=58.0MiB/s][r=15.1k,w=15.1k IOPS][eta 00m:55s] Jobs: 1 (f=1): [m(1)][56.2%][r=60.0MiB/s,w=58.6MiB/s][r=15.4k,w=15.0k IOPS][eta 00m:53s] Jobs: 1 (f=1): [m(1)][57.9%][r=57.7MiB/s,w=58.1MiB/s][r=14.8k,w=14.9k IOPS][eta 00m:51s] Jobs: 1 (f=1): [m(1)][59.5%][r=14.0MiB/s,w=14.3MiB/s][r=3592,w=3651 IOPS][eta 00m:49s] Jobs: 1 (f=1): [m(1)][61.2%][r=17.4MiB/s,w=17.4MiB/s][r=4443,w=4457 IOPS][eta 00m:47s] Jobs: 1 (f=1): [m(1)][62.8%][r=18.1MiB/s,w=18.7MiB/s][r=4640,w=4783 IOPS][eta 00m:45s] Jobs: 1 (f=1): [m(1)][64.5%][r=7896KiB/s,w=8300KiB/s][r=1974,w=2075 IOPS][eta 00m:43s] Jobs: 1 (f=1): [m(1)][66.1%][r=47.8MiB/s,w=47.3MiB/s][r=12.2k,w=12.1k IOPS][eta 00m:41s]
-- Philip Brown| Sr. Linux System Administrator | Medata, Inc. 5 Peters Canyon Rd Suite 250 Irvine CA 92606 Office 714.918.1310| Fax 714.918.1325 pbrown@medata.com| www.medata.com _______________________________________________ ceph-users mailing list -- ceph-users@ceph.io To unsubscribe send an email to ceph-users-leave@ceph.io
-- Jason
Aha.... Insightful question! running rados bench write to the same pool, does not exhibit any problems. It consistently shows around 480M/sec throughput, every second. So this would seem to be something to do with using rbd devices. Which we need to do. For what it's worth, I'm using Micron 5200 Pro SSDs on all nodes. ----- Original Message ----- From: "Jason Dillaman" <jdillama@redhat.com> To: "Philip Brown" <pbrown@medata.com> Cc: "ceph-users" <ceph-users@ceph.io> Sent: Monday, December 14, 2020 8:33:09 AM Subject: Re: [ceph-users] performance degredation every 30 seconds On Mon, Dec 14, 2020 at 11:28 AM Philip Brown <pbrown@medata.com> wrote:
I have a new 3 node octopus cluster, set up on SSDs.
I'm running fio to benchmark the setup, with
fio --filename=/dev/rbd0 --direct=1 --rw=randrw --bs=4k --ioengine=libaio --iodepth=256 --numjobs=1 --time_based --group_reporting --name=iops-test-job --runtime=120 --eta-newline=1
However, I notice that, approximately every 30 seconds, performance tanks for a bit.
Any ideas on why, and better yet, how to get rid of the problem?
Does the same issue appear when running a direct rados bench? What brand are your SSDs (i.e. are they data center grade)?
Further experimentation with fio's -rw flag, setting to rw=read, and rw=randwrite, in addition to the original rw=randrw, indicates that it is tied to writes. Possibly some kind of buffer flush delay or cache sync delay when using rbd device, even though fio specified --direct=1 ? ----- Original Message ----- From: "Philip Brown" <pbrown@medata.com> To: "dillaman" <dillaman@redhat.com> Cc: "ceph-users" <ceph-users@ceph.io> Sent: Monday, December 14, 2020 9:01:21 AM Subject: Re: [ceph-users] performance degredation every 30 seconds Aha.... Insightful question! running rados bench write to the same pool, does not exhibit any problems. It consistently shows around 480M/sec throughput, every second. So this would seem to be something to do with using rbd devices. Which we need to do. For what it's worth, I'm using Micron 5200 Pro SSDs on all nodes. ----- Original Message ----- From: "Jason Dillaman" <jdillama@redhat.com> To: "Philip Brown" <pbrown@medata.com> Cc: "ceph-users" <ceph-users@ceph.io> Sent: Monday, December 14, 2020 8:33:09 AM Subject: Re: [ceph-users] performance degredation every 30 seconds On Mon, Dec 14, 2020 at 11:28 AM Philip Brown <pbrown@medata.com> wrote:
I have a new 3 node octopus cluster, set up on SSDs.
I'm running fio to benchmark the setup, with
fio --filename=/dev/rbd0 --direct=1 --rw=randrw --bs=4k --ioengine=libaio --iodepth=256 --numjobs=1 --time_based --group_reporting --name=iops-test-job --runtime=120 --eta-newline=1
However, I notice that, approximately every 30 seconds, performance tanks for a bit.
Any ideas on why, and better yet, how to get rid of the problem?
Does the same issue appear when running a direct rados bench? What brand are your SSDs (i.e. are they data center grade)?
On Mon, Dec 14, 2020 at 12:46 PM Philip Brown <pbrown@medata.com> wrote:
Further experimentation with fio's -rw flag, setting to rw=read, and rw=randwrite, in addition to the original rw=randrw, indicates that it is tied to writes.
Possibly some kind of buffer flush delay or cache sync delay when using rbd device, even though fio specified --direct=1 ?
It might be worthwhile testing with a more realistic io-depth instead of 256 in case you are hitting weird limits due to an untested corner case? Does the performance still degrade with "--iodepth=16" or "--iodepth=32"?
----- Original Message ----- From: "Philip Brown" <pbrown@medata.com> To: "dillaman" <dillaman@redhat.com> Cc: "ceph-users" <ceph-users@ceph.io> Sent: Monday, December 14, 2020 9:01:21 AM Subject: Re: [ceph-users] performance degredation every 30 seconds
Aha.... Insightful question! running rados bench write to the same pool, does not exhibit any problems. It consistently shows around 480M/sec throughput, every second.
So this would seem to be something to do with using rbd devices. Which we need to do.
For what it's worth, I'm using Micron 5200 Pro SSDs on all nodes.
----- Original Message ----- From: "Jason Dillaman" <jdillama@redhat.com> To: "Philip Brown" <pbrown@medata.com> Cc: "ceph-users" <ceph-users@ceph.io> Sent: Monday, December 14, 2020 8:33:09 AM Subject: Re: [ceph-users] performance degredation every 30 seconds
On Mon, Dec 14, 2020 at 11:28 AM Philip Brown <pbrown@medata.com> wrote:
I have a new 3 node octopus cluster, set up on SSDs.
I'm running fio to benchmark the setup, with
fio --filename=/dev/rbd0 --direct=1 --rw=randrw --bs=4k --ioengine=libaio --iodepth=256 --numjobs=1 --time_based --group_reporting --name=iops-test-job --runtime=120 --eta-newline=1
However, I notice that, approximately every 30 seconds, performance tanks for a bit.
Any ideas on why, and better yet, how to get rid of the problem?
Does the same issue appear when running a direct rados bench? What brand are your SSDs (i.e. are they data center grade)?
-- Jason
Our goal is to put up a high performance ceph cluster that can deal with 100 very active clients. So for us, testing with iodepth=256 is actually fairly realistic. but it does also exhibit the problem with iodepth=32 [root@irviscsi03 ~]# fio --filename=/dev/rbd0 --direct=1 --rw=randwrite --bs=4k --ioengine=libaio --iodepth=32 --numjobs=1 --time_based --group_reporting --name=iops-test-job --runtime=120 --eta-newline=1 iops-test-job: (g=0): rw=randwrite, bs=(R) 4096B-4096B, (W) 4096B-4096B, (T) 4096B-4096B, ioengine=libaio, iodepth=32 fio-3.7 Starting 1 process fio: file /dev/rbd0 exceeds 32-bit tausworthe random generator. fio: Switching to tausworthe64. Use the random_generator= option to get rid of this warning. Jobs: 1 (f=1): [w(1)][2.5%][r=0KiB/s,w=20.5MiB/s][r=0,w=5258 IOPS][eta 01m:58s] Jobs: 1 (f=1): [w(1)][4.1%][r=0KiB/s,w=41.1MiB/s][r=0,w=10.5k IOPS][eta 01m:56s] Jobs: 1 (f=1): [w(1)][5.8%][r=0KiB/s,w=45.7MiB/s][r=0,w=11.7k IOPS][eta 01m:54s] Jobs: 1 (f=1): [w(1)][7.4%][r=0KiB/s,w=55.3MiB/s][r=0,w=14.2k IOPS][eta 01m:52s] Jobs: 1 (f=1): [w(1)][9.1%][r=0KiB/s,w=54.4MiB/s][r=0,w=13.9k IOPS][eta 01m:50s] Jobs: 1 (f=1): [w(1)][10.7%][r=0KiB/s,w=53.4MiB/s][r=0,w=13.7k IOPS][eta 01m:48s] Jobs: 1 (f=1): [w(1)][12.4%][r=0KiB/s,w=53.7MiB/s][r=0,w=13.7k IOPS][eta 01m:46s] Jobs: 1 (f=1): [w(1)][14.0%][r=0KiB/s,w=55.7MiB/s][r=0,w=14.3k IOPS][eta 01m:44s] Jobs: 1 (f=1): [w(1)][15.7%][r=0KiB/s,w=54.4MiB/s][r=0,w=13.9k IOPS][eta 01m:42s] Jobs: 1 (f=1): [w(1)][17.4%][r=0KiB/s,w=51.6MiB/s][r=0,w=13.2k IOPS][eta 01m:40s] Jobs: 1 (f=1): [w(1)][19.0%][r=0KiB/s,w=38.1MiB/s][r=0,w=9748 IOPS][eta 01m:38s] Jobs: 1 (f=1): [w(1)][20.7%][r=0KiB/s,w=24.1MiB/s][r=0,w=6158 IOPS][eta 01m:36s] Jobs: 1 (f=1): [w(1)][22.3%][r=0KiB/s,w=12.4MiB/s][r=0,w=3178 IOPS][eta 01m:34s] Jobs: 1 (f=1): [w(1)][24.0%][r=0KiB/s,w=31.5MiB/s][r=0,w=8056 IOPS][eta 01m:32s] Jobs: 1 (f=1): [w(1)][25.6%][r=0KiB/s,w=48.6MiB/s][r=0,w=12.4k IOPS][eta 01m:30s] Jobs: 1 (f=1): [w(1)][27.3%][r=0KiB/s,w=52.2MiB/s][r=0,w=13.4k IOPS][eta 01m:28s] Jobs: 1 (f=1): [w(1)][28.9%][r=0KiB/s,w=54.3MiB/s][r=0,w=13.9k IOPS][eta 01m:26s] Jobs: 1 (f=1): [w(1)][30.6%][r=0KiB/s,w=52.6MiB/s][r=0,w=13.5k IOPS][eta 01m:24s] Jobs: 1 (f=1): [w(1)][32.2%][r=0KiB/s,w=55.1MiB/s][r=0,w=14.1k IOPS][eta 01m:22s] Jobs: 1 (f=1): [w(1)][33.9%][r=0KiB/s,w=34.3MiB/s][r=0,w=8775 IOPS][eta 01m:20s] Jobs: 1 (f=1): [w(1)][35.5%][r=0KiB/s,w=52.5MiB/s][r=0,w=13.4k IOPS][eta 01m:18s] Jobs: 1 (f=1): [w(1)][37.2%][r=0KiB/s,w=52.7MiB/s][r=0,w=13.5k IOPS][eta 01m:16s] Jobs: 1 (f=1): [w(1)][38.8%][r=0KiB/s,w=53.9MiB/s][r=0,w=13.8k IOPS][eta 01m:14s] .. etc. ----- Original Message ----- From: "Jason Dillaman" <jdillama@redhat.com> To: "Philip Brown" <pbrown@medata.com> Cc: "ceph-users" <ceph-users@ceph.io> Sent: Monday, December 14, 2020 10:19:48 AM Subject: Re: [ceph-users] performance degredation every 30 seconds On Mon, Dec 14, 2020 at 12:46 PM Philip Brown <pbrown@medata.com> wrote:
Further experimentation with fio's -rw flag, setting to rw=read, and rw=randwrite, in addition to the original rw=randrw, indicates that it is tied to writes.
Possibly some kind of buffer flush delay or cache sync delay when using rbd device, even though fio specified --direct=1 ?
It might be worthwhile testing with a more realistic io-depth instead of 256 in case you are hitting weird limits due to an untested corner case? Does the performance still degrade with "--iodepth=16" or "--iodepth=32"?
On Mon, Dec 14, 2020 at 1:28 PM Philip Brown <pbrown@medata.com> wrote:
Our goal is to put up a high performance ceph cluster that can deal with 100 very active clients. So for us, testing with iodepth=256 is actually fairly realistic.
100 active clients on the same node or just 100 active clients?
but it does also exhibit the problem with iodepth=32
[root@irviscsi03 ~]# fio --filename=/dev/rbd0 --direct=1 --rw=randwrite --bs=4k --ioengine=libaio --iodepth=32 --numjobs=1 --time_based --group_reporting --name=iops-test-job --runtime=120 --eta-newline=1 iops-test-job: (g=0): rw=randwrite, bs=(R) 4096B-4096B, (W) 4096B-4096B, (T) 4096B-4096B, ioengine=libaio, iodepth=32 fio-3.7 Starting 1 process fio: file /dev/rbd0 exceeds 32-bit tausworthe random generator. fio: Switching to tausworthe64. Use the random_generator= option to get rid of this warning. Jobs: 1 (f=1): [w(1)][2.5%][r=0KiB/s,w=20.5MiB/s][r=0,w=5258 IOPS][eta 01m:58s] Jobs: 1 (f=1): [w(1)][4.1%][r=0KiB/s,w=41.1MiB/s][r=0,w=10.5k IOPS][eta 01m:56s] Jobs: 1 (f=1): [w(1)][5.8%][r=0KiB/s,w=45.7MiB/s][r=0,w=11.7k IOPS][eta 01m:54s] Jobs: 1 (f=1): [w(1)][7.4%][r=0KiB/s,w=55.3MiB/s][r=0,w=14.2k IOPS][eta 01m:52s] Jobs: 1 (f=1): [w(1)][9.1%][r=0KiB/s,w=54.4MiB/s][r=0,w=13.9k IOPS][eta 01m:50s] Jobs: 1 (f=1): [w(1)][10.7%][r=0KiB/s,w=53.4MiB/s][r=0,w=13.7k IOPS][eta 01m:48s] Jobs: 1 (f=1): [w(1)][12.4%][r=0KiB/s,w=53.7MiB/s][r=0,w=13.7k IOPS][eta 01m:46s] Jobs: 1 (f=1): [w(1)][14.0%][r=0KiB/s,w=55.7MiB/s][r=0,w=14.3k IOPS][eta 01m:44s] Jobs: 1 (f=1): [w(1)][15.7%][r=0KiB/s,w=54.4MiB/s][r=0,w=13.9k IOPS][eta 01m:42s] Jobs: 1 (f=1): [w(1)][17.4%][r=0KiB/s,w=51.6MiB/s][r=0,w=13.2k IOPS][eta 01m:40s] Jobs: 1 (f=1): [w(1)][19.0%][r=0KiB/s,w=38.1MiB/s][r=0,w=9748 IOPS][eta 01m:38s] Jobs: 1 (f=1): [w(1)][20.7%][r=0KiB/s,w=24.1MiB/s][r=0,w=6158 IOPS][eta 01m:36s] Jobs: 1 (f=1): [w(1)][22.3%][r=0KiB/s,w=12.4MiB/s][r=0,w=3178 IOPS][eta 01m:34s] Jobs: 1 (f=1): [w(1)][24.0%][r=0KiB/s,w=31.5MiB/s][r=0,w=8056 IOPS][eta 01m:32s] Jobs: 1 (f=1): [w(1)][25.6%][r=0KiB/s,w=48.6MiB/s][r=0,w=12.4k IOPS][eta 01m:30s] Jobs: 1 (f=1): [w(1)][27.3%][r=0KiB/s,w=52.2MiB/s][r=0,w=13.4k IOPS][eta 01m:28s] Jobs: 1 (f=1): [w(1)][28.9%][r=0KiB/s,w=54.3MiB/s][r=0,w=13.9k IOPS][eta 01m:26s] Jobs: 1 (f=1): [w(1)][30.6%][r=0KiB/s,w=52.6MiB/s][r=0,w=13.5k IOPS][eta 01m:24s] Jobs: 1 (f=1): [w(1)][32.2%][r=0KiB/s,w=55.1MiB/s][r=0,w=14.1k IOPS][eta 01m:22s] Jobs: 1 (f=1): [w(1)][33.9%][r=0KiB/s,w=34.3MiB/s][r=0,w=8775 IOPS][eta 01m:20s] Jobs: 1 (f=1): [w(1)][35.5%][r=0KiB/s,w=52.5MiB/s][r=0,w=13.4k IOPS][eta 01m:18s] Jobs: 1 (f=1): [w(1)][37.2%][r=0KiB/s,w=52.7MiB/s][r=0,w=13.5k IOPS][eta 01m:16s] Jobs: 1 (f=1): [w(1)][38.8%][r=0KiB/s,w=53.9MiB/s][r=0,w=13.8k IOPS][eta 01m:14s]
Have you tried different kernel versions? Might also be worthwhile testing using fio's "rados" engine [1] (vs your rados bench test) since it might not have been comparing apples-to-apples given the
400MiB/s throughout you listed (i.e. large IOs are handled differently than small IOs internally).
.. etc.
----- Original Message ----- From: "Jason Dillaman" <jdillama@redhat.com> To: "Philip Brown" <pbrown@medata.com> Cc: "ceph-users" <ceph-users@ceph.io> Sent: Monday, December 14, 2020 10:19:48 AM Subject: Re: [ceph-users] performance degredation every 30 seconds
On Mon, Dec 14, 2020 at 12:46 PM Philip Brown <pbrown@medata.com> wrote:
Further experimentation with fio's -rw flag, setting to rw=read, and rw=randwrite, in addition to the original rw=randrw, indicates that it is tied to writes.
Possibly some kind of buffer flush delay or cache sync delay when using rbd device, even though fio specified --direct=1 ?
It might be worthwhile testing with a more realistic io-depth instead of 256 in case you are hitting weird limits due to an untested corner case? Does the performance still degrade with "--iodepth=16" or "--iodepth=32"?
[1] https://github.com/axboe/fio/blob/master/examples/rados.fio -- Jason
Perhaps WAL is filling up when iodepth is so high? Is WAL on the same SSDs? If you double the WAL size, does it change? On Mon, Dec 14, 2020 at 9:05 PM Jason Dillaman <jdillama@redhat.com> wrote:
On Mon, Dec 14, 2020 at 1:28 PM Philip Brown <pbrown@medata.com> wrote:
Our goal is to put up a high performance ceph cluster that can deal with 100 very active clients. So for us, testing with iodepth=256 is actually fairly realistic.
100 active clients on the same node or just 100 active clients?
but it does also exhibit the problem with iodepth=32
[root@irviscsi03 ~]# fio --filename=/dev/rbd0 --direct=1 --rw=randwrite --bs=4k --ioengine=libaio --iodepth=32 --numjobs=1 --time_based --group_reporting --name=iops-test-job --runtime=120 --eta-newline=1 iops-test-job: (g=0): rw=randwrite, bs=(R) 4096B-4096B, (W) 4096B-4096B, (T) 4096B-4096B, ioengine=libaio, iodepth=32 fio-3.7 Starting 1 process fio: file /dev/rbd0 exceeds 32-bit tausworthe random generator. fio: Switching to tausworthe64. Use the random_generator= option to get rid of this warning. Jobs: 1 (f=1): [w(1)][2.5%][r=0KiB/s,w=20.5MiB/s][r=0,w=5258 IOPS][eta 01m:58s] Jobs: 1 (f=1): [w(1)][4.1%][r=0KiB/s,w=41.1MiB/s][r=0,w=10.5k IOPS][eta 01m:56s] Jobs: 1 (f=1): [w(1)][5.8%][r=0KiB/s,w=45.7MiB/s][r=0,w=11.7k IOPS][eta 01m:54s] Jobs: 1 (f=1): [w(1)][7.4%][r=0KiB/s,w=55.3MiB/s][r=0,w=14.2k IOPS][eta 01m:52s] Jobs: 1 (f=1): [w(1)][9.1%][r=0KiB/s,w=54.4MiB/s][r=0,w=13.9k IOPS][eta 01m:50s] Jobs: 1 (f=1): [w(1)][10.7%][r=0KiB/s,w=53.4MiB/s][r=0,w=13.7k IOPS][eta 01m:48s] Jobs: 1 (f=1): [w(1)][12.4%][r=0KiB/s,w=53.7MiB/s][r=0,w=13.7k IOPS][eta 01m:46s] Jobs: 1 (f=1): [w(1)][14.0%][r=0KiB/s,w=55.7MiB/s][r=0,w=14.3k IOPS][eta 01m:44s] Jobs: 1 (f=1): [w(1)][15.7%][r=0KiB/s,w=54.4MiB/s][r=0,w=13.9k IOPS][eta 01m:42s] Jobs: 1 (f=1): [w(1)][17.4%][r=0KiB/s,w=51.6MiB/s][r=0,w=13.2k IOPS][eta 01m:40s] Jobs: 1 (f=1): [w(1)][19.0%][r=0KiB/s,w=38.1MiB/s][r=0,w=9748 IOPS][eta 01m:38s] Jobs: 1 (f=1): [w(1)][20.7%][r=0KiB/s,w=24.1MiB/s][r=0,w=6158 IOPS][eta 01m:36s] Jobs: 1 (f=1): [w(1)][22.3%][r=0KiB/s,w=12.4MiB/s][r=0,w=3178 IOPS][eta 01m:34s] Jobs: 1 (f=1): [w(1)][24.0%][r=0KiB/s,w=31.5MiB/s][r=0,w=8056 IOPS][eta 01m:32s] Jobs: 1 (f=1): [w(1)][25.6%][r=0KiB/s,w=48.6MiB/s][r=0,w=12.4k IOPS][eta 01m:30s] Jobs: 1 (f=1): [w(1)][27.3%][r=0KiB/s,w=52.2MiB/s][r=0,w=13.4k IOPS][eta 01m:28s] Jobs: 1 (f=1): [w(1)][28.9%][r=0KiB/s,w=54.3MiB/s][r=0,w=13.9k IOPS][eta 01m:26s] Jobs: 1 (f=1): [w(1)][30.6%][r=0KiB/s,w=52.6MiB/s][r=0,w=13.5k IOPS][eta 01m:24s] Jobs: 1 (f=1): [w(1)][32.2%][r=0KiB/s,w=55.1MiB/s][r=0,w=14.1k IOPS][eta 01m:22s] Jobs: 1 (f=1): [w(1)][33.9%][r=0KiB/s,w=34.3MiB/s][r=0,w=8775 IOPS][eta 01m:20s] Jobs: 1 (f=1): [w(1)][35.5%][r=0KiB/s,w=52.5MiB/s][r=0,w=13.4k IOPS][eta 01m:18s] Jobs: 1 (f=1): [w(1)][37.2%][r=0KiB/s,w=52.7MiB/s][r=0,w=13.5k IOPS][eta 01m:16s] Jobs: 1 (f=1): [w(1)][38.8%][r=0KiB/s,w=53.9MiB/s][r=0,w=13.8k IOPS][eta 01m:14s]
Have you tried different kernel versions? Might also be worthwhile testing using fio's "rados" engine [1] (vs your rados bench test) since it might not have been comparing apples-to-apples given the
400MiB/s throughout you listed (i.e. large IOs are handled differently than small IOs internally).
.. etc.
----- Original Message ----- From: "Jason Dillaman" <jdillama@redhat.com> To: "Philip Brown" <pbrown@medata.com> Cc: "ceph-users" <ceph-users@ceph.io> Sent: Monday, December 14, 2020 10:19:48 AM Subject: Re: [ceph-users] performance degredation every 30 seconds
On Mon, Dec 14, 2020 at 12:46 PM Philip Brown <pbrown@medata.com> wrote:
Further experimentation with fio's -rw flag, setting to rw=read, and rw=randwrite, in addition to the original rw=randrw, indicates that it is tied to writes.
Possibly some kind of buffer flush delay or cache sync delay when using rbd device, even though fio specified --direct=1 ?
It might be worthwhile testing with a more realistic io-depth instead of 256 in case you are hitting weird limits due to an untested corner case? Does the performance still degrade with "--iodepth=16" or "--iodepth=32"?
[1] https://github.com/axboe/fio/blob/master/examples/rados.fio
-- Jason _______________________________________________ ceph-users mailing list -- ceph-users@ceph.io To unsubscribe send an email to ceph-users-leave@ceph.io
Hi all, After reboot one node, one OSD in other node has 'slow requests' and 'currently waiting for peered' a long time util restart this OSD. Is this a bug? See the attachment for more osd log. 2020-12-11 15:39:12.837391 7f3906fa2700 0 log_channel(cluster) log [WRN] : 15 slow requests, 1 included below; oldest blocked for > 85.733762 secs 2020-12-11 15:39:12.837400 7f3906fa2700 0 log_channel(cluster) log [WRN] : slow request 30.753996 seconds old, received at 2020-12-11 15:38:42.083351: osd_op(client.105567860.0:3107598 10.d393182f (undecoded) ack+ondisk+write+known_if_redirected e101930) currently waiting for peered 2020-12-11 15:39:19.996370 7f3906fa2700 0 log_channel(cluster) log [WRN] : 16 slow requests, 1 included below; oldest blocked for > 92.892750 secs 2020-12-11 15:39:19.996379 7f3906fa2700 0 log_channel(cluster) log [WRN] : slow request 30.655350 seconds old, received at 2020-12-11 15:38:49.340985: osd_op(client.64107841.0:99173823 10.dc5382f (undecoded) ack+read+known_if_redirected e101935) currently waiting for peered 2020-12-11 15:39:20.996497 7f3906fa2700 0 log_channel(cluster) log [WRN] : 17 slow requests, 2 included below; oldest blocked for > 93.892874 secs 2020-12-11 15:39:20.996504 7f3906fa2700 0 log_channel(cluster) log [WRN] : slow request 30.812449 seconds old, received at 2020-12-11 15:38:50.184011: osd_op(client.107537847.0:661426 10.71d5b82f (undecoded) ack+ondisk+write+known_if_redirected e101936) currently waiting for peered 2020-12-11 15:39:20.996507 7f3906fa2700 0 log_channel(cluster) log [WRN] : slow request 60.055144 seconds old, received at 2020-12-11 15:38:20.941316: osd_op(client.86166236.0:644979868 10.ec1182f (undecoded) ack+read+known_if_redirected e101919) currently waiting for peered 2020-12-11 15:39:21.996663 7f3906fa2700 0 log_channel(cluster) log [WRN] : 19 slow requests, 2 included below; oldest blocked for > 94.893016 secs 2020-12-11 15:39:21.996675 7f3906fa2700 0 log_channel(cluster) log [WRN] : slow request 30.947898 seconds old, received at 2020-12-11 15:38:51.048703: osd_op(client.106338809.0:4203455 10.6b2e582f (undecoded) ack+ondisk+write+known_if_redirected e101937) currently waiting for peered 2020-12-11 15:39:21.996679 7f3906fa2700 0 log_channel(cluster) log [WRN] : slow request 30.947137 seconds old, received at 2020-12-11 15:38:51.049464: osd_op(client.106338809.0:4203456 10.6b2e582f (undecoded) ack+ondisk+write+known_if_redirected e101937) currently waiting for peered 2020-12-11 15:39:23.996900 7f3906fa2700 0 log_channel(cluster) log [WRN] : 20 slow requests, 1 included below; oldest blocked for > 96.893269 secs 2020-12-11 15:39:23.996911 7f3906fa2700 0 log_channel(cluster) log [WRN] : slow request 30.175843 seconds old, received at 2020-12-11 15:38:53.821011: osd_op(client.85915739.0:221584769 10.e221f82f (undecoded) ack+read+known_if_redirected e101938) currently waiting for peered 2020-12-11 15:39:25.997168 7f3906fa2700 0 log_channel(cluster) log [WRN] : 21 slow requests, 1 included below; oldest blocked for > 98.893549 secs 2020-12-11 15:39:25.997175 7f3906fa2700 0 log_channel(cluster) log [WRN] : slow request 30.394852 seconds old, received at 2020-12-11 15:38:55.602282: osd_op(client.85915916.0:326668357 10.97bb82f (undecoded) ack+read+known_if_redirected e101939) currently waiting for peered 2020-12-11 15:39:26.997329 7f3906fa2700 0 log_channel(cluster) log [WRN] : 21 slow requests, 1 included below; oldest blocked for > 99.893677 secs 2020-12-11 15:39:26.997341 7f3906fa2700 0 log_channel(cluster) log [WRN] : slow request 60.617348 seconds old, received at 2020-12-11 15:38:26.379914: osd_op(client.85915739.0:221580487 10.e221f82f (undecoded) ack+read+known_if_redirected e101921) currently waiting for peered 2020-12-11 15:39:28.088682 7f3906fa2700 0 log_channel(cluster) log [WRN] : 21 slow requests, 1 included below; oldest blocked for > 100.985064 secs 2020-12-11 15:39:28.088688 7f3906fa2700 0 log_channel(cluster) log [WRN] : slow request 60.916264 seconds old, received at 2020-12-11 15:38:27.172385: osd_op(client.63799264.0:171265768 10.2dabb82f (undecoded) ack+read+known_if_redirected e101922) currently waiting for peered 2020-12-11 15:39:29.088805 7f3906fa2700 0 log_channel(cluster) log [WRN] : 22 slow requests, 1 included below; oldest blocked for > 101.985181 secs 2020-12-11 15:39:29.088813 7f3906fa2700 0 log_channel(cluster) log [WRN] : slow request 30.872263 seconds old, received at 2020-12-11 15:38:58.216504: osd_op(client.99944805.0:110150263 10.8474382f (undecoded) ack+ondisk+write+known_if_redirected e101939) currently waiting for peered 2020-12-11 15:39:30.088957 7f3906fa2700 0 log_channel(cluster) log [WRN] : 23 slow requests, 2 included below; oldest blocked for > 102.985309 secs 2020-12-11 15:39:30.088965 7f3906fa2700 0 log_channel(cluster) log [WRN] : slow request 30.242255 seconds old, received at 2020-12-11 15:38:59.846639: osd_op(client.92349012.0:326975621 10.afc8f82f (undecoded) ack+read+known_if_redirected e101939) currently waiting for peered Beset Regards， LiuGangbiao
It wont be on the same node... but since as you saw, the problem still shows up with iodepth=32.... seems we're still in the same problem ball park also... there may be 100 client machines.. but each client can have anywhere between 1-30 threads running at a time. as far as fio using the rados engine as you suggested... Wouldnt that bypass /dev/rbd That would negate the whole point of benchmarking. We cant use direct rados for our actual application. We need to benchmark the performance of the end-to-end system through /dev/rbd We specifically want to use rbds, because that's how our clients will be accessing it. New information: when I drop the iodepth down to 16.. the problem still happens, but not at 30 seconds. with high iodepth, its more dependably around 30 seconds. but with iodepth=16, i've seen times between 50-60 seconds. And then the second hit is unevenly spaced. On this run it took 100 seconds more. # fio --filename=/dev/rbd0 --direct=1 --rw=randrw --bs=4k --ioengine=libaio --iodepth=16 --numjobs=1 --time_based --group_reporting --name=iops-test-job --runtime=240 --eta-newline=1 iops-test-job: (g=0): rw=randrw, bs=(R) 4096B-4096B, (W) 4096B-4096B, (T) 4096B-4096B, ioengine=libaio, iodepth=16 fio-3.7 Starting 1 process fio: file /dev/rbd0 exceeds 32-bit tausworthe random generator. fio: Switching to tausworthe64. Use the random_generator= option to get rid of this warning. Jobs: 1 (f=1): [m(1)][1.2%][r=16.6MiB/s,w=16.8MiB/s][r=4237,w=4301 IOPS][eta 03m:58s] Jobs: 1 (f=1): [m(1)][2.1%][r=17.4MiB/s,w=17.5MiB/s][r=4452,w=4471 IOPS][eta 03m:56s] Jobs: 1 (f=1): [m(1)][2.9%][r=19.2MiB/s,w=18.8MiB/s][r=4925,w=4810 IOPS][eta 03m:54s] Jobs: 1 (f=1): [m(1)][3.7%][r=18.8MiB/s,w=19.1MiB/s][r=4822,w=4886 IOPS][eta 03m:52s] Jobs: 1 (f=1): [m(1)][4.6%][r=21.6MiB/s,w=20.8MiB/s][r=5537,w=5318 IOPS][eta 03m:50s] Jobs: 1 (f=1): [m(1)][5.4%][r=22.2MiB/s,w=22.2MiB/s][r=5691,w=5695 IOPS][eta 03m:48s] Jobs: 1 (f=1): [m(1)][6.2%][r=21.4MiB/s,w=20.0MiB/s][r=5474,w=5366 IOPS][eta 03m:46s] Jobs: 1 (f=1): [m(1)][7.1%][r=22.4MiB/s,w=22.7MiB/s][r=5722,w=5819 IOPS][eta 03m:44s] Jobs: 1 (f=1): [m(1)][7.9%][r=21.2MiB/s,w=21.4MiB/s][r=5423,w=5491 IOPS][eta 03m:42s] Jobs: 1 (f=1): [m(1)][8.7%][r=21.5MiB/s,w=21.9MiB/s][r=5502,w=5603 IOPS][eta 03m:40s] Jobs: 1 (f=1): [m(1)][9.5%][r=23.3MiB/s,w=22.9MiB/s][r=5958,w=5851 IOPS][eta 03m:38s] Jobs: 1 (f=1): [m(1)][10.4%][r=22.6MiB/s,w=22.9MiB/s][r=5790,w=5853 IOPS][eta 03m:36s] Jobs: 1 (f=1): [m(1)][11.2%][r=23.3MiB/s,w=23.6MiB/s][r=5964,w=6035 IOPS][eta 03m:34s] Jobs: 1 (f=1): [m(1)][12.0%][r=20.6MiB/s,w=20.5MiB/s][r=5269,w=5243 IOPS][eta 03m:32s] Jobs: 1 (f=1): [m(1)][12.9%][r=21.1MiB/s,w=20.9MiB/s][r=5405,w=5344 IOPS][eta 03m:30s] Jobs: 1 (f=1): [m(1)][13.7%][r=21.1MiB/s,w=20.6MiB/s][r=5397,w=5273 IOPS][eta 03m:28s] Jobs: 1 (f=1): [m(1)][14.5%][r=22.2MiB/s,w=21.7MiB/s][r=5683,w=5544 IOPS][eta 03m:26s] Jobs: 1 (f=1): [m(1)][15.4%][r=21.1MiB/s,w=21.6MiB/s][r=5392,w=5525 IOPS][eta 03m:24s] Jobs: 1 (f=1): [m(1)][16.2%][r=22.2MiB/s,w=22.6MiB/s][r=5688,w=5789 IOPS][eta 03m:22s] Jobs: 1 (f=1): [m(1)][17.0%][r=22.1MiB/s,w=21.0MiB/s][r=5667,w=5630 IOPS][eta 03m:20s] Jobs: 1 (f=1): [m(1)][17.8%][r=20.6MiB/s,w=21.1MiB/s][r=5275,w=5405 IOPS][eta 03m:18s] Jobs: 1 (f=1): [m(1)][18.7%][r=22.6MiB/s,w=22.5MiB/s][r=5781,w=5754 IOPS][eta 03m:16s] Jobs: 1 (f=1): [m(1)][19.5%][r=22.0MiB/s,w=22.1MiB/s][r=5644,w=5654 IOPS][eta 03m:14s] Jobs: 1 (f=1): [m(1)][20.3%][r=21.4MiB/s,w=22.0MiB/s][r=5485,w=5642 IOPS][eta 03m:12s] Jobs: 1 (f=1): [m(1)][21.2%][r=21.8MiB/s,w=22.3MiB/s][r=5588,w=5713 IOPS][eta 03m:10s] Jobs: 1 (f=1): [m(1)][22.0%][r=24.1MiB/s,w=23.6MiB/s][r=6162,w=6030 IOPS][eta 03m:08s] Jobs: 1 (f=1): [m(1)][22.8%][r=23.2MiB/s,w=22.2MiB/s][r=5943,w=5676 IOPS][eta 03m:06s] Jobs: 1 (f=1): [m(1)][23.7%][r=23.4MiB/s,w=22.8MiB/s][r=5980,w=5848 IOPS][eta 03m:04s] Jobs: 1 (f=1): [m(1)][24.5%][r=22.8MiB/s,w=22.3MiB/s][r=5844,w=5719 IOPS][eta 03m:02s] Jobs: 1 (f=1): [m(1)][25.3%][r=23.6MiB/s,w=22.9MiB/s][r=6038,w=5865 IOPS][eta 03m:00s] Jobs: 1 (f=1): [m(1)][26.1%][r=22.7MiB/s,w=22.9MiB/s][r=5809,w=5861 IOPS][eta 02m:58s] Jobs: 1 (f=1): [m(1)][27.0%][r=14.3MiB/s,w=14.2MiB/s][r=3662,w=3644 IOPS][eta 02m:56s] Jobs: 1 (f=1): [m(1)][27.8%][r=8784KiB/s,w=8436KiB/s][r=2196,w=2109 IOPS][eta 02m:54s] Jobs: 1 (f=1): [m(1)][28.6%][r=2962KiB/s,w=3191KiB/s][r=740,w=797 IOPS][eta 02m:52s] **** Jobs: 1 (f=1): [m(1)][29.5%][r=5532KiB/s,w=6072KiB/s][r=1383,w=1518 IOPS][eta 02m:50s] Jobs: 1 (f=1): [m(1)][30.3%][r=13.5MiB/s,w=14.0MiB/s][r=3461,w=3586 IOPS][eta 02m:48s] .. .SKIP... *** Jobs: 1 (f=1): [m(1)][70.1%][r=14.1MiB/s,w=13.6MiB/s][r=3598,w=3479 IOPS][eta 01m:12s] Jobs: 1 (f=1): [m(1)][71.0%][r=6588KiB/s,w=6656KiB/s][r=1647,w=1664 IOPS][eta 01m:10s] Jobs: 1 (f=1): [m(1)][71.8%][r=3192KiB/s,w=2892KiB/s][r=798,w=723 IOPS][eta 01m:08s] Jobs: 1 (f=1): [m(1)][72.6%][r=3296KiB/s,w=3176KiB/s][r=824,w=794 IOPS][eta 01m:06s] Jobs: 1 (f=1): [m(1)][73.4%][r=2640KiB/s,w=2644KiB/s][r=660,w=661 IOPS][eta 01m:04s] Jobs: 1 (f=1): [m(1)][74.3%][r=1792KiB/s,w=2008KiB/s][r=448,w=502 IOPS][eta 01m:02s] Jobs: 1 (f=1): [m(1)][75.1%][r=12.9MiB/s,w=13.1MiB/s][r=3291,w=3351 IOPS][eta 01m:00s] Jobs: 1 (f=1): [m(1)][75.9%][r=14.9MiB/s,w=15.0MiB/s][r=3819,w=3844 IOPS][eta 00m:58s]
On Tue, Dec 15, 2020 at 12:24 PM Philip Brown <pbrown@medata.com> wrote:
It wont be on the same node... but since as you saw, the problem still shows up with iodepth=32.... seems we're still in the same problem ball park also... there may be 100 client machines.. but each client can have anywhere between 1-30 threads running at a time.
as far as fio using the rados engine as you suggested... Wouldnt that bypass /dev/rbd
That would negate the whole point of benchmarking. We cant use direct rados for our actual application. We need to benchmark the performance of the end-to-end system through /dev/rbd
Yup, that's the goal -- to better isolate the issue between a client-side vs a server-side issue. You could also use the "ioengine=rbd" to the same effect.
We specifically want to use rbds, because that's how our clients will be accessing it.
New information:
when I drop the iodepth down to 16.. the problem still happens, but not at 30 seconds. with high iodepth, its more dependably around 30 seconds. but with iodepth=16, i've seen times between 50-60 seconds. And then the second hit is unevenly spaced. On this run it took 100 seconds more.
# fio --filename=/dev/rbd0 --direct=1 --rw=randrw --bs=4k --ioengine=libaio --iodepth=16 --numjobs=1 --time_based --group_reporting --name=iops-test-job --runtime=240 --eta-newline=1 iops-test-job: (g=0): rw=randrw, bs=(R) 4096B-4096B, (W) 4096B-4096B, (T) 4096B-4096B, ioengine=libaio, iodepth=16 fio-3.7 Starting 1 process fio: file /dev/rbd0 exceeds 32-bit tausworthe random generator. fio: Switching to tausworthe64. Use the random_generator= option to get rid of this warning. Jobs: 1 (f=1): [m(1)][1.2%][r=16.6MiB/s,w=16.8MiB/s][r=4237,w=4301 IOPS][eta 03m:58s] Jobs: 1 (f=1): [m(1)][2.1%][r=17.4MiB/s,w=17.5MiB/s][r=4452,w=4471 IOPS][eta 03m:56s] Jobs: 1 (f=1): [m(1)][2.9%][r=19.2MiB/s,w=18.8MiB/s][r=4925,w=4810 IOPS][eta 03m:54s] Jobs: 1 (f=1): [m(1)][3.7%][r=18.8MiB/s,w=19.1MiB/s][r=4822,w=4886 IOPS][eta 03m:52s] Jobs: 1 (f=1): [m(1)][4.6%][r=21.6MiB/s,w=20.8MiB/s][r=5537,w=5318 IOPS][eta 03m:50s] Jobs: 1 (f=1): [m(1)][5.4%][r=22.2MiB/s,w=22.2MiB/s][r=5691,w=5695 IOPS][eta 03m:48s] Jobs: 1 (f=1): [m(1)][6.2%][r=21.4MiB/s,w=20.0MiB/s][r=5474,w=5366 IOPS][eta 03m:46s] Jobs: 1 (f=1): [m(1)][7.1%][r=22.4MiB/s,w=22.7MiB/s][r=5722,w=5819 IOPS][eta 03m:44s] Jobs: 1 (f=1): [m(1)][7.9%][r=21.2MiB/s,w=21.4MiB/s][r=5423,w=5491 IOPS][eta 03m:42s] Jobs: 1 (f=1): [m(1)][8.7%][r=21.5MiB/s,w=21.9MiB/s][r=5502,w=5603 IOPS][eta 03m:40s] Jobs: 1 (f=1): [m(1)][9.5%][r=23.3MiB/s,w=22.9MiB/s][r=5958,w=5851 IOPS][eta 03m:38s] Jobs: 1 (f=1): [m(1)][10.4%][r=22.6MiB/s,w=22.9MiB/s][r=5790,w=5853 IOPS][eta 03m:36s] Jobs: 1 (f=1): [m(1)][11.2%][r=23.3MiB/s,w=23.6MiB/s][r=5964,w=6035 IOPS][eta 03m:34s] Jobs: 1 (f=1): [m(1)][12.0%][r=20.6MiB/s,w=20.5MiB/s][r=5269,w=5243 IOPS][eta 03m:32s] Jobs: 1 (f=1): [m(1)][12.9%][r=21.1MiB/s,w=20.9MiB/s][r=5405,w=5344 IOPS][eta 03m:30s] Jobs: 1 (f=1): [m(1)][13.7%][r=21.1MiB/s,w=20.6MiB/s][r=5397,w=5273 IOPS][eta 03m:28s] Jobs: 1 (f=1): [m(1)][14.5%][r=22.2MiB/s,w=21.7MiB/s][r=5683,w=5544 IOPS][eta 03m:26s] Jobs: 1 (f=1): [m(1)][15.4%][r=21.1MiB/s,w=21.6MiB/s][r=5392,w=5525 IOPS][eta 03m:24s] Jobs: 1 (f=1): [m(1)][16.2%][r=22.2MiB/s,w=22.6MiB/s][r=5688,w=5789 IOPS][eta 03m:22s] Jobs: 1 (f=1): [m(1)][17.0%][r=22.1MiB/s,w=21.0MiB/s][r=5667,w=5630 IOPS][eta 03m:20s] Jobs: 1 (f=1): [m(1)][17.8%][r=20.6MiB/s,w=21.1MiB/s][r=5275,w=5405 IOPS][eta 03m:18s] Jobs: 1 (f=1): [m(1)][18.7%][r=22.6MiB/s,w=22.5MiB/s][r=5781,w=5754 IOPS][eta 03m:16s] Jobs: 1 (f=1): [m(1)][19.5%][r=22.0MiB/s,w=22.1MiB/s][r=5644,w=5654 IOPS][eta 03m:14s] Jobs: 1 (f=1): [m(1)][20.3%][r=21.4MiB/s,w=22.0MiB/s][r=5485,w=5642 IOPS][eta 03m:12s] Jobs: 1 (f=1): [m(1)][21.2%][r=21.8MiB/s,w=22.3MiB/s][r=5588,w=5713 IOPS][eta 03m:10s] Jobs: 1 (f=1): [m(1)][22.0%][r=24.1MiB/s,w=23.6MiB/s][r=6162,w=6030 IOPS][eta 03m:08s] Jobs: 1 (f=1): [m(1)][22.8%][r=23.2MiB/s,w=22.2MiB/s][r=5943,w=5676 IOPS][eta 03m:06s] Jobs: 1 (f=1): [m(1)][23.7%][r=23.4MiB/s,w=22.8MiB/s][r=5980,w=5848 IOPS][eta 03m:04s] Jobs: 1 (f=1): [m(1)][24.5%][r=22.8MiB/s,w=22.3MiB/s][r=5844,w=5719 IOPS][eta 03m:02s] Jobs: 1 (f=1): [m(1)][25.3%][r=23.6MiB/s,w=22.9MiB/s][r=6038,w=5865 IOPS][eta 03m:00s] Jobs: 1 (f=1): [m(1)][26.1%][r=22.7MiB/s,w=22.9MiB/s][r=5809,w=5861 IOPS][eta 02m:58s] Jobs: 1 (f=1): [m(1)][27.0%][r=14.3MiB/s,w=14.2MiB/s][r=3662,w=3644 IOPS][eta 02m:56s] Jobs: 1 (f=1): [m(1)][27.8%][r=8784KiB/s,w=8436KiB/s][r=2196,w=2109 IOPS][eta 02m:54s] Jobs: 1 (f=1): [m(1)][28.6%][r=2962KiB/s,w=3191KiB/s][r=740,w=797 IOPS][eta 02m:52s] **** Jobs: 1 (f=1): [m(1)][29.5%][r=5532KiB/s,w=6072KiB/s][r=1383,w=1518 IOPS][eta 02m:50s] Jobs: 1 (f=1): [m(1)][30.3%][r=13.5MiB/s,w=14.0MiB/s][r=3461,w=3586 IOPS][eta 02m:48s]
.. .SKIP... ***
Jobs: 1 (f=1): [m(1)][70.1%][r=14.1MiB/s,w=13.6MiB/s][r=3598,w=3479 IOPS][eta 01m:12s] Jobs: 1 (f=1): [m(1)][71.0%][r=6588KiB/s,w=6656KiB/s][r=1647,w=1664 IOPS][eta 01m:10s] Jobs: 1 (f=1): [m(1)][71.8%][r=3192KiB/s,w=2892KiB/s][r=798,w=723 IOPS][eta 01m:08s] Jobs: 1 (f=1): [m(1)][72.6%][r=3296KiB/s,w=3176KiB/s][r=824,w=794 IOPS][eta 01m:06s] Jobs: 1 (f=1): [m(1)][73.4%][r=2640KiB/s,w=2644KiB/s][r=660,w=661 IOPS][eta 01m:04s] Jobs: 1 (f=1): [m(1)][74.3%][r=1792KiB/s,w=2008KiB/s][r=448,w=502 IOPS][eta 01m:02s] Jobs: 1 (f=1): [m(1)][75.1%][r=12.9MiB/s,w=13.1MiB/s][r=3291,w=3351 IOPS][eta 01m:00s] Jobs: 1 (f=1): [m(1)][75.9%][r=14.9MiB/s,w=15.0MiB/s][r=3819,w=3844 IOPS][eta 00m:58s]
_______________________________________________ ceph-users mailing list -- ceph-users@ceph.io To unsubscribe send an email to ceph-users-leave@ceph.io
-- Jason
I did a git pull of latest fio from git://git.kernel.dk/fio.git and built with # gcc --version gcc (GCC) 7.3.1 20180303 (Red Hat 7.3.1-5) Results were as expected. Using straight rados, there were no performance hiccups. But using fio --direct=1 --rw=randwrite --bs=4k --ioengine=rbd --pool=testpool --rbdname=testrbd --iodepth=256 --numjobs=1 --time_based --group_reporting --name=iops-test-job --runtime=120 --eta-newline=1 exhibited the same behaviour, albeit slightly different timing. Jobs: 1 (f=1): [w(1)][19.0%][r=0KiB/s,w=69.7MiB/s][r=0,w=17.8k IOPS][eta 01m:38s] Jobs: 1 (f=1): [w(1)][20.7%][r=0KiB/s,w=2044KiB/s][r=0,w=511 IOPS][eta 01m:36s] Jobs: 1 (f=1): [w(1)][22.3%][r=0KiB/s,w=52.5MiB/s][r=0,w=13.4k IOPS][eta 01m:34s] .. SKIP .. Jobs: 1 (f=1): [w(1)][38.8%][r=0KiB/s,w=56.8MiB/s][r=0,w=14.5k IOPS][eta 01m:14s] Jobs: 1 (f=1): [w(1)][40.5%][r=0KiB/s,w=16.3MiB/s][r=0,w=4182 IOPS][eta 01m:12s] Jobs: 1 (f=1): [w(1)][42.1%][r=0KiB/s,w=15.6MiB/s][r=0,w=3990 IOPS][eta 01m:10s] Jobs: 1 (f=1): [w(1)][43.8%][r=0KiB/s,w=16.1MiB/s][r=0,w=4114 IOPS][eta 01m:08s] Jobs: 1 (f=1): [w(1)][45.5%][r=0KiB/s,w=11.1MiB/s][r=0,w=2853 IOPS][eta 01m:06s] Jobs: 1 (f=1): [w(1)][47.1%][r=0KiB/s,w=9793KiB/s][r=0,w=2448 IOPS][eta 01m:04s] Jobs: 1 (f=1): [w(1)][48.8%][r=0KiB/s,w=55.1MiB/s][r=0,w=14.1k IOPS][eta 01m:02s] Side note: # fio --filename=/dev/rbd0 --direct=1 --rw=randwrite --bs=4k --ioengine=rados --iodepth=128 --numjobs=1 --time_based --group_reporting --name=iops-test-job --runtime=120 --eta-newline=1 iops-test-job: (g=0): rw=randwrite, bs=(R) 4096B-4096B, (W) 4096B-4096B, (T) 4096B-4096B, ioengine=rbd, iodepth=128 fio-3.7 Starting 1 process terminate called after throwing an instance of 'std::logic_error' what(): basic_string::_S_construct null not valid Aborted (core dumped) It would be nice if it did a more user-friendly arg check, and said "you need to specify pool" instead of coredumping. ----- Original Message ----- From: "Jason Dillaman" <jdillama@redhat.com> To: "Philip Brown" <pbrown@medata.com> Cc: "ceph-users" <ceph-users@ceph.io> Sent: Tuesday, December 15, 2020 9:41:12 AM Subject: Re: [ceph-users] Re: performance degredation every 30 seconds On Tue, Dec 15, 2020 at 12:24 PM Philip Brown <pbrown@medata.com> wrote:
It wont be on the same node... but since as you saw, the problem still shows up with iodepth=32.... seems we're still in the same problem ball park also... there may be 100 client machines.. but each client can have anywhere between 1-30 threads running at a time.
as far as fio using the rados engine as you suggested... Wouldnt that bypass /dev/rbd
That would negate the whole point of benchmarking. We cant use direct rados for our actual application. We need to benchmark the performance of the end-to-end system through /dev/rbd
Yup, that's the goal -- to better isolate the issue between a client-side vs a server-side issue. You could also use the "ioengine=rbd" to the same effect.
We specifically want to use rbds, because that's how our clients will be accessing it.
New information:
when I drop the iodepth down to 16.. the problem still happens, but not at 30 seconds. with high iodepth, its more dependably around 30 seconds. but with iodepth=16, i've seen times between 50-60 seconds. And then the second hit is unevenly spaced. On this run it took 100 seconds more.
# fio --filename=/dev/rbd0 --direct=1 --rw=randrw --bs=4k --ioengine=libaio --iodepth=16 --numjobs=1 --time_based --group_reporting --name=iops-test-job --runtime=240 --eta-newline=1 iops-test-job: (g=0): rw=randrw, bs=(R) 4096B-4096B, (W) 4096B-4096B, (T) 4096B-4096B, ioengine=libaio, iodepth=16 fio-3.7 Starting 1 process fio: file /dev/rbd0 exceeds 32-bit tausworthe random generator. fio: Switching to tausworthe64. Use the random_generator= option to get rid of this warning. Jobs: 1 (f=1): [m(1)][1.2%][r=16.6MiB/s,w=16.8MiB/s][r=4237,w=4301 IOPS][eta 03m:58s] Jobs: 1 (f=1): [m(1)][2.1%][r=17.4MiB/s,w=17.5MiB/s][r=4452,w=4471 IOPS][eta 03m:56s] Jobs: 1 (f=1): [m(1)][2.9%][r=19.2MiB/s,w=18.8MiB/s][r=4925,w=4810 IOPS][eta 03m:54s] Jobs: 1 (f=1): [m(1)][3.7%][r=18.8MiB/s,w=19.1MiB/s][r=4822,w=4886 IOPS][eta 03m:52s] Jobs: 1 (f=1): [m(1)][4.6%][r=21.6MiB/s,w=20.8MiB/s][r=5537,w=5318 IOPS][eta 03m:50s] Jobs: 1 (f=1): [m(1)][5.4%][r=22.2MiB/s,w=22.2MiB/s][r=5691,w=5695 IOPS][eta 03m:48s] Jobs: 1 (f=1): [m(1)][6.2%][r=21.4MiB/s,w=20.0MiB/s][r=5474,w=5366 IOPS][eta 03m:46s] Jobs: 1 (f=1): [m(1)][7.1%][r=22.4MiB/s,w=22.7MiB/s][r=5722,w=5819 IOPS][eta 03m:44s] Jobs: 1 (f=1): [m(1)][7.9%][r=21.2MiB/s,w=21.4MiB/s][r=5423,w=5491 IOPS][eta 03m:42s] Jobs: 1 (f=1): [m(1)][8.7%][r=21.5MiB/s,w=21.9MiB/s][r=5502,w=5603 IOPS][eta 03m:40s] Jobs: 1 (f=1): [m(1)][9.5%][r=23.3MiB/s,w=22.9MiB/s][r=5958,w=5851 IOPS][eta 03m:38s] Jobs: 1 (f=1): [m(1)][10.4%][r=22.6MiB/s,w=22.9MiB/s][r=5790,w=5853 IOPS][eta 03m:36s] Jobs: 1 (f=1): [m(1)][11.2%][r=23.3MiB/s,w=23.6MiB/s][r=5964,w=6035 IOPS][eta 03m:34s] Jobs: 1 (f=1): [m(1)][12.0%][r=20.6MiB/s,w=20.5MiB/s][r=5269,w=5243 IOPS][eta 03m:32s] Jobs: 1 (f=1): [m(1)][12.9%][r=21.1MiB/s,w=20.9MiB/s][r=5405,w=5344 IOPS][eta 03m:30s] Jobs: 1 (f=1): [m(1)][13.7%][r=21.1MiB/s,w=20.6MiB/s][r=5397,w=5273 IOPS][eta 03m:28s] Jobs: 1 (f=1): [m(1)][14.5%][r=22.2MiB/s,w=21.7MiB/s][r=5683,w=5544 IOPS][eta 03m:26s] Jobs: 1 (f=1): [m(1)][15.4%][r=21.1MiB/s,w=21.6MiB/s][r=5392,w=5525 IOPS][eta 03m:24s] Jobs: 1 (f=1): [m(1)][16.2%][r=22.2MiB/s,w=22.6MiB/s][r=5688,w=5789 IOPS][eta 03m:22s] Jobs: 1 (f=1): [m(1)][17.0%][r=22.1MiB/s,w=21.0MiB/s][r=5667,w=5630 IOPS][eta 03m:20s] Jobs: 1 (f=1): [m(1)][17.8%][r=20.6MiB/s,w=21.1MiB/s][r=5275,w=5405 IOPS][eta 03m:18s] Jobs: 1 (f=1): [m(1)][18.7%][r=22.6MiB/s,w=22.5MiB/s][r=5781,w=5754 IOPS][eta 03m:16s] Jobs: 1 (f=1): [m(1)][19.5%][r=22.0MiB/s,w=22.1MiB/s][r=5644,w=5654 IOPS][eta 03m:14s] Jobs: 1 (f=1): [m(1)][20.3%][r=21.4MiB/s,w=22.0MiB/s][r=5485,w=5642 IOPS][eta 03m:12s] Jobs: 1 (f=1): [m(1)][21.2%][r=21.8MiB/s,w=22.3MiB/s][r=5588,w=5713 IOPS][eta 03m:10s] Jobs: 1 (f=1): [m(1)][22.0%][r=24.1MiB/s,w=23.6MiB/s][r=6162,w=6030 IOPS][eta 03m:08s] Jobs: 1 (f=1): [m(1)][22.8%][r=23.2MiB/s,w=22.2MiB/s][r=5943,w=5676 IOPS][eta 03m:06s] Jobs: 1 (f=1): [m(1)][23.7%][r=23.4MiB/s,w=22.8MiB/s][r=5980,w=5848 IOPS][eta 03m:04s] Jobs: 1 (f=1): [m(1)][24.5%][r=22.8MiB/s,w=22.3MiB/s][r=5844,w=5719 IOPS][eta 03m:02s] Jobs: 1 (f=1): [m(1)][25.3%][r=23.6MiB/s,w=22.9MiB/s][r=6038,w=5865 IOPS][eta 03m:00s] Jobs: 1 (f=1): [m(1)][26.1%][r=22.7MiB/s,w=22.9MiB/s][r=5809,w=5861 IOPS][eta 02m:58s] Jobs: 1 (f=1): [m(1)][27.0%][r=14.3MiB/s,w=14.2MiB/s][r=3662,w=3644 IOPS][eta 02m:56s] Jobs: 1 (f=1): [m(1)][27.8%][r=8784KiB/s,w=8436KiB/s][r=2196,w=2109 IOPS][eta 02m:54s] Jobs: 1 (f=1): [m(1)][28.6%][r=2962KiB/s,w=3191KiB/s][r=740,w=797 IOPS][eta 02m:52s] **** Jobs: 1 (f=1): [m(1)][29.5%][r=5532KiB/s,w=6072KiB/s][r=1383,w=1518 IOPS][eta 02m:50s] Jobs: 1 (f=1): [m(1)][30.3%][r=13.5MiB/s,w=14.0MiB/s][r=3461,w=3586 IOPS][eta 02m:48s]
.. .SKIP... ***
Jobs: 1 (f=1): [m(1)][70.1%][r=14.1MiB/s,w=13.6MiB/s][r=3598,w=3479 IOPS][eta 01m:12s] Jobs: 1 (f=1): [m(1)][71.0%][r=6588KiB/s,w=6656KiB/s][r=1647,w=1664 IOPS][eta 01m:10s] Jobs: 1 (f=1): [m(1)][71.8%][r=3192KiB/s,w=2892KiB/s][r=798,w=723 IOPS][eta 01m:08s] Jobs: 1 (f=1): [m(1)][72.6%][r=3296KiB/s,w=3176KiB/s][r=824,w=794 IOPS][eta 01m:06s] Jobs: 1 (f=1): [m(1)][73.4%][r=2640KiB/s,w=2644KiB/s][r=660,w=661 IOPS][eta 01m:04s] Jobs: 1 (f=1): [m(1)][74.3%][r=1792KiB/s,w=2008KiB/s][r=448,w=502 IOPS][eta 01m:02s] Jobs: 1 (f=1): [m(1)][75.1%][r=12.9MiB/s,w=13.1MiB/s][r=3291,w=3351 IOPS][eta 01m:00s] Jobs: 1 (f=1): [m(1)][75.9%][r=14.9MiB/s,w=15.0MiB/s][r=3819,w=3844 IOPS][eta 00m:58s]
_______________________________________________ ceph-users mailing list -- ceph-users@ceph.io To unsubscribe send an email to ceph-users-leave@ceph.io
-- Jason
Hi, check your rbd cache, by default it's enabled, for ssd/nvme better is to disable it. Looks like your cache/buffers are full and need flush. It could harmful your env. BR, Sebastian On 11.12.2020 19:08, Philip Brown wrote:
I have a new 3 node octopus cluster, set up on SSDs.
I'm running fio to benchmark the setup, with
fio --filename=/dev/rbd0 --direct=1 --rw=randrw --bs=4k --ioengine=libaio --iodepth=256 --numjobs=1 --time_based --group_reporting --name=iops-test-job --runtime=120 --eta-newline=1
However, I notice that, approximately every 30 seconds, performance tanks for a bit.
Any ideas on why, and better yet, how to get rid of the problem?
Sample debug output below. Notice the transitions at [eta 01m:27s] and [eta 00m:49s] It happens again at [00m:09], but figured I didnt need to redundantly post that.
Jobs: 1 (f=1): [m(1)][2.5%][r=43.4MiB/s,w=43.3MiB/s][r=11.1k,w=11.1k IOPS][eta 01m:58s] Jobs: 1 (f=1): [m(1)][4.1%][r=47.3MiB/s,w=47.8MiB/s][r=12.1k,w=12.2k IOPS][eta 01m:56s] Jobs: 1 (f=1): [m(1)][5.8%][r=48.6MiB/s,w=49.3MiB/s][r=12.5k,w=12.6k IOPS][eta 01m:54s] Jobs: 1 (f=1): [m(1)][7.4%][r=52.4MiB/s,w=53.1MiB/s][r=13.4k,w=13.6k IOPS][eta 01m:52s] Jobs: 1 (f=1): [m(1)][9.1%][r=54.7MiB/s,w=54.1MiB/s][r=13.0k,w=13.8k IOPS][eta 01m:50s] Jobs: 1 (f=1): [m(1)][10.7%][r=41.5MiB/s,w=42.6MiB/s][r=10.6k,w=10.9k IOPS][eta 01m:48s] Jobs: 1 (f=1): [m(1)][12.4%][r=51.5MiB/s,w=50.6MiB/s][r=13.2k,w=12.0k IOPS][eta 01m:46s] Jobs: 1 (f=1): [m(1)][14.0%][r=16.6MiB/s,w=16.0MiB/s][r=4248,w=4098 IOPS][eta 01m:44s] Jobs: 1 (f=1): [m(1)][14.9%][r=33.3MiB/s,w=33.5MiB/s][r=8526,w=8579 IOPS][eta 01m:43s] Jobs: 1 (f=1): [m(1)][16.5%][r=47.1MiB/s,w=47.4MiB/s][r=12.1k,w=12.1k IOPS][eta 01m:41s] Jobs: 1 (f=1): [m(1)][18.2%][r=49.6MiB/s,w=49.0MiB/s][r=12.7k,w=12.8k IOPS][eta 01m:39s] Jobs: 1 (f=1): [m(1)][19.8%][r=50.3MiB/s,w=51.4MiB/s][r=12.9k,w=13.1k IOPS][eta 01m:37s] Jobs: 1 (f=1): [m(1)][21.5%][r=53.5MiB/s,w=52.9MiB/s][r=13.7k,w=13.5k IOPS][eta 01m:35s] Jobs: 1 (f=1): [m(1)][23.1%][r=52.7MiB/s,w=52.1MiB/s][r=13.5k,w=13.3k IOPS][eta 01m:33s] Jobs: 1 (f=1): [m(1)][24.8%][r=55.3MiB/s,w=54.9MiB/s][r=14.1k,w=14.1k IOPS][eta 01m:31s] Jobs: 1 (f=1): [m(1)][26.4%][r=44.0MiB/s,w=45.2MiB/s][r=11.5k,w=11.6k IOPS][eta 01m:29s] Jobs: 1 (f=1): [m(1)][28.1%][r=12.1MiB/s,w=11.8MiB/s][r=3105,w=3011 IOPS][eta 01m:27s] Jobs: 1 (f=1): [m(1)][29.8%][r=16.6MiB/s,w=17.3MiB/s][r=4238,w=4422 IOPS][eta 01m:25s] Jobs: 1 (f=1): [m(1)][31.4%][r=9820KiB/s,w=9516KiB/s][r=2455,w=2379 IOPS][eta 01m:23s] Jobs: 1 (f=1): [m(1)][33.1%][r=6974KiB/s,w=7099KiB/s][r=1743,w=1774 IOPS][eta 01m:21s] Jobs: 1 (f=1): [m(1)][34.7%][r=49.5MiB/s,w=49.2MiB/s][r=12.7k,w=12.6k IOPS][eta 01m:19s] Jobs: 1 (f=1): [m(1)][36.4%][r=49.3MiB/s,w=49.8MiB/s][r=12.6k,w=12.8k IOPS][eta 01m:17s] Jobs: 1 (f=1): [m(1)][38.0%][r=36.4MiB/s,w=35.9MiB/s][r=9326,w=9200 IOPS][eta 01m:15s] Jobs: 1 (f=1): [m(1)][39.7%][r=43.4MiB/s,w=43.3MiB/s][r=11.1k,w=11.1k IOPS][eta 01m:13s] Jobs: 1 (f=1): [m(1)][41.3%][r=47.1MiB/s,w=47.1MiB/s][r=12.1k,w=12.1k IOPS][eta 01m:11s] Jobs: 1 (f=1): [m(1)][43.0%][r=47.9MiB/s,w=48.0MiB/s][r=12.3k,w=12.5k IOPS][eta 01m:09s] Jobs: 1 (f=1): [m(1)][44.6%][r=49.9MiB/s,w=48.8MiB/s][r=12.8k,w=12.5k IOPS][eta 01m:07s] Jobs: 1 (f=1): [m(1)][46.3%][r=46.4MiB/s,w=46.9MiB/s][r=11.9k,w=11.0k IOPS][eta 01m:05s] Jobs: 1 (f=1): [m(1)][47.9%][r=46.7MiB/s,w=46.4MiB/s][r=11.0k,w=11.9k IOPS][eta 01m:03s] Jobs: 1 (f=1): [m(1)][49.6%][r=55.3MiB/s,w=55.3MiB/s][r=14.1k,w=14.2k IOPS][eta 01m:01s] Jobs: 1 (f=1): [m(1)][51.2%][r=54.1MiB/s,w=53.2MiB/s][r=13.8k,w=13.6k IOPS][eta 00m:59s] Jobs: 1 (f=1): [m(1)][52.9%][r=53.4MiB/s,w=52.9MiB/s][r=13.7k,w=13.6k IOPS][eta 00m:57s] Jobs: 1 (f=1): [m(1)][54.5%][r=58.8MiB/s,w=58.0MiB/s][r=15.1k,w=15.1k IOPS][eta 00m:55s] Jobs: 1 (f=1): [m(1)][56.2%][r=60.0MiB/s,w=58.6MiB/s][r=15.4k,w=15.0k IOPS][eta 00m:53s] Jobs: 1 (f=1): [m(1)][57.9%][r=57.7MiB/s,w=58.1MiB/s][r=14.8k,w=14.9k IOPS][eta 00m:51s] Jobs: 1 (f=1): [m(1)][59.5%][r=14.0MiB/s,w=14.3MiB/s][r=3592,w=3651 IOPS][eta 00m:49s] Jobs: 1 (f=1): [m(1)][61.2%][r=17.4MiB/s,w=17.4MiB/s][r=4443,w=4457 IOPS][eta 00m:47s] Jobs: 1 (f=1): [m(1)][62.8%][r=18.1MiB/s,w=18.7MiB/s][r=4640,w=4783 IOPS][eta 00m:45s] Jobs: 1 (f=1): [m(1)][64.5%][r=7896KiB/s,w=8300KiB/s][r=1974,w=2075 IOPS][eta 00m:43s] Jobs: 1 (f=1): [m(1)][66.1%][r=47.8MiB/s,w=47.3MiB/s][r=12.2k,w=12.1k IOPS][eta 00m:41s]
-- Philip Brown| Sr. Linux System Administrator | Medata, Inc. 5 Peters Canyon Rd Suite 250 Irvine CA 92606 Office 714.918.1310| Fax 714.918.1325 pbrown@medata.com| www.medata.com _______________________________________________ ceph-users mailing list -- ceph-users@ceph.io To unsubscribe send an email to ceph-users-leave@ceph.io
I would think it should be something like that. However, I just tried: rbd image-meta set testpool/testrbd conf_rbd_cache false fio --direct=1 --rw=randwrite --bs=4k --ioengine=rbd --pool=testpool --rbdname=testrbd --iodepth=256 --numjobs=1 --time_based --group_reporting --name=iops-rbd-test-job --runtime=120 --eta-newline=1 but it still dipped hard, albeing with slightly more random timing. iops-rbd-test-job: (g=0): rw=randwrite, bs=(R) 4096B-4096B, (W) 4096B-4096B, (T) 4096B-4096B, ioengine=rbd, iodepth=256 fio-3.7 Starting 1 process fio: file iops-rbd-test-job.0.0 exceeds 32-bit tausworthe random generator. fio: Switching to tausworthe64. Use the random_generator= option to get rid of this warning. Jobs: 1 (f=1): [w(1)][2.5%][r=0KiB/s,w=60.6MiB/s][r=0,w=15.5k IOPS][eta 01m:58s] Jobs: 1 (f=1): [w(1)][4.1%][r=0KiB/s,w=58.0MiB/s][r=0,w=14.9k IOPS][eta 01m:56s] Jobs: 1 (f=1): [w(1)][5.8%][r=0KiB/s,w=62.8MiB/s][r=0,w=16.1k IOPS][eta 01m:54s] Jobs: 1 (f=1): [w(1)][7.4%][r=0KiB/s,w=25.6MiB/s][r=0,w=6557 IOPS][eta 01m:52s] Jobs: 1 (f=1): [w(1)][9.1%][r=0KiB/s,w=17.2MiB/s][r=0,w=4409 IOPS][eta 01m:50s] Jobs: 1 (f=1): [w(1)][10.7%][r=0KiB/s,w=19.2MiB/s][r=0,w=4921 IOPS][eta 01m:48s] Jobs: 1 (f=1): [w(1)][12.4%][r=0KiB/s,w=9829KiB/s][r=0,w=2457 IOPS][eta 01m:46s] Jobs: 1 (f=1): [w(1)][14.0%][r=0KiB/s,w=7719KiB/s][r=0,w=1929 IOPS][eta 01m:44s] Jobs: 1 (f=1): [w(1)][14.9%][r=0KiB/s,w=22.2MiB/s][r=0,w=5692 IOPS][eta 01m:43s] Jobs: 1 (f=1): [w(1)][16.5%][r=0KiB/s,w=46.7MiB/s][r=0,w=11.0k IOPS][eta 01m:41s] Jobs: 1 (f=1): [w(1)][18.2%][r=0KiB/s,w=50.8MiB/s][r=0,w=13.0k IOPS][eta 01m:39s] Jobs: 1 (f=1): [w(1)][19.8%][r=0KiB/s,w=49.7MiB/s][r=0,w=12.7k IOPS][eta 01m:37s] If there's a better way to change the value or something, please let me know. ----- Original Message ----- From: "Sebastian Trojanowski" <sebcio.t@gazeta.pl> To: "ceph-users" <ceph-users@ceph.io> Sent: Tuesday, December 15, 2020 1:34:39 AM Subject: [ceph-users] Re: performance degredation every 30 seconds Hi, check your rbd cache, by default it's enabled, for ssd/nvme better is to disable it. Looks like your cache/buffers are full and need flush. It could harmful your env. BR, Sebastian On 11.12.2020 19:08, Philip Brown wrote:
I have a new 3 node octopus cluster, set up on SSDs.
I'm running fio to benchmark the setup, with
fio --filename=/dev/rbd0 --direct=1 --rw=randrw --bs=4k --ioengine=libaio --iodepth=256 --numjobs=1 --time_based --group_reporting --name=iops-test-job --runtime=120 --eta-newline=1
However, I notice that, approximately every 30 seconds, performance tanks for a bit.
Any ideas on why, and better yet, how to get rid of the problem?
Sample debug output below. Notice the transitions at [eta 01m:27s] and [eta 00m:49s] It happens again at [00m:09], but figured I didnt need to redundantly post that.
Jobs: 1 (f=1): [m(1)][2.5%][r=43.4MiB/s,w=43.3MiB/s][r=11.1k,w=11.1k IOPS][eta 01m:58s] Jobs: 1 (f=1): [m(1)][4.1%][r=47.3MiB/s,w=47.8MiB/s][r=12.1k,w=12.2k IOPS][eta 01m:56s] Jobs: 1 (f=1): [m(1)][5.8%][r=48.6MiB/s,w=49.3MiB/s][r=12.5k,w=12.6k IOPS][eta 01m:54s] Jobs: 1 (f=1): [m(1)][7.4%][r=52.4MiB/s,w=53.1MiB/s][r=13.4k,w=13.6k IOPS][eta 01m:52s] Jobs: 1 (f=1): [m(1)][9.1%][r=54.7MiB/s,w=54.1MiB/s][r=13.0k,w=13.8k IOPS][eta 01m:50s] Jobs: 1 (f=1): [m(1)][10.7%][r=41.5MiB/s,w=42.6MiB/s][r=10.6k,w=10.9k IOPS][eta 01m:48s] Jobs: 1 (f=1): [m(1)][12.4%][r=51.5MiB/s,w=50.6MiB/s][r=13.2k,w=12.0k IOPS][eta 01m:46s] Jobs: 1 (f=1): [m(1)][14.0%][r=16.6MiB/s,w=16.0MiB/s][r=4248,w=4098 IOPS][eta 01m:44s] Jobs: 1 (f=1): [m(1)][14.9%][r=33.3MiB/s,w=33.5MiB/s][r=8526,w=8579 IOPS][eta 01m:43s] Jobs: 1 (f=1): [m(1)][16.5%][r=47.1MiB/s,w=47.4MiB/s][r=12.1k,w=12.1k IOPS][eta 01m:41s] Jobs: 1 (f=1): [m(1)][18.2%][r=49.6MiB/s,w=49.0MiB/s][r=12.7k,w=12.8k IOPS][eta 01m:39s] Jobs: 1 (f=1): [m(1)][19.8%][r=50.3MiB/s,w=51.4MiB/s][r=12.9k,w=13.1k IOPS][eta 01m:37s] Jobs: 1 (f=1): [m(1)][21.5%][r=53.5MiB/s,w=52.9MiB/s][r=13.7k,w=13.5k IOPS][eta 01m:35s] Jobs: 1 (f=1): [m(1)][23.1%][r=52.7MiB/s,w=52.1MiB/s][r=13.5k,w=13.3k IOPS][eta 01m:33s] Jobs: 1 (f=1): [m(1)][24.8%][r=55.3MiB/s,w=54.9MiB/s][r=14.1k,w=14.1k IOPS][eta 01m:31s] Jobs: 1 (f=1): [m(1)][26.4%][r=44.0MiB/s,w=45.2MiB/s][r=11.5k,w=11.6k IOPS][eta 01m:29s] Jobs: 1 (f=1): [m(1)][28.1%][r=12.1MiB/s,w=11.8MiB/s][r=3105,w=3011 IOPS][eta 01m:27s] Jobs: 1 (f=1): [m(1)][29.8%][r=16.6MiB/s,w=17.3MiB/s][r=4238,w=4422 IOPS][eta 01m:25s] Jobs: 1 (f=1): [m(1)][31.4%][r=9820KiB/s,w=9516KiB/s][r=2455,w=2379 IOPS][eta 01m:23s] Jobs: 1 (f=1): [m(1)][33.1%][r=6974KiB/s,w=7099KiB/s][r=1743,w=1774 IOPS][eta 01m:21s] Jobs: 1 (f=1): [m(1)][34.7%][r=49.5MiB/s,w=49.2MiB/s][r=12.7k,w=12.6k IOPS][eta 01m:19s] Jobs: 1 (f=1): [m(1)][36.4%][r=49.3MiB/s,w=49.8MiB/s][r=12.6k,w=12.8k IOPS][eta 01m:17s] Jobs: 1 (f=1): [m(1)][38.0%][r=36.4MiB/s,w=35.9MiB/s][r=9326,w=9200 IOPS][eta 01m:15s] Jobs: 1 (f=1): [m(1)][39.7%][r=43.4MiB/s,w=43.3MiB/s][r=11.1k,w=11.1k IOPS][eta 01m:13s] Jobs: 1 (f=1): [m(1)][41.3%][r=47.1MiB/s,w=47.1MiB/s][r=12.1k,w=12.1k IOPS][eta 01m:11s] Jobs: 1 (f=1): [m(1)][43.0%][r=47.9MiB/s,w=48.0MiB/s][r=12.3k,w=12.5k IOPS][eta 01m:09s] Jobs: 1 (f=1): [m(1)][44.6%][r=49.9MiB/s,w=48.8MiB/s][r=12.8k,w=12.5k IOPS][eta 01m:07s] Jobs: 1 (f=1): [m(1)][46.3%][r=46.4MiB/s,w=46.9MiB/s][r=11.9k,w=11.0k IOPS][eta 01m:05s] Jobs: 1 (f=1): [m(1)][47.9%][r=46.7MiB/s,w=46.4MiB/s][r=11.0k,w=11.9k IOPS][eta 01m:03s] Jobs: 1 (f=1): [m(1)][49.6%][r=55.3MiB/s,w=55.3MiB/s][r=14.1k,w=14.2k IOPS][eta 01m:01s] Jobs: 1 (f=1): [m(1)][51.2%][r=54.1MiB/s,w=53.2MiB/s][r=13.8k,w=13.6k IOPS][eta 00m:59s] Jobs: 1 (f=1): [m(1)][52.9%][r=53.4MiB/s,w=52.9MiB/s][r=13.7k,w=13.6k IOPS][eta 00m:57s] Jobs: 1 (f=1): [m(1)][54.5%][r=58.8MiB/s,w=58.0MiB/s][r=15.1k,w=15.1k IOPS][eta 00m:55s] Jobs: 1 (f=1): [m(1)][56.2%][r=60.0MiB/s,w=58.6MiB/s][r=15.4k,w=15.0k IOPS][eta 00m:53s] Jobs: 1 (f=1): [m(1)][57.9%][r=57.7MiB/s,w=58.1MiB/s][r=14.8k,w=14.9k IOPS][eta 00m:51s] Jobs: 1 (f=1): [m(1)][59.5%][r=14.0MiB/s,w=14.3MiB/s][r=3592,w=3651 IOPS][eta 00m:49s] Jobs: 1 (f=1): [m(1)][61.2%][r=17.4MiB/s,w=17.4MiB/s][r=4443,w=4457 IOPS][eta 00m:47s] Jobs: 1 (f=1): [m(1)][62.8%][r=18.1MiB/s,w=18.7MiB/s][r=4640,w=4783 IOPS][eta 00m:45s] Jobs: 1 (f=1): [m(1)][64.5%][r=7896KiB/s,w=8300KiB/s][r=1974,w=2075 IOPS][eta 00m:43s] Jobs: 1 (f=1): [m(1)][66.1%][r=47.8MiB/s,w=47.3MiB/s][r=12.2k,w=12.1k IOPS][eta 00m:41s]
-- Philip Brown| Sr. Linux System Administrator | Medata, Inc. 5 Peters Canyon Rd Suite 250 Irvine CA 92606 Office 714.918.1310| Fax 714.918.1325 pbrown@medata.com| www.medata.com _______________________________________________ ceph-users mailing list -- ceph-users@ceph.io To unsubscribe send an email to ceph-users-leave@ceph.io
_______________________________________________ ceph-users mailing list -- ceph-users@ceph.io To unsubscribe send an email to ceph-users-leave@ceph.io
btw, I also tried putting [client] rbd cache = false in the /etc/ceph/ceph.conf file on the main node, then doing systemctl stop ceph.target systemctl status ceph.target on the main node. but after restart, it tells me rbd cache is still enabled # ceph --admin-daemon /var/run/ceph/7994e544-3a5f-11eb-8a7b-9cb65496ebd0/ceph-osd.0.asok config show|grep rbd_cache "rbd_cache": "true", ....
I am happy to say, this seems to have been the solution. After running ceph config set global rbd_cache false I can now run the full 256 thread varient, fio --direct=1 --rw=randwrite --bs=4k --ioengine=libaio --filename=/dev/rbd0 --iodepth=256 --numjobs=1 --time_based --group_reporting --name=iops-test-job --runtime=120 --eta-newline=1 and there is no longer a noticeable performance dip. Thanks Sebastian ----- Original Message ----- From: "Sebastian Trojanowski" <sebcio.t@gazeta.pl> To: "ceph-users" <ceph-users@ceph.io> Sent: Tuesday, December 15, 2020 1:34:39 AM Subject: [ceph-users] Re: performance degredation every 30 seconds Hi, check your rbd cache, by default it's enabled, for ssd/nvme better is to disable it. Looks like your cache/buffers are full and need flush. It could harmful your env. BR, Sebastian
one final word of warning for everyone. while i no longer have the performance glitch.... I can no longer reproduce it. Doing ceph config set global rbd_cache true does not seem to reproduce the old behaviour. even if i do things like unmap and remap the test rbd. Which is worrying. because if I cant control the behaviour.... who is to say it wont mysteriously come back? ----- Original Message ----- From: "Philip Brown" <pbrown@medata.com> To: "Sebastian Trojanowski" <sebcio.t@gazeta.pl> Cc: "ceph-users" <ceph-users@ceph.io> Sent: Thursday, December 17, 2020 9:02:05 AM Subject: Re: [ceph-users] Re: performance degredation every 30 seconds I am happy to say, this seems to have been the solution. After running ceph config set global rbd_cache false I can now run the full 256 thread varient, fio --direct=1 --rw=randwrite --bs=4k --ioengine=libaio --filename=/dev/rbd0 --iodepth=256 --numjobs=1 --time_based --group_reporting --name=iops-test-job --runtime=120 --eta-newline=1 and there is no longer a noticeable performance dip. Thanks Sebastian
participants (5)
-
912273695＠qq.com
-
Jason Dillaman
-
Nathan Fish
-
Philip Brown
-
Sebastian Trojanowski