diff --git a/apps/emqx/src/config/emqx_config_logger.erl b/apps/emqx/src/config/emqx_config_logger.erl index 73b4d0b3b..35f54630f 100644 --- a/apps/emqx/src/config/emqx_config_logger.erl +++ b/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 diff --git a/apps/emqx/src/emqx_logger_jsonfmt.erl b/apps/emqx/src/emqx_logger_jsonfmt.erl index d8dcc77dc..1c4682171 100644 --- a/apps/emqx/src/emqx_logger_jsonfmt.erl +++ b/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 diff --git a/apps/emqx/src/emqx_logger_textfmt.erl b/apps/emqx/src/emqx_logger_textfmt.erl index bbba75c51..f1df7ab76 100644 --- a/apps/emqx/src/emqx_logger_textfmt.erl +++ b/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). diff --git a/apps/emqx/test/emqx_logger_fmt_SUITE.erl b/apps/emqx/test/emqx_logger_fmt_SUITE.erl index 63069fd58..3ab1b443c 100644 --- a/apps/emqx/test/emqx_logger_fmt_SUITE.erl +++ b/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 }. diff --git a/apps/emqx_conf/src/emqx_conf_schema.erl b/apps/emqx_conf/src/emqx_conf_schema.erl index 5c1bab4ff..4c72b74b1 100644 --- a/apps/emqx_conf/src/emqx_conf_schema.erl +++ b/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() -> diff --git a/apps/emqx_conf/test/emqx_conf_schema_tests.erl b/apps/emqx_conf/test/emqx_conf_schema_tests.erl index 4b4dff4cf..80cbf6e11 100644 --- a/apps/emqx_conf/test/emqx_conf_schema_tests.erl +++ b/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 }} ). diff --git a/changes/ce/feat-13348.en.md b/changes/ce/feat-13348.en.md new file mode 100644 index 000000000..0f52ea182 --- /dev/null +++ b/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.