Include timing on -init_debug to further aid debugging

1 files changed, 35 insertions, 23 deletions

diff --git a/erts/preloaded/src/init.erl b/erts/preloaded/src/init.erl
index 9d28d214fa..cfd530bec1 100644
--- a/erts/preloaded/src/init.erl
+++ b/erts/preloaded/src/init.erl
@@ -98,6 +98,17 @@
 debug(false, _) -> ok;
 debug(_, T)     -> erlang:display(T).
 
+debug(false, _, Fun) ->
+    Fun();
+debug(_, T, Fun) ->
+    erlang:display(T),
+    T1 = erlang:monotonic_time(),
+    Val = Fun(),
+    T2 = erlang:monotonic_time(),
+    Time = erlang:convert_time_unit(T2 - T1, native, microsecond),
+    erlang:display({'done_in_μs', Time}),
+    Val.
+
 -spec get_configfd(integer()) -> none | term().
 get_configfd(ConfigFdId) ->
     request({get_configfd, ConfigFdId}).
@@ -1039,12 +1050,10 @@ eval_script([{primLoad,Mods}|T], #es{init=Init,prim_load=PrimLoad}=Es)
     eval_script(T, Es);
 eval_script([{kernelProcess,Server,{Mod,Fun,Args}}|T],
 	    #es{init=Init,debug=Deb}=Es) ->
-    debug(Deb, {start,Server}),
-    start_in_kernel(Server, Mod, Fun, Args, Init),
+    debug(Deb, {start,Server}, fun() -> start_in_kernel(Server, Mod, Fun, Args, Init) end),
     eval_script(T, Es);
 eval_script([{apply,{Mod,Fun,Args}}=Apply|T], #es{debug=Deb}=Es) ->
-    debug(Deb, Apply),
-    apply(Mod, Fun, Args),
+    debug(Deb, Apply, fun() -> apply(Mod, Fun, Args) end),
     eval_script(T, Es);
 eval_script([], #es{}) ->
     ok;
@@ -1536,28 +1545,31 @@ on_load_loop(Mods, Debug0) ->
     end.
 
 run_on_load_handlers([M|Ms], Debug) ->
-    debug(Debug, {running_on_load_handler,M}),
+    debug(Debug,
+          {running_on_load_handler,M},
+          fun() -> run_on_load_handler(M, Debug) end),
+    run_on_load_handlers(Ms, Debug);
+run_on_load_handlers([], _) -> ok.
+
+run_on_load_handler(M, Debug) ->
     Fun = fun() ->
-		  Res = erlang:call_on_load_function(M),
-		  exit(Res)
-	  end,
+                  Res = erlang:call_on_load_function(M),
+                  exit(Res)
+          end,
     {Pid,Ref} = spawn_monitor(Fun),
     receive
-	{'DOWN',Ref,process,Pid,OnLoadRes} ->
-	    Keep = OnLoadRes =:= ok,
-	    erlang:finish_after_on_load(M, Keep),
-	    case Keep of
-		false ->
-		    Error = {on_load_function_failed,M,OnLoadRes},
-		    debug(Debug, Error),
-		    exit(Error);
-		true ->
-		    debug(Debug, {on_load_handler_returned_ok,M}),
-		    run_on_load_handlers(Ms, Debug)
-	    end
-    end;
-run_on_load_handlers([], _) -> ok.
-
+        {'DOWN',Ref,process,Pid,OnLoadRes} ->
+            Keep = OnLoadRes =:= ok,
+            erlang:finish_after_on_load(M, Keep),
+            case Keep of
+                false ->
+                    Error = {on_load_function_failed,M,OnLoadRes},
+                    debug(Debug, Error),
+                    exit(Error);
+                true ->
+                    debug(Debug, {on_load_handler_returned_ok,M})
+            end
+    end.
 
 %% debug profile (light variant of eprof)
 debug_profile_start() ->