Erlang/OTP - Timing Applications

You can use eprof or fprof.

Here's how to use eprof, likely the easiest solution for you:

First you need to start it, like most applications out there:

23> eprof:start().
{ok,<0.95.0>}

Eprof supports two profiling mode. You can call it and ask to profile a certain function, but we can't use that because other processes will mess everything up. We need to manually start it profiling and tell it when to stop (this is why you won't have an easy script, by the way).

24> eprof:start_profiling([self()]).
profiling

This tells eprof to profile everything that will be run and spawned from the shell. New processes will be included here. I will run some arbitrary multiprocessing function I have, which spawns about 4 processes communicating with each other for a few seconds:

25> trade_calls:main_ab().
Spawned Carl: <0.99.0>
Spawned Jim: <0.101.0>
<0.100.0>
Jim: asking user <0.99.0> for a trade
Carl: <0.101.0> asked for a trade negotiation
Carl: accepting negotiation
Jim: starting negotiation
... <snip> ...

We can now tell eprof to stop profiling once the function is done running.

26> eprof:stop_profiling().
profiling_stopped

And we want the logs. Eprof will print them to screen by default. You can ask it to also log to a file with eprof:log(File). Then you can tell it to analyze the results. We tell it to collapse the run time from all processes into a single table with the option total (see the manual for more options):

27> eprof:analyze(total).           
FUNCTION                                  CALLS      %  TIME  [uS / CALLS]
--------                                  -----    ---  ----  [----------]
io:o_request/3                               46   0.00     0  [      0.00]
io:columns/0                                  2   0.00     0  [      0.00]
io:columns/1                                  2   0.00     0  [      0.00]
io:format/1                                   4   0.00     0  [      0.00]
io:format/2                                  46   0.00     0  [      0.00]
io:request/2                                 48   0.00     0  [      0.00]
...
erlang:atom_to_list/1                         5   0.00     0  [      0.00]
io:format/3                                  46  16.67  1000  [     21.74]
erl_eval:bindings/1                           4  16.67  1000  [    250.00]
dict:store_bkt_val/3                        400  16.67  1000  [      2.50]
dict:store/3                                114  50.00  3000  [     26.32]

And you can see that most of the time (50%) is spent in dict:store/3. 16.67% is taken in outputting the result, another 16.67% is taken by erl_eval (this is why you get by running short functions in the shell -- parsing them becomes longer than running them).

You can then start going from there. That's the basics of profiling run times with Erlang. Handle with care, eprof can be quite a load on a production system or for functions that run for too long. Especially on a production system.