From 8df53e8de0c323efd03c959bef801216952722f8 Mon Sep 17 00:00:00 2001 From: Siri Hansen Date: Fri, 10 Aug 2018 16:38:48 +0200 Subject: [logger] Avoid unwanted commas introduced by formatter's single_line option When printing a map with ~p in a log message, the formatter's single_line option in some cases introduced unwanted commas after '=>', for example: This is now corrected. When single_line==true, width 0 is added to all ~p and ~P control sequences in the format string. --- lib/kernel/doc/src/logger_formatter.xml | 14 +++-- lib/kernel/src/logger_formatter.erl | 87 ++++++++++++++++++------------ lib/kernel/test/logger_formatter_SUITE.erl | 50 +++++++++++++++++ 3 files changed, 113 insertions(+), 38 deletions(-) (limited to 'lib') diff --git a/lib/kernel/doc/src/logger_formatter.xml b/lib/kernel/doc/src/logger_formatter.xml index 9226d19834..5a060fd42b 100644 --- a/lib/kernel/doc/src/logger_formatter.xml +++ b/lib/kernel/doc/src/logger_formatter.xml @@ -130,10 +130,16 @@ single_line = boolean() -

If set to true, all newlines in the message are - replaced with ", ", and white spaces following - directly after newlines are removed. Notice that newlines - added by the template parameter are not replaced.

+

If set to true, each log event is printed as a + single line. To achieve this, logger_formatter + sets the field width to 0 for all ~p + and ~P control sequences in the format a string + (see + io:format/2), and replaces all + newlines in the message with ", ". White spaces + following directly after newlines are removed. Notice + that newlines added by the template parameter are + not replaced.

Defaults to true.

 diff --git a/lib/kernel/src/logger_formatter.erl b/lib/kernel/src/logger_formatter.erl index a5c6984bc6..b0d4adc14d 100644 --- a/lib/kernel/src/logger_formatter.erl +++ b/lib/kernel/src/logger_formatter.erl @@ -188,41 +188,51 @@ format_msg({report,Report},Meta,Config) -> format_msg({report,Report}, Meta#{report_cb=>fun logger:format_report/1}, Config); -format_msg(Msg,_Meta,#{depth:=Depth,chars_limit:=CharsLimit,encoding:=Enc}) -> - limit_size(Msg, Depth, CharsLimit, Enc). - -limit_size(Msg,Depth,unlimited,Enc) -> - limit_size(Msg,Depth,[],Enc); -limit_size(Msg,Depth,CharsLimit,Enc) when is_integer(CharsLimit) -> - limit_size(Msg,Depth,[{chars_limit,CharsLimit}],Enc); -limit_size({Format,Args},unlimited,Opts,Enc) when is_list(Opts) -> - try io_lib:format(Format,Args,Opts) - catch _:_ -> - P = p(Enc), - io_lib:format("FORMAT ERROR: "++P++" - "++P,[Format,Args],Opts) - end; -limit_size({Format0,Args},Depth,Opts,Enc) when is_integer(Depth) -> +format_msg(Msg,_Meta,#{depth:=Depth,chars_limit:=CharsLimit, + encoding:=Enc,single_line:=Single}) -> + Opts = chars_limit_to_opts(CharsLimit), + format_msg(Msg, Depth, Opts, Enc, Single). + +chars_limit_to_opts(unlimited) -> []; +chars_limit_to_opts(CharsLimit) -> [{chars_limit,CharsLimit}]. + +format_msg({Format0,Args},Depth,Opts,Enc,Single) -> try Format1 = io_lib:scan_format(Format0, Args), - Format = limit_format(Format1, Depth), + Format = reformat(Format1, Depth, Single), io_lib:build_text(Format,Opts) - catch _:_ -> - P = p(Enc), - limit_size({"FORMAT ERROR: "++P++" - "++P,[Format0,Args]}, - Depth,Opts,Enc) + catch C:R:S -> + P = p(Enc,Single), + FormatError = "FORMAT ERROR: "++P++" - "++P, + case Format0 of + FormatError -> + %% already been here - avoid failing cyclically + erlang:raise(C,R,S); + _ -> + format_msg({FormatError,[Format0,Args]}, + Depth,Opts,Enc,Single) + end end. -limit_format([#{control_char:=C0}=M0|T], Depth) when C0 =:= $p; - C0 =:= $w -> - C = C0 - ($a - $A), %To uppercase. - #{args:=Args} = M0, - M = M0#{control_char:=C,args:=Args++[Depth]}, - [M|limit_format(T, Depth)]; -limit_format([H|T], Depth) -> - [H|limit_format(T, Depth)]; -limit_format([], _) -> +reformat(Format,unlimited,false) -> + Format; +reformat([#{control_char:=C}=M|T], Depth, true) when C =:= $p -> + [limit_depth(M#{width => 0}, Depth)|reformat(T, Depth, true)]; +reformat([#{control_char:=C}=M|T], Depth, true) when C =:= $P -> + [M#{width => 0}|reformat(T, Depth, true)]; +reformat([#{control_char:=C}=M|T], Depth, Single) when C =:= $p; C =:= $w -> + [limit_depth(M, Depth)|reformat(T, Depth, Single)]; +reformat([H|T], Depth, Single) -> + [H|reformat(T, Depth, Single)]; +reformat([], _, _) -> []. +limit_depth(M0, unlimited) -> + M0; +limit_depth(#{control_char:=C0, args:=Args}=M0, Depth) -> + C = C0 - ($a - $A), %To uppercase. + M0#{control_char:=C,args:=Args++[Depth]}. + truncate(String,unlimited) -> String; truncate(String,Size) -> @@ -492,12 +502,21 @@ check_timezone(Tz) -> error end. -p(#{encoding:=Enc}) -> - p(Enc); -p(latin1) -> - "~p"; -p(_) -> - "~tp". +p(#{encoding:=Enc, single_line:=Single}) -> + p(Enc,Single). + +p(Enc,Single) -> + "~"++p_width(Single)++p_char(Enc). + +p_width(true) -> + "0"; +p_width(false) -> + "". + +p_char(latin1) -> + "p"; +p_char(_) -> + "tp". s(#{encoding:=Enc}) -> s(Enc); diff --git a/lib/kernel/test/logger_formatter_SUITE.erl b/lib/kernel/test/logger_formatter_SUITE.erl index aa8dc42691..2ec4b243cf 100644 --- a/lib/kernel/test/logger_formatter_SUITE.erl +++ b/lib/kernel/test/logger_formatter_SUITE.erl @@ -166,6 +166,56 @@ single_line(_Config) -> " info:\nterm\n" = string:prefix(String2,ExpectedTimestamp), String2 = format(info,{"~p",[term]},#{time=>Time},#{single_line=>bad}), + + + %% Test that no extra commas/spaces are added when removing + %% newlines, especially not after "=>" in a map association (as + %% was the case in OTP-21.0, when the only single_line adjustment + %% was done by regexp replacement of "\n" by ", "). + Prefix = + "Some characters to fill the line ------------------------------------- ", + String3 = format(info,{"~s~p~n~s~p~n",[Prefix, + lists:seq(1,10), + Prefix, + #{a=>map,with=>a,few=>accociations}]}, + #{time=>Time}, + #{single_line=>true}), + ct:log(String3), + match = re:run(String3,"\\[1,2,3,4,5,6,7,8,9,10\\]",[{capture,none}]), + match = re:run(String3, + "#{a => map,few => accociations,with => a}", + [{capture,none}]), + + %% This part is added to make sure that the previous test made + %% sense, i.e. that there would actually be newlines inside the + %% list and map. + String4 = format(info,{"~s~p~n~s~p~n",[Prefix, + lists:seq(1,10), + Prefix, + #{a=>map,with=>a,few=>accociations}]}, + #{time=>Time}, + #{single_line=>false}), + ct:log(String4), + match = re:run(String4,"\\[1,2,3,\n",[global,{capture,none}]), + {match,Match4} = re:run(String4,"=>\n",[global,{capture,all}]), + 3 = length(Match4), + + %% Test that big metadata fields do not get line breaks + String5 = format(info,"", + #{mymeta=>lists:seq(1,100)}, + #{single_line=>true,template=>[mymeta,"\n"]}), + ct:log(String5), + [_] = string:lexemes(String5,"\n"), + + %% Ensure that the previous test made sense, i.e. that the + %% metadata field does produce multiple lines if + %% single_line==false. + String6 = format(info,"", + #{mymeta=>lists:seq(1,100)}, + #{single_line=>false,template=>[mymeta,"\n"]}), + ct:log(String6), + [_,_|_] = string:lexemes(String6,"\n"), + ok. template(_Config) -> -- cgit v1.2.3