From 74c346f9d1c063e529bbcf419096610ccdbd18ef Mon Sep 17 00:00:00 2001 From: firest Date: Fri, 2 Aug 2024 12:00:36 +0800 Subject: [PATCH] fix(log): respect payload encoding settings when formatting packets --- apps/emqx/include/logger.hrl | 2 +- apps/emqx/src/emqx_logger_jsonfmt.erl | 2 +- apps/emqx/src/emqx_logger_textfmt.erl | 24 +++++-- apps/emqx/src/emqx_packet.erl | 5 -- .../src/emqx_trace/emqx_trace_formatter.erl | 5 -- apps/emqx/src/emqx_ws_connection.erl | 2 +- apps/emqx/test/emqx_packet_SUITE.erl | 72 ++++++++++++------- 7 files changed, 67 insertions(+), 45 deletions(-) diff --git a/apps/emqx/include/logger.hrl b/apps/emqx/include/logger.hrl index a7455418d..4cda2d8af 100644 --- a/apps/emqx/include/logger.hrl +++ b/apps/emqx/include/logger.hrl @@ -88,7 +88,7 @@ ?_DO_TRACE(Tag, Msg, Meta), ?SLOG( Level, - (emqx_trace_formatter:format_meta_map(Meta))#{msg => Msg, tag => Tag}, + (Meta)#{msg => Msg, tag => Tag}, #{is_trace => false} ) end). diff --git a/apps/emqx/src/emqx_logger_jsonfmt.erl b/apps/emqx/src/emqx_logger_jsonfmt.erl index 1c4682171..54c88018c 100644 --- a/apps/emqx/src/emqx_logger_jsonfmt.erl +++ b/apps/emqx/src/emqx_logger_jsonfmt.erl @@ -105,7 +105,7 @@ format(Msg, Meta, Config) -> maybe_format_msg(undefined, _Meta, _Config) -> #{}; maybe_format_msg({report, Report0} = Msg, #{report_cb := Cb} = Meta, Config) -> - Report = emqx_logger_textfmt:try_encode_payload(Report0, Config), + Report = emqx_logger_textfmt:try_encode_meta(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 f1df7ab76..c1084142f 100644 --- a/apps/emqx/src/emqx_logger_textfmt.erl +++ b/apps/emqx/src/emqx_logger_textfmt.erl @@ -20,7 +20,7 @@ -export([format/2]). -export([check_config/1]). --export([try_format_unicode/1, try_encode_payload/2]). +-export([try_format_unicode/1, try_encode_meta/2]). %% Used in the other log formatters -export([evaluate_lazy_values_if_dbg_level/1, evaluate_lazy_values/1]). @@ -105,7 +105,7 @@ is_list_report_acceptable(_) -> 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), + ReportRaw = try_encode_meta(ReportRaw0, Config), Topic = case maps:get(topic, Meta, undefined) of undefined -> maps:get(topic, ReportRaw, undefined); @@ -172,9 +172,22 @@ enrich_topic({Fmt, Args}, #{topic := Topic}) when is_list(Fmt) -> enrich_topic(Msg, _) -> Msg. -try_encode_payload(#{payload := Payload} = Report, #{payload_encode := Encode}) -> +try_encode_meta(Report, Config) -> + lists:foldl( + fun(Meta, Acc) -> + try_encode_meta(Meta, Acc, Config) + end, + Report, + [payload, packet] + ). + +try_encode_meta(payload, #{payload := Payload} = Report, #{payload_encode := Encode}) -> Report#{payload := encode_payload(Payload, Encode)}; -try_encode_payload(Report, _Config) -> +try_encode_meta(packet, #{packet := Packet} = Report, #{payload_encode := Encode}) when + is_tuple(Packet) +-> + Report#{packet := emqx_packet:format(Packet, Encode)}; +try_encode_meta(_, Report, _Config) -> Report. encode_payload(Payload, text) -> @@ -182,4 +195,5 @@ encode_payload(Payload, text) -> encode_payload(_Payload, hidden) -> "******"; encode_payload(Payload, hex) -> - binary:encode_hex(Payload). + Bin = emqx_utils_conv:bin(Payload), + binary:encode_hex(Bin). diff --git a/apps/emqx/src/emqx_packet.erl b/apps/emqx/src/emqx_packet.erl index 9d6516126..6f5fa0972 100644 --- a/apps/emqx/src/emqx_packet.erl +++ b/apps/emqx/src/emqx_packet.erl @@ -51,7 +51,6 @@ ]). -export([ - format/1, format/2 ]). @@ -481,10 +480,6 @@ will_msg(#mqtt_packet_connect{ headers = #{username => Username, properties => Props} }. -%% @doc Format packet --spec format(emqx_types:packet()) -> iolist(). -format(Packet) -> format(Packet, emqx_trace_handler:payload_encode()). - %% @doc Format packet -spec format(emqx_types:packet(), hex | text | hidden) -> iolist(). format(#mqtt_packet{header = Header, variable = Variable, payload = Payload}, PayloadEncode) -> diff --git a/apps/emqx/src/emqx_trace/emqx_trace_formatter.erl b/apps/emqx/src/emqx_trace/emqx_trace_formatter.erl index e540ae82a..728280700 100644 --- a/apps/emqx/src/emqx_trace/emqx_trace_formatter.erl +++ b/apps/emqx/src/emqx_trace/emqx_trace_formatter.erl @@ -17,7 +17,6 @@ -include("emqx_mqtt.hrl"). -export([format/2]). --export([format_meta_map/1]). %% logger_formatter:config/0 is not exported. -type config() :: map(). @@ -43,10 +42,6 @@ format( format(Event, Config) -> emqx_logger_textfmt:format(Event, Config). -format_meta_map(Meta) -> - Encode = emqx_trace_handler:payload_encode(), - format_meta_map(Meta, Encode). - format_meta_map(Meta, Encode) -> format_meta_map(Meta, Encode, [ {packet, fun format_packet/2}, diff --git a/apps/emqx/src/emqx_ws_connection.erl b/apps/emqx/src/emqx_ws_connection.erl index 5d04b3304..db4151416 100644 --- a/apps/emqx/src/emqx_ws_connection.erl +++ b/apps/emqx/src/emqx_ws_connection.erl @@ -820,7 +820,7 @@ serialize_and_inc_stats_fun(#state{serialize = Serialize}) -> ?LOG(warning, #{ msg => "packet_discarded", reason => "frame_too_large", - packet => emqx_packet:format(Packet) + packet => Packet }), ok = emqx_metrics:inc('delivery.dropped.too_large'), ok = emqx_metrics:inc('delivery.dropped'), diff --git a/apps/emqx/test/emqx_packet_SUITE.erl b/apps/emqx/test/emqx_packet_SUITE.erl index 4ba6d1d82..04ad53a1e 100644 --- a/apps/emqx/test/emqx_packet_SUITE.erl +++ b/apps/emqx/test/emqx_packet_SUITE.erl @@ -377,42 +377,60 @@ t_will_msg(_) -> t_format(_) -> io:format("~ts", [ - emqx_packet:format(#mqtt_packet{ - header = #mqtt_packet_header{type = ?CONNACK, retain = true, dup = 0}, - variable = undefined - }) - ]), - io:format("~ts", [ - emqx_packet:format(#mqtt_packet{ - header = #mqtt_packet_header{type = ?CONNACK}, variable = 1, payload = <<"payload">> - }) + emqx_packet:format( + #mqtt_packet{ + header = #mqtt_packet_header{type = ?CONNACK, retain = true, dup = 0}, + variable = undefined + }, + text + ) ]), + io:format( + "~ts", + [ + emqx_packet:format( + #mqtt_packet{ + header = #mqtt_packet_header{type = ?CONNACK}, + variable = 1, + payload = <<"payload">> + }, + text + ) + ] + ), io:format("~ts", [ emqx_packet:format( - ?CONNECT_PACKET(#mqtt_packet_connect{ - will_flag = true, - will_retain = true, - will_qos = ?QOS_2, - will_topic = <<"topic">>, - will_payload = <<"payload">> - }) + ?CONNECT_PACKET( + #mqtt_packet_connect{ + will_flag = true, + will_retain = true, + will_qos = ?QOS_2, + will_topic = <<"topic">>, + will_payload = <<"payload">> + } + ), + text ) ]), io:format("~ts", [ - emqx_packet:format(?CONNECT_PACKET(#mqtt_packet_connect{password = password})) + emqx_packet:format(?CONNECT_PACKET(#mqtt_packet_connect{password = password}), text) ]), - io:format("~ts", [emqx_packet:format(?CONNACK_PACKET(?CONNACK_SERVER))]), - io:format("~ts", [emqx_packet:format(?PUBLISH_PACKET(?QOS_1, 1))]), - io:format("~ts", [emqx_packet:format(?PUBLISH_PACKET(?QOS_2, <<"topic">>, 10, <<"payload">>))]), - io:format("~ts", [emqx_packet:format(?PUBACK_PACKET(?PUBACK, 98))]), - io:format("~ts", [emqx_packet:format(?PUBREL_PACKET(99))]), + io:format("~ts", [emqx_packet:format(?CONNACK_PACKET(?CONNACK_SERVER), text)]), + io:format("~ts", [emqx_packet:format(?PUBLISH_PACKET(?QOS_1, 1), text)]), io:format("~ts", [ - emqx_packet:format(?SUBSCRIBE_PACKET(15, [{<<"topic">>, ?QOS_0}, {<<"topic1">>, ?QOS_1}])) + emqx_packet:format(?PUBLISH_PACKET(?QOS_2, <<"topic">>, 10, <<"payload">>), text) ]), - io:format("~ts", [emqx_packet:format(?SUBACK_PACKET(40, [?QOS_0, ?QOS_1]))]), - io:format("~ts", [emqx_packet:format(?UNSUBSCRIBE_PACKET(89, [<<"t">>, <<"t2">>]))]), - io:format("~ts", [emqx_packet:format(?UNSUBACK_PACKET(90))]), - io:format("~ts", [emqx_packet:format(?DISCONNECT_PACKET(128))]). + io:format("~ts", [emqx_packet:format(?PUBACK_PACKET(?PUBACK, 98), text)]), + io:format("~ts", [emqx_packet:format(?PUBREL_PACKET(99), text)]), + io:format("~ts", [ + emqx_packet:format( + ?SUBSCRIBE_PACKET(15, [{<<"topic">>, ?QOS_0}, {<<"topic1">>, ?QOS_1}]), text + ) + ]), + io:format("~ts", [emqx_packet:format(?SUBACK_PACKET(40, [?QOS_0, ?QOS_1]), text)]), + io:format("~ts", [emqx_packet:format(?UNSUBSCRIBE_PACKET(89, [<<"t">>, <<"t2">>]), text)]), + io:format("~ts", [emqx_packet:format(?UNSUBACK_PACKET(90), text)]), + io:format("~ts", [emqx_packet:format(?DISCONNECT_PACKET(128), text)]). t_parse_empty_publish(_) -> %% 52: 0011(type=PUBLISH) 0100 (QoS=2)