How to find out what's going on

[Sean Hinde]

Joel,

Check the message queue length of the disk_log_server.

disk_log:alog sends an async message to the disk_log_server.

Try with disk_log:log instead and see if you get the same result.  
 From what I have seen in the past the throughput under full load  
will increase dramatically - especially if combined with emulator  
thread pool (erl +A 10).

To answer your question, the only way to really see where time is  
being spent in the emulator is to profile the emulator itself while  
running your program. If you figure out how to get profiling working  
with the gnu tools then a blog post on that would be quite  
interesting :-)

Sean

On 3 Jan 2006, at 23:07, Joel Reymont wrote:

> Folks,
>
> I'm writing poker bots and my goal is to launch as many per VM as I  
> can. The bots use a binary protocol to talk to the poker server.  
> I'm tracing to a disk log periodically.
>
> Here I launched 10 bots and looked at the trace log for one of  
> them. I have a separate module that analyzes the disk log.
>
> 22:52:46: <0.32.0>: Received: 0.000797s: srv_table_state
> 22:53:08: <0.32.0>: Received: 0.000110s: {srv_table_state, ...}
>
> You can see a difference of 22 seconds above. Normally this would  
> not be cause for concern but the two traces are from two  
> consecutive lines in the same module!
>
> 	    trace(Bot, 90, "Received: ~.6. fs: ~p",
> 		  [Seconds, Cmd1]),
> 	    trace(Bot, 80, "Received: ~.6. fs: ~p",
> 		  [Seconds, element(1, Cmd1)]);
>
> Trace itself is defined thusly:
>
> trace(Bot, Level, Format, Args)
>   when Level =< Bot#bot.debug_level ->
>     {_, Time} = erlang:localtime(),
>     disk_log:alog(Bot#bot.log, {trace, self(), Format, Args, Time});
>
> How do I find out where the 22 seconds went?
>
> 	Thanks, Joel
>
> --
> http://wagerlabs.com/
>
>
>
>
>