fix: clean up trace messages to make it easier to interpret

This commit removes some redundant trace messages and renames some to
make it easier to interpret what is happening for the user.
This commit is contained in:
Kjell Winblad 2024-04-18 13:50:22 +02:00
parent 3232ab5ea3
commit 8f1486f6d3
3 changed files with 8 additions and 13 deletions

View File

@ -418,9 +418,8 @@ t_send_get_trace_messages(Config) ->
begin begin
Bin = read_rule_trace_file(TraceName, Now), Bin = read_rule_trace_file(TraceName, Now),
?assertNotEqual(nomatch, binary:match(Bin, [<<"rule_activated">>])), ?assertNotEqual(nomatch, binary:match(Bin, [<<"rule_activated">>])),
?assertNotEqual(nomatch, binary:match(Bin, [<<"SELECT_yielded_result">>])), ?assertNotEqual(nomatch, binary:match(Bin, [<<"SQL_yielded_result">>])),
?assertNotEqual(nomatch, binary:match(Bin, [<<"bridge_action">>])), ?assertNotEqual(nomatch, binary:match(Bin, [<<"bridge_action">>])),
?assertNotEqual(nomatch, binary:match(Bin, [<<"action_activated">>])),
?assertNotEqual(nomatch, binary:match(Bin, [<<"action_template_rendered">>])), ?assertNotEqual(nomatch, binary:match(Bin, [<<"action_template_rendered">>])),
?assertNotEqual(nomatch, binary:match(Bin, [<<"QUERY_ASYNC">>])) ?assertNotEqual(nomatch, binary:match(Bin, [<<"QUERY_ASYNC">>]))
end end

View File

@ -132,7 +132,7 @@ apply_rule(Rule = #{id := RuleID}, Columns, Envs) ->
reason => Error, reason => Error,
stacktrace => StkTrace stacktrace => StkTrace
}, },
warning error
), ),
{error, {Error, StkTrace}} {error, {Error, StkTrace}}
after after
@ -176,18 +176,18 @@ do_apply_rule(
{ok, ColumnsAndSelected, FinalCollection} -> {ok, ColumnsAndSelected, FinalCollection} ->
case FinalCollection of case FinalCollection of
[] -> [] ->
trace_rule_sql("FOREACH_yielded_no_result"), trace_rule_sql("SQL_yielded_no_result"),
ok = emqx_metrics_worker:inc(rule_metrics, RuleId, 'failed.no_result'); ok = emqx_metrics_worker:inc(rule_metrics, RuleId, 'failed.no_result');
_ -> _ ->
trace_rule_sql( trace_rule_sql(
"FOREACH_yielded_result", #{result => FinalCollection}, debug "SQL_yielded_result", #{result => FinalCollection}, debug
), ),
ok = emqx_metrics_worker:inc(rule_metrics, RuleId, 'passed') ok = emqx_metrics_worker:inc(rule_metrics, RuleId, 'passed')
end, end,
NewEnvs = maps:merge(ColumnsAndSelected, Envs), NewEnvs = maps:merge(ColumnsAndSelected, Envs),
{ok, [handle_action_list(RuleId, Actions, Coll, NewEnvs) || Coll <- FinalCollection]}; {ok, [handle_action_list(RuleId, Actions, Coll, NewEnvs) || Coll <- FinalCollection]};
false -> false ->
trace_rule_sql("FOREACH_yielded_no_result_no_match"), trace_rule_sql("SQL_yielded_no_result"),
ok = emqx_metrics_worker:inc(rule_metrics, RuleId, 'failed.no_result'), ok = emqx_metrics_worker:inc(rule_metrics, RuleId, 'failed.no_result'),
{error, nomatch} {error, nomatch}
end; end;
@ -204,11 +204,11 @@ do_apply_rule(
) -> ) ->
case evaluate_select(Fields, Columns, Conditions) of case evaluate_select(Fields, Columns, Conditions) of
{ok, Selected} -> {ok, Selected} ->
trace_rule_sql("SELECT_yielded_result", #{result => Selected}, debug), trace_rule_sql("SQL_yielded_result", #{result => Selected}, debug),
ok = emqx_metrics_worker:inc(rule_metrics, RuleId, 'passed'), ok = emqx_metrics_worker:inc(rule_metrics, RuleId, 'passed'),
{ok, handle_action_list(RuleId, Actions, Selected, maps:merge(Columns, Envs))}; {ok, handle_action_list(RuleId, Actions, Selected, maps:merge(Columns, Envs))};
false -> false ->
trace_rule_sql("SELECT_yielded_no_result_no_match"), trace_rule_sql("SQL_yielded_no_result"),
ok = emqx_metrics_worker:inc(rule_metrics, RuleId, 'failed.no_result'), ok = emqx_metrics_worker:inc(rule_metrics, RuleId, 'failed.no_result'),
{error, nomatch} {error, nomatch}
end. end.
@ -392,10 +392,8 @@ handle_action_list(RuleId, Actions, Selected, Envs) ->
handle_action(RuleId, ActId, Selected, Envs) -> handle_action(RuleId, ActId, Selected, Envs) ->
ok = emqx_metrics_worker:inc(rule_metrics, RuleId, 'actions.total'), ok = emqx_metrics_worker:inc(rule_metrics, RuleId, 'actions.total'),
trace_action(ActId, "activating_action"),
try try
Result = do_handle_action(RuleId, ActId, Selected, Envs), Result = do_handle_action(RuleId, ActId, Selected, Envs),
trace_action(ActId, "action_activated", #{result => Result}),
Result Result
catch catch
throw:out_of_service -> throw:out_of_service ->
@ -467,7 +465,6 @@ do_handle_action(RuleId, #{mod := Mod, func := Func} = Action, Selected, Envs) -
Result = Mod:Func(Selected, Envs, Args), Result = Mod:Func(Selected, Envs, Args),
{_, IncCtx} = do_handle_action_get_trace_inc_metrics_context(RuleId, Action), {_, IncCtx} = do_handle_action_get_trace_inc_metrics_context(RuleId, Action),
inc_action_metrics(IncCtx, Result), inc_action_metrics(IncCtx, Result),
trace_action(Action, "call_action_function_result", #{result => Result}, debug),
Result. Result.
do_handle_action_get_trace_inc_metrics_context(RuleID, Action) -> do_handle_action_get_trace_inc_metrics_context(RuleID, Action) ->

View File

@ -128,9 +128,8 @@ basic_apply_rule_test_helper(Config, TraceType, StopAfterRender) ->
Bin = read_rule_trace_file(TraceName, TraceType, Now), Bin = read_rule_trace_file(TraceName, TraceType, Now),
io:format("THELOG:~n~s", [Bin]), io:format("THELOG:~n~s", [Bin]),
?assertNotEqual(nomatch, binary:match(Bin, [<<"rule_activated">>])), ?assertNotEqual(nomatch, binary:match(Bin, [<<"rule_activated">>])),
?assertNotEqual(nomatch, binary:match(Bin, [<<"SELECT_yielded_result">>])), ?assertNotEqual(nomatch, binary:match(Bin, [<<"SQL_yielded_result">>])),
?assertNotEqual(nomatch, binary:match(Bin, [<<"bridge_action">>])), ?assertNotEqual(nomatch, binary:match(Bin, [<<"bridge_action">>])),
?assertNotEqual(nomatch, binary:match(Bin, [<<"action_activated">>])),
?assertNotEqual(nomatch, binary:match(Bin, [<<"action_template_rendered">>])), ?assertNotEqual(nomatch, binary:match(Bin, [<<"action_template_rendered">>])),
?assertNotEqual(nomatch, binary:match(Bin, [<<"QUERY_ASYNC">>])) ?assertNotEqual(nomatch, binary:match(Bin, [<<"QUERY_ASYNC">>]))
end end