fprof

 

相关文档 http://erlangdisplay.iteye.com/blog/318975

输出文件test.analyse 测试

Eshell V5.7.4  (abort with ^G)
1> fprof:trace([start,{file,test.trace}]).
ok
2> fprof:trace(stop)
2> .
ok
----------------------------------------
3> fprof:profile([{file,test.trace}]).
Reading trace data...
..
End of trace!
ok
4> fprof:analyse([{dest,test.analyse}])
4> .
Processing data...
Creating output...
Done!
ok
5> 

 

CNT表示总的函数调用次数，ACC表示Trace起始经历的时间，OWN是Trace中所有函数执行的时间和（不包含调用函数的执行时间），我们这个例子中OWN和ACC比较接近，因为我们这里在启动trace后就立即开始了函数调用，没有进行其他特殊的工作。这里时间的单位为ms。(来自 相关文档  )

 

 1 -module(chat).                                                                                                                                           
  2 -compile(export_all).
  3 %-behaviour(gen_server).
  4 start(N) ->
  5     fprof:trace(start,"chat.trace"),
  6     start_link(),
  7     test(),
  8     test(N),
  9     testcast(),           
 10     fprof:trace(stop),    
 11     fprof:profile(file,"chat.trace"),
 12     %fprof:analyse([{dest,"chat.analysis"}]).
 13     fprof:analyse([{dest,"chat.analysis"},{callers,true},{sort,own}]),
 14     io:format("11111111111~p~n",[whereis(chat)]).
 15    
 16 test(0)->
 17     gen_server:call(?MODULE, {test,0});
 18 test(N)->
 19     gen_server:call(?MODULE, {test,N}),
 20     test(N-1).
 21 test()->
 22     chat ! {test,1}.
 23 testcast() ->
 24     gen_server:cast(?MODULE,castttt).
 25 
 26 start_link() ->
 27     gen_server:start_link({local,?MODULE},?MODULE,[],[]).
 28 
 29 init([]) ->
 30     {ok, {}}.
 31 handle_cast(Msg,State) ->
 32     tttt(), 
 33     io:format("cast=~p~n",[Msg]),  
 34     {noreply,State}.
 35 
 36 handle_call({test,Number},From, State) when is_number(Number) ->
 37     Reply = Number+1,
                                                                                                                                           1,14         顶端

部分分析结果  
1 %% Analysis results:
  2 {  analysis_options,
  3  [{callers, true},
  4   {sort, own},
  5   {totals, false},
  6   {details, true}]}.
  7 
  8 %                                               CNT       ACC       OWN        
  9 [{ totals,                                     110269,  799.622,  736.349}].  %%%
 10 
 11 
 12 %                                               CNT       ACC       OWN        
 13 [{ "<0.33.0>",                                 110269,undefined,  736.349}].   %%
 14 
 15 {[{{gen,do_call,4},                            10001,  276.089,  159.700}],     
 16  { {gen,wait_resp_mon,3},                      10001,  276.089,  159.700},     %
 17  [{{erlang,demonitor,2},                       10001,   53.116,   53.116},      
 18   {suspend,                                    9983,   63.273,    0.000}]}.    
 19 
 20 {[{{gen,call,4},                               10001,  499.306,  124.766}],     
 21  { {gen,do_call,4},                            10001,  499.306,  124.766},     %
 22  [{{gen,wait_resp_mon,3},                      10001,  276.089,  159.700},      
 23   {{erlang,send,3},                            10001,   53.294,   53.294},      
 24   {{erlang,monitor,2},                         10001,   43.054,   43.054},      
 25   {garbage_collect,                             257,    2.103,    2.103}]}.    
 26 
 27 {[{{gen,call,3},                               10001,  617.283,   77.498}],     
 28  { {gen,call,4},                               10001,  617.283,   77.498},     %
 29  [{{gen,do_call,4},                            10001,  499.306,  124.766},      
 30   {{erlang,whereis,1},                         10001,   40.479,   40.479}]}.    
 31 
 32 {[{{chat,test,1},                              10000,    0.000,   72.848},      
 33   {{chat,start,1},                                1,  798.851,    0.060}],     
 34  { {chat,test,1},                              10001,  798.851,   72.908},     %
 35  [{{chat,test,1},                              10000,    0.000,   72.848},      
 36   {{gen_server,call,2},                        10001,  725.943,   71.115}]}.   

 

 

手册
http://www.erlang.org/doc/apps/tools/fprof_chapter.html

从手册上看到以下三种方式：

4.1  Profiling from the source code

4.2  Profiling a function

4.3  Immediate profiling

It is also possible to trace immediately into the profiling process that creates the raw profile data, that is to short circuit the tracing and profiling steps so that the filesystem is not used.

Do something like this:

{ok, Tracer} = fprof:profile(start),
fprof:trace([start, {tracer, Tracer}]),
%% Code to profile
fprof:trace(stop);

针对这三种方式进行了学习，前两个顺利通过，能看到结果。

问题：4.3 Immediate profiling 没有打印出预期的结果。 当打印了不少"..."

我在.erl文件用试过也没有出现预期的结果

1> {ok, Tracer} = fprof:profile(start),

1> fprof:trace([start, {tracer, Tracer}])

1> .

Reading trace data...

ok

2> self().

.<0.33.0>

.7> Pid =self().

.<0.33.0>

.8> Pid.

.<0.33.0>

..9> Pid ! ssdf, receive X -> X after 1 -> sdf end .

....ssdf

.10> Pid ! ssdf, receive X -> X after 1 -> sdf end .

....ssdf

16> 

16> fprof:trace(stop).

...

End of trace!

ok

17> 

预期结果类似是：

%                                               CNT       ACC       OWN        

[{ totals,                                     12256,   89.323,   88.890}].  %%%

%                                               CNT       ACC       OWN        

[{ "<0.35.0>",                                 12256,undefined,   88.890}].   %%

{[{undefined,                                     0,   89.323,    0.027}],     

 { {fprof,apply_start_stop,4},                    0,   89.323,    0.027},     %

 [{{foo,create_file_slow,2},                      1,   89.296,    0.028},      

  {suspend,                                       1,    0.000,    0.000}]}.