From: Stefan Priebe <s.priebe@profihost.ag>
To: Mark Nelson <mnelson@redhat.com>,
"ceph-devel@vger.kernel.org" <ceph-devel@vger.kernel.org>
Subject: Re: speed decrease since firefly,giant,hammer the 2nd try
Date: Mon, 16 Feb 2015 22:22:01 +0100 [thread overview]
Message-ID: <54E25F79.8030009@profihost.ag> (raw)
In-Reply-To: <54E0E82D.20007@profihost.ag>
I've now upgraded server side and client side to latest upstream/firefly.
This results in fio-rbd showing avg 26000 iop/s instead of 30500 iop/s
while running dumpling...
Greets,
Stefan
Am 15.02.2015 um 19:40 schrieb Stefan Priebe:
> Hi Mark,
>
> what's next?
>
> I've this test cluster only for 2 more days.
>
> Here some perf Details:
>
> dumpling:
> 12,65% libc-2.13.so [.] 0x79000
> 2,86% libc-2.13.so [.] malloc
> 2,80% kvm [.] 0xb59c5
> 2,59% libc-2.13.so [.] free
> 2,35% [kernel] [k] __schedule
> 2,16% [kernel] [k] _raw_spin_lock
> 1,92% [kernel] [k] __switch_to
> 1,58% [kernel] [k] lapic_next_deadline
> 1,09% [kernel] [k] update_sd_lb_stats
> 1,08% [kernel] [k] _raw_spin_lock_irqsave
> 0,91% librados.so.2.0.0 [.] ceph_crc32c_le_intel
> 0,91% libpthread-2.13.so [.] pthread_mutex_trylock
> 0,87% [kernel] [k] resched_task
> 0,72% [kernel] [k] cpu_startup_entry
> 0,71% librados.so.2.0.0 [.] crush_hash32_3
> 0,66% [kernel] [k] leave_mm
> 0,65% librados.so.2.0.0 [.] Mutex::Lock(bool)
> 0,64% [kernel] [k] idle_cpu
> 0,62% libpthread-2.13.so [.] __pthread_mutex_unlock_usercnt
> 0,59% [kernel] [k] try_to_wake_up
> 0,56% [kernel] [k] wake_futex
> 0,50% librados.so.2.0.0 [.] ceph::buffer::ptr::release()
>
> firefly:
> 12,56% libc-2.13.so [.] 0x7905d
> 2,82% libc-2.13.so [.] malloc
> 2,64% libc-2.13.so [.] free
> 2,61% kvm [.] 0x34322f
> 2,33% [kernel] [k] __schedule
> 2,14% [kernel] [k] _raw_spin_lock
> 1,83% [kernel] [k] __switch_to
> 1,62% [kernel] [k] lapic_next_deadline
> 1,17% [kernel] [k] _raw_spin_lock_irqsave
> 1,09% [kernel] [k] update_sd_lb_stats
> 1,08% libpthread-2.13.so [.] pthread_mutex_trylock
> 0,85% libpthread-2.13.so [.] __pthread_mutex_unlock_usercnt
> 0,77% [kernel] [k] resched_task
> 0,74% librbd.so.1.0.0 [.] 0x71b73
> 0,72% librados.so.2.0.0 [.] Mutex::Lock(bool)
> 0,68% librados.so.2.0.0 [.] crush_hash32_3
> 0,67% [kernel] [k] idle_cpu
> 0,65% [kernel] [k] leave_mm
> 0,65% [kernel] [k] cpu_startup_entry
> 0,59% [kernel] [k] try_to_wake_up
> 0,51% librados.so.2.0.0 [.] ceph::buffer::ptr::release()
> 0,51% [kernel] [k] wake_futex
>
> Stefan
>
> Am 11.02.2015 um 06:42 schrieb Stefan Priebe:
>>
>> Am 11.02.2015 um 05:45 schrieb Mark Nelson:
>>> On 02/10/2015 04:18 PM, Stefan Priebe wrote:
>>>>
>>>> Am 10.02.2015 um 22:38 schrieb Mark Nelson:
>>>>> On 02/10/2015 03:11 PM, Stefan Priebe wrote:
>>>>>>
>>>>>> mhm i installed librbd1-dbg and librados2-dbg - but the output still
>>>>>> looks useless to me. Should i upload it somewhere?
>>>>>
>>>>> Meh, if it's all just symbols it's probably not that helpful.
>>>>>
>>>>> I've summarized your results here:
>>>>>
>>>>> 1 concurrent 4k write (libaio, direct=1, iodepth=1)
>>>>>
>>>>> IOPS Latency
>>>>> wb on wb off wb on wb off
>>>>> dumpling 10870 536 ~100us ~2ms
>>>>> firefly 10350 525 ~100us ~2ms
>>>>>
>>>>> So in single op tests dumpling and firefly are far closer. Now let's
>>>>> see each of these cases with iodepth=32 (still 1 thread for now).
>>>>
>>>>
>>>> dumpling:
>>>>
>>>> file1: (g=0): rw=randwrite, bs=4K-4K/4K-4K, ioengine=libaio, iodepth=32
>>>> 2.0.8
>>>> Starting 1 thread
>>>> Jobs: 1 (f=1): [w] [100.0% done] [0K/72812K /s] [0 /18.3K iops] [eta
>>>> 00m:00s]
>>>> file1: (groupid=0, jobs=1): err= 0: pid=3011
>>>> write: io=2060.6MB, bw=70329KB/s, iops=17582 , runt= 30001msec
>>>> slat (usec): min=1 , max=3517 , avg= 3.42, stdev= 7.30
>>>> clat (usec): min=93 , max=7475 , avg=1815.72, stdev=233.43
>>>> lat (usec): min=219 , max=7477 , avg=1819.27, stdev=233.52
>>>> clat percentiles (usec):
>>>> | 1.00th=[ 1480], 5.00th=[ 1576], 10.00th=[ 1608], 20.00th=[
>>>> 1672],
>>>> | 30.00th=[ 1704], 40.00th=[ 1752], 50.00th=[ 1800], 60.00th=[
>>>> 1832],
>>>> | 70.00th=[ 1896], 80.00th=[ 1960], 90.00th=[ 2064], 95.00th=[
>>>> 2128],
>>>> | 99.00th=[ 2352], 99.50th=[ 2448], 99.90th=[ 4704], 99.95th=[
>>>> 5344],
>>>> | 99.99th=[ 7072]
>>>> bw (KB/s) : min=59696, max=77840, per=100.00%, avg=70351.27,
>>>> stdev=4783.25
>>>> lat (usec) : 100=0.01%, 250=0.01%, 500=0.01%, 750=0.01%,
>>>> 1000=0.53%
>>>> lat (msec) : 2=85.02%, 4=14.31%, 10=0.13%
>>>> cpu : usr=1.96%, sys=6.71%, ctx=22791, majf=0, minf=133
>>>> IO depths : 1=0.1%, 2=0.1%, 4=0.1%, 8=0.1%, 16=0.1%, 32=100.0%,
>>>> >=64=0.0%
>>>> submit : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%,
>>>> >=64=0.0%
>>>> complete : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.1%, 64=0.0%,
>>>> >=64=0.0%
>>>> issued : total=r=0/w=527487/d=0, short=r=0/w=0/d=0
>>>>
>>>> Run status group 0 (all jobs):
>>>> WRITE: io=2060.6MB, aggrb=70329KB/s, minb=70329KB/s, maxb=70329KB/s,
>>>> mint=30001msec, maxt=30001msec
>>>>
>>>> Disk stats (read/write):
>>>> sdb: ios=166/526079, merge=0/0, ticks=24/890120, in_queue=890064,
>>>> util=98.73%
>>>>
>>>> firefly:
>>>>
>>>> file1: (g=0): rw=randwrite, bs=4K-4K/4K-4K, ioengine=libaio, iodepth=32
>>>> 2.0.8
>>>> Starting 1 thread
>>>> Jobs: 1 (f=1): [w] [100.0% done] [0K/69096K /s] [0 /17.3K iops] [eta
>>>> 00m:00s]
>>>> file1: (groupid=0, jobs=1): err= 0: pid=2982
>>>> write: io=1784.9MB, bw=60918KB/s, iops=15229 , runt= 30002msec
>>>> slat (usec): min=1 , max=1389 , avg= 3.43, stdev= 5.32
>>>> clat (usec): min=117 , max=8235 , avg=2096.88, stdev=396.30
>>>> lat (usec): min=540 , max=8258 , avg=2100.43, stdev=396.61
>>>> clat percentiles (usec):
>>>> | 1.00th=[ 1608], 5.00th=[ 1720], 10.00th=[ 1768], 20.00th=[
>>>> 1832],
>>>> | 30.00th=[ 1896], 40.00th=[ 1944], 50.00th=[ 2008], 60.00th=[
>>>> 2064],
>>>> | 70.00th=[ 2160], 80.00th=[ 2256], 90.00th=[ 2512], 95.00th=[
>>>> 2896],
>>>> | 99.00th=[ 3600], 99.50th=[ 3792], 99.90th=[ 5088], 99.95th=[
>>>> 6304],
>>>> | 99.99th=[ 6752]
>>>> bw (KB/s) : min=36717, max=73712, per=99.94%, avg=60879.92,
>>>> stdev=8302.27
>>>> lat (usec) : 250=0.01%, 750=0.01%
>>>> lat (msec) : 2=48.56%, 4=51.18%, 10=0.26%
>>>> cpu : usr=2.03%, sys=5.48%, ctx=20440, majf=0, minf=133
>>>> IO depths : 1=0.1%, 2=0.1%, 4=0.1%, 8=0.1%, 16=0.1%, 32=100.0%,
>>>> >=64=0.0%
>>>> submit : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%,
>>>> >=64=0.0%
>>>> complete : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.1%, 64=0.0%,
>>>> >=64=0.0%
>>>> issued : total=r=0/w=456918/d=0, short=r=0/w=0/d=0
>>>>
>>>> Run status group 0 (all jobs):
>>>> WRITE: io=1784.9MB, aggrb=60918KB/s, minb=60918KB/s, maxb=60918KB/s,
>>>> mint=30002msec, maxt=30002msec
>>>>
>>>> Disk stats (read/write):
>>>> sdb: ios=166/455574, merge=0/0, ticks=12/897748, in_queue=897696,
>>>> util=98.96%
>>>>
>>>
>>> Ok, so it looks like as you increase concurrency the effect increases
>>> (ie contention?). Does the same thing happen without cache enabled?
>>
>> here again without rbd cache:
>>
>> dumpling:
>> file1: (g=0): rw=randwrite, bs=4K-4K/4K-4K, ioengine=libaio, iodepth=32
>> 2.0.8
>> Starting 1 thread
>> Jobs: 1 (f=1): [w] [100.0% done] [0K/83488K /s] [0 /20.9K iops] [eta
>> 00m:00s]
>> file1: (groupid=0, jobs=1): err= 0: pid=3000
>> write: io=2449.2MB, bw=83583KB/s, iops=20895 , runt= 30005msec
>> slat (usec): min=1 , max=975 , avg= 4.50, stdev= 5.25
>> clat (usec): min=364 , max=80566 , avg=1525.87, stdev=1194.57
>> lat (usec): min=519 , max=80568 , avg=1530.51, stdev=1194.44
>> clat percentiles (usec):
>> | 1.00th=[ 660], 5.00th=[ 780], 10.00th=[ 876], 20.00th=[
>> 1032],
>> | 30.00th=[ 1144], 40.00th=[ 1240], 50.00th=[ 1304], 60.00th=[
>> 1384],
>> | 70.00th=[ 1480], 80.00th=[ 1640], 90.00th=[ 2096], 95.00th=[
>> 2960],
>> | 99.00th=[ 6816], 99.50th=[ 7840], 99.90th=[11712],
>> 99.95th=[13888],
>> | 99.99th=[18816]
>> bw (KB/s) : min=47184, max=95432, per=100.00%, avg=83639.19,
>> stdev=7973.92
>> lat (usec) : 500=0.01%, 750=3.82%, 1000=14.40%
>> lat (msec) : 2=70.57%, 4=7.91%, 10=3.11%, 20=0.17%, 50=0.01%
>> lat (msec) : 100=0.01%
>> cpu : usr=3.12%, sys=11.49%, ctx=74951, majf=0, minf=133
>> IO depths : 1=0.1%, 2=0.1%, 4=0.1%, 8=0.1%, 16=0.1%, 32=100.0%,
>> >=64=0.0%
>> submit : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%,
>> >=64=0.0%
>> complete : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.1%, 64=0.0%,
>> >=64=0.0%
>> issued : total=r=0/w=626979/d=0, short=r=0/w=0/d=0
>>
>> Run status group 0 (all jobs):
>> WRITE: io=2449.2MB, aggrb=83583KB/s, minb=83583KB/s, maxb=83583KB/s,
>> mint=30005msec, maxt=30005msec
>>
>> Disk stats (read/write):
>> sdb: ios=168/625292, merge=0/0, ticks=144/916096, in_queue=916128,
>> util=99.93%
>>
>>
>> firefly:
>>
>> fio --filename=/dev/sdb --direct=1 --rw=randwrite --bs=4k --numjobs=1
>> --thread --iodepth=32 --ioengine=libaio --runtime=30 --group_reporting
>> --name=file1
>> file1: (g=0): rw=randwrite, bs=4K-4K/4K-4K, ioengine=libaio, iodepth=32
>> 2.0.8
>> Starting 1 thread
>> Jobs: 1 (f=1): [w] [100.0% done] [0K/90044K /s] [0 /22.6K iops] [eta
>> 00m:00s]
>> file1: (groupid=0, jobs=1): err= 0: pid=2970
>> write: io=2372.9MB, bw=80976KB/s, iops=20244 , runt= 30006msec
>> slat (usec): min=1 , max=4047 , avg= 4.36, stdev= 7.17
>> clat (usec): min=197 , max=76656 , avg=1575.29, stdev=1165.74
>> lat (usec): min=523 , max=76660 , avg=1579.79, stdev=1165.59
>> clat percentiles (usec):
>> | 1.00th=[ 676], 5.00th=[ 804], 10.00th=[ 916], 20.00th=[
>> 1096],
>> | 30.00th=[ 1224], 40.00th=[ 1304], 50.00th=[ 1384], 60.00th=[
>> 1448],
>> | 70.00th=[ 1544], 80.00th=[ 1704], 90.00th=[ 2128], 95.00th=[
>> 2736],
>> | 99.00th=[ 6752], 99.50th=[ 7904], 99.90th=[12096],
>> 99.95th=[14656],
>> | 99.99th=[18560]
>> bw (KB/s) : min=47800, max=91952, per=99.91%, avg=80900.88,
>> stdev=7234.98
>> lat (usec) : 250=0.01%, 500=0.01%, 750=2.95%, 1000=11.38%
>> lat (msec) : 2=73.81%, 4=8.81%, 10=2.85%, 20=0.19%, 50=0.01%
>> lat (msec) : 100=0.01%
>> cpu : usr=2.99%, sys=10.60%, ctx=66549, majf=0, minf=133
>> IO depths : 1=0.1%, 2=0.1%, 4=0.1%, 8=0.1%, 16=0.1%, 32=100.0%,
>> >=64=0.0%
>> submit : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%,
>> >=64=0.0%
>> complete : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.1%, 64=0.0%,
>> >=64=0.0%
>> issued : total=r=0/w=607445/d=0, short=r=0/w=0/d=0
>>
>> Run status group 0 (all jobs):
>> WRITE: io=2372.9MB, aggrb=80976KB/s, minb=80976KB/s, maxb=80976KB/s,
>> mint=30006msec, maxt=30006msec
>>
>> Disk stats (read/write):
>> sdb: ios=170/605440, merge=0/0, ticks=156/916492, in_queue=916560,
>> util=99.93%
>>
>> Stefan
>>
next prev parent reply other threads:[~2015-02-16 21:21 UTC|newest]
Thread overview: 32+ messages / expand[flat|nested] mbox.gz Atom feed top
2015-02-10 18:55 speed decrease since firefly,giant,hammer the 2nd try Stefan Priebe
2015-02-10 19:05 ` Gregory Farnum
2015-02-10 19:12 ` Stefan Priebe
2015-02-10 19:10 ` Mark Nelson
2015-02-10 19:13 ` Stefan Priebe
2015-02-10 19:40 ` Mark Nelson
2015-02-10 20:24 ` Stefan Priebe
2015-02-10 20:36 ` Mark Nelson
2015-02-10 21:11 ` Stefan Priebe
2015-02-10 21:38 ` Mark Nelson
2015-02-10 22:18 ` Stefan Priebe
2015-02-11 4:45 ` Mark Nelson
2015-02-11 5:42 ` Stefan Priebe
[not found] ` <1032317804.358821.1423634390142.JavaMail.zimbra@oxygem.tv>
2015-02-11 5:59 ` Alexandre DERUMIER
2015-02-15 18:40 ` Stefan Priebe
[not found] ` <1880785650.892634.1424077856500.JavaMail.zimbra@oxygem.tv>
2015-02-16 9:11 ` Alexandre DERUMIER
2015-02-16 14:50 ` Stefan Priebe - Profihost AG
2015-02-16 15:35 ` Mark Nelson
2015-02-16 15:36 ` Alexandre DERUMIER
2015-02-16 19:10 ` Stefan Priebe
[not found] ` <198700848.1004998.1424124086231.JavaMail.zimbra@oxygem.tv>
2015-02-16 22:01 ` Alexandre DERUMIER
[not found] ` <1760409866.980984.1424105112443.JavaMail.zimbra@oxygem.tv>
2015-02-16 16:45 ` Alexandre DERUMIER
2015-02-16 19:40 ` Stefan Priebe
2015-02-16 21:22 ` Stefan Priebe [this message]
[not found] ` <2015376321.1005004.1424124122884.JavaMail.zimbra@oxygem.tv>
2015-02-16 22:02 ` Alexandre DERUMIER
2015-02-16 22:08 ` Stefan Priebe - Profihost AG
[not found] ` <1975903570.1005549.1424125095286.JavaMail.zimbra@oxygem.tv>
2015-02-16 22:18 ` Alexandre DERUMIER
2015-02-17 9:15 ` Stefan Priebe - Profihost AG
[not found] ` <1999473015.1036573.1424165503094.JavaMail.zimbra@oxygem.tv>
2015-02-17 9:31 ` Alexandre DERUMIER
[not found] ` <764258391.358931.1423634637318.JavaMail.zimbra@oxygem.tv>
2015-02-11 6:04 ` Alexandre DERUMIER
[not found] ` <1971513819.362434.1423640637237.JavaMail.zimbra@oxygem.tv>
2015-02-11 7:44 ` Alexandre DERUMIER
2015-02-11 8:32 ` Stefan Priebe - Profihost AG
Reply instructions:
You may reply publicly to this message via plain-text email
using any one of the following methods:
* Save the following mbox file, import it into your mail client,
and reply-to-all from there: mbox
Avoid top-posting and favor interleaved quoting:
https://en.wikipedia.org/wiki/Posting_style#Interleaved_style
* Reply using the --to, --cc, and --in-reply-to
switches of git-send-email(1):
git send-email \
--in-reply-to=54E25F79.8030009@profihost.ag \
--to=s.priebe@profihost.ag \
--cc=ceph-devel@vger.kernel.org \
--cc=mnelson@redhat.com \
/path/to/YOUR_REPLY
https://kernel.org/pub/software/scm/git/docs/git-send-email.html
* If your mail client supports setting the In-Reply-To header
via mailto: links, try the mailto: link
Be sure your reply has a Subject: header at the top and a blank line
before the message body.
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox