[Caml-list] an OCaml program profile

[Caml-list] an OCaml program profile

[Francois Berenger]

Hello,

I am running experiments with a program.
I'd like the program to run faster because
it would reduce experiments round-trip.

Here is the top of the profile:
---
Flat profile:

Each sample counts as 0.01 seconds.
   %   cumulative   self              self     total
  time   seconds   seconds    calls   s/call   s/call  name
  58.07    132.13   132.13 161527987     0.00     0.00  caml_fl_allocate
  21.13    180.21    48.08     2339     0.02     0.02  caml_fl_add_blocks
   4.87    191.30    11.09     5497     0.00     0.00  mark_slice
   1.65    195.06     3.76 979591485     0.00     0.00 
caml_page_table_lookup
   1.50    198.47     3.41     5620     0.00     0.00  sweep_slice
   1.20    201.21     2.74 186584504     0.00     0.00  caml_oldify_one
   1.04    203.57     2.36 134849325     0.00     0.00  compare_val
   1.02    205.89     2.32 290049921     0.00     0.00  caml_float_compare
   0.80    207.71     1.82 123048730     0.00     0.00  caml_hash
   0.76    209.44     1.73 161525648     0.00     0.00  caml_alloc_shr
---

I think the program spends most of its time doing garbage
collection.

How can I make it go faster?

Would the OPAM switch 4.00.1+alloc-profiling (support allocation 
profiling on x86_64) would allow me to find the culprit function?

If yes, how to use it?

Thanks a lot,
Francois.

Re: [Caml-list] an OCaml program profile

[Kakadu]

I have had the same issue with my parser combinators this summer.
OCamlLex based lexer was allocating a lot during lexing phase nad
that's why my heap was consist of many small free block which couldn't
be used for new allocations. Increasing minor heap size fas a partial
solution. Running Gc.compact () manually was a main solution.

Happy hacking,
Kakadu

On Fri, Sep 6, 2013 at 5:48 AM, Francois Berenger <berenger@riken.jp> wrote:
> Hello,
>
> I am running experiments with a program.
> I'd like the program to run faster because
> it would reduce experiments round-trip.
>
> Here is the top of the profile:
> ---
> Flat profile:
>
> Each sample counts as 0.01 seconds.
>   %   cumulative   self              self     total
>  time   seconds   seconds    calls   s/call   s/call  name
>  58.07    132.13   132.13 161527987     0.00     0.00  caml_fl_allocate
>  21.13    180.21    48.08     2339     0.02     0.02  caml_fl_add_blocks
>   4.87    191.30    11.09     5497     0.00     0.00  mark_slice
>   1.65    195.06     3.76 979591485     0.00     0.00 caml_page_table_lookup
>   1.50    198.47     3.41     5620     0.00     0.00  sweep_slice
>   1.20    201.21     2.74 186584504     0.00     0.00  caml_oldify_one
>   1.04    203.57     2.36 134849325     0.00     0.00  compare_val
>   1.02    205.89     2.32 290049921     0.00     0.00  caml_float_compare
>   0.80    207.71     1.82 123048730     0.00     0.00  caml_hash
>   0.76    209.44     1.73 161525648     0.00     0.00  caml_alloc_shr
> ---
>
> I think the program spends most of its time doing garbage
> collection.
>
> How can I make it go faster?
>
> Would the OPAM switch 4.00.1+alloc-profiling (support allocation profiling
> on x86_64) would allow me to find the culprit function?
>
> If yes, how to use it?
>
> Thanks a lot,
> Francois.
>
> --
> Caml-list mailing list.  Subscription management and archives:
> https://sympa.inria.fr/sympa/arc/caml-list
> Beginner's list: http://groups.yahoo.com/group/ocaml_beginners
> Bug reports: http://caml.inria.fr/bin/caml-bugs

Re: [Caml-list] an OCaml program profile

[John Whitington]

Hi,

Francois Berenger wrote:
> Hello,
>
> I am running experiments with a program.
> I'd like the program to run faster because
> it would reduce experiments round-trip.
>
> Here is the top of the profile:
> ---
> Flat profile:
>
> Each sample counts as 0.01 seconds.
> % cumulative self self total
> time seconds seconds calls s/call s/call name
> 58.07 132.13 132.13 161527987 0.00 0.00 caml_fl_allocate
> 21.13 180.21 48.08 2339 0.02 0.02 caml_fl_add_blocks
> 4.87 191.30 11.09 5497 0.00 0.00 mark_slice
> 1.65 195.06 3.76 979591485 0.00 0.00 caml_page_table_lookup
> 1.50 198.47 3.41 5620 0.00 0.00 sweep_slice
> 1.20 201.21 2.74 186584504 0.00 0.00 caml_oldify_one
> 1.04 203.57 2.36 134849325 0.00 0.00 compare_val
> 1.02 205.89 2.32 290049921 0.00 0.00 caml_float_compare
> 0.80 207.71 1.82 123048730 0.00 0.00 caml_hash
> 0.76 209.44 1.73 161525648 0.00 0.00 caml_alloc_shr
> ---
>
> I think the program spends most of its time doing garbage
> collection.
>
> How can I make it go faster?

Look further down the profile in the individual numbered sections for 
each function. The section for "caml_call_gc" usually provides the most 
useful start.

For example, if most calls to caml_call_gc are from List.rev, look at 
calls to that etc. It's not entirely straightforward, but after a bit of 
following numbers around the file, you'll get used to it.

Thanks,

-- 
John Whitington
Director, Coherent Graphics Ltd
http://www.coherentpdf.com/

Re: [Caml-list] an OCaml program profile

[Gabriel Scherer]

I have found the "poor man profiler" approach to work well when you
want to know not only which functions calls some slow runtime function
the most, but only in which situation (it depends on the callstack and
not only the source location). Ygrek's pmpa script is very helpful for
that
  http://ygrek.org.ua/p/code/pmpa


On Fri, Sep 6, 2013 at 10:28 AM, John Whitington
<john@coherentgraphics.co.uk> wrote:
> Hi,
>
>
> Francois Berenger wrote:
>>
>> Hello,
>>
>> I am running experiments with a program.
>> I'd like the program to run faster because
>> it would reduce experiments round-trip.
>>
>> Here is the top of the profile:
>> ---
>> Flat profile:
>>
>> Each sample counts as 0.01 seconds.
>> % cumulative self self total
>> time seconds seconds calls s/call s/call name
>> 58.07 132.13 132.13 161527987 0.00 0.00 caml_fl_allocate
>> 21.13 180.21 48.08 2339 0.02 0.02 caml_fl_add_blocks
>> 4.87 191.30 11.09 5497 0.00 0.00 mark_slice
>> 1.65 195.06 3.76 979591485 0.00 0.00 caml_page_table_lookup
>> 1.50 198.47 3.41 5620 0.00 0.00 sweep_slice
>> 1.20 201.21 2.74 186584504 0.00 0.00 caml_oldify_one
>> 1.04 203.57 2.36 134849325 0.00 0.00 compare_val
>> 1.02 205.89 2.32 290049921 0.00 0.00 caml_float_compare
>> 0.80 207.71 1.82 123048730 0.00 0.00 caml_hash
>> 0.76 209.44 1.73 161525648 0.00 0.00 caml_alloc_shr
>> ---
>>
>> I think the program spends most of its time doing garbage
>> collection.
>>
>> How can I make it go faster?
>
>
> Look further down the profile in the individual numbered sections for each
> function. The section for "caml_call_gc" usually provides the most useful
> start.
>
> For example, if most calls to caml_call_gc are from List.rev, look at calls
> to that etc. It's not entirely straightforward, but after a bit of following
> numbers around the file, you'll get used to it.
>
> Thanks,
>
> --
> John Whitington
> Director, Coherent Graphics Ltd
> http://www.coherentpdf.com/
>
>
>
> --
> Caml-list mailing list.  Subscription management and archives:
> https://sympa.inria.fr/sympa/arc/caml-list
> Beginner's list: http://groups.yahoo.com/group/ocaml_beginners
> Bug reports: http://caml.inria.fr/bin/caml-bugs

Re: [Caml-list] an OCaml program profile

[Francois Berenger]

For the record, I replaced a function using a list
and a hash table by a function using a float array.
Since the culprit function is a numerical algorithm,
that's probably what I should have done from the beginning.
The program is way faster now.

On 09/06/2013 05:49 PM, Gabriel Scherer wrote:
> I have found the "poor man profiler" approach to work well when you
> want to know not only which functions calls some slow runtime function
> the most, but only in which situation (it depends on the callstack and
> not only the source location). Ygrek's pmpa script is very helpful for
> that
>    http://ygrek.org.ua/p/code/pmpa
>
>
> On Fri, Sep 6, 2013 at 10:28 AM, John Whitington
> <john@coherentgraphics.co.uk> wrote:
>> Hi,
>>
>>
>> Francois Berenger wrote:
>>>
>>> Hello,
>>>
>>> I am running experiments with a program.
>>> I'd like the program to run faster because
>>> it would reduce experiments round-trip.
>>>
>>> Here is the top of the profile:
>>> ---
>>> Flat profile:
>>>
>>> Each sample counts as 0.01 seconds.
>>> % cumulative self self total
>>> time seconds seconds calls s/call s/call name
>>> 58.07 132.13 132.13 161527987 0.00 0.00 caml_fl_allocate
>>> 21.13 180.21 48.08 2339 0.02 0.02 caml_fl_add_blocks
>>> 4.87 191.30 11.09 5497 0.00 0.00 mark_slice
>>> 1.65 195.06 3.76 979591485 0.00 0.00 caml_page_table_lookup
>>> 1.50 198.47 3.41 5620 0.00 0.00 sweep_slice
>>> 1.20 201.21 2.74 186584504 0.00 0.00 caml_oldify_one
>>> 1.04 203.57 2.36 134849325 0.00 0.00 compare_val
>>> 1.02 205.89 2.32 290049921 0.00 0.00 caml_float_compare
>>> 0.80 207.71 1.82 123048730 0.00 0.00 caml_hash
>>> 0.76 209.44 1.73 161525648 0.00 0.00 caml_alloc_shr
>>> ---
>>>
>>> I think the program spends most of its time doing garbage
>>> collection.
>>>
>>> How can I make it go faster?
>>
>>
>> Look further down the profile in the individual numbered sections for each
>> function. The section for "caml_call_gc" usually provides the most useful
>> start.
>>
>> For example, if most calls to caml_call_gc are from List.rev, look at calls
>> to that etc. It's not entirely straightforward, but after a bit of following
>> numbers around the file, you'll get used to it.
>>
>> Thanks,
>>
>> --
>> John Whitington
>> Director, Coherent Graphics Ltd
>> http://www.coherentpdf.com/
>>
>>
>>
>> --
>> Caml-list mailing list.  Subscription management and archives:
>> https://sympa.inria.fr/sympa/arc/caml-list
>> Beginner's list: http://groups.yahoo.com/group/ocaml_beginners
>> Bug reports: http://caml.inria.fr/bin/caml-bugs
>