extreme ceph-osd cpu load for rand. 4k write

extreme ceph-osd cpu load for rand. 4k write

[Stefan Priebe]

Hello list,

whiling benchmarking i was wondering, why the ceph-osd load is so 
extreme high while having random 4k write i/o.

Here an example while benchmarking:

random 4k write: 16.000 iop/s 180% CPU Load in top from EACH ceph-osd 
process

random 4k read: 16.000 iop/s 19% CPU Load in top from EACH ceph-osd process

seq 4M write: 800MB/s 14% CPU Load in top from EACH ceph-osd process

seq 4M read: 1600MB/s 9% CPU Load in top from EACH ceph-osd process

I can't understand why in this single case the load is so EXTREMELY high.

Greets
Stefan

Re: extreme ceph-osd cpu load for rand. 4k write

[Stefan Priebe - Profihost AG]

Is there any way to find out why a ceph-osd process takes around 10 
times more load on rand 4k writes than on 4k reads?

Stefan

Am 07.11.2012 21:41, schrieb Stefan Priebe:
> Hello list,
>
> whiling benchmarking i was wondering, why the ceph-osd load is so
> extreme high while having random 4k write i/o.
>
> Here an example while benchmarking:
>
> random 4k write: 16.000 iop/s 180% CPU Load in top from EACH ceph-osd
> process
>
> random 4k read: 16.000 iop/s 19% CPU Load in top from EACH ceph-osd process
>
> seq 4M write: 800MB/s 14% CPU Load in top from EACH ceph-osd process
>
> seq 4M read: 1600MB/s 9% CPU Load in top from EACH ceph-osd process
>
> I can't understand why in this single case the load is so EXTREMELY high.
>
> Greets
> Stefan

Re: extreme ceph-osd cpu load for rand. 4k write

[Sage Weil]

On Thu, 8 Nov 2012, Stefan Priebe - Profihost AG wrote:
> Is there any way to find out why a ceph-osd process takes around 10 times more
> load on rand 4k writes than on 4k reads?

Something like perf or oprofile is probably your best bet.  perf can be 
tedious to deploy, depending on where your kernel is coming from.  
oprofile seems to be deprecated, although I've had good results with it in 
the past.

 would love to see where the CPU is spending most of it's time.  This is 
on current master?  I expect there are still some low-hanging fruit that 
can bring CPU utilization down (or even boost iops).

sage



> 
> Stefan
> 
> Am 07.11.2012 21:41, schrieb Stefan Priebe:
> > Hello list,
> > 
> > whiling benchmarking i was wondering, why the ceph-osd load is so
> > extreme high while having random 4k write i/o.
> > 
> > Here an example while benchmarking:
> > 
> > random 4k write: 16.000 iop/s 180% CPU Load in top from EACH ceph-osd
> > process
> > 
> > random 4k read: 16.000 iop/s 19% CPU Load in top from EACH ceph-osd process
> > 
> > seq 4M write: 800MB/s 14% CPU Load in top from EACH ceph-osd process
> > 
> > seq 4M read: 1600MB/s 9% CPU Load in top from EACH ceph-osd process
> > 
> > I can't understand why in this single case the load is so EXTREMELY high.
> > 
> > Greets
> > Stefan
> --
> To unsubscribe from this list: send the line "unsubscribe ceph-devel" in
> the body of a message to majordomo@vger.kernel.org
> More majordomo info at  http://vger.kernel.org/majordomo-info.html
> 
> 

Re: extreme ceph-osd cpu load for rand. 4k write

[Stefan Priebe - Profihost AG]

Am 08.11.2012 16:01, schrieb Sage Weil:
> On Thu, 8 Nov 2012, Stefan Priebe - Profihost AG wrote:
>> Is there any way to find out why a ceph-osd process takes around 10 times more
>> load on rand 4k writes than on 4k reads?
>
> Something like perf or oprofile is probably your best bet.  perf can be
> tedious to deploy, depending on where your kernel is coming from.
> oprofile seems to be deprecated, although I've had good results with it in
> the past.

I've recorded 10s with perf - it is now a 300MB perf.data file. Sadly 
i've no idea what todo with it next.

>   would love to see where the CPU is spending most of it's time.  This is
> on current master?
Yes

>  I expect there are still some low-hanging fruit that
> can bring CPU utilization down (or even boost iops).
Would be great to find them.

Stefan

Re: extreme ceph-osd cpu load for rand. 4k write

[Mark Nelson]

On 11/08/2012 09:45 AM, Stefan Priebe - Profihost AG wrote:
> Am 08.11.2012 16:01, schrieb Sage Weil:
>> On Thu, 8 Nov 2012, Stefan Priebe - Profihost AG wrote:
>>> Is there any way to find out why a ceph-osd process takes around 10
>>> times more
>>> load on rand 4k writes than on 4k reads?
>>
>> Something like perf or oprofile is probably your best bet.  perf can be
>> tedious to deploy, depending on where your kernel is coming from.
>> oprofile seems to be deprecated, although I've had good results with
>> it in
>> the past.
>
> I've recorded 10s with perf - it is now a 300MB perf.data file. Sadly
> i've no idea what todo with it next.

Pour yourself a stiff drink! (haha!)

Try just doing a "perf report" in the directory where you've got the 
data file.  Here's a nice tutorial:

https://perf.wiki.kernel.org/index.php/Tutorial

Also, if you see missing symbols you might benefit by chowning the file 
to root and running perf report as root.  If you still see missing 
symbols, you may want to just give up and try sysprof.

>
>>   would love to see where the CPU is spending most of it's time.  This is
>> on current master?
> Yes
>
>>  I expect there are still some low-hanging fruit that
>> can bring CPU utilization down (or even boost iops).
> Would be great to find them.
>
> Stefan
> --
> To unsubscribe from this list: send the line "unsubscribe ceph-devel" in
> the body of a message to majordomo@vger.kernel.org
> More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: extreme ceph-osd cpu load for rand. 4k write

[Stefan Priebe]

[-- Attachment #1: Type: text/plain, Size: 1301 bytes --]

Am 08.11.2012 17:06, schrieb Mark Nelson:
> On 11/08/2012 09:45 AM, Stefan Priebe - Profihost AG wrote:
>> Am 08.11.2012 16:01, schrieb Sage Weil:
>>> On Thu, 8 Nov 2012, Stefan Priebe - Profihost AG wrote:
>>>> Is there any way to find out why a ceph-osd process takes around 10
>>>> times more
>>>> load on rand 4k writes than on 4k reads?
>>>
>>> Something like perf or oprofile is probably your best bet.  perf can be
>>> tedious to deploy, depending on where your kernel is coming from.
>>> oprofile seems to be deprecated, although I've had good results with
>>> it in
>>> the past.
>>
>> I've recorded 10s with perf - it is now a 300MB perf.data file. Sadly
>> i've no idea what todo with it next.
>
> Pour yourself a stiff drink! (haha!)
>
> Try just doing a "perf report" in the directory where you've got the
> data file.  Here's a nice tutorial:
>
> https://perf.wiki.kernel.org/index.php/Tutorial
>
> Also, if you see missing symbols you might benefit by chowning the file
> to root and running perf report as root.  If you still see missing
> symbols, you may want to just give up and try sysprof.

I've now used google perftools / google CPU profiler. It was the only 
tool who worked out of the box ;-)

Attached is a PDF with a profiled ceph-osd process while 4k random write.

Stefan

[-- Attachment #2: out.pdf --]
[-- Type: application/pdf, Size: 20834 bytes --]

Re: extreme ceph-osd cpu load for rand. 4k write

[Josh Durgin]

On 11/08/2012 01:27 PM, Stefan Priebe wrote:
> Am 08.11.2012 17:06, schrieb Mark Nelson:
>> On 11/08/2012 09:45 AM, Stefan Priebe - Profihost AG wrote:
>>> Am 08.11.2012 16:01, schrieb Sage Weil:
>>>> On Thu, 8 Nov 2012, Stefan Priebe - Profihost AG wrote:
>>>>> Is there any way to find out why a ceph-osd process takes around 10
>>>>> times more
>>>>> load on rand 4k writes than on 4k reads?
>>>>
>>>> Something like perf or oprofile is probably your best bet.  perf can be
>>>> tedious to deploy, depending on where your kernel is coming from.
>>>> oprofile seems to be deprecated, although I've had good results with
>>>> it in
>>>> the past.
>>>
>>> I've recorded 10s with perf - it is now a 300MB perf.data file. Sadly
>>> i've no idea what todo with it next.
>>
>> Pour yourself a stiff drink! (haha!)
>>
>> Try just doing a "perf report" in the directory where you've got the
>> data file.  Here's a nice tutorial:
>>
>> https://perf.wiki.kernel.org/index.php/Tutorial
>>
>> Also, if you see missing symbols you might benefit by chowning the file
>> to root and running perf report as root.  If you still see missing
>> symbols, you may want to just give up and try sysprof.
>
> I've now used google perftools / google CPU profiler. It was the only
> tool who worked out of the box ;-)
>
> Attached is a PDF with a profiled ceph-osd process while 4k random write.

It looks like a not insignificant portion of time is spent in the
logging infrastructure. Could you add this to the osds' configuration
to prevent any debug log gathering (it's logged/gathered):

debug lockdep = 0/0
debug context = 0/0
debug crush = 0/0
debug buffer = 0/0
debug timer = 0/0
debug journaler = 0/0
debug osd = 0/0
debug optracker = 0/0
debug objclass = 0/0
debug filestore = 0/0
debug journal = 0/0
debug ms = 0/0
debug monc = 0/0
debug tp = 0/0
debug auth = 0/0
debug finisher = 0/0
debug heartbeatmap = 0/0
debug perfcounter = 0/0
debug asok = 0/0
debug throttle = 0/0

Josh

Re: extreme ceph-osd cpu load for rand. 4k write

[Mark Nelson]

On 11/08/2012 03:50 PM, Josh Durgin wrote:
> On 11/08/2012 01:27 PM, Stefan Priebe wrote:
>> Am 08.11.2012 17:06, schrieb Mark Nelson:
>>> On 11/08/2012 09:45 AM, Stefan Priebe - Profihost AG wrote:
>>>> Am 08.11.2012 16:01, schrieb Sage Weil:
>>>>> On Thu, 8 Nov 2012, Stefan Priebe - Profihost AG wrote:
>>>>>> Is there any way to find out why a ceph-osd process takes around 10
>>>>>> times more
>>>>>> load on rand 4k writes than on 4k reads?
>>>>>
>>>>> Something like perf or oprofile is probably your best bet.  perf
>>>>> can be
>>>>> tedious to deploy, depending on where your kernel is coming from.
>>>>> oprofile seems to be deprecated, although I've had good results with
>>>>> it in
>>>>> the past.
>>>>
>>>> I've recorded 10s with perf - it is now a 300MB perf.data file. Sadly
>>>> i've no idea what todo with it next.
>>>
>>> Pour yourself a stiff drink! (haha!)
>>>
>>> Try just doing a "perf report" in the directory where you've got the
>>> data file.  Here's a nice tutorial:
>>>
>>> https://perf.wiki.kernel.org/index.php/Tutorial
>>>
>>> Also, if you see missing symbols you might benefit by chowning the file
>>> to root and running perf report as root.  If you still see missing
>>> symbols, you may want to just give up and try sysprof.
>>
>> I've now used google perftools / google CPU profiler. It was the only
>> tool who worked out of the box ;-)
>>
>> Attached is a PDF with a profiled ceph-osd process while 4k random write.
>
> It looks like a not insignificant portion of time is spent in the
> logging infrastructure. Could you add this to the osds' configuration
> to prevent any debug log gathering (it's logged/gathered):
>
> debug lockdep = 0/0
> debug context = 0/0
> debug crush = 0/0
> debug buffer = 0/0
> debug timer = 0/0
> debug journaler = 0/0
> debug osd = 0/0
> debug optracker = 0/0
> debug objclass = 0/0
> debug filestore = 0/0
> debug journal = 0/0
> debug ms = 0/0
> debug monc = 0/0
> debug tp = 0/0
> debug auth = 0/0
> debug finisher = 0/0
> debug heartbeatmap = 0/0
> debug perfcounter = 0/0
> debug asok = 0/0
> debug throttle = 0/0
>
> Josh

Also, I'm not sure what version you are running, but you may want to try 
testing master and see if that helps.  Sam has done some work on our 
threading and locking code that might help.

Re: extreme ceph-osd cpu load for rand. 4k write

[Stefan Priebe]

Am 08.11.2012 22:58, schrieb Mark Nelson:
> Also, I'm not sure what version you are running, but you may want to try
> testing master and see if that helps.  Sam has done some work on our
> threading and locking code that might help.

This is git master (two hours old).

Stefan

Re: extreme ceph-osd cpu load for rand. 4k write

[Stefan Priebe]

[-- Attachment #1: Type: text/plain, Size: 322 bytes --]

Am 08.11.2012 22:50, schrieb Josh Durgin:
> It looks like a not insignificant portion of time is spent in the
> logging infrastructure. Could you add this to the osds' configuration
> to prevent any debug log gathering (it's logged/gathered):
>
> debug lockdep = 0/0
...

> debug throttle = 0/0

New one attached.

Stefan

[-- Attachment #2: out.pdf --]
[-- Type: application/pdf, Size: 21224 bytes --]

Re: extreme ceph-osd cpu load for rand. 4k write

[Stefan Priebe - Profihost AG]

Disabling the logging with:
  debug lockdep = 0/0
  debug context = 0/0
  debug crush = 0/0
  debug buffer = 0/0
  debug timer = 0/0
  debug journaler = 0/0
  debug osd = 0/0
  debug optracker = 0/0
  debug objclass = 0/0
  debug filestore = 0/0
  debug journal = 0/0
  debug ms = 0/0
  debug monc = 0/0
  debug tp = 0/0
  debug auth = 0/0
  debug finisher = 0/0
  debug heartbeatmap = 0/0
  debug perfcounter = 0/0
  debug asok = 0/0
  debug throttle = 0/0

reduced the CPU load about 50% ! So each OSD process now takes only one 
whole 3.6Ghz core instead of two.

Have you looked at my latest profile graph with disabled debug options?

Greets,
Stefan


Am 08.11.2012 17:06, schrieb Mark Nelson:
> On 11/08/2012 09:45 AM, Stefan Priebe - Profihost AG wrote:
>> Am 08.11.2012 16:01, schrieb Sage Weil:
>>> On Thu, 8 Nov 2012, Stefan Priebe - Profihost AG wrote:
>>>> Is there any way to find out why a ceph-osd process takes around 10
>>>> times more
>>>> load on rand 4k writes than on 4k reads?
>>>
>>> Something like perf or oprofile is probably your best bet.  perf can be
>>> tedious to deploy, depending on where your kernel is coming from.
>>> oprofile seems to be deprecated, although I've had good results with
>>> it in
>>> the past.
>>
>> I've recorded 10s with perf - it is now a 300MB perf.data file. Sadly
>> i've no idea what todo with it next.
>
> Pour yourself a stiff drink! (haha!)
>
> Try just doing a "perf report" in the directory where you've got the
> data file.  Here's a nice tutorial:
>
> https://perf.wiki.kernel.org/index.php/Tutorial
>
> Also, if you see missing symbols you might benefit by chowning the file
> to root and running perf report as root.  If you still see missing
> symbols, you may want to just give up and try sysprof.
>
>>
>>>   would love to see where the CPU is spending most of it's time.
>>> This is
>>> on current master?
>> Yes
>>
>>>  I expect there are still some low-hanging fruit that
>>> can bring CPU utilization down (or even boost iops).
>> Would be great to find them.
>>
>> Stefan
>> --
>> To unsubscribe from this list: send the line "unsubscribe ceph-devel" in
>> the body of a message to majordomo@vger.kernel.org
>> More majordomo info at  http://vger.kernel.org/majordomo-info.html
>
> --
> To unsubscribe from this list: send the line "unsubscribe ceph-devel" in
> the body of a message to majordomo@vger.kernel.org
> More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: extreme ceph-osd cpu load for rand. 4k write

[Stefan Priebe - Profihost AG]

[-- Attachment #1: Type: text/plain, Size: 2890 bytes --]

New graph from today. fsetxattr seems to take a lot of CPU too.

Am 09.11.2012 11:09, schrieb Stefan Priebe - Profihost AG:
>
> Disabling the logging with:
>   debug lockdep = 0/0
>   debug context = 0/0
>   debug crush = 0/0
>   debug buffer = 0/0
>   debug timer = 0/0
>   debug journaler = 0/0
>   debug osd = 0/0
>   debug optracker = 0/0
>   debug objclass = 0/0
>   debug filestore = 0/0
>   debug journal = 0/0
>   debug ms = 0/0
>   debug monc = 0/0
>   debug tp = 0/0
>   debug auth = 0/0
>   debug finisher = 0/0
>   debug heartbeatmap = 0/0
>   debug perfcounter = 0/0
>   debug asok = 0/0
>   debug throttle = 0/0
>
> reduced the CPU load about 50% ! So each OSD process now takes only one
> whole 3.6Ghz core instead of two.
>
> Have you looked at my latest profile graph with disabled debug options?
>
> Greets,
> Stefan
>
>
> Am 08.11.2012 17:06, schrieb Mark Nelson:
>> On 11/08/2012 09:45 AM, Stefan Priebe - Profihost AG wrote:
>>> Am 08.11.2012 16:01, schrieb Sage Weil:
>>>> On Thu, 8 Nov 2012, Stefan Priebe - Profihost AG wrote:
>>>>> Is there any way to find out why a ceph-osd process takes around 10
>>>>> times more
>>>>> load on rand 4k writes than on 4k reads?
>>>>
>>>> Something like perf or oprofile is probably your best bet.  perf can be
>>>> tedious to deploy, depending on where your kernel is coming from.
>>>> oprofile seems to be deprecated, although I've had good results with
>>>> it in
>>>> the past.
>>>
>>> I've recorded 10s with perf - it is now a 300MB perf.data file. Sadly
>>> i've no idea what todo with it next.
>>
>> Pour yourself a stiff drink! (haha!)
>>
>> Try just doing a "perf report" in the directory where you've got the
>> data file.  Here's a nice tutorial:
>>
>> https://perf.wiki.kernel.org/index.php/Tutorial
>>
>> Also, if you see missing symbols you might benefit by chowning the file
>> to root and running perf report as root.  If you still see missing
>> symbols, you may want to just give up and try sysprof.
>>
>>>
>>>>   would love to see where the CPU is spending most of it's time.
>>>> This is
>>>> on current master?
>>> Yes
>>>
>>>>  I expect there are still some low-hanging fruit that
>>>> can bring CPU utilization down (or even boost iops).
>>> Would be great to find them.
>>>
>>> Stefan
>>> --
>>> To unsubscribe from this list: send the line "unsubscribe ceph-devel" in
>>> the body of a message to majordomo@vger.kernel.org
>>> More majordomo info at  http://vger.kernel.org/majordomo-info.html
>>
>> --
>> To unsubscribe from this list: send the line "unsubscribe ceph-devel" in
>> the body of a message to majordomo@vger.kernel.org
>> More majordomo info at  http://vger.kernel.org/majordomo-info.html
> --
> To unsubscribe from this list: send the line "unsubscribe ceph-devel" in
> the body of a message to majordomo@vger.kernel.org
> More majordomo info at  http://vger.kernel.org/majordomo-info.html

[-- Attachment #2: out.pdf --]
[-- Type: application/pdf, Size: 20401 bytes --]

Re: extreme ceph-osd cpu load for rand. 4k write

[Samuel Just]

Can you describe the osd and client set up (number of nodes, number of
osds per node, journal disks, replication level, and osd disks)?
Looks like a lot of time is spent looking up objects in the filestore
(lfn_open, etc).
-Sam

On Fri, Nov 9, 2012 at 2:21 AM, Stefan Priebe - Profihost AG
<s.priebe@profihost.ag> wrote:
> New graph from today. fsetxattr seems to take a lot of CPU too.
>
> Am 09.11.2012 11:09, schrieb Stefan Priebe - Profihost AG:
>
>>
>> Disabling the logging with:
>>   debug lockdep = 0/0
>>   debug context = 0/0
>>   debug crush = 0/0
>>   debug buffer = 0/0
>>   debug timer = 0/0
>>   debug journaler = 0/0
>>   debug osd = 0/0
>>   debug optracker = 0/0
>>   debug objclass = 0/0
>>   debug filestore = 0/0
>>   debug journal = 0/0
>>   debug ms = 0/0
>>   debug monc = 0/0
>>   debug tp = 0/0
>>   debug auth = 0/0
>>   debug finisher = 0/0
>>   debug heartbeatmap = 0/0
>>   debug perfcounter = 0/0
>>   debug asok = 0/0
>>   debug throttle = 0/0
>>
>> reduced the CPU load about 50% ! So each OSD process now takes only one
>> whole 3.6Ghz core instead of two.
>>
>> Have you looked at my latest profile graph with disabled debug options?
>>
>> Greets,
>> Stefan
>>
>>
>> Am 08.11.2012 17:06, schrieb Mark Nelson:
>>>
>>> On 11/08/2012 09:45 AM, Stefan Priebe - Profihost AG wrote:
>>>>
>>>> Am 08.11.2012 16:01, schrieb Sage Weil:
>>>>>
>>>>> On Thu, 8 Nov 2012, Stefan Priebe - Profihost AG wrote:
>>>>>>
>>>>>> Is there any way to find out why a ceph-osd process takes around 10
>>>>>> times more
>>>>>> load on rand 4k writes than on 4k reads?
>>>>>
>>>>>
>>>>> Something like perf or oprofile is probably your best bet.  perf can be
>>>>> tedious to deploy, depending on where your kernel is coming from.
>>>>> oprofile seems to be deprecated, although I've had good results with
>>>>> it in
>>>>> the past.
>>>>
>>>>
>>>> I've recorded 10s with perf - it is now a 300MB perf.data file. Sadly
>>>> i've no idea what todo with it next.
>>>
>>>
>>> Pour yourself a stiff drink! (haha!)
>>>
>>> Try just doing a "perf report" in the directory where you've got the
>>> data file.  Here's a nice tutorial:
>>>
>>> https://perf.wiki.kernel.org/index.php/Tutorial
>>>
>>> Also, if you see missing symbols you might benefit by chowning the file
>>> to root and running perf report as root.  If you still see missing
>>> symbols, you may want to just give up and try sysprof.
>>>
>>>>
>>>>>   would love to see where the CPU is spending most of it's time.
>>>>> This is
>>>>> on current master?
>>>>
>>>> Yes
>>>>
>>>>>  I expect there are still some low-hanging fruit that
>>>>> can bring CPU utilization down (or even boost iops).
>>>>
>>>> Would be great to find them.
>>>>
>>>> Stefan
>>>> --
>>>> To unsubscribe from this list: send the line "unsubscribe ceph-devel" in
>>>> the body of a message to majordomo@vger.kernel.org
>>>> More majordomo info at  http://vger.kernel.org/majordomo-info.html
>>>
>>>
>>> --
>>> To unsubscribe from this list: send the line "unsubscribe ceph-devel" in
>>> the body of a message to majordomo@vger.kernel.org
>>> More majordomo info at  http://vger.kernel.org/majordomo-info.html
>>
>> --
>> To unsubscribe from this list: send the line "unsubscribe ceph-devel" in
>> the body of a message to majordomo@vger.kernel.org
>> More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: extreme ceph-osd cpu load for rand. 4k write

[Stefan Priebe - Profihost AG]

Am 09.11.2012 um 22:21 schrieb Samuel Just <sam.just@inktank.com>:

> Can you describe the osd and client set up (number of nodes, number of
> osds per node, journal disks, replication level, and osd disks)?
> Looks like a lot of time is spent looking up objects in the filestore
> (lfn_open, etc).

Sure. I have 5 nodes each with 4 ssds one per osd. The graph is from one osd process. Replication level was set to two. Journal is on tmpfs.

Anything else you need to know?

Stefan

> -Sam
> 
> On Fri, Nov 9, 2012 at 2:21 AM, Stefan Priebe - Profihost AG
> <s.priebe@profihost.ag> wrote:
>> New graph from today. fsetxattr seems to take a lot of CPU too.
>> 
>> Am 09.11.2012 11:09, schrieb Stefan Priebe - Profihost AG:
>> 
>>> 
>>> Disabling the logging with:
>>>  debug lockdep = 0/0
>>>  debug context = 0/0
>>>  debug crush = 0/0
>>>  debug buffer = 0/0
>>>  debug timer = 0/0
>>>  debug journaler = 0/0
>>>  debug osd = 0/0
>>>  debug optracker = 0/0
>>>  debug objclass = 0/0
>>>  debug filestore = 0/0
>>>  debug journal = 0/0
>>>  debug ms = 0/0
>>>  debug monc = 0/0
>>>  debug tp = 0/0
>>>  debug auth = 0/0
>>>  debug finisher = 0/0
>>>  debug heartbeatmap = 0/0
>>>  debug perfcounter = 0/0
>>>  debug asok = 0/0
>>>  debug throttle = 0/0
>>> 
>>> reduced the CPU load about 50% ! So each OSD process now takes only one
>>> whole 3.6Ghz core instead of two.
>>> 
>>> Have you looked at my latest profile graph with disabled debug options?
>>> 
>>> Greets,
>>> Stefan
>>> 
>>> 
>>> Am 08.11.2012 17:06, schrieb Mark Nelson:
>>>> 
>>>> On 11/08/2012 09:45 AM, Stefan Priebe - Profihost AG wrote:
>>>>> 
>>>>> Am 08.11.2012 16:01, schrieb Sage Weil:
>>>>>> 
>>>>>> On Thu, 8 Nov 2012, Stefan Priebe - Profihost AG wrote:
>>>>>>> 
>>>>>>> Is there any way to find out why a ceph-osd process takes around 10
>>>>>>> times more
>>>>>>> load on rand 4k writes than on 4k reads?
>>>>>> 
>>>>>> 
>>>>>> Something like perf or oprofile is probably your best bet.  perf can be
>>>>>> tedious to deploy, depending on where your kernel is coming from.
>>>>>> oprofile seems to be deprecated, although I've had good results with
>>>>>> it in
>>>>>> the past.
>>>>> 
>>>>> 
>>>>> I've recorded 10s with perf - it is now a 300MB perf.data file. Sadly
>>>>> i've no idea what todo with it next.
>>>> 
>>>> 
>>>> Pour yourself a stiff drink! (haha!)
>>>> 
>>>> Try just doing a "perf report" in the directory where you've got the
>>>> data file.  Here's a nice tutorial:
>>>> 
>>>> https://perf.wiki.kernel.org/index.php/Tutorial
>>>> 
>>>> Also, if you see missing symbols you might benefit by chowning the file
>>>> to root and running perf report as root.  If you still see missing
>>>> symbols, you may want to just give up and try sysprof.
>>>> 
>>>>> 
>>>>>>  would love to see where the CPU is spending most of it's time.
>>>>>> This is
>>>>>> on current master?
>>>>> 
>>>>> Yes
>>>>> 
>>>>>> I expect there are still some low-hanging fruit that
>>>>>> can bring CPU utilization down (or even boost iops).
>>>>> 
>>>>> Would be great to find them.
>>>>> 
>>>>> Stefan
>>>>> --
>>>>> To unsubscribe from this list: send the line "unsubscribe ceph-devel" in
>>>>> the body of a message to majordomo@vger.kernel.org
>>>>> More majordomo info at  http://vger.kernel.org/majordomo-info.html
>>>> 
>>>> 
>>>> --
>>>> To unsubscribe from this list: send the line "unsubscribe ceph-devel" in
>>>> the body of a message to majordomo@vger.kernel.org
>>>> More majordomo info at  http://vger.kernel.org/majordomo-info.html
>>> 
>>> --
>>> To unsubscribe from this list: send the line "unsubscribe ceph-devel" in
>>> the body of a message to majordomo@vger.kernel.org
>>> More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: extreme ceph-osd cpu load for rand. 4k write

[Samuel Just]

How did you obtain those numbers?  Were the 8k and 16k numbers per
osd, or the raw throughput of 1 client?
-Sam

On Fri, Nov 9, 2012 at 1:34 PM, Stefan Priebe - Profihost AG
<s.priebe@profihost.ag> wrote:
> Am 09.11.2012 um 22:21 schrieb Samuel Just <sam.just@inktank.com>:
>
>> Can you describe the osd and client set up (number of nodes, number of
>> osds per node, journal disks, replication level, and osd disks)?
>> Looks like a lot of time is spent looking up objects in the filestore
>> (lfn_open, etc).
>
> Sure. I have 5 nodes each with 4 ssds one per osd. The graph is from one osd process. Replication level was set to two. Journal is on tmpfs.
>
> Anything else you need to know?
>
> Stefan
>
>> -Sam
>>
>> On Fri, Nov 9, 2012 at 2:21 AM, Stefan Priebe - Profihost AG
>> <s.priebe@profihost.ag> wrote:
>>> New graph from today. fsetxattr seems to take a lot of CPU too.
>>>
>>> Am 09.11.2012 11:09, schrieb Stefan Priebe - Profihost AG:
>>>
>>>>
>>>> Disabling the logging with:
>>>>  debug lockdep = 0/0
>>>>  debug context = 0/0
>>>>  debug crush = 0/0
>>>>  debug buffer = 0/0
>>>>  debug timer = 0/0
>>>>  debug journaler = 0/0
>>>>  debug osd = 0/0
>>>>  debug optracker = 0/0
>>>>  debug objclass = 0/0
>>>>  debug filestore = 0/0
>>>>  debug journal = 0/0
>>>>  debug ms = 0/0
>>>>  debug monc = 0/0
>>>>  debug tp = 0/0
>>>>  debug auth = 0/0
>>>>  debug finisher = 0/0
>>>>  debug heartbeatmap = 0/0
>>>>  debug perfcounter = 0/0
>>>>  debug asok = 0/0
>>>>  debug throttle = 0/0
>>>>
>>>> reduced the CPU load about 50% ! So each OSD process now takes only one
>>>> whole 3.6Ghz core instead of two.
>>>>
>>>> Have you looked at my latest profile graph with disabled debug options?
>>>>
>>>> Greets,
>>>> Stefan
>>>>
>>>>
>>>> Am 08.11.2012 17:06, schrieb Mark Nelson:
>>>>>
>>>>> On 11/08/2012 09:45 AM, Stefan Priebe - Profihost AG wrote:
>>>>>>
>>>>>> Am 08.11.2012 16:01, schrieb Sage Weil:
>>>>>>>
>>>>>>> On Thu, 8 Nov 2012, Stefan Priebe - Profihost AG wrote:
>>>>>>>>
>>>>>>>> Is there any way to find out why a ceph-osd process takes around 10
>>>>>>>> times more
>>>>>>>> load on rand 4k writes than on 4k reads?
>>>>>>>
>>>>>>>
>>>>>>> Something like perf or oprofile is probably your best bet.  perf can be
>>>>>>> tedious to deploy, depending on where your kernel is coming from.
>>>>>>> oprofile seems to be deprecated, although I've had good results with
>>>>>>> it in
>>>>>>> the past.
>>>>>>
>>>>>>
>>>>>> I've recorded 10s with perf - it is now a 300MB perf.data file. Sadly
>>>>>> i've no idea what todo with it next.
>>>>>
>>>>>
>>>>> Pour yourself a stiff drink! (haha!)
>>>>>
>>>>> Try just doing a "perf report" in the directory where you've got the
>>>>> data file.  Here's a nice tutorial:
>>>>>
>>>>> https://perf.wiki.kernel.org/index.php/Tutorial
>>>>>
>>>>> Also, if you see missing symbols you might benefit by chowning the file
>>>>> to root and running perf report as root.  If you still see missing
>>>>> symbols, you may want to just give up and try sysprof.
>>>>>
>>>>>>
>>>>>>>  would love to see where the CPU is spending most of it's time.
>>>>>>> This is
>>>>>>> on current master?
>>>>>>
>>>>>> Yes
>>>>>>
>>>>>>> I expect there are still some low-hanging fruit that
>>>>>>> can bring CPU utilization down (or even boost iops).
>>>>>>
>>>>>> Would be great to find them.
>>>>>>
>>>>>> Stefan
>>>>>> --
>>>>>> To unsubscribe from this list: send the line "unsubscribe ceph-devel" in
>>>>>> the body of a message to majordomo@vger.kernel.org
>>>>>> More majordomo info at  http://vger.kernel.org/majordomo-info.html
>>>>>
>>>>>
>>>>> --
>>>>> To unsubscribe from this list: send the line "unsubscribe ceph-devel" in
>>>>> the body of a message to majordomo@vger.kernel.org
>>>>> More majordomo info at  http://vger.kernel.org/majordomo-info.html
>>>>
>>>> --
>>>> To unsubscribe from this list: send the line "unsubscribe ceph-devel" in
>>>> the body of a message to majordomo@vger.kernel.org
>>>> More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: extreme ceph-osd cpu load for rand. 4k write

[Samuel Just]

How are the 4 ssds per osd set up?  RAID 5?
-Sam

On Sat, Nov 10, 2012 at 12:36 PM, Samuel Just <sam.just@inktank.com> wrote:
> How did you obtain those numbers?  Were the 8k and 16k numbers per
> osd, or the raw throughput of 1 client?
> -Sam
>
> On Fri, Nov 9, 2012 at 1:34 PM, Stefan Priebe - Profihost AG
> <s.priebe@profihost.ag> wrote:
>> Am 09.11.2012 um 22:21 schrieb Samuel Just <sam.just@inktank.com>:
>>
>>> Can you describe the osd and client set up (number of nodes, number of
>>> osds per node, journal disks, replication level, and osd disks)?
>>> Looks like a lot of time is spent looking up objects in the filestore
>>> (lfn_open, etc).
>>
>> Sure. I have 5 nodes each with 4 ssds one per osd. The graph is from one osd process. Replication level was set to two. Journal is on tmpfs.
>>
>> Anything else you need to know?
>>
>> Stefan
>>
>>> -Sam
>>>
>>> On Fri, Nov 9, 2012 at 2:21 AM, Stefan Priebe - Profihost AG
>>> <s.priebe@profihost.ag> wrote:
>>>> New graph from today. fsetxattr seems to take a lot of CPU too.
>>>>
>>>> Am 09.11.2012 11:09, schrieb Stefan Priebe - Profihost AG:
>>>>
>>>>>
>>>>> Disabling the logging with:
>>>>>  debug lockdep = 0/0
>>>>>  debug context = 0/0
>>>>>  debug crush = 0/0
>>>>>  debug buffer = 0/0
>>>>>  debug timer = 0/0
>>>>>  debug journaler = 0/0
>>>>>  debug osd = 0/0
>>>>>  debug optracker = 0/0
>>>>>  debug objclass = 0/0
>>>>>  debug filestore = 0/0
>>>>>  debug journal = 0/0
>>>>>  debug ms = 0/0
>>>>>  debug monc = 0/0
>>>>>  debug tp = 0/0
>>>>>  debug auth = 0/0
>>>>>  debug finisher = 0/0
>>>>>  debug heartbeatmap = 0/0
>>>>>  debug perfcounter = 0/0
>>>>>  debug asok = 0/0
>>>>>  debug throttle = 0/0
>>>>>
>>>>> reduced the CPU load about 50% ! So each OSD process now takes only one
>>>>> whole 3.6Ghz core instead of two.
>>>>>
>>>>> Have you looked at my latest profile graph with disabled debug options?
>>>>>
>>>>> Greets,
>>>>> Stefan
>>>>>
>>>>>
>>>>> Am 08.11.2012 17:06, schrieb Mark Nelson:
>>>>>>
>>>>>> On 11/08/2012 09:45 AM, Stefan Priebe - Profihost AG wrote:
>>>>>>>
>>>>>>> Am 08.11.2012 16:01, schrieb Sage Weil:
>>>>>>>>
>>>>>>>> On Thu, 8 Nov 2012, Stefan Priebe - Profihost AG wrote:
>>>>>>>>>
>>>>>>>>> Is there any way to find out why a ceph-osd process takes around 10
>>>>>>>>> times more
>>>>>>>>> load on rand 4k writes than on 4k reads?
>>>>>>>>
>>>>>>>>
>>>>>>>> Something like perf or oprofile is probably your best bet.  perf can be
>>>>>>>> tedious to deploy, depending on where your kernel is coming from.
>>>>>>>> oprofile seems to be deprecated, although I've had good results with
>>>>>>>> it in
>>>>>>>> the past.
>>>>>>>
>>>>>>>
>>>>>>> I've recorded 10s with perf - it is now a 300MB perf.data file. Sadly
>>>>>>> i've no idea what todo with it next.
>>>>>>
>>>>>>
>>>>>> Pour yourself a stiff drink! (haha!)
>>>>>>
>>>>>> Try just doing a "perf report" in the directory where you've got the
>>>>>> data file.  Here's a nice tutorial:
>>>>>>
>>>>>> https://perf.wiki.kernel.org/index.php/Tutorial
>>>>>>
>>>>>> Also, if you see missing symbols you might benefit by chowning the file
>>>>>> to root and running perf report as root.  If you still see missing
>>>>>> symbols, you may want to just give up and try sysprof.
>>>>>>
>>>>>>>
>>>>>>>>  would love to see where the CPU is spending most of it's time.
>>>>>>>> This is
>>>>>>>> on current master?
>>>>>>>
>>>>>>> Yes
>>>>>>>
>>>>>>>> I expect there are still some low-hanging fruit that
>>>>>>>> can bring CPU utilization down (or even boost iops).
>>>>>>>
>>>>>>> Would be great to find them.
>>>>>>>
>>>>>>> Stefan
>>>>>>> --
>>>>>>> To unsubscribe from this list: send the line "unsubscribe ceph-devel" in
>>>>>>> the body of a message to majordomo@vger.kernel.org
>>>>>>> More majordomo info at  http://vger.kernel.org/majordomo-info.html
>>>>>>
>>>>>>
>>>>>> --
>>>>>> To unsubscribe from this list: send the line "unsubscribe ceph-devel" in
>>>>>> the body of a message to majordomo@vger.kernel.org
>>>>>> More majordomo info at  http://vger.kernel.org/majordomo-info.html
>>>>>
>>>>> --
>>>>> To unsubscribe from this list: send the line "unsubscribe ceph-devel" in
>>>>> the body of a message to majordomo@vger.kernel.org
>>>>> More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: extreme ceph-osd cpu load for rand. 4k write

[Stefan Priebe]

Am 10.11.2012 21:37, schrieb Samuel Just:
> How are the 4 ssds per osd set up?  RAID 5?

no, one ssd per osd like suggested by inktank.

Greets Stefan

Re: extreme ceph-osd cpu load for rand. 4k write

[Stefan Priebe]

Am 10.11.2012 21:36, schrieb Samuel Just:
> How did you obtain those numbers?  Were the 8k and 16k numbers per
> osd, or the raw throughput of 1 client?

That's the raw throughput of 1 client.

Stefan

Re: extreme ceph-osd cpu load for rand. 4k write

[Mark Nelson]

Hi Stefan,

You might want to try running sysprof or perf while the OSDs are running 
during the tests and see where CPU time is being spent.  Also, how are 
you determining how much CPU usage is being used?

Mark

On 11/08/2012 08:58 AM, Stefan Priebe - Profihost AG wrote:
> Is there any way to find out why a ceph-osd process takes around 10
> times more load on rand 4k writes than on 4k reads?
>
> Stefan
>
> Am 07.11.2012 21:41, schrieb Stefan Priebe:
>> Hello list,
>>
>> whiling benchmarking i was wondering, why the ceph-osd load is so
>> extreme high while having random 4k write i/o.
>>
>> Here an example while benchmarking:
>>
>> random 4k write: 16.000 iop/s 180% CPU Load in top from EACH ceph-osd
>> process
>>
>> random 4k read: 16.000 iop/s 19% CPU Load in top from EACH ceph-osd
>> process
>>
>> seq 4M write: 800MB/s 14% CPU Load in top from EACH ceph-osd process
>>
>> seq 4M read: 1600MB/s 9% CPU Load in top from EACH ceph-osd process
>>
>> I can't understand why in this single case the load is so EXTREMELY high.
>>
>> Greets
>> Stefan
> --
> To unsubscribe from this list: send the line "unsubscribe ceph-devel" in
> the body of a message to majordomo@vger.kernel.org
> More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: extreme ceph-osd cpu load for rand. 4k write

[Stefan Priebe - Profihost AG]

Am 08.11.2012 16:01, schrieb Mark Nelson:
> Hi Stefan,
>
> You might want to try running sysprof or perf while the OSDs are running
> during the tests and see where CPU time is being spent.  Also, how are
> you determining how much CPU usage is being used?

Hi Mark,

have a 300MB perf.data file and no idea what todo next ;-)

Stefan