Merge pull request #13348 from lafirest/fix/drop_payload

feat(log): allows custom the encoding of payload in the log

apps/emqx/src/config/emqx_config_logger.erl

@@ -238,8 +238,9 @@ log_formatter(HandlerName, Conf) ->
                 conf_get("formatter", Conf)
         end,
     TsFormat = timstamp_format(Conf),
+    PayloadEncode = conf_get("payload_encode", Conf, text),
     do_formatter(
-        Format, CharsLimit, SingleLine, TimeOffSet, Depth, TsFormat
+        Format, CharsLimit, SingleLine, TimeOffSet, Depth, TsFormat, PayloadEncode
     ).
 
 %% auto | epoch | rfc3339
@@ -247,22 +248,24 @@ timstamp_format(Conf) ->
     conf_get("timestamp_format", Conf).
 
 %% helpers
-do_formatter(json, CharsLimit, SingleLine, TimeOffSet, Depth, TsFormat) ->
+do_formatter(json, CharsLimit, SingleLine, TimeOffSet, Depth, TsFormat, PayloadEncode) ->
     {emqx_logger_jsonfmt, #{
         chars_limit => CharsLimit,
         single_line => SingleLine,
         time_offset => TimeOffSet,
         depth => Depth,
-        timestamp_format => TsFormat
+        timestamp_format => TsFormat,
+        payload_encode => PayloadEncode
     }};
-do_formatter(text, CharsLimit, SingleLine, TimeOffSet, Depth, TsFormat) ->
+do_formatter(text, CharsLimit, SingleLine, TimeOffSet, Depth, TsFormat, PayloadEncode) ->
     {emqx_logger_textfmt, #{
         template => ["[", level, "] ", msg, "\n"],
         chars_limit => CharsLimit,
         single_line => SingleLine,
         time_offset => TimeOffSet,
         depth => Depth,
-        timestamp_format => TsFormat
+        timestamp_format => TsFormat,
+        payload_encode => PayloadEncode
     }}.
 
 %% Don't record all logger message

apps/emqx/src/emqx_logger_jsonfmt.erl

@@ -55,7 +55,8 @@
     depth => pos_integer() | unlimited,
     report_cb => logger:report_cb(),
     single_line => boolean(),
-    chars_limit => unlimited | pos_integer()
+    chars_limit => unlimited | pos_integer(),
+    payload_encode => text | hidden | hex
 }.
 
 -define(IS_STRING(String), (is_list(String) orelse is_binary(String))).
@@ -103,7 +104,8 @@ format(Msg, Meta, Config) ->
 
 maybe_format_msg(undefined, _Meta, _Config) ->
     #{};
-maybe_format_msg({report, Report} = Msg, #{report_cb := Cb} = Meta, Config) ->
+maybe_format_msg({report, Report0} = Msg, #{report_cb := Cb} = Meta, Config) ->
+    Report = emqx_logger_textfmt:try_encode_payload(Report0, Config),
     case is_map(Report) andalso Cb =:= ?DEFAULT_FORMATTER of
         true ->
             %% reporting a map without a customised format function

apps/emqx/src/emqx_logger_textfmt.erl

@@ -20,11 +20,12 @@
 
 -export([format/2]).
 -export([check_config/1]).
--export([try_format_unicode/1]).
+-export([try_format_unicode/1, try_encode_payload/2]).
 %% Used in the other log formatters
 -export([evaluate_lazy_values_if_dbg_level/1, evaluate_lazy_values/1]).
 
-check_config(X) -> logger_formatter:check_config(maps:without([timestamp_format], X)).
+check_config(X) ->
+    logger_formatter:check_config(maps:without([timestamp_format, payload_encode], X)).
 
 %% Principle here is to delegate the formatting to logger_formatter:format/2
 %% as much as possible, and only enrich the report with clientid, peername, topic, username
@@ -32,7 +33,7 @@ format(#{msg := {report, ReportMap0}, meta := _Meta} = Event0, Config) when is_m
     #{msg := {report, ReportMap}, meta := Meta} = Event = evaluate_lazy_values_if_dbg_level(Event0),
     %% The most common case, when entering from SLOG macro
     %% i.e. logger:log(Level, #{msg => "my_msg", foo => bar})
-    ReportList = enrich_report(ReportMap, Meta),
+    ReportList = enrich_report(ReportMap, Meta, Config),
     Report =
         case is_list_report_acceptable(Meta) of
             true ->
@@ -101,9 +102,10 @@ is_list_report_acceptable(#{report_cb := Cb}) ->
 is_list_report_acceptable(_) ->
     false.
 
-enrich_report(ReportRaw, Meta) ->
+enrich_report(ReportRaw0, Meta, Config) ->
     %% clientid and peername always in emqx_conn's process metadata.
     %% topic and username can be put in meta using ?SLOG/3, or put in msg's report by ?SLOG/2
+    ReportRaw = try_encode_payload(ReportRaw0, Config),
     Topic =
         case maps:get(topic, Meta, undefined) of
             undefined -> maps:get(topic, ReportRaw, undefined);
@@ -169,3 +171,15 @@ enrich_topic({Fmt, Args}, #{topic := Topic}) when is_list(Fmt) ->
     {" topic: ~ts" ++ Fmt, [Topic | Args]};
 enrich_topic(Msg, _) ->
     Msg.
+
+try_encode_payload(#{payload := Payload} = Report, #{payload_encode := Encode}) ->
+    Report#{payload := encode_payload(Payload, Encode)};
+try_encode_payload(Report, _Config) ->
+    Report.
+
+encode_payload(Payload, text) ->
+    Payload;
+encode_payload(_Payload, hidden) ->
+    "******";
+encode_payload(Payload, hex) ->
+    binary:encode_hex(Payload).

apps/emqx/test/emqx_logger_fmt_SUITE.erl

@@ -36,12 +36,18 @@ t_text_fmt_lazy_values(_) ->
 t_text_fmt_lazy_values_only_in_debug_level_events(_) ->
     check_fmt_lazy_values_only_in_debug_level_events(emqx_logger_textfmt).
 
+t_text_payload(_) ->
+    check_fmt_payload(emqx_logger_textfmt).
+
 t_json_fmt_lazy_values(_) ->
     check_fmt_lazy_values(emqx_logger_jsonfmt).
 
 t_json_fmt_lazy_values_only_in_debug_level_events(_) ->
     check_fmt_lazy_values_only_in_debug_level_events(emqx_logger_jsonfmt).
 
+t_json_payload(_) ->
+    check_fmt_payload(emqx_logger_jsonfmt).
+
 check_fmt_lazy_values(FormatModule) ->
     LogEntryIOData = FormatModule:format(event_with_lazy_value(), conf()),
     LogEntryBin = unicode:characters_to_binary(LogEntryIOData),
@@ -62,6 +68,18 @@ check_fmt_lazy_values_only_in_debug_level_events(FormatModule) ->
     ?assertNotEqual(nomatch, binary:match(LogEntryBin, [<<"emqx_trace_format_func_data">>])),
     ok.
 
+check_fmt_payload(FormatModule) ->
+    %% For performace reason we only search for lazy values to evaluate if log level is debug
+    WarningEvent = (event_with_lazy_value())#{level => info},
+    Conf = conf(),
+    LogEntryIOData = FormatModule:format(WarningEvent, Conf#{payload_encode => hidden}),
+    LogEntryBin = unicode:characters_to_binary(LogEntryIOData),
+    %% The input data for the formatting should exist
+    ?assertEqual(nomatch, binary:match(LogEntryBin, [<<"content">>])),
+    %% The lazy value should not have been evaluated
+    ?assertNotEqual(nomatch, binary:match(LogEntryBin, [<<"******">>])),
+    ok.
+
 conf() ->
     #{
         time_offset => [],
@@ -84,7 +102,8 @@ event_with_lazy_value() ->
             {report, #{
                 reason =>
                     #emqx_trace_format_func_data{function = fun(Data) -> Data end, data = hej},
-                msg => hej
+                msg => hej,
+                payload => <<"content">>
             }},
         level => debug
     }.

apps/emqx_conf/src/emqx_conf_schema.erl

@@ -1358,7 +1358,13 @@ log_handler_common_confs(Handler, Default) ->
                     desc => ?DESC("common_handler_max_depth"),
                     importance => ?IMPORTANCE_HIDDEN
                 }
-            )}
+            )},
+        {"payload_encode",
+            sc(hoconsc:enum([hex, text, hidden]), #{
+                default => text,
+                importance => ?IMPORTANCE_HIDDEN,
+                desc => ?DESC(emqx_schema, fields_trace_payload_encode)
+            })}
     ].
 
 crash_dump_file_default() ->

apps/emqx_conf/test/emqx_conf_schema_tests.erl

@@ -133,7 +133,8 @@ log.file_handlers {
         single_line => true,
         template => ["[", level, "] ", msg, "\n"],
         time_offset => TimeOffset,
-        timestamp_format => auto
+        timestamp_format => auto,
+        payload_encode => text
     }}
 ).
 

changes/ce/feat-13348.en.md

@@ -0,0 +1 @@
+Added a new field `payload_encode` to the log configuration to determine the format of the payload in the log data.