How to find out what's going on

[Joel Reymont]

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/