[erlang-questions] gen_server and init

Loïc Hoguin essen@REDACTED
Mon Jul 27 21:14:37 CEST 2015


(Had problems pasting so hope it's all OK!)

I'm not sure what you wrote there but I can give you two scenarios where 
it can fail off the top of my head. The first is very unlikely and can 
only fail if you use the 0 timeout, while the second is actually much 
easier to observe and can fail with both methods:

P1 calls start_link
P2 init (returns 0 timeout)
P2 yields before calling receive
P1 returns from start_link and sends P2 a message
P2 receives message

And:

P1 calls start_link
P2 in init subscribes to some kind of pubsub PS
PS sends P2 message(s)
P2 returns from init and receive those messages

I'm not sure why your tool doesn't catch the first case, Concuerror 
*definitely does*, and without needing to write all this weird code too. :-)

Here is the module:

-module(z).
-behaviour(gen_server).

-export([start_link/0]).

%% Operational API
-export([read/0]).

%% gen_server API
-export([
          init/1,
          handle_cast/2,
          handle_call/3,
          terminate/2,
          code_change/3,
          handle_info/2,
		 test/0
]).

test() ->
	start_link(),
	ready = read(),
	stop().

%% API
start_link() ->
     gen_server:start({local, ?MODULE}, ?MODULE, [], []).

read() ->
     gen_server:call(?MODULE, read).

stop() ->
	gen_server:call(?MODULE, stop).

%% Callbacks
init([]) ->
     {ok, initializing, 0}.

handle_call(read, _From, State) ->
     {reply, State, State};
handle_call(stop, _, State) ->
	{stop, normal, ok, stop}.

handle_cast(_M, State) ->
     {noreply, State}.

handle_info(timeout, _State) ->
     {noreply, ready}.

terminate(_How, _State) ->
     ok.

code_change(_OldVsn, State, _Extra) ->
     {ok, State}.

%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%

Here is the Concuerror output:

% erlc z.erl && ./concuerror -f z.erl -m z -k --after_timeout 1000 && 
cat concuerror_report.txt
z.erl:42: Warning: variable 'State' is unused
concuerror: WARNING: file z.erl shadows the default ./z.beam
Concuerror started at 27 Jul 2015 19:08:58
Writing results in concuerror_report.txt

Info: Instrumented z
Info: Instrumented io_lib
Info: Instrumented gen_server
Info: Instrumented gen
Info: Instrumented proc_lib
Info: Instrumented erlang
Info: Instrumented init
Info: Instrumented sys
Info: You can see pairs of racing instructions (in the report and 
--graph) with '--show_races true'
Warning: Continuing after error
Done! (Exit status: completed)
   Summary: 1 errors, 4/4 interleavings explored
################################################################################

Concuerror started with options:
   [{after_timeout,1000},
    {assume_racing,true},
    {depth_bound,5000},
    {entry_point,{z,test,[]}},
    {files,["z.erl"]},
    {ignore_error,[]},
    {instant_delivery,false},
    {interleaving_bound,infinity},
    {keep_going,true},
    {non_racing_system,[]},
    {optimal,true},
    {print_depth,20},
    {scheduling,round_robin},
    {scheduling_bound,infinity},
    {scheduling_bound_type,none},
    {show_races,false},
    {strict_scheduling,false},
    {symbolic_names,true},
    {timeout,1000},
    {treat_as_normal,[]}]
################################################################################

Erroneous interleaving 1:
* At step 24 process P exited abnormally
     Reason:
       {{badmatch,initializing},[{z,test,0,[{file,"z.erl"},{line,22}]}]}
     Stacktrace:
       [{z,test,0,[{file,"z.erl"},{line,22}]}]
* Blocked at a 'receive' (when all other processes have exited):
     P.1 in gen_server.erl line 360
--------------------------------------------------------------------------------

Interleaving info:
    1: P: undefined = erlang:whereis(z)
     in gen.erl line 284
    2: P: [] = erlang:process_info(P, registered_name)
     in proc_lib.erl line 675
    3: P: {P.1,#Ref<0.0.0.177>} = 
erlang:spawn_opt({proc_lib,init_p,[P,[],gen,init_it,[gen_server,P,self,{local,z},z,[],[]]],[monitor]})
     in erlang.erl line 2496
    4: P.1: undefined = erlang:put('$ancestors', [P])
     in proc_lib.erl line 231
    5: P.1: undefined = erlang:put('$initial_call', {z,init,1})
     in proc_lib.erl line 232
    6: P.1: true = erlang:register(z, P.1)
     in gen.erl line 287
    7: P.1: {P.1,{get_argument,generic_debug}} = init ! 
{P.1,{get_argument,generic_debug}}
     in init.erl line 145
    8: Message ({P.1,{get_argument,generic_debug}}) from P.1 reaches init
    9: Message ({init,error}) from init reaches P.1
   10: P.1: receives message ({init,error})
     in init.erl line 146
   11: P.1: {ack,P.1,{ok,P.1}} = P ! {ack,P.1,{ok,P.1}}
     in proc_lib.erl line 375
   12: Message ({ack,P.1,{ok,P.1}}) from P.1 reaches P
   13: P: receives message ({ack,P.1,{ok,P.1}})
     in proc_lib.erl line 344
   14: P: true = erlang:demonitor(#Ref<0.0.0.177>, [flush])
     in proc_lib.erl line 346
   15: P: P.1 = erlang:whereis(z)
     in gen.erl line 157
   16: P: #Ref<0.0.0.223> = erlang:monitor(process, P.1)
     in gen.erl line 200
   17: P: {'$gen_call',{P,#Ref<0.0.0.223>},read} = erlang:send(P.1, 
{'$gen_call',{P,#Ref<0.0.0.223>},read}, [noconnect])
     in gen.erl line 211
   18: Message ({'$gen_call',{P,#Ref<0.0.0.223>},read}) from P reaches P.1
   19: P.1: receives message ({'$gen_call',{P,#Ref<0.0.0.223>},read})
     in gen_server.erl line 360
   20: P.1: {#Ref<0.0.0.223>,initializing} = P ! 
{#Ref<0.0.0.223>,initializing}
     in gen_server.erl line 219
   21: Message ({#Ref<0.0.0.223>,initializing}) from P.1 reaches P
   22: P: receives message ({#Ref<0.0.0.223>,initializing})
     in gen.erl line 213
   23: P: true = erlang:demonitor(#Ref<0.0.0.223>, [flush])
     in gen.erl line 215
   24: P: exits abnormally 
({{badmatch,initializing},[{z,test,0,[{file,[122,46,101,114,108]},{line,22}]}]})
################################################################################

Warnings:
--------------------------------------------------------------------------------

Continuing after error

################################################################################

Info:
--------------------------------------------------------------------------------

Instrumented z
Instrumented io_lib
Instrumented gen_server
Instrumented gen
Instrumented proc_lib
Instrumented erlang
Instrumented init
Instrumented sys
You can see pairs of racing instructions (in the report and --graph) 
with '--show_races true'

################################################################################

Done! (Exit status: completed)
   Summary: 1 errors, 4/4 interleavings explored

%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%

As you can see P.1 yields before getting to the receive, then P calls 
read, and so the "after 0" doesn't run because the call message is in 
the mailbox already.

Enjoy!

On 07/27/2015 08:29 PM, Jesper Louis Andersen wrote:
>
> On Mon, Jul 27, 2015 at 4:40 PM, Loïc Hoguin <essen@REDACTED
> <mailto:essen@REDACTED>> wrote:
>
>     This and sending yourself a message is a bad idea. It will usually
>     work, until it doesn't, and you will have a very hard time figuring
>     out why.
>
>
> I'm quite curious. What is the scenario where this fails? I have never
> observed this in practice on very busy systems, and I think going
> through proc_lib for this is a detour I'd rather not we'd have to take.
>
> Here are two modules, z0 and z.erl. They are very boring gen servers:
>
> -module(z0).
> -behaviour(gen_server).
>
> -ifdef(PULSE).
> -include_lib("pulse_otp/include/pulse_otp.hrl").
> -endif.
>
> -export([start_link/0]).
>
> %% Operational API
> -export([read/0, read_p/1]).
>
> %% gen_server API
> -export([
>           init/1,
>           handle_cast/2,
>           handle_call/3,
>           terminate/2,
>           code_change/3,
>           handle_info/2
> ]).
>
> %% API
> start_link() ->
>      gen_server:start_link({local, ?MODULE}, ?MODULE, [], []).
>
> read() ->
>      gen_server:call(?MODULE, read).
>
> read_p(P) ->
>      gen_server:call(P, read).
>
> %% Callbacks
> init([]) ->
>      {ok, initializing, 0}.
>
> handle_call(read, _From, State) ->
>      {reply, State, State}.
> handle_cast(_M, State) ->
>      {noreply, State}.
>
> handle_info(timeout, _State) ->
>      {noreply, ready}.
> terminate(_How, _State) ->
>      ok.
> code_change(_OldVsn, State, _Extra) ->
>      {ok, State}.
>
> ---------------------
>
> -module(z).
> -behaviour(gen_server).
>
> -ifdef(PULSE).
> -include_lib("pulse_otp/include/pulse_otp.hrl").
> -endif.
>
> -export([start_link/0]).
>
> %% Operational API
> -export([read/0, read_p/1]).
>
> %% gen_server API
> -export([
>           init/1,
>           handle_cast/2,
>           handle_call/3,
>           terminate/2,
>           code_change/3,
>           handle_info/2
> ]).
>
> %% API
> start_link() ->
>      gen_server:start_link({local, ?MODULE}, ?MODULE, [], []).
>
> read() ->
>      gen_server:call(?MODULE, read).
>
> read_p(P) ->
>      gen_server:call(P, read).
>
> %% Callbacks
> init([]) ->
>      self() ! timeout,
>      {ok, initializing}.
>
> handle_call(read, _From, State) ->
>      {reply, State, State}.
> handle_cast(_M, State) ->
>      {noreply, State}.
>
> handle_info(timeout, _State) ->
>      {noreply, ready}.
> terminate(_How, _State) ->
>      ok.
> code_change(_OldVsn, State, _Extra) ->
>      {ok, State}.
>
> ---------------------
>
> Ok, now with these down, we can use EQC and PULSE to generate the
> counterexample if any should be in there:
>
> -module(z_eqc).
> -include_lib("eqc/include/eqc.hrl").
> -include_lib("eqc/include/eqc_statem.hrl").
>
> -include_lib("pulse/include/pulse.hrl").
> -include_lib("pulse_otp/include/pulse_otp.hrl").
>
> -compile(export_all).
>
> -record(state, { init, ref }).
>
> initial_state() ->
>      #state { init = false }.
> server_start() ->
>      {ok, Pid} = z:start_link(),
>      unlink(Pid),
>      Pid.
> %% SERVER START_LINK
> server_start_pre(S) -> not initialized(S).
> server_start_args(_S) -> [].
>
> server_start_next(S, Ref, []) ->
>      S#state { ref = Ref, init = true }.
> server_start_post(_S, [], Ref) -> is_pid(Ref).
>
> %% READ BY PID
> read_p(P) ->
>      z:read_p(P).
> read_p_pre(S) -> initialized(S).
> read_p_args(#state { ref = Ref }) -> [Ref].
>
> read_p_return(_S, [_Ref]) -> ready.
>
> %% READ
> read() ->
>      try z:read() of
>        M -> M
>      catch
>        _Class:_Err ->
>          {error, undefined}
>      end.
> read_args(_S) -> [].
> read_return(#state { init = false}, []) -> {error, undefined};
> read_return(#state { init = true}, []) -> ready.
>
> %% Run a test under PULSE to randomize the process schedule as well.
> prop_model_pulse() ->
>     ?SETUP(fun() ->
>                     setup(),
>                     fun() -> ok end
>             end,
>    ?LET(Shrinking, parameter(shrinking, false),
>    ?FORALL(Cmds, parallel_commands(?MODULE),
>      ?ALWAYS(if not Shrinking -> 1; Shrinking -> 20 end,
>        ?PULSE(HSR={_, _, R},
>          begin
>            ok = cleanup(),
>            run_parallel_commands(?MODULE, Cmds)
>          end,
>          aggregate(command_names(Cmds),
>          pretty_commands(?MODULE, Cmds, HSR, R == ok))))))).
>
> setup() ->
>      error_logger:tty(false),
>      ok.
>
> cleanup() ->
>      case whereis(z) of
>          undefined -> ok;
>          Pid ->
>              exit(Pid, kill),
>              timer:sleep(3)
>      end,
>      ok.
>
> initialized(#state { init = I }) -> I.
>
> pulse_instrument() ->
>    [ pulse_instrument(File) || File <- filelib:wildcard("*.erl") ],
>    ok.
> pulse_instrument(File) ->
>      io:format("Compiling: ~p~n", [File]),
>      {ok, Mod} = compile:file(File, [{d, 'PULSE', true}, {d,
> 'WITH_PULSE', true},
>                                      {d, 'EQC_TESTING', true},
>                                      {parse_transform, pulse_instrument}]),
>    code:purge(Mod),
>    code:load_file(Mod),
>    Mod.
>
> -----------------------------
>
> However, when I run this, I get no errors, even though I'm trying to
> behave non-nicely:
>
> I won't call the Pid until I know about it.
> I will blindly call the name, z, and if I get an error on this, I'll
> verify that the possible linearization is that the process was not
> started yet. If I get a result, I force it to be ready:
>
> 60> eqc:module({testing_time, 30}, z_eqc).
> prop_model_pulse:
> ....................................................................................................(x10)....................................................................................................(x100)............................(x10).......
> Time limit reached: 30.0 seconds.
>
> OK, passed 3970 tests
>
> 49.857% {z_eqc,read,0}
> 44.492% {z_eqc,read_p,1}
> 5.651% {z_eqc,server_start,0}
> []
>
> ...
>
> So: What is the scenario where this approach fails?
>
>
>
> --
> J.

-- 
Loïc Hoguin
http://ninenines.eu
Author of The Erlanger Playbook,
A book about software development using Erlang



More information about the erlang-questions mailing list