Merge pull request #4561 from esl/tomas/log-large-structs

Refactor logging to use `c2s_data` consistently in log messages

Author: chrzaszcz

src/c2s/mongoose_c2s.erl

@@ -444,7 +444,7 @@ handle_sasl_success(StateData = #c2s_data{jid = MaybeInitialJid, info = Info}, S
                                             info = maps:merge(Info, #{auth_module => AuthMod})},
             El = mongoose_c2s_stanzas:sasl_success_stanza(MaybeServerOut),
             send_acc_from_server_jid(StateData1, SaslAcc, El),
-            ?LOG_INFO(#{what => auth_success, text => <<"Accepted SASL authentication">>, c2s_state => StateData1}),
+            ?LOG_INFO(#{what => auth_success, text => <<"Accepted SASL authentication">>, c2s_data => StateData1}),
             {next_state, {wait_for_stream, authenticated}, StateData1, state_timeout(StateData1)};
         false ->
             c2s_stream_error(StateData, mongoose_xmpp_errors:invalid_from())
@@ -551,7 +551,7 @@ verify_user(wait_for_session_establishment, _, _, Acc) ->
 verify_user(session_established, HostType, #{c2s_data := StateData} = HookParams, Acc) ->
     case mongoose_c2s_hooks:user_open_session(HostType, Acc, HookParams) of
         {ok, Acc1} ->
-            ?LOG_INFO(#{what => c2s_opened_session, c2s_state => StateData}),
+            ?LOG_INFO(#{what => c2s_opened_session, c2s_data => StateData}),
             {ok, Acc1};
         {stop, Acc1} ->
             Jid = StateData#c2s_data.jid,
@@ -689,7 +689,7 @@ verify_process_alive(StateData, C2SState, Pid) ->
         true ->
             ?LOG_WARNING(#{what => c2s_replaced_wait_timeout,
                            text => <<"Some processes are not responding when handling replace messages">>,
-                           replaced_pid => Pid, state_name => C2SState, c2s_state => StateData})
+                           replaced_pid => Pid, state_name => C2SState, c2s_data => StateData})
     end.
 
 -spec maybe_retry_state(state()) -> state() | {stop, term()}.
@@ -914,7 +914,7 @@ send_trailer(StateData) ->
 
 -spec c2s_stream_error(data(), exml:element()) -> fsm_res().
 c2s_stream_error(StateData, Error) ->
-    ?LOG_DEBUG(#{what => c2s_stream_error, xml_error => Error, c2s_state => StateData}),
+    ?LOG_DEBUG(#{what => c2s_stream_error, xml_error => Error, c2s_data => StateData}),
     send_element_from_server_jid(StateData, Error),
     send_xml(StateData, ?XML_STREAM_TRAILER),
     {stop, {shutdown, stream_error}, StateData}.

src/logger/mongoose_log_filter.erl

@@ -29,13 +29,26 @@ fill_metadata_filter(Event, _) ->
     Event.
 
 format_c2s_state_filter(Event=#{msg := {report, Msg=#{c2s_data := State}}}, _) ->
-    StateMap = filter_undefined(c2s_data_to_map(State)),
-    %% C2S fields have lower priority, if the field is already present in msg.
-    Msg2 = maps:merge(StateMap, maps:remove(c2s_data, Msg)),
-    Event#{msg => {report, Msg2}};
+    do_format_c2s_state(Event, Msg, State, c2s_data);
+%% Backward compatibility for logs that incorrectly use c2s_state key for StateData
+format_c2s_state_filter(Event=#{msg := {report, Msg=#{c2s_state := State}}}, _) ->
+    try
+        do_format_c2s_state(Event, Msg, State, c2s_state)
+    catch
+        _:_ ->
+            %% Not a c2s_data record, leave as is
+            Event
+    end;
 format_c2s_state_filter(Event, _) ->
     Event.
 
+%% Helper function to format c2s state data
+do_format_c2s_state(Event, Msg, State, KeyToRemove) ->
+    StateMap = filter_undefined(c2s_data_to_map(State)),
+    %% C2S fields have lower priority, if the field is already present in msg.
+    Msg2 = maps:merge(StateMap, maps:remove(KeyToRemove, Msg)),
+    Event#{msg => {report, Msg2}}.
+
 format_acc_filter(Event=#{msg := {report, Msg=#{acc := Acc}}}, _) ->
     FormattedAcc = format_acc(Acc),
     Msg2 = maps:merge(FormattedAcc, maps:remove(acc, Msg)),

src/mod_presence.erl

@@ -507,7 +507,7 @@ presence_broadcast_to_trusted(Acc, FromJid, Presences, Packet) ->
 
 -spec resend_offline_messages(mongoose_acc:t(), mongoose_c2s:data()) -> mongoose_acc:t().
 resend_offline_messages(Acc, StateData) ->
-    ?LOG_DEBUG(#{what => resend_offline_messages, acc => Acc, c2s_state => StateData}),
+    ?LOG_DEBUG(#{what => resend_offline_messages, acc => Acc, c2s_data => StateData}),
     Jid = mongoose_c2s:get_jid(StateData),
     Acc1 = mongoose_hooks:resend_offline_messages(Acc, Jid),
     Rs = mongoose_acc:get(offline, messages, [], Acc1),

src/stream_management/mod_stream_management.erl

@@ -454,7 +454,7 @@ handle_stream_mgmt(Acc, _Params, _El) ->
 handle_r(Acc, #{c2s_data := StateData}) ->
     case get_mod_state(StateData) of
         {error, not_found} ->
-            ?LOG_WARNING(#{what => unexpected_r, c2s_state => StateData,
+            ?LOG_WARNING(#{what => unexpected_r, c2s_data => StateData,
                            text => <<"received <r/> but stream management is off!">>}),
             {ok, Acc};
         #sm_state{counter_in = In} ->

test/mongoose_log_filter_SUITE.erl

@@ -0,0 +1,45 @@
+-module(mongoose_log_filter_SUITE).
+
+-include_lib("common_test/include/ct.hrl").
+-include_lib("eunit/include/eunit.hrl").
+
+-export([all/0, init_per_testcase/2, end_per_testcase/2]).
+-export([
+    format_c2s_state_with_invalid_c2s_state/1,
+    format_c2s_state_with_no_c2s_keys/1
+]).
+
+all() ->
+    [
+        format_c2s_state_with_invalid_c2s_state,
+        format_c2s_state_with_no_c2s_keys
+    ].
+
+init_per_testcase(_TestCase, Config) ->
+    Config.
+
+end_per_testcase(_TestCase, _Config) ->
+    ok.
+
+format_c2s_state_with_invalid_c2s_state(_Config) ->
+    % Test the backward compatibility path with invalid c2s_state data
+    % This tests the try-catch block that should prevent crashes
+    Event = #{
+        msg => {report, #{what => test_invalid, c2s_state => <<"not_a_record">>}}
+    },
+    
+    Result = mongoose_log_filter:format_c2s_state_filter(Event, no_state),
+    
+    % The result should be unchanged when c2s_state contains invalid data
+    ?assertEqual(Event, Result).
+
+format_c2s_state_with_no_c2s_keys(_Config) ->
+    % Test when there are no c2s_data or c2s_state keys
+    Event = #{
+        msg => {report, #{what => test_no_c2s}}
+    },
+    
+    Result = mongoose_log_filter:format_c2s_state_filter(Event, no_state),
+    
+    % The result should be unchanged
+    ?assertEqual(Event, Result).