Merge pull request #480 from erlang-lager/adt/better-sys-trace

Improve debug tracing support

README.md

@@ -973,6 +973,18 @@ function in a target process by doing
 lager:install_trace(Pid, notice).
 ```
 
+You can also customize the tracing somewhat:
+
+```erlang
+lager:install_trace(Pid, notice, [{count, 100}, {timeout, 5000}, {format_string, "my trace event ~p ~p"]}).
+```
+
+The trace options are currently:
+
+* timeout - how long the trace stays installed: `infinity` (the default) or a millisecond timeout
+* count - how many trace events to log: `infinity` (default) or a positive number
+* format_string - the format string to log the event with. *Must* have 2 format specifiers for the 2 parameters supplied.
+
 This will, on every 'system event' for an OTP process (usually inbound messages, replies
 and state changes) generate a lager message at the specified log level.
 
@@ -982,6 +994,14 @@ You can remove the trace when you're done by doing:
 lager:remove_trace(Pid).
 ```
 
+If you want to start an OTP process with tracing enabled from the very beginning, you can do something like this:
+
+```erlang
+gen_server:start_link(mymodule, [], [{debug, [{install, {fun lager:trace_func/3, lager:trace_state(undefined, notice, [])}}]}]).
+```
+
+The third argument to the trace_state function is the Option list documented above.
+
 Console output to another group leader process
 ----------------------------------------------
 

src/lager.erl

@@ -31,7 +31,7 @@
         md/0, md/1,
         rotate_handler/1, rotate_handler/2, rotate_sink/1, rotate_all/0,
         trace/2, trace/3, trace_file/2, trace_file/3, trace_file/4, trace_console/1, trace_console/2,
-        install_trace/2, remove_trace/1, trace_func/3,
+        install_trace/2, install_trace/3, remove_trace/1, trace_state/3, trace_func/3,
         list_all_sinks/0, clear_all_traces/0, clear_trace_by_destination/1, stop_trace/1, stop_trace/3, status/0,
         get_loglevel/1, get_loglevel/2, set_loglevel/2, set_loglevel/3, set_loglevel/4, get_loglevels/1,
         update_loglevel_config/1, posix_error/1, set_loghwm/2, set_loghwm/3, set_loghwm/4,
@@ -43,12 +43,25 @@
 
 -export_type([log_level/0, log_level_number/0]).
 
+-record(trace_func_state_v1, {
+          pid :: undefined | pid(),
+          level :: log_level(),
+          count :: infinity | pos_integer(),
+          format_string :: string(),
+          timeout :: infinity | pos_integer(),
+          started = os:timestamp() :: erlang:timestamp() %% use os:timestamp for compatability
+         }).
+
 %% API
 
 %% @doc installs a lager trace handler into the target process (using sys:install) at the specified level.
 -spec install_trace(pid(), log_level()) -> ok.
 install_trace(Pid, Level) ->
-    sys:install(Pid, {fun ?MODULE:trace_func/3, {Pid, Level}}).
+    install_trace(Pid, Level, []).
+
+-spec install_trace(pid(), log_level(), [{count, infinity | pos_integer()} | {format_string, string()} | {timeout, timeout()}]) -> ok.
+install_trace(Pid, Level, Options) ->
+    sys:install(Pid, {fun ?MODULE:trace_func/3, trace_state(Pid, Level, Options)}).
 
 %% @doc remove a previously installed lager trace handler from the target process.
 -spec remove_trace(pid()) -> ok.
@@ -677,6 +690,32 @@ rotate_handler(Handler, Sink) ->
     gen_event:call(Sink, Handler, rotate, ?ROTATE_TIMEOUT).
 
 %% @private
-trace_func({Pid, Level}=FuncState, Event, ProcState) ->
-    lager:log(Level, Pid, "TRACE ~p ~p", [Event, ProcState]),
-    FuncState.
+trace_func(#trace_func_state_v1{pid=Pid, level=Level, format_string=Fmt}=FuncState, Event, ProcState) ->
+    lager:log(Level, Pid, Fmt, [Event, ProcState]),
+    check_timeout(decrement_count(FuncState)).
+
+%% @private
+trace_state(Pid, Level, Options) ->
+    #trace_func_state_v1{pid=Pid,
+                         level=Level,
+                         count=proplists:get_value(count, Options, infinity),
+                         timeout=proplists:get_value(timeout, Options, infinity),
+                         format_string=proplists:get_value(format_string, Options, "TRACE ~p ~p")}.
+
+decrement_count(#trace_func_state_v1{count=infinity} = FuncState) ->
+    FuncState;
+decrement_count(#trace_func_state_v1{count=1}) ->
+    %% hit the counter limit
+    done;
+decrement_count(#trace_func_state_v1{count=Count} = FuncState) ->
+    FuncState#trace_func_state_v1{count=Count - 1}.
+
+check_timeout(#trace_func_state_v1{timeout=infinity} = FuncState) ->
+    FuncState;
+check_timeout(#trace_func_state_v1{timeout=Timeout, started=Started} = FuncState) ->
+    case (timer:now_diff(os:timestamp(), Started) / 1000) > Timeout of
+        true ->
+            done;
+        false ->
+            FuncState
+    end.