Merge pull request #1251 from basho/at-rt-redbug

redbug tracing in riak test

Author: Andy Till

README.md

@@ -356,6 +356,30 @@ you add them via one of the methods listed previously.
 
     {load_intercepts, false}
 
+### Adding Tracing to Nodes Under Test
+
+Erlang Tracing can be added to test suites to trace function calls on
+nodes under test. By default, trace calls will not execute without the
+`riak_test` tracing command line argument
+
+```shell
+--trace
+```
+
+To add tracing to target nodes, make a call to the `rt_redbug:trace/2`
+function. `Nodes` is a single node name or a list of node names that the
+trace should be applied to. The second argument is a string or list of
+string traces using the redbug syntax.  An arity three function is also
+exported that takes options as defined in the redbug docs.
+
+```erlang
+rt_redbug:trace(Nodes, ["module:function"])
+```
+
+Tracing is output to the terminal and `test.log` file. More documentation on
+redbug can be found
+[here](https://github.com/massemanet/eper/blob/master/doc/redbug.txt).
+
 #### Config
 
 Here is how you would add the `dropped_put` intercept via the config.

src/riak_test_escript.erl

@@ -44,7 +44,8 @@ cli_options() ->
  {upgrade_version,    $u, "upgrade",  atom,       "which version to upgrade from [ previous | legacy ]"},
  {keep,        undefined, "keep",     boolean,    "do not teardown cluster"},
  {report,             $r, "report",   string,     "you're reporting an official test run, provide platform info (e.g. ubuntu-1204-64)\nUse 'config' if you want to pull from ~/.riak_test.config"},
- {file,               $F, "file",     string,     "use the specified file instead of ~/.riak_test.config"}
+ {file,               $F, "file",     string,     "use the specified file instead of ~/.riak_test.config"},
+ {apply_traces,undefined, "trace",    undefined,  "Apply traces to the target node, defined in the SUITEs"}
 ].
 
 print_help() ->
@@ -210,6 +211,11 @@ parse_command_line_tests(ParsedArgs) ->
                    [] -> [undefined];
                    UpgradeList -> UpgradeList
                end,
+    %% this is a little ugly, the process that creates the ets table to store
+    %% the tracing state cannot shutdown or the table will be gc'ed, so create
+    %% a dummy proc that doens't die
+    rt_redbug:new(),
+    rt_redbug:set_tracing_applied(proplists:is_defined(apply_traces, ParsedArgs)),
     %% Parse Command Line Tests
     {CodePaths, SpecificTests} =
         lists:foldl(fun extract_test_names/2,

src/rt_redbug.erl

@@ -0,0 +1,115 @@
+%% -------------------------------------------------------------------
+%%
+%% Copyright (c) 2016 Basho Technologies, Inc.
+%%
+%% This file is provided to you under the Apache License,
+%% Version 2.0 (the "License"); you may not use this file
+%% except in compliance with the License.  You may obtain
+%% a copy of the License at
+%%
+%%   http://www.apache.org/licenses/LICENSE-2.0
+%%
+%% Unless required by applicable law or agreed to in writing,
+%% software distributed under the License is distributed on an
+%% "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY
+%% KIND, either express or implied.  See the License for the
+%% specific language governing permissions and limitations
+%% under the License.
+%%
+%% Enable and disable tracing from the riak_test command line,
+%% add `--tracing` to the test run to execute any calls to
+%% `rt_redbug:trace/2` that are in the test suites. The traces
+%% are printed to the test.log
+%%
+%% -------------------------------------------------------------------
+
+-module(rt_redbug).
+
+-export([is_tracing_applied/0]).
+-export([new/0]).
+-export([set_tracing_applied/1]).
+-export([stop/1]).
+-export([trace/2, trace/3]).
+
+%% Create a new ets to store globally whether we're tracing or not.
+new() -> 
+    ok.
+
+set_tracing_applied(TracingApplied) when is_boolean(TracingApplied) ->
+    lager:info("Setting apply tracing to ~p", [TracingApplied]),
+    rt_config:set(apply_traces, TracingApplied).
+
+is_tracing_applied() ->
+    rt_config:get(apply_traces).
+
+%% Apply traces to one or more nodes using redbug tracing and syntax.
+%%
+%% eper documentation for the redbug trace string and options is here:
+%%
+%% https://github.com/massemanet/eper/blob/master/doc/redbug.txt
+%%
+%% docs on profiling using redbug (for test timeouts) is here:
+%%
+%% http://roberto-aloi.com/erlang/profiling-erlang-applications-using-redbug
+%%
+%% Set a trace on a function
+%%     rt_redbug:trace(Node, "riak_kv_qry_compiler:compile").
+%%     rt_redbug:trace(Node, ["riak_kv_qry_compiler:compile", "riak_ql_parser:parse"]).
+%%
+%% Multiple traces can be set in one call. Calling the `rt_redbug:trace`
+%% function a second time stops the traces started by the first call.
+%%
+%% Traces can be stopped by calling `rt_redbug:stop(Nodes)` with the nodes in
+%% the test cluster. This is important if there are multiple tests in the same
+%% suite, but not if the cluster is torn down at the end of the suite.
+trace(Nodes, TraceStrings) ->
+    trace(Nodes, TraceStrings, []).
+
+trace(Nodes, TraceStrings, Options1) when (is_atom(Nodes) orelse is_list(Nodes)) ->
+    case is_tracing_applied() of
+        true ->
+            Options2 = apply_options_to_defaults(Options1),
+            [apply_trace(N, TraceStrings, Options2) || N <- ensure_list(Nodes)],
+            ok;
+        false ->
+            ok
+    end.
+
+%%
+apply_trace(Node, TraceString, Options) ->
+    rpc:call(Node, redbug, start, [TraceString, Options]).
+
+%%
+apply_options_to_defaults(Options) ->
+    lists:foldl(
+        fun({K,_} = E,Acc) ->
+            lists:keystore(K, 1, Acc, E)
+        end, default_trace_options(), Options).
+
+%%
+default_trace_options() ->
+    [
+     %% default ct timeout of 30 minutes
+     %% http://erlang.org/doc/apps/common_test/write_test_chapter.html#id77922
+     {time,(30*60*1000)},
+     %% raise the threshold for the number of traces that can be received by
+     %% redbug before tracing is suspended
+     {msgs, 1000},
+     %% print milliseconds
+     {print_msec, true}
+    ].
+
+%% Stop redbug tracing on a node or list of nodes
+stop(Nodes) ->
+    case is_tracing_applied() of
+        true ->
+            [rpc:call(N, redbug, stop, []) || N <- ensure_list(Nodes)],
+            ok;
+        false ->
+            ok
+    end.
+
+%% Doesn't work on lists of strings!
+ensure_list(V) ->
+    lists:flatten([V]).
+