From 3c87bcde46f3827bc7bbbe5294f1f0c181869193 Mon Sep 17 00:00:00 2001 From: Kjell Winblad Date: Mon, 20 May 2024 10:57:15 +0200 Subject: [PATCH] fix(rule trace): restore logger metadata to its previous value --- .../src/emqx_resource_buffer_worker.erl | 27 ++++--------- .../src/emqx_rule_runtime.erl | 30 ++++----------- .../src/emqx_rule_sqltester.erl | 38 ++++++++++--------- 3 files changed, 34 insertions(+), 61 deletions(-) diff --git a/apps/emqx_resource/src/emqx_resource_buffer_worker.erl b/apps/emqx_resource/src/emqx_resource_buffer_worker.erl index 285bc57b6..5f269c112 100644 --- a/apps/emqx_resource/src/emqx_resource_buffer_worker.erl +++ b/apps/emqx_resource/src/emqx_resource_buffer_worker.erl @@ -1174,12 +1174,13 @@ call_query(QM, Id, Index, Ref, Query, QueryOpts) -> {ok, _Group, #{status := ?status_connecting, error := unhealthy_target}} -> {error, {unrecoverable_error, unhealthy_target}}; {ok, _Group, Resource} -> + PrevLoggerProcessMetadata = logger:get_process_metadata(), QueryResult = try set_rule_id_trace_meta_data(Query), do_call_query(QM, Id, Index, Ref, Query, QueryOpts, Resource) after - unset_rule_id_trace_meta_data() + reset_logger_process_metadata(PrevLoggerProcessMetadata) end, QueryResult; {error, not_found} -> @@ -1216,6 +1217,11 @@ set_rule_id_trace_meta_data(Request) -> set_rule_id_trace_meta_data([Request]), ok. +reset_logger_process_metadata(undefined = _PrevProcessMetadata) -> + logger:unset_process_metadata(); +reset_logger_process_metadata(PrevProcessMetadata) -> + logger:set_process_metadata(PrevProcessMetadata). + collect_rule_id(?QUERY(_, _, _, _, #{rule_id := RuleId}), Acc) -> Acc#{RuleId => true}; collect_rule_id(?QUERY(_, _, _, _, _), Acc) -> @@ -1231,25 +1237,6 @@ collect_rule_trigger_times(?QUERY(_, _, _, _, #{rule_trigger_ts := Time}), Acc) collect_rule_trigger_times(?QUERY(_, _, _, _, _), Acc) -> Acc. -unset_rule_id_trace_meta_data() -> - case logger:get_process_metadata() of - undefined -> - ok; - OldLoggerProcessMetadata -> - NewLoggerProcessMetadata = - maps:without( - [ - rule_ids, - client_ids, - stop_action_after_render, - rule_trigger_ts - ], - OldLoggerProcessMetadata - ), - logger:set_process_metadata(NewLoggerProcessMetadata), - ok - end. - %% action:kafka_producer:myproducer1:connector:kafka_producer:mykakfaclient1 extract_connector_id(Id) when is_binary(Id) -> case binary:split(Id, <<":">>, [global]) of diff --git a/apps/emqx_rule_engine/src/emqx_rule_runtime.erl b/apps/emqx_rule_engine/src/emqx_rule_runtime.erl index 25c5e846b..003a2b5a3 100644 --- a/apps/emqx_rule_engine/src/emqx_rule_runtime.erl +++ b/apps/emqx_rule_engine/src/emqx_rule_runtime.erl @@ -70,6 +70,7 @@ apply_rule_discard_result(Rule, Columns, Envs) -> ok. apply_rule(Rule = #{id := RuleID}, Columns, Envs) -> + PrevProcessMetadata = logger:get_process_metadata(), set_process_trace_metadata(RuleID, Columns), trace_rule_sql( "rule_activated", @@ -137,7 +138,7 @@ apply_rule(Rule = #{id := RuleID}, Columns, Envs) -> ), {error, {Error, StkTrace}} after - reset_process_trace_metadata(Columns) + reset_logger_process_metadata(PrevProcessMetadata) end. set_process_trace_metadata(RuleID, #{clientid := ClientID} = Columns) -> @@ -152,6 +153,11 @@ set_process_trace_metadata(RuleID, Columns) -> rule_trigger_ts => [rule_trigger_time(Columns)] }). +reset_logger_process_metadata(undefined = _PrevProcessMetadata) -> + logger:unset_process_metadata(); +reset_logger_process_metadata(PrevProcessMetadata) -> + logger:set_process_metadata(PrevProcessMetadata). + rule_trigger_time(Columns) -> case Columns of #{timestamp := Timestamp} -> @@ -160,28 +166,6 @@ rule_trigger_time(Columns) -> erlang:system_time(millisecond) end. -reset_process_trace_metadata(#{clientid := _ClientID}) -> - Meta0 = logger:get_process_metadata(), - Meta1 = maps:without( - [ - clientid, - rule_id, - rule_trigger_ts - ], - Meta0 - ), - logger:set_process_metadata(Meta1); -reset_process_trace_metadata(_) -> - Meta0 = logger:get_process_metadata(), - Meta1 = maps:without( - [ - rule_id, - rule_trigger_ts - ], - Meta0 - ), - logger:set_process_metadata(Meta1). - do_apply_rule( #{ id := RuleId, diff --git a/apps/emqx_rule_engine/src/emqx_rule_sqltester.erl b/apps/emqx_rule_engine/src/emqx_rule_sqltester.erl index 449b8f52d..90a717930 100644 --- a/apps/emqx_rule_engine/src/emqx_rule_sqltester.erl +++ b/apps/emqx_rule_engine/src/emqx_rule_sqltester.erl @@ -69,18 +69,22 @@ do_apply_rule( end. do_apply_matched_rule(Rule, Context, StopAfterRender, EventTopics) -> - update_process_trace_metadata(StopAfterRender), - FullContext = fill_default_values( - hd(EventTopics), - emqx_rule_maps:atom_key_map(Context) - ), - ApplyRuleRes = emqx_rule_runtime:apply_rule( - Rule, - FullContext, - apply_rule_environment() - ), - reset_trace_process_metadata(StopAfterRender), - ApplyRuleRes. + PrevLoggerProcessMetadata = logger:get_process_metadata(), + try + update_process_trace_metadata(StopAfterRender), + FullContext = fill_default_values( + hd(EventTopics), + emqx_rule_maps:atom_key_map(Context) + ), + ApplyRuleRes = emqx_rule_runtime:apply_rule( + Rule, + FullContext, + apply_rule_environment() + ), + ApplyRuleRes + after + reset_logger_process_metadata(PrevLoggerProcessMetadata) + end. update_process_trace_metadata(true = _StopAfterRender) -> logger:update_process_metadata(#{ @@ -89,12 +93,10 @@ update_process_trace_metadata(true = _StopAfterRender) -> update_process_trace_metadata(false = _StopAfterRender) -> ok. -reset_trace_process_metadata(true = _StopAfterRender) -> - Meta = logger:get_process_metadata(), - NewMeta = maps:remove(stop_action_after_render, Meta), - logger:set_process_metadata(NewMeta); -reset_trace_process_metadata(false = _StopAfterRender) -> - ok. +reset_logger_process_metadata(undefined = _PrevProcessMetadata) -> + logger:unset_process_metadata(); +reset_logger_process_metadata(PrevProcessMetadata) -> + logger:set_process_metadata(PrevProcessMetadata). %% At the time of writing the environment passed to the apply rule function is %% not used at all for normal actions. When it is used for custom functions it