[erlang-questions] Mysterious gen_server timeouts in MIX

[Vance Shipley]

On Fri, Nov 01, 2013 at 09:21:29PM -0700, John R. Ashmun wrote:
}  sometimes running using application:start( 'MIX' ) and sometimes booting
}  MIX as an Erlang release -- sometimes compiling using +debug_info (or not)
}  has seemed to change from success to failure (or, equally likely, the
}  opposite).

If your program is correct it's just too busy to respond before the
timeout.  In my experience however when you get to the point where a
message roundtrip is over 5 seconds you are in bad design territory.

You may have a race condition.  You say you have several gen_server
behaviour processes communicating with each other.  Hopefully this
communication is accomplished asynchronously.  Whenever you use a
receive statement, which you effectively do when you call a function
like gen_server:call/2, your process stops being a generic behaviour
until the call is completed.  No system messages or any others will
be processed during this time.

Here is an example of a pathological program which will eventually
deadlock:

-module(race).
-export([init/1, handle_info/2, handle_call/3, terminate/2]).
-record(state, {name, count}).

init([Name]) ->
	State = #state{name = Name, count = 0},
	random:seed(now()),
	Timeout = random:uniform(4000) + 1000,
	{ok, State, Timeout}.

handle_info(timeout, #state{name = Name, count = Count} = State) ->
	NewCount = gen_server:call(Name, Count),
	{noreply, State#state{count = NewCount}, random:uniform(1000)}.

handle_call(N, _From, State) ->
	{reply, N + 1, State, 0}.

terminate(_Reason, _State) ->
	ok.

Run it like this:

     1> gen_server:start({local, ping}, race, [pong], []),
     1> gen_server:start({local, pong}, race, [ping], []).
     {ok,<0.35.0>}

... and some time later:

     =ERROR REPORT==== 2-Nov-2013::14:47:10 ===
     ** Generic server pong terminating 
     ** Last message in was timeout
     ** When Server state == {state,ping,103446400}
     ** Reason for termination == 
     ** {timeout,{gen_server,call,[ping,103446400]}}
     
     =ERROR REPORT==== 2-Nov-2013::14:48:55 ===
     ** Generic server ping terminating 
     ** Last message in was timeout
     ** When Server state == {state,pong,103446400}
     ** Reason for termination == 
     ** {{timeout,{gen_server,call,[ping,103446400]}},
         {gen_server,call,[pong,103446400]}}

Here the processes have called each other a hundred million times
before deadlocking.

-- 
	-Vance