[Caml-list] Profiling ocaml with lwt

[Caml-list] Profiling ocaml with lwt

[Kasper Janssens]

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

Hello,


I’m trying to profile an ocaml application that has a performance degradation of about 20 %, with quite some code changes between both versions. I tried attaching perf and gprof to it, but to no real avail. Sure, there are slight differences in the running time of functions in the gprof result, but nothing whatsoever that seems to explain that kind of delay. Perf doesn’t seem to indicate a problem neither.


The thing is, I think it’s a delay in one of the servers that the application communicates with. The communication to those servers is done asynchronously, through lwt (epoll). I suspect that is the reason why delays in that communication don’t show up in the gprof result, but I’m not really sure.


Does anybody know of a way to profile lwt applications in a way that these kinds of delays might show up so I know which backend system I have to focus on?


Kasper
Western Digital Corporation (and its subsidiaries) E-mail Confidentiality Notice & Disclaimer:

This e-mail and any files transmitted with it may contain confidential or legally privileged information of WDC and/or its affiliates, and are intended solely for the use of the individual or entity to which they are addressed. If you are not the intended recipient, any disclosure, copying, distribution or any action taken or omitted to be taken in reliance on it, is prohibited. If you have received this e-mail in error, please notify the sender immediately and delete the e-mail in its entirety from your system.

[-- Attachment #2: Type: text/html, Size: 2934 bytes --]

Re: [Caml-list] Profiling ocaml with lwt

[Malcolm Matalka]

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

Generally I wrap external calls in something that gets that gets the wall
time of an external service call and logs it somewhere.
Den 9 mar 2016 9:54 fm skrev "Kasper Janssens" <Kasper.Janssens@hgst.com>:

> Hello,
>
>
> I’m trying to profile an ocaml application that has a performance
> degradation of about 20 %, with quite some code changes between both
> versions. I tried attaching perf and gprof to it, but to no real avail.
> Sure, there are slight differences in the running time of functions in the
> gprof result, but nothing whatsoever that seems to explain that kind of
> delay. Perf doesn’t seem to indicate a problem neither.
>
>
> The thing is, I think it’s a delay in one of the servers that the
> application communicates with. The communication to those servers is done
> asynchronously, through lwt (epoll). I suspect that is the reason why
> delays in that communication don’t show up in the gprof result, but I’m not
> really sure.
>
>
> Does anybody know of a way to profile lwt applications in a way that these
> kinds of delays might show up so I know which backend system I have to
> focus on?
>
>
> Kasper
>
> *Western Digital Corporation (and its subsidiaries) E-mail Confidentiality
> Notice & Disclaimer:*
>
> This e-mail and any files transmitted with it may contain confidential or
> legally privileged information of WDC and/or its affiliates, and are
> intended solely for the use of the individual or entity to which they are
> addressed. If you are not the intended recipient, any disclosure, copying,
> distribution or any action taken or omitted to be taken in reliance on it,
> is prohibited. If you have received this e-mail in error, please notify the
> sender immediately and delete the e-mail in its entirety from your system.
>

[-- Attachment #2: Type: text/html, Size: 3065 bytes --]

Re: [Caml-list] Profiling ocaml with lwt

[Kasper Janssens]

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

Yes, considered that, but the thing is, there are quite q few functions that would need to be wrapped, on two slightly different code bases. It doesn’t seem very feasible but it might be what I’ll have to resort to.
Other than that, isn’t that an error prone approach when lwt swaps to another thread in the mean time? Don’t you run the risk of timing not just your call but also everything that is done in between (e.g. Having lwt swapping in another thread in the mean time, won’t that show in the timing as well?)?

Kasper

From: Malcolm Matalka <mmatalka@gmail.com<mailto:mmatalka@gmail.com>>
Date: Wednesday 9 March 2016 at 10:49
To: Kasper <Kasper.Janssens@hgst.com<mailto:Kasper.Janssens@hgst.com>>
Cc: caml-list <caml-list@inria.fr<mailto:caml-list@inria.fr>>
Subject: Re: [Caml-list] Profiling ocaml with lwt


Generally I wrap external calls in something that gets that gets the wall time of an external service call and logs it somewhere.

Den 9 mar 2016 9:54 fm skrev "Kasper Janssens" <Kasper.Janssens@hgst.com<mailto:Kasper.Janssens@hgst.com>>:

Hello,


I’m trying to profile an ocaml application that has a performance degradation of about 20 %, with quite some code changes between both versions. I tried attaching perf and gprof to it, but to no real avail. Sure, there are slight differences in the running time of functions in the gprof result, but nothing whatsoever that seems to explain that kind of delay. Perf doesn’t seem to indicate a problem neither.


The thing is, I think it’s a delay in one of the servers that the application communicates with. The communication to those servers is done asynchronously, through lwt (epoll). I suspect that is the reason why delays in that communication don’t show up in the gprof result, but I’m not really sure.


Does anybody know of a way to profile lwt applications in a way that these kinds of delays might show up so I know which backend system I have to focus on?


Kasper

Western Digital Corporation (and its subsidiaries) E-mail Confidentiality Notice & Disclaimer:

This e-mail and any files transmitted with it may contain confidential or legally privileged information of WDC and/or its affiliates, and are intended solely for the use of the individual or entity to which they are addressed. If you are not the intended recipient, any disclosure, copying, distribution or any action taken or omitted to be taken in reliance on it, is prohibited. If you have received this e-mail in error, please notify the sender immediately and delete the e-mail in its entirety from your system.
Western Digital Corporation (and its subsidiaries) E-mail Confidentiality Notice & Disclaimer:

This e-mail and any files transmitted with it may contain confidential or legally privileged information of WDC and/or its affiliates, and are intended solely for the use of the individual or entity to which they are addressed. If you are not the intended recipient, any disclosure, copying, distribution or any action taken or omitted to be taken in reliance on it, is prohibited. If you have received this e-mail in error, please notify the sender immediately and delete the e-mail in its entirety from your system.

[-- Attachment #2: Type: text/html, Size: 5705 bytes --]

Re: [Caml-list] Profiling ocaml with lwt

[Török Edwin]

On 03/09/2016 11:57, Kasper Janssens wrote:
> Den 9 mar 2016 9:54 fm skrev "Kasper Janssens" <Kasper.Janssens@hgst.com <mailto:Kasper.Janssens@hgst.com>>:
> 
>     Hello,
> 
> 
>     I’m trying to profile an ocaml application that has a performance degradation of about 20 %, with quite some code changes between both versions. I tried attaching perf and gprof to it, but to no real avail. Sure, there are slight differences in the running time of functions in the gprof result, but nothing whatsoever that seems to explain that kind of delay. Perf doesn’t seem to indicate a problem neither.
> 
> 
>     The thing is, I think it’s a delay in one of the servers that the application communicates with.

Is that communication done over a TCP/UDP socket?
You could use wireshark and see if you spot anything (e.g. too many SSL handshakes -> application would benefit from persistent connections, etc.)

Depending on the complexity of your application you may try to use a branch of Lwt that reports more tracing information,
although this would likely require manual annotations to produce useful output:
http://roscidus.com/blog/blog/2014/10/27/visualising-an-asynchronous-monad/

I usually just wrap+log calls and use strace though, as already mentioned in this thread.

Best regards,
-- 
Edwin Török | Co-founder and Lead Developer

Skylable open-source object storage: reliable, fast, secure
http://www.skylable.com

Re: [Caml-list] Profiling ocaml with lwt

[Malcolm Matalka]

Török Edwin <edwin+ml-ocaml@etorok.net> writes:

> On 03/09/2016 11:57, Kasper Janssens wrote:
>> Den 9 mar 2016 9:54 fm skrev "Kasper Janssens" <Kasper.Janssens@hgst.com <mailto:Kasper.Janssens@hgst.com>>:
>> 
>>     Hello,
>> 
>> 
>>     I’m trying to profile an ocaml application that has a performance degradation of about 20 %, with quite some code changes between both
>> versions. I tried attaching perf and gprof to it, but to no real avail. Sure, there are slight differences in the running time of
>> functions in the gprof result, but nothing whatsoever that seems to explain that kind of delay. Perf doesn’t seem to indicate a problem
>> neither.
>> 
>> 
>>     The thing is, I think it’s a delay in one of the servers that the application communicates with.
>
> Is that communication done over a TCP/UDP socket?
> You could use wireshark and see if you spot anything (e.g. too many SSL handshakes -> application would benefit from persistent connections, etc.)
>
> Depending on the complexity of your application you may try to use a branch of Lwt that reports more tracing information,
> although this would likely require manual annotations to produce useful output:
> http://roscidus.com/blog/blog/2014/10/27/visualising-an-asynchronous-monad/
>
> I usually just wrap+log calls and use strace though, as already
> mentioned in this thread.

And if you're on FreeBSD or OS X or Solaris you can use dtrace.

>
> Best regards,
> -- 
> Edwin Török | Co-founder and Lead Developer
>
> Skylable open-source object storage: reliable, fast, secure
> http://www.skylable.com

Re: [Caml-list] Profiling ocaml with lwt

[Adrien Nader]

Hi,

I tend to (ab)use strace. It has options to only instrument some
syscalls, it can count time spent in syscalls, time spent between
syscalls, has microsecond precision, ...

My first runs are usually "strace -tt -f -o log" to get times with
microseconds, follow forks and write to a file rather than stderr
(heavily advised, especially since text editors have syntax highlighting
for strace's output [ vim at least even though you need to :set
ft=strace when using -tt).

After that, you can also use -T to get the time spent in syscalls, -e to
trace fewer things, ...

It's a hammer and requires a fair bit of eye-crossing but it covers
everything, it's overhead isn't that big and it can easily reduce the
scope of what you need to look more deeply at. However it's probably useless to try
to spend more than 2 hours on a strace's output if you can't find the
answer you're looking for.

Re: [Caml-list] Profiling ocaml with lwt

[tools]

You can always use valgrind's callgrind to profile your applications. It has options to record systimes as well. 
Kcachegrind does a decent job in helping you to interprete the results.


Have fun,

Romain.