Skip to content

Commit 5ef0e1c

Browse files
committed
rabbit_logger_exchange_h: Do not re-enter itself
[Why] Publishing a log message to an exchange might trigger other messages to be logged. This caused two issues: 1. the exchange logger re-entering itself in an infinite loop 2. if the message is logged from a gen_server-like process, like a Ra server, that is involved in the publishing code path, the process might call itself, leading to a blocked situation [How] The first issue is fixed with a variable stored in the process dictionary by the `log/2` function. This way, the function can check if it is called from itself because the first incantation stored a variable there. The second issue is fixed by publishing the message asynchronously from a separate process. This is ok because we don't care if the publish was successful or not. We re-use the process that was started initially to declare the exchange. Fixes #14069.
1 parent f412512 commit 5ef0e1c

File tree

1 file changed

+32
-7
lines changed

1 file changed

+32
-7
lines changed

deps/rabbit/src/rabbit_logger_exchange_h.erl

Lines changed: 32 additions & 7 deletions
Original file line numberDiff line numberDiff line change
@@ -43,8 +43,16 @@ filter_config(Config) ->
4343
log(#{meta := #{mfa := {?MODULE, _, _}}}, _) ->
4444
ok;
4545
log(LogEvent, Config) ->
46+
%% Publishing the log message to an exchange might trigger more logging,
47+
%% triggering an infinite logging loop. To prevent that, we make use the
48+
%% process dictionary to record the fact that this logger was already
49+
%% entered. If that's the case when this function is called, we just drop
50+
%% the log event.
51+
Key = ?MODULE,
52+
ReEntered = erlang:get(Key) =/= undefined,
4653
case rabbit_boot_state:get() of
47-
ready ->
54+
ready when not ReEntered ->
55+
erlang:put(Key, ?FUNCTION_NAME),
4856
try
4957
do_log(LogEvent, Config)
5058
catch
@@ -53,22 +61,29 @@ log(LogEvent, Config) ->
5361
%% removes the logger_exchange handler, which in
5462
%% turn deletes the log exchange and its bindings
5563
erlang:display({?MODULE, crashed, {C, R, S}})
64+
after
65+
erlang:erase(Key)
5666
end,
5767
ok;
5868
_ -> ok
5969
end.
6070

61-
do_log(LogEvent, #{config := #{exchange := Exchange}} = Config) ->
71+
do_log(
72+
LogEvent,
73+
#{config := #{exchange := Exchange,
74+
setup_proc := Pid}} = Config) ->
6275
RoutingKey = make_routing_key(LogEvent, Config),
6376
PBasic = log_event_to_amqp_msg(LogEvent, Config),
6477
Body = try_format_body(LogEvent, Config),
6578
Content = rabbit_basic:build_content(PBasic, Body),
6679
case mc_amqpl:message(Exchange, RoutingKey, Content) of
6780
{ok, Msg} ->
68-
case rabbit_queue_type:publish_at_most_once(Exchange, Msg) of
69-
ok -> ok;
70-
{error, not_found} -> ok
71-
end;
81+
%% Publishing a message might involve a Erlang process, like a Ra
82+
%% server process, to log something and call itself. We need to
83+
%% publish the message asynchronously from a separate process and
84+
%% ignore the fate of that publish, to not block an Erlang
85+
%% process.
86+
Pid ! {publish, Msg};
7287
{error, _Reason} ->
7388
%% it would be good to log this error but can we?
7489
ok
@@ -169,7 +184,8 @@ setup_proc(
169184
ok ->
170185
?LOG_INFO(
171186
"Logging to ~ts ready", [rabbit_misc:rs(Exchange)],
172-
#{domain => ?RMQLOG_DOMAIN_GLOBAL});
187+
#{domain => ?RMQLOG_DOMAIN_GLOBAL}),
188+
loop(Config);
173189
error ->
174190
?LOG_DEBUG(
175191
"Logging to ~ts not ready, trying again in ~b second(s)",
@@ -182,6 +198,15 @@ setup_proc(
182198
end
183199
end.
184200

201+
loop(#{config := #{exchange := Exchange}} = Config) ->
202+
receive
203+
{publish, Msg} ->
204+
_ = rabbit_queue_type:publish_at_most_once(Exchange, Msg),
205+
loop(Config);
206+
stop ->
207+
ok
208+
end.
209+
185210
declare_exchange(#{config := #{exchange := Exchange}}) ->
186211
try rabbit_exchange:declare(
187212
Exchange, topic, true, false, true, [], ?INTERNAL_USER) of

0 commit comments

Comments
 (0)