From 2ea3d7b972141ac73a1dd7f0ac1a3ccbde342f6d Mon Sep 17 00:00:00 2001 From: Siri Hansen Date: Mon, 30 Apr 2018 13:58:34 +0200 Subject: Set single_line=true by default in logger_formatter --- lib/common_test/src/Makefile | 2 +- lib/kernel/src/logger_formatter.erl | 2 +- lib/kernel/src/logger_internal.hrl | 1 + lib/kernel/test/logger_formatter_SUITE.erl | 46 ++++++++++++++++-------------- lib/sasl/src/sasl.erl | 1 + 5 files changed, 28 insertions(+), 24 deletions(-) diff --git a/lib/common_test/src/Makefile b/lib/common_test/src/Makefile index 2a2a9cb5bc..9adcf2f13b 100644 --- a/lib/common_test/src/Makefile +++ b/lib/common_test/src/Makefile @@ -166,4 +166,4 @@ release_tests_spec: opt release_docs_spec: docs # Include dependencies -- list below added by Kostis Sagonas -$(EBIN)/cth_log_redirect.beam: ../../kernel/include/logger.hrl +$(EBIN)/cth_log_redirect.beam: ../../kernel/include/logger.hrl ../../kernel/src/logger_internal.hrl diff --git a/lib/kernel/src/logger_formatter.erl b/lib/kernel/src/logger_formatter.erl index 386e7832e2..5358652692 100644 --- a/lib/kernel/src/logger_formatter.erl +++ b/lib/kernel/src/logger_formatter.erl @@ -263,7 +263,7 @@ utcstr(_) -> "". add_default_config(#{utc:=_}=Config0) -> Default = #{legacy_header=>false, - single_line=>false, + single_line=>true, chars_limit=>unlimited}, MaxSize = get_max_size(maps:get(max_size,Config0,false)), Depth = get_depth(maps:get(depth,Config0,false)), diff --git a/lib/kernel/src/logger_internal.hrl b/lib/kernel/src/logger_internal.hrl index 82df499c2b..8c0fc2725d 100644 --- a/lib/kernel/src/logger_internal.hrl +++ b/lib/kernel/src/logger_internal.hrl @@ -31,6 +31,7 @@ {no_domain,{fun logger_filters:domain/2,{log,no_domain,[]}}}]). -define(DEFAULT_FORMATTER,logger_formatter). -define(DEFAULT_FORMAT_CONFIG,#{legacy_header=>true, + single_line=>false, template=>?DEFAULT_FORMAT_TEMPLATE_HEADER}). -define(DEFAULT_FORMAT_TEMPLATE_HEADER, [{logger_formatter,header},"\n",msg,"\n"]). diff --git a/lib/kernel/test/logger_formatter_SUITE.erl b/lib/kernel/test/logger_formatter_SUITE.erl index ac1abba629..7d1f33746d 100644 --- a/lib/kernel/test/logger_formatter_SUITE.erl +++ b/lib/kernel/test/logger_formatter_SUITE.erl @@ -73,18 +73,19 @@ all() -> default(_Config) -> String1 = format(info,{"~p",[term]},#{},#{}), ct:log(String1), - [_Date,_Time,"info:\nterm\n"] = string:lexemes(String1," "), + [_Date,_Time,"info:","term\n"] = string:lexemes(String1," "), Time = timestamp(), ExpectedTimestamp = default_time_format(Time), String2 = format(info,{"~p",[term]},#{time=>Time},#{}), ct:log(String2), - " info:\nterm\n" = string:prefix(String2,ExpectedTimestamp), + " info: term\n" = string:prefix(String2,ExpectedTimestamp), ok. legacy_header(_Config) -> Time = timestamp(), - String1 = format(info,{"~p",[term]},#{time=>Time},#{legacy_header=>true}), + String1 = format(info,{"~p",[term]},#{time=>Time},#{legacy_header=>true, + single_line=>false}), ct:log(String1), "=INFO REPORT==== "++Rest = String1, [Timestamp,"\nterm\n"] = string:lexemes(Rest," ="), @@ -98,12 +99,14 @@ legacy_header(_Config) -> true = lists:member(M,["Jan","Feb","Mar","Apr","May","Jun", "Jul","Aug","Sep","Oct","Nov","Dec"]), - String2 = format(info,{"~p",[term]},#{time=>Time},#{legacy_header=>false}), + String2 = format(info,{"~p",[term]},#{time=>Time},#{legacy_header=>false, + single_line=>false}), ct:log(String2), ExpectedTimestamp = default_time_format(Time), " info:\nterm\n" = string:prefix(String2,ExpectedTimestamp), - String3 = format(info,{"~p",[term]},#{time=>Time},#{legacy_header=>bad}), + String3 = format(info,{"~p",[term]},#{time=>Time},#{legacy_header=>bad, + single_line=>false}), ct:log(String3), String3 = String2, @@ -114,7 +117,8 @@ legacy_header(_Config) -> String4 = String1, String5 = format(info,{"~p",[term]},#{}, % <--- no time - #{legacy_header=>true}), + #{legacy_header=>true, + single_line=>false}), ct:log(String5), "=INFO REPORT==== "++_ = String5, ok. @@ -289,38 +293,36 @@ report_cb(_Config) -> ok. max_size(_Config) -> - Template = [msg], + Cfg = #{template=>[msg], + single_line=>false}, "12345678901234567890" = - format(info,{"12345678901234567890",[]},#{},#{template=>Template}), + format(info,{"12345678901234567890",[]},#{},Cfg), application:set_env(kernel,logger_max_size,11), "12345678901234567890" = % min value is 50, so this is not limited - format(info,{"12345678901234567890",[]},#{},#{template=>Template}), + format(info,{"12345678901234567890",[]},#{},Cfg), "12345678901234567890123456789012345678901234567..." = % 50 format(info, {"123456789012345678901234567890123456789012345678901234567890", []}, #{}, - #{template=>Template}), + Cfg), application:set_env(kernel,logger_max_size,53), "12345678901234567890123456789012345678901234567890..." = %53 format(info, {"123456789012345678901234567890123456789012345678901234567890", []}, #{}, - #{template=>Template}), + Cfg), "123456789012..." = - format(info,{"12345678901234567890",[]},#{},#{template=>Template, - max_size=>15}), + format(info,{"12345678901234567890",[]},#{},Cfg#{max_size=>15}), "12345678901234567890" = - format(info,{"12345678901234567890",[]},#{},#{template=>Template, - max_size=>unlimited}), + format(info,{"12345678901234567890",[]},#{},Cfg#{max_size=>unlimited}), %% Check that one newline at the end of the line is kept (if it exists) "12345678901...\n" = - format(info,{"12345678901234567890\n",[]},#{},#{template=>Template, - max_size=>15}), + format(info,{"12345678901234567890\n",[]},#{},Cfg#{max_size=>15}), "12345678901...\n" = - format(info,{"12345678901234567890",[]},#{},#{template=>[msg,"\n"], - max_size=>15}), + format(info,{"12345678901234567890",[]},#{},Cfg#{template=>[msg,"\n"], + max_size=>15}), ok. max_size(cleanup,_Config) -> application:unset_env(kernel,logger_max_size), @@ -441,20 +443,20 @@ format_time(_Config) -> ExpectedTimestamp1 = default_time_format(Time1), String1 = format(info,{"~p",[term]},#{time=>Time1},#{}), ct:log(String1), - " info:\nterm\n" = string:prefix(String1,ExpectedTimestamp1), + " info: term\n" = string:prefix(String1,ExpectedTimestamp1), Time2 = timestamp(), ExpectedTimestamp2 = default_time_format(Time2,true), String2 = format(info,{"~p",[term]},#{time=>Time2},#{utc=>true}), ct:log(String2), - " info:\nterm\n" = string:prefix(String2,ExpectedTimestamp2), + " info: term\n" = string:prefix(String2,ExpectedTimestamp2), application:set_env(kernel,logger_utc,true), Time3 = timestamp(), ExpectedTimestamp3 = default_time_format(Time3,true), String3 = format(info,{"~p",[term]},#{time=>Time3},#{}), ct:log(String3), - " info:\nterm\n" = string:prefix(String3,ExpectedTimestamp3), + " info: term\n" = string:prefix(String3,ExpectedTimestamp3), ok. diff --git a/lib/sasl/src/sasl.erl b/lib/sasl/src/sasl.erl index 657eb6688a..2bf11bdcdf 100644 --- a/lib/sasl/src/sasl.erl +++ b/lib/sasl/src/sasl.erl @@ -130,6 +130,7 @@ add_sasl_logger(undefined, _Level) -> ok; add_sasl_logger(std, undefined) -> ok; add_sasl_logger(Dest, Level) -> FC0 = #{legacy_header=>true, + single_line=>false, template=>[{logger_formatter,header},"\n",msg,"\n"]}, FC = case application:get_env(sasl,utc_log) of {ok,Bool} when is_boolean(Bool) -> -- cgit v1.2.3 From 0d3b793ac551f9c69f9e1c0c5a76186386f3cd04 Mon Sep 17 00:00:00 2001 From: Siri Hansen Date: Wed, 2 May 2018 11:50:49 +0200 Subject: Update logger documentation --- lib/kernel/doc/src/kernel_app.xml | 30 ++--- lib/kernel/doc/src/logger.xml | 6 +- lib/kernel/doc/src/logger_chapter.xml | 5 +- lib/kernel/doc/src/logger_formatter.xml | 217 +++++++++++++++++++------------- 4 files changed, 146 insertions(+), 112 deletions(-) diff --git a/lib/kernel/doc/src/kernel_app.xml b/lib/kernel/doc/src/kernel_app.xml index 554d675383..f96d946a5d 100644 --- a/lib/kernel/doc/src/kernel_app.xml +++ b/lib/kernel/doc/src/kernel_app.xml @@ -226,7 +226,7 @@

This configuration parameter is used both for the global logger level, and for the standard handler started by the Kernel application (see logger_dest variable above).

-

The default value is info

+

The default value is info.

logger_disk_log_type = halt | wrap @@ -251,14 +251,14 @@ logger_disk_log_maxbytes = 1048576

If this parameter is set to true, then the logger handler started by kernel will not log any progress-, crash-, or - supervisor reports. If the SASL application is starated, + supervisor reports. If the SASL application is started, these log events will be sent to a second handler instance - named sasl_h, according to values of the SASL environment - variables sasl_error_logger + named sasl_h, according to values of the SASL + environment variables sasl_error_logger and sasl_errlog_type, see SASL(6)

-

The default value is false

+

The default value is false.

See chapter Backwards compatibility with error_logger for more information about handling of the so called SASL reports.

@@ -271,7 +271,7 @@ logger_disk_log_maxbytes = 1048576 reports from supervisor and application_controller shall be logged or not.

-

If logger_sasl_compatible = false, +

If logger_sasl_compatible = true, then logger_log_progress is ignored.

 @@ -280,14 +280,6 @@ logger_disk_log_maxbytes = 1048576

Can be used to limit the size of the formatted output from the logger handlers.

-

This configuration parameter was introduced in OTP 18.1 - and is experimental. Based on user feedback, it - can be changed or improved in future releases, for example, - to gain better control over how to limit the size of the - formatted output. We have no plans to remove this - new feature entirely, unless it turns out to be - useless.

 -

Depth is a positive integer representing the maximum depth to which terms are printed by the logger handlers included in OTP. This @@ -312,11 +304,11 @@ logger_disk_log_maxbytes = 1048576 logger_max_size = integer() | unlimited -

This parameter specifies the maximum size (bytes) each - log event can have when printed by the standard logger - handler. If the resulting string after formatting an event - is bigger than this, it will be truncated before printed - to the handler's destination.

+

This parameter specifies a hard maximum size limit (number + of characters) each log event can have when printed by the + default logger formatter. If the resulting string after + formatting an event is bigger than this, it will be + truncated before printed to the handler's destination.

logger_utc = boolean() diff --git a/lib/kernel/doc/src/logger.xml b/lib/kernel/doc/src/logger.xml index 66e6e5c689..ded9c1fb37 100644 --- a/lib/kernel/doc/src/logger.xml +++ b/lib/kernel/doc/src/logger.xml @@ -131,8 +131,8 @@ #{mfa=>{?MODULE,?FUNCTION_NAME,?FUNCTION_ARITY}, - file=>?FILE, - line=>?LINE} + file=>?FILE, + line=>?LINE}

The call is wrapped in a case statement and will be evaluated @@ -297,7 +297,7 @@ print Pretty print all the current logger configuration to standard out. Example: - logger:i(). + logger:i(print). Current logger configuration: Level: info FilterDefault: log diff --git a/lib/kernel/doc/src/logger_chapter.xml b/lib/kernel/doc/src/logger_chapter.xml index 88dcfbe8d9..78d6f46c95 100644 --- a/lib/kernel/doc/src/logger_chapter.xml +++ b/lib/kernel/doc/src/logger_chapter.xml @@ -488,8 +488,9 @@ error_logger:add_report_handler/1,2. level => debug} 2> logger:add_handler(debug_handler,logger_std_h,Config). ok -

By default, the handler receives all events, so we need to add a filter - to stop all non-debug events:

+

By default, the handler receives all events + (filter_defalt=log), so we need to add a filter to stop + all non-debug events:

 3> Fun = fun(#{level:=debug}=Log,_) -> Log; (_,_) -> stop end.
 #Fun<erl_eval.12.98642416>
diff --git a/lib/kernel/doc/src/logger_formatter.xml b/lib/kernel/doc/src/logger_formatter.xml
index 6a17e3641f..a0940100ee 100644
--- a/lib/kernel/doc/src/logger_formatter.xml
+++ b/lib/kernel/doc/src/logger_formatter.xml
@@ -37,116 +37,157 @@
 
   
     
Default formatter for the Logger application.

-  
-
-  
-    
-      
-      
-      
-    
-  
-
-  
-    
-      
-      Formats the given message.
-      
-        
Formats the given message.

-	
The template is a list of atoms, tuples and strings. Atoms
-	  can be level or msg, which are placeholders
-	  for the severity level and the log message,
-	  repectively. Tuples are interpreted as placeholders for
-	  metadata. Each element in the tuple must be an atom which
-	  matches a key in the nested metadata map, e.g. the
-	  tuple {key1,key2} will be replaced by the value of
-	  the key2 field in this nested map (the value vill be
-	  converted to a string):

-
-
-#{key1=>#{key2=>my_value,
-          ...},
-  ...}
-
-
-        
 Strings are printed literally.

-
-	
depth is a positive integer representing the maximum
-	  depth to which terms shall be printed by this
-	  formatter. Format strings passed to this formatter are
-	  rewritten. The format controls ~p and ~w are replaced with
-	  ~P and ~W, respectively, and the value is used as the depth
-	  parameter. For details, see
-	  io:format/2,3
-	  in STDLIB.

-
-	
chars_limit is a positive integer representing the
-	  value of the option with the same name to be used when calling
-	  io:format/3. This
-	  value limits the total number of characters printed bu the
-	  formatter. Notes that this is a soft limit. For a hard
-	  truncation limit, see option max_size.

-
-	
max_size is a positive integer representing the
-	  maximum size a string returned from this formatter can
-	  have. If the formatted string is longer, after possibly
-	  being limited by depth and/or chars_limit, it
-	  will be truncated.

-
-	
utc is a boolean. If set to true, all dates are
-	  displayed in Universal Coordinated Time. Default
-	  is false.

 
-	
report_cb must be a function with arity 1,
-	  returning {Format,Args}. This function will replace
-	  any report_cb found in metadata.

-
-	
If single_line=true, all newlines in the message are
-	  replaced with ", ", and whitespaces following directly
-	  after newlines are removed. Note that newlines added by the
-	  formatter template are not replaced.

+  
 
-	
If legacy_header=true a header field is added to
+  

+    Configuration
+    
The following configuration parameters can be set
+      for logger_formatter:

+    
+      single_line = boolean()
+      
+	
If set to true, all newlines in the message are
+	  replaced with ", ", and whitespaces following
+	  directly after newlines are removed. Note that newlines
+	  added by the formatter template are not replaced.

+	
Default is true.

+      
+      legacy_header = boolen()
+      
+	
If set to true a header field is added to
 	  logger_formatter's part of Metadata. The value of
 	  this field is a string similar to the header created by the
 	  old error_logger event handlers. It can be included
 	  in the log event by adding the
-	  tuple {logger_formatter,header} to the template.

-
-	
The default template when legacy_header=true is

-
-	[{logger_formatter,header},"\n",msg,"\n"]
+	  tuple {logger_formatter,header} to the
+	  template. See Default
+	  Templates for more information

+	
Default is false.

+      
+      report_cb = fun((logger:report()) -> {io:format(),[term()]})
+      
+	
A function with arity 1,
+	  returning {Format,Args}. This function will replace
+	  any report_cb found in metadata.

+      
+      depth = pos_integer() | unlimited
+      
+	
A positive integer representing the maximum depth to
+	  which terms shall be printed by this formatter. Format
+	  strings passed to this formatter are rewritten. The format
+	  controls ~p and ~w are replaced with ~P and ~W,
+	  respectively, and the value is used as the depth
+	  parameter. For details, see
+	  io:format/2,3
+	  in STDLIB.

+	
Default is unlimited.

+      
+      chars_limit = pos_integer() | unlimited
+      
+	
A positive integer representing the value of the option
+	  with the same name to be used when calling
+	  io_lib:format/3.
+	  This value limits the total number of characters printed
+	  for each log event. Note that this is a soft limit. For a
+	  hard truncation limit, see option max_size.

+	
Default is unlimited.

+      
+      max_size = pos_integer() | unlimited
+      
+	
A positive integer representing the absolute maximum size
+	  a string returned from this formatter can have. If the
+	  formatted string is longer, after possibly being limited
+	  by depth and/or chars_limit, it will be
+	  truncated.

+	
Default is unlimited.

+      
+      template = template()
+      
+	
The template is a list of atoms, tuples and strings. The
+	  atoms level or msg, are treated as
+	  placeholders for the severity level and the log message,
+	  repectively. Other atoms or tuples are interpreted as
+	  placeholders for metadata, where atoms are expected to
+	  match top level keys, and tuples represent paths to sub
+	  keys in a nested map. For example the
+	  tuple {key1,key2} will be replaced by the value of
+	  the key2 field in the nested map below. The
+	  atom key1 on its own would be replaced by the
+	  complete value of the key1 field. The values are
+	  converted to strings.

 
-	
which will cause log entries like this:

+
+#{key1=>#{key2=>my_value,
+          ...}
+  ...}
 
-	=ERROR REPORT==== 29-Dec-2017::13:30:51.245123 ===
+        
Strings are printed literally.

+	
The default template differs depending on the values
+	  of legacy_header
+	  and single_line. See Default
+	  Templates for more information

+      
+      utc = boolean()
+      
+	
If set to true, all dates are displayed in Universal
+	  Coordinated Time. Default is false.

+      
+    
+  

+
+  

+    
+    Default templates
+    
The default template when legacy_header=true is

+
+    [{logger_formatter,header},"\n",msg,"\n"]
+
+    
which will cause log entries like this:

+
+    =ERROR REPORT==== 29-Dec-2017::13:30:51.245123 ===
     process: <0.74.0>
     exit_reason: "Something went wrong"
 
-	
Note that all eight levels might occur here, not
-	  only ERROR, WARNING or INFO. And also
-	  that micro seconds are added at the end of the
-	  timestamp.

+    
Note that all eight levels might occur here, not
+      only ERROR, WARNING or INFO. And also that
+      micro seconds are added at the end of the timestamp.

 
-	
The default template when single_line=true is

+    
The default template when single_line=true is

 
-	[time," ",level,": ",msg,"\n"]
+    [time," ",level,": ",msg,"\n"]
 
-	
which will cause log entries like this:

+    
which will cause log entries like this:

 
-	2017-12-29 13:31:49.640317 error: process: <0.74.0>, exit_reason: "Something went wrong"
+    2017-12-29 13:31:49.640317 error: process: <0.74.0>, exit_reason: "Something went wrong"
 
-	
The default template when both legacy_header and
-	  single_line are set to false is:

+    
The default template when both legacy_header and
+      single_line are set to false is:

 
-	[time," ",level,":\n",msg,"\n"]
+    [time," ",level,":\n",msg,"\n"]
 
-	
which will cause log entries like this:

+    
which will cause log entries like this:

 
-	2017-12-29 13:32:25.191925 error:
+    2017-12-29 13:32:25.191925 error:
     process: <0.74.0>
     exit_reason: "Something went wrong"
+  

+
+  
+    
+      
+      
+      
+    
+  
 
+  
+    
+      
+      Formats the given message.
+      
+	
This the callback function to be called from handlers. It
+	  formats the given messages.

       
     
 
-- 
cgit v1.2.3


From 6aff9ab0a70e1ee3776d601c93f8697cde87b89a Mon Sep 17 00:00:00 2001
From: Siri Hansen 
Date: Wed, 2 May 2018 15:55:02 +0200
Subject: Improve test of logger_disk_log_h and logger_std_h

---
 lib/kernel/test/logger_disk_log_h_SUITE.erl |  55 +++++-----
 lib/kernel/test/logger_std_h_SUITE.erl      | 163 +++++++++++++++++++---------
 2 files changed, 136 insertions(+), 82 deletions(-)

diff --git a/lib/kernel/test/logger_disk_log_h_SUITE.erl b/lib/kernel/test/logger_disk_log_h_SUITE.erl
index c7c6137380..63e5b56021 100644
--- a/lib/kernel/test/logger_disk_log_h_SUITE.erl
+++ b/lib/kernel/test/logger_disk_log_h_SUITE.erl
@@ -497,24 +497,19 @@ disk_log_sync(Config) ->
                               filters=>?DEFAULT_HANDLER_FILTERS([?MODULE]),
                               formatter=>{?MODULE,nl}}),
 
-    start_tracer([{?MODULE,format,2},
-                  {disk_log,blog,2},
+    start_tracer([{disk_log,blog,2},
                   {disk_log,sync,1}],
-                 [{formatter,"first"},
-                  {disk_log,blog},
+                 [{disk_log,blog,<<"first\n">>},
                   {disk_log,sync}]),
 
     logger:info("first", ?domain),
     %% wait for automatic disk_log_sync
     check_tracer(?FILESYNC_REPEAT_INTERVAL*2),
     
-    start_tracer([{?MODULE,format,2},
-                  {disk_log,blog,2},
+    start_tracer([{disk_log,blog,2},
                   {disk_log,sync,1}],
-                 [{formatter,"second"},
-                  {formatter,"third"},
-                  {disk_log,blog},
-                  {disk_log,blog},
+                 [{disk_log,blog,<<"second\n">>},
+                  {disk_log,blog,<<"third\n">>},
                   {disk_log,sync}]),
     %% two log requests in fast succession will make the handler skip
     %% an automatic disk log sync
@@ -531,13 +526,10 @@ disk_log_sync(Config) ->
     no_repeat = maps:get(filesync_repeat_interval,
                          logger_disk_log_h:info(?MODULE)),
 
-    start_tracer([{?MODULE,format,2},
-                  {disk_log,blog,2},
+    start_tracer([{disk_log,blog,2},
                   {disk_log,sync,1}],
-                 [{formatter,"fourth"},
-                  {disk_log,blog},
-                  {formatter,"fifth"},
-                  {disk_log,blog},
+                 [{disk_log,blog,<<"fourth\n">>},
+                  {disk_log,blog,<<"fifth\n">>},
                   {disk_log,sync}]),
 
     logger:info("fourth", ?domain),
@@ -566,6 +558,7 @@ disk_log_sync(Config) ->
     check_tracer(100),
     ok.
 disk_log_sync(cleanup,_Config) ->
+    dbg:stop_clear(),
     logger:remove_handler(?MODULE).
 
 disk_log_wrap(Config) ->
@@ -623,6 +616,7 @@ disk_log_wrap(Config) ->
     ok.
 
 disk_log_wrap(cleanup,_Config) ->
+    dbg:stop_clear(),
     logger:remove_handler(?MODULE).
 
 disk_log_full(Config) ->
@@ -668,6 +662,7 @@ disk_log_full(Config) ->
      {trace,{error_status,{error,{full,_}}}}] = Received,
     ok.
 disk_log_full(cleanup, _Config) ->
+    dbg:stop_clear(),
     logger:remove_handler(?MODULE).    
 
 disk_log_events(Config) ->
@@ -713,6 +708,7 @@ disk_log_events(Config) ->
                   end, Received),
     ok.
 disk_log_events(cleanup, _Config) ->
+    dbg:stop_clear(),
     logger:remove_handler(?MODULE).    
 
 write_failure(Config) ->
@@ -763,7 +759,7 @@ sync_failure(Config) ->
     Dir = ?config(priv_dir, Config),
     FileName = lists:concat([?MODULE,"_",?FUNCTION_NAME]),
     File = filename:join(Dir, FileName),
-    Log = lists:concat([File,".1"]),
+
 
     Node = start_h_on_new_node(Config, ?FUNCTION_NAME, File),
     false = (undefined == rpc:call(Node, ets, whereis, [?TEST_HOOKS_TAB])),
@@ -832,10 +828,10 @@ log_on_remote_node(Node,Msg) ->
     ok.
 
 %% functions for test hook macros to be called by rpc
-set_internal_log(Mod, Func) ->
-    ?set_internal_log({Mod,Func}).
-set_result(Op, Result) ->
-    ?set_result(Op, Result).
+set_internal_log(_Mod, _Func) ->
+    ?set_internal_log({_Mod,_Func}).
+set_result(_Op, _Result) ->
+    ?set_result(_Op, _Result).
 set_defaults() ->
     ?set_defaults().
 
@@ -885,7 +881,7 @@ op_switch_to_drop(cleanup, _Config) ->
     ok = stop_handler(?MODULE).
 
 op_switch_to_flush() ->
-    [{timetrap,{seconds,60}}].
+    [{timetrap,{minutes,3}}].
 op_switch_to_flush(Config) ->
     {Log,HConfig,DLHConfig} = start_handler(?MODULE, ?FUNCTION_NAME, Config),
     
@@ -988,7 +984,7 @@ kill_disabled(cleanup, _Config) ->
     ok = stop_handler(?MODULE).
 
 qlen_kill_new(Config) ->
-    {Log,HConfig,DLHConfig} = start_handler(?MODULE, ?FUNCTION_NAME, Config),
+    {_Log,HConfig,DLHConfig} = start_handler(?MODULE, ?FUNCTION_NAME, Config),
     Pid0 = whereis(?MODULE),
     {_,Mem0} = process_info(Pid0, memory),
     RestartAfter = 2000,
@@ -1025,7 +1021,7 @@ qlen_kill_new(cleanup, _Config) ->
     ok = stop_handler(?MODULE).
 
 mem_kill_new(Config) ->
-    {Log,HConfig,DLHConfig} = start_handler(?MODULE, ?FUNCTION_NAME, Config),
+    {_Log,HConfig,DLHConfig} = start_handler(?MODULE, ?FUNCTION_NAME, Config),
     Pid0 = whereis(?MODULE),
     {_,Mem0} = process_info(Pid0, memory),
     RestartAfter = 2000,
@@ -1111,7 +1107,7 @@ restart_after(cleanup, _Config) ->
 %% during high load to verify that sync, dropping and flushing is
 %% handled correctly.
 handler_requests_under_load() ->
-    [{timetrap,{seconds,60}}].
+    [{timetrap,{minutes,3}}].
 handler_requests_under_load(Config) ->
     {Log,HConfig,DLHConfig} = start_handler(?MODULE, ?FUNCTION_NAME, Config),
     NewHConfig =
@@ -1140,7 +1136,7 @@ handler_requests_under_load(Config) ->
     NoOfReqs = lists:foldl(fun({_,Res}, N) -> N + length(Res) end, 0, ReqResult),
     ct:pal("~w requests made. Errors: ~n~p", [NoOfReqs,Errors]),
     ok = file:delete(Log).
-handler_requests_under_load(cleanup, Config) ->
+handler_requests_under_load(cleanup, _Config) ->
     ok = stop_handler(?MODULE).
 
 send_requests(HName, TO, Reqs = [{Req,Res}|Rs]) ->
@@ -1369,7 +1365,6 @@ start_tracer(Trace,Expected) ->
     Pid = self(),
     dbg:tracer(process,{fun tracer/2,{Pid,Expected}}),
     dbg:p(whereis(?MODULE),[c]),
-    dbg:p(Pid,[c]),
     tpl(Trace),
     ok.
 
@@ -1387,13 +1382,14 @@ tpl([{M,F,A}|Trace]) ->
 tpl([]) ->
     ok.
 
-tracer({trace,_,call,{?MODULE,format,[#{msg:={string,Msg}}|_]}}, {Pid,[{formatter,Msg}|Expected]}) ->
-    maybe_tracer_done(Pid,Expected,{formatter,Msg});
 tracer({trace,_,call,{logger_disk_log_h,handle_cast,[{Op,_}|_]}}, {Pid,[{Mod,Func,Op}|Expected]}) ->
     maybe_tracer_done(Pid,Expected,{Mod,Func,Op});
+tracer({trace,_,call,{Mod=disk_log,Func=blog,[_,Data]}}, {Pid,[{Mod,Func,Data}|Expected]}) ->
+    maybe_tracer_done(Pid,Expected,{Mod,Func,Data});
 tracer({trace,_,call,{Mod,Func,_}}, {Pid,[{Mod,Func}|Expected]}) ->
     maybe_tracer_done(Pid,Expected,{Mod,Func});
 tracer({trace,_,call,Call}, {Pid,Expected}) ->
+    ct:log("Tracer got unexpected: ~p~nExpected: ~p~n",[Call,Expected]),
     Pid ! {tracer_got_unexpected,Call,Expected},
     {Pid,Expected}.
 
@@ -1413,5 +1409,6 @@ check_tracer(T) ->
             dbg:stop_clear(),
             ct:fail({tracer_got_unexpected,Got,Expected})
     after T ->
+            dbg:stop_clear(),
             ct:fail({timeout,tracer})
     end.
diff --git a/lib/kernel/test/logger_std_h_SUITE.erl b/lib/kernel/test/logger_std_h_SUITE.erl
index e940e0a026..7c8d63cbbd 100644
--- a/lib/kernel/test/logger_std_h_SUITE.erl
+++ b/lib/kernel/test/logger_std_h_SUITE.erl
@@ -499,86 +499,79 @@ filesync(Config) ->
                             #{logger_std_h => #{type => Type},
                               filter_default=>log,
                               filters=>?DEFAULT_HANDLER_FILTERS([?MODULE]),
-                              formatter=>{?MODULE,self()}}),
-    Tester = self(),
-    TraceFun = fun({trace,_,call,{Mod,Func,Details}}, Pid) ->
-                       Pid ! {trace,Mod,Func,Details},
-                       Pid;
-                  ({trace,TPid,'receive',Received}, Pid) ->
-                       Pid ! {trace,TPid,Received},
-                       Pid
-               end,
-    {ok,_} = dbg:tracer(process, {TraceFun, Tester}),
-    FileCtrlPid = maps:get(file_ctrl_pid , logger_std_h:info(?MODULE)),
-    {ok,_} = dbg:p(FileCtrlPid, [c]),
-    {ok,_} = dbg:tpl(logger_std_h, write_to_dev, 5, []),
-    {ok,_} = dbg:tpl(logger_std_h, sync_dev, 4, []),
-    {ok,_} = dbg:tp(file, datasync, 1, []),
+                              formatter=>{?MODULE,nl}}),
+
+    %% check repeated filesync happens
+    start_tracer([{logger_std_h, write_to_dev, 5},
+                  {logger_std_h, sync_dev, 4},
+                  {file, datasync, 1}],
+                 [{logger_std_h, write_to_dev, <<"first\n">>},
+                  {logger_std_h, sync_dev},
+                  {file,datasync}]),
 
     logger:info("first", ?domain),
     %% wait for automatic filesync
-    timer:sleep(?FILESYNC_REP_INT),
-    Expected1 = [{log,"first"}, {trace,logger_std_h,write_to_dev},
-                 {trace,logger_std_h,sync_dev}, {trace,file,datasync}],
-    
+    check_tracer(?FILESYNC_REP_INT*2),
+
+    %% check that explicit filesync is only done once
+    start_tracer([{logger_std_h, write_to_dev, 5},
+                  {logger_std_h, sync_dev, 4},
+                  {file, datasync, 1}],
+                 [{logger_std_h, write_to_dev, <<"second\n">>},
+                  {logger_std_h, sync_dev},
+                  {file,datasync},
+                  {no_more,500}
+                 ]),
     logger:info("second", ?domain),
     %% do explicit filesync
     logger_std_h:filesync(?MODULE),
     %% a second filesync should be ignored
     logger_std_h:filesync(?MODULE),
-    Expected2 =  [{log,"second"}, {trace,logger_std_h,write_to_dev},
-                  {trace,logger_std_h,sync_dev}, {trace,file,datasync}],
+    check_tracer(100),
 
     %% check that if there's no repeated filesync active,
     %% a filesync is still performed when handler goes idle
     logger:set_handler_config(?MODULE, logger_std_h,
                               #{filesync_repeat_interval => no_repeat}),
     no_repeat = maps:get(filesync_repeat_interval, logger_std_h:info(?MODULE)),
+    %% The following timer is to make sure the time from last log
+    %% ("second") to next ("third") is long enough, so the a flush is
+    %% triggered by the idle timeout between "thrid" and "fourth".
+    timer:sleep(?IDLE_DETECT_TIME_MSEC*2),
+    start_tracer([{logger_std_h, write_to_dev, 5},
+                  {logger_std_h, sync_dev, 4},
+                  {file, datasync, 1}],
+                 [{logger_std_h, write_to_dev, <<"third\n">>},
+                  {logger_std_h, sync_dev},
+                  {file,datasync},
+                  {logger_std_h, write_to_dev, <<"fourth\n">>},
+                  {logger_std_h, sync_dev},
+                  {file,datasync}]),
     logger:info("third", ?domain),
+    %% wait for automatic filesync
     timer:sleep(?IDLE_DETECT_TIME_MSEC*2),
     logger:info("fourth", ?domain),
     %% wait for automatic filesync
-    timer:sleep(?IDLE_DETECT_TIME_MSEC*2),
-    Expected3 = [{log,"third"}, {trace,logger_std_h,write_to_dev},
-                 {log,"fourth"}, {trace,logger_std_h,write_to_dev},
-                 {trace,logger_std_h,sync_dev}, {trace,file,datasync}],
-
-    dbg:stop_clear(),
-
-    %% verify that filesync has been performed as expected
-    Received1 = lists:map(fun({trace,M,F,_}) -> {trace,M,F};
-                             (Other) -> Other
-                          end, test_server:messages_get()),
-    ct:pal("Trace #1 =~n~p", [Received1]),
-    Received1 = Expected1 ++ Expected2 ++ Expected3,
-
-    try_read_file(Log, {ok,<<"first\nsecond\nthird\nfourth\n">>}, 1000),
-    
-    {ok,_} = dbg:tracer(process, {TraceFun, Tester}),
-    {ok,_} = dbg:p(whereis(?MODULE), [c]),
-    {ok,_} = dbg:tpl(logger_std_h, handle_cast, 2, []),
+    check_tracer(?IDLE_DETECT_TIME_MSEC*2),
 
     %% switch repeated filesync on and verify that the looping works
     SyncInt = 1000,
     WaitT = 4500,
+    OneSync = {logger_std_h,handle_cast,repeated_filesync},
+    %% receive 1 initial repeated_filesync, then 1 per sec
+    start_tracer([{logger_std_h,handle_cast,2}],
+                 [OneSync || _ <- lists:seq(1, 1 + trunc(WaitT/SyncInt))]),
+
     logger:set_handler_config(?MODULE, logger_std_h,
                               #{filesync_repeat_interval => SyncInt}),
     SyncInt = maps:get(filesync_repeat_interval, logger_std_h:info(?MODULE)),
     timer:sleep(WaitT),
     logger:set_handler_config(?MODULE, logger_std_h,
-                              #{filesync_repeat_interval => no_repeat}),    
-    dbg:stop_clear(),
-
-    Received2 = lists:map(fun({trace,_M,handle_cast,[{Op,_},_]}) -> {trace,Op};
-                             (Other) -> Other
-                          end, test_server:messages_get()),
-    ct:pal("Trace #2 =~n~p", [Received2]),
-    OneSync = [{trace,repeated_filesync}],
-    %% receive 1 initial repeated_filesync, then 1 per sec
-    Received2 =
-        lists:flatten([OneSync || _ <- lists:seq(1, 1 + trunc(WaitT/SyncInt))]),
+                              #{filesync_repeat_interval => no_repeat}),
+    check_tracer(100),
     ok.
 filesync(cleanup, _Config) ->
+    dbg:stop_clear(),
     logger:remove_handler(?MODULE).
 
 write_failure(Config) ->
@@ -785,7 +778,7 @@ op_switch_to_drop_tty(cleanup, _Config) ->
     ok = stop_handler(?MODULE).
 
 op_switch_to_flush_file() ->
-    [{timetrap,{seconds,60}}].
+    [{timetrap,{minutes,3}}].
 op_switch_to_flush_file(Config) ->
     {Log,HConfig,StdHConfig} = start_handler(?MODULE, ?FUNCTION_NAME, Config),
 
@@ -1052,7 +1045,7 @@ restart_after(cleanup, _Config) ->
 %% during high load to verify that sync, dropping and flushing is
 %% handled correctly.
 handler_requests_under_load() ->
-    [{timetrap,{seconds,60}}].
+    [{timetrap,{minutes,3}}].
 handler_requests_under_load(Config) ->
     {Log,HConfig,StdHConfig} =
         start_handler(?MODULE, ?FUNCTION_NAME, Config),
@@ -1394,3 +1387,67 @@ analyse(Msgs) ->
             From ! {result,self(),TestFun(Msgs)},
             analyse(Msgs)
     end.
+
+start_tracer(Trace,Expected) ->
+    Pid = self(),
+    FileCtrlPid = maps:get(file_ctrl_pid, logger_std_h:info(?MODULE)),
+    dbg:tracer(process,{fun tracer/2,{Pid,Expected}}),
+    dbg:p(whereis(?MODULE),[c]),
+    dbg:p(FileCtrlPid,[c]),
+    tpl(Trace),
+    ok.
+
+tpl([{M,F,A}|Trace]) ->
+    {ok,Match} = dbg:tpl(M,F,A,[]),
+    case lists:keyfind(matched,1,Match) of
+        {_,_,1} ->
+            ok;
+        _ ->
+            dbg:stop_clear(),
+            throw({skip,"Can't trace "++atom_to_list(M)++":"++
+                       atom_to_list(F)++"/"++integer_to_list(A)})
+    end,
+    tpl(Trace);
+tpl([]) ->
+    ok.
+
+tracer({trace,_,call,{logger_std_h,handle_cast,[{Op,_}|_]}},
+       {Pid,[{Mod,Func,Op}|Expected]}) ->
+    maybe_tracer_done(Pid,Expected,{Mod,Func,Op});
+tracer({trace,_,call,{Mod=logger_std_h,Func=write_to_dev,[_,Data,_,_,_]}},
+       {Pid,[{Mod,Func,Data}|Expected]}) ->
+    maybe_tracer_done(Pid,Expected,{Mod,Func,Data});
+tracer({trace,_,call,{Mod,Func,_}}, {Pid,[{Mod,Func}|Expected]}) ->
+    maybe_tracer_done(Pid,Expected,{Mod,Func});
+tracer({trace,_,call,Call}, {Pid,Expected}) ->
+    ct:log("Tracer got unexpected: ~p~nExpected: ~p~n",[Call,Expected]),
+    Pid ! {tracer_got_unexpected,Call,Expected},
+    {Pid,Expected}.
+
+maybe_tracer_done(Pid,[]=Expected,Got) ->
+    ct:log("Tracer got: ~p~n",[Got]),
+    Pid ! {tracer_done,0},
+    {Pid,Expected};
+maybe_tracer_done(Pid,[{no_more,T}]=Expected,Got) ->
+    ct:log("Tracer got: ~p~n",[Got]),
+    Pid ! {tracer_done,T},
+    {Pid,Expected};
+maybe_tracer_done(Pid,Expected,Got) ->
+    ct:log("Tracer got: ~p~n",[Got]),
+    {Pid,Expected}.
+
+check_tracer(T) ->
+    check_tracer(T,fun() -> ct:fail({timeout,tracer}) end).
+check_tracer(T,TimeoutFun) ->
+    receive
+        {tracer_done,Delay} ->
+            %% Possibly wait Delay ms to check that no unexpected
+            %% traces are received
+            check_tracer(Delay,fun() -> ok end);
+        {tracer_got_unexpected,Got,Expected} ->
+            dbg:stop_clear(),
+            ct:fail({tracer_got_unexpected,Got,Expected})
+    after T ->
+            dbg:stop_clear(),
+            TimeoutFun()
+    end.
-- 
cgit v1.2.3


From de2965827bfb903dcfcd0a97603548b2f8e3a807 Mon Sep 17 00:00:00 2001
From: Siri Hansen 
Date: Wed, 2 May 2018 18:55:10 +0200
Subject: Change return type from logger_formatter:format/2

This used to be string() is now changed to unicode:chardata().
---
 lib/kernel/doc/src/logger_chapter.xml | 22 ++++------------------
 lib/kernel/src/logger_formatter.erl   |  5 ++---
 2 files changed, 6 insertions(+), 21 deletions(-)

diff --git a/lib/kernel/doc/src/logger_chapter.xml b/lib/kernel/doc/src/logger_chapter.xml
index 78d6f46c95..36f5f6dea3 100644
--- a/lib/kernel/doc/src/logger_chapter.xml
+++ b/lib/kernel/doc/src/logger_chapter.xml
@@ -157,7 +157,7 @@
 	  
A formatter is defined as a module exporting the following
 	    function:

 
-	  format(Log,Extra) -> string()
+	  format(Log,Extra) -> unicode:chardata()
 
 	  
The formatter plugin is called by each handler, and the
 	    returned string can be printed to the handler's destination
@@ -322,19 +322,6 @@
 	    return ignore.

 	  
Default is log.

 	
-        depth = pos_integer() | unlimited
-	
-	  
Specifies if the depth of terms in the log events shall
-	    be limited by using control characters ~P
-	    and ~W instead of ~p and ~w,
-	    respectively. See
-	    io:format.

-	
-        max_size = pos_integer() | unlimited
-	
-	  
Specifies if the size of a log event shall be limited by
-	    truncating the formatted string.

-	
 	formatter = {Module::module(),Extra::term()}
 	
 	  
See Formatter for more
@@ -347,10 +334,9 @@
 
       
Note that level and filters are obeyed by
 	Logger itself before forwarding the log events to each
-	handler, while depth, max_size
-	and formatter are left to the handler
-	implementation. All Logger's built-in handlers do apply these
-	configuration parameters before printing.

+	handler, while formatter is left to the handler
+	implementation. All Logger's built-in handlers will call the
+	given formatter before printing.

     
 
   
diff --git a/lib/kernel/src/logger_formatter.erl b/lib/kernel/src/logger_formatter.erl
index 5358652692..8e954f8d98 100644
--- a/lib/kernel/src/logger_formatter.erl
+++ b/lib/kernel/src/logger_formatter.erl
@@ -29,7 +29,7 @@
 
 %%%-----------------------------------------------------------------
 %%% API
--spec format(Log,Config) -> String when
+-spec format(Log,Config) -> unicode:chardata() when
       Log :: logger:log(),
       Config :: #{single_line=>boolean(),
                   legacy_header=>boolean(),
@@ -38,8 +38,7 @@
                   max_size=>pos_integer() | unlimited,
                   depth=>pos_integer() | unlimited,
                   template=>template(),
-                  utc=>boolean()},
-      String :: string().
+                  utc=>boolean()}.
 format(#{level:=Level,msg:=Msg0,meta:=Meta},Config0)
   when is_map(Config0) ->
     Config = add_default_config(Config0),
-- 
cgit v1.2.3


From 336e7eed4e44fe9267234e4702db6fd613064dcd Mon Sep 17 00:00:00 2001
From: Siri Hansen 
Date: Wed, 2 May 2018 18:57:23 +0200
Subject: Improve documentation of logger:set_*_config functions

---
 lib/kernel/doc/src/logger.xml | 38 ++++++++++++++++++++++++++++++++++++--
 1 file changed, 36 insertions(+), 2 deletions(-)

diff --git a/lib/kernel/doc/src/logger.xml b/lib/kernel/doc/src/logger.xml
index ded9c1fb37..2beefd1240 100644
--- a/lib/kernel/doc/src/logger.xml
+++ b/lib/kernel/doc/src/logger.xml
@@ -404,21 +404,55 @@ Current logger configuration:
 
     
       
+      Set configuration data for the logger.
+      
+        
Set configuration data for the logger. This overwrites the
+          current logger configuration.

+	
To modify the existing configuration,
+	  use set_logger_config/2
+	  , or read the current configuration
+	  with get_logger_config/0
+	  , then merge in your added or updated
+	  associations before writing it back.

+      
+    
+
+    
       
       Add or update configuration data for the logger.
       
-        
Add or update configuration data for the logger.

+        
Add or update configuration data for the logger. If the
+          given Key already exists, its associated
+          value will be set to Value. If it
+          doesn't exist, it will be added.

       
     
 
     
       
+      Set configuration data for the specified handler.
+      
+        
Set configuration data for the specified handler. This
+          overwrites the current handler configuration.

+	
To modify the existing configuration,
+	  use set_handler_config/3
+	  , or read the current configuration
+	  with get_handler_config/1
+	  , then merge in your added or updated
+	  associations before writing it back.

+      
+    
+
+    
       
       Add or update configuration data for the specified
         handler.
       
         
Add or update configuration data for the specified
-          handler.

+          handler. If the
+          given Key already exists, its associated
+          value will be set to Value. If it
+          doesn't exist, it will be added.

       
     
 
-- 
cgit v1.2.3


From 3cef0524e4332ebf547180ec0d0feafe0a559b5c Mon Sep 17 00:00:00 2001
From: Siri Hansen 
Date: Wed, 2 May 2018 19:20:27 +0200
Subject: Add logger:update_process_metadata/1

---
 lib/kernel/doc/src/logger.xml    | 22 ++++++++++++++++++----
 lib/kernel/src/logger.erl        | 17 +++++++++++++++--
 lib/kernel/test/logger_SUITE.erl |  3 +++
 3 files changed, 36 insertions(+), 6 deletions(-)

diff --git a/lib/kernel/doc/src/logger.xml b/lib/kernel/doc/src/logger.xml
index 2beefd1240..2f7feb5eef 100644
--- a/lib/kernel/doc/src/logger.xml
+++ b/lib/kernel/doc/src/logger.xml
@@ -471,10 +471,9 @@ Current logger configuration:
       
       Set metadata to use when logging from current process.
       
-        
Set metadata which logger automatically inserts it
-          in all log events produced on the current
-          process. Subsequent calls will overwrite previous data set
-          by this function.

+        
Set metadata which logger automatically inserts in
+          all log events produced on the current process. Subsequent
+          calls will overwrite previous data set by this function.

 	
When logging, location data produced by the log macros,
 	  and/or metadata given as argument to the log call (API
 	  function or macro), will be merged with the process
@@ -485,6 +484,21 @@ Current logger configuration:
       
     
 
+    
+      
+      Update metadata to use when logging from current process.
+      
+	
Update metadata to use when logging from current process

+	
This function behaves as if it was implemented as follows:

+	
+logger:set_process_metadata(maps:merge(logger:get_process_metadata(),Meta))
+	
+	
If no process metadata exists, the function behaves as
+	  set_process_metadata/1
+	  .

+      
+    
+
     
       
       Retrieve data set with set_process_metadata/1.
diff --git a/lib/kernel/src/logger.erl b/lib/kernel/src/logger.erl
index 943ef8c2d1..5562764204 100644
--- a/lib/kernel/src/logger.erl
+++ b/lib/kernel/src/logger.erl
@@ -44,8 +44,8 @@
 
 %% Misc
 -export([compare_levels/2]).
--export([set_process_metadata/1, unset_process_metadata/0,
-         get_process_metadata/0]).
+-export([set_process_metadata/1, update_process_metadata/1,
+         unset_process_metadata/0, get_process_metadata/0]).
 -export([i/0, i/1]).
 -export([setup_standard_handler/0, replace_simple_handler/3]).
 -export([limit_term/1, get_format_depth/0, get_max_size/0, get_utc_config/0]).
@@ -390,6 +390,19 @@ set_process_metadata(Meta) when is_map(Meta) ->
 set_process_metadata(Meta) ->
     erlang:error(badarg,[Meta]).
 
+-spec update_process_metadata(Meta) -> ok when
+      Meta :: metadata().
+update_process_metadata(Meta) when is_map(Meta) ->
+    case get_process_metadata() of
+        undefined ->
+            set_process_metadata(Meta);
+        Meta0 when is_map(Meta0) ->
+            set_process_metadata(maps:merge(Meta0,Meta)),
+            ok
+    end;
+update_process_metadata(Meta) ->
+    erlang:error(badarg,[Meta]).
+
 -spec get_process_metadata() -> Meta | undefined when
       Meta :: metadata().
 get_process_metadata() ->
diff --git a/lib/kernel/test/logger_SUITE.erl b/lib/kernel/test/logger_SUITE.erl
index 0edce3e34c..94fd87bdb0 100644
--- a/lib/kernel/test/logger_SUITE.erl
+++ b/lib/kernel/test/logger_SUITE.erl
@@ -666,6 +666,9 @@ process_metadata(_Config) ->
     check_logged(info,S3,#{time=>Time,line=>0,custom=>func}),
 
     ProcMeta = logger:get_process_metadata(),
+    ok = logger:update_process_metadata(#{custom=>changed,custom2=>added}),
+    Expected = ProcMeta#{custom:=changed,custom2=>added},
+    Expected = logger:get_process_metadata(),
     ok = logger:unset_process_metadata(),
     undefined = logger:get_process_metadata(),
 
-- 
cgit v1.2.3


From d8e804043c6b4974943884cb15b86b40a5c870f1 Mon Sep 17 00:00:00 2001
From: Siri Hansen 
Date: Thu, 3 May 2018 15:46:57 +0200
Subject: Don't crash logger_server due to unexpected message

---
 lib/kernel/src/logger_server.erl | 8 +++++++-
 1 file changed, 7 insertions(+), 1 deletion(-)

diff --git a/lib/kernel/src/logger_server.erl b/lib/kernel/src/logger_server.erl
index 6ef3b8582a..052036b8d0 100644
--- a/lib/kernel/src/logger_server.erl
+++ b/lib/kernel/src/logger_server.erl
@@ -234,7 +234,13 @@ handle_info({log,Level,Report,Meta}, State) ->
     {noreply, State};
 handle_info({Ref,_Reply},State) when is_reference(Ref) ->
     %% Assuming this is a timed-out gen_server reply - ignoring
-    {noreply, State}.
+    {noreply, State};
+handle_info(Unexpected,State) ->
+    ?LOG_INTERNAL(debug,
+                  [{logger,got_unexpected_message},
+                   {process,?SERVER},
+                   {message,Unexpected}]),
+    {noreply,State}.
 
 terminate(_Reason, _State) ->
     ok.
-- 
cgit v1.2.3


From 3c9e4adff06a3f74513cb6658405e43e674133c1 Mon Sep 17 00:00:00 2001
From: Siri Hansen 
Date: Fri, 4 May 2018 16:40:55 +0200
Subject: Change logger callback removing_handler/1 to removing_handler/2

---
 lib/kernel/doc/src/logger_chapter.xml | 8 ++++----
 lib/kernel/src/error_logger.erl       | 6 +++---
 lib/kernel/src/logger_disk_log_h.erl  | 4 ++--
 lib/kernel/src/logger_server.erl      | 2 +-
 lib/kernel/src/logger_simple.erl      | 4 ++--
 lib/kernel/src/logger_std_h.erl       | 4 ++--
 lib/kernel/test/logger_SUITE.erl      | 2 +-
 7 files changed, 15 insertions(+), 15 deletions(-)

diff --git a/lib/kernel/doc/src/logger_chapter.xml b/lib/kernel/doc/src/logger_chapter.xml
index 36f5f6dea3..519df2ba48 100644
--- a/lib/kernel/doc/src/logger_chapter.xml
+++ b/lib/kernel/doc/src/logger_chapter.xml
@@ -503,7 +503,7 @@ ok

It may also implement the following callbacks:

adding_handler(logger:handler_id(),logger:config()) -> {ok,logger:config()} | {error,term()} -removing_handler(logger:handler_id()) -> ok +removing_handler(logger:handler_id(),logger:config()) -> ok changing_config(logger:handler_id(),logger:config(),logger:config()) -> {ok,logger:config()} | {error,term()}

When logger:add_handler(Id,Module,Config) is called, logger @@ -513,7 +513,7 @@ changing_config(logger:handler_id(),logger:config(),logger:config()) -> {ok,logg events as calls to Module:log/2.

A handler can be removed by calling logger:remove_handler(Id). logger will call - Module:removing_handler(Id), and then remove the handler's + Module:removing_handler(Id,Config), and then remove the handler's configuration from the configuration database.

When logger:set_handler_config is called, logger calls Module:changing_config(Id,OldConfig,NewConfig). If this function @@ -534,7 +534,7 @@ log(Log,#{formatter:={FModule,FConfig}) -> this:

-module(myhandler). --export([adding_handler/2, removing_handler/1, log/2]). +-export([adding_handler/2, removing_handler/2, log/2]). -export([init/1, handle_call/3, handle_cast/2, terminate/2]). adding_handler(Id,Config) -> @@ -563,7 +563,7 @@ log(Log,#{myhandler_fd:=Fd,formatter:={FModule,FConfig}}) -> single process.

-module(myhandler). --export([adding_handler/2, removing_handler/1, log/2]). +-export([adding_handler/2, removing_handler/2, log/2]). -export([init/1, handle_call/3, handle_cast/2, terminate/2]). adding_handler(Id,Config) -> diff --git a/lib/kernel/src/error_logger.erl b/lib/kernel/src/error_logger.erl index 0706220a94..47d0ca5ea3 100644 --- a/lib/kernel/src/error_logger.erl +++ b/lib/kernel/src/error_logger.erl @@ -32,7 +32,7 @@ which_report_handlers/0]). %% logger callbacks --export([adding_handler/2, removing_handler/1, log/2]). +-export([adding_handler/2, removing_handler/2, log/2]). -export([get_format_depth/0, limit_term/1]). @@ -111,8 +111,8 @@ adding_handler(?MODULE,Config) -> Error end. --spec removing_handler(logger:handler_id()) -> ok. -removing_handler(?MODULE) -> +-spec removing_handler(logger:handler_id(),logger:config()) -> ok. +removing_handler(?MODULE,_Config) -> stop(), ok. diff --git a/lib/kernel/src/logger_disk_log_h.erl b/lib/kernel/src/logger_disk_log_h.erl index 3b71f936d8..0150fa781a 100644 --- a/lib/kernel/src/logger_disk_log_h.erl +++ b/lib/kernel/src/logger_disk_log_h.erl @@ -34,7 +34,7 @@ %% logger callbacks -export([log/2, - adding_handler/2, removing_handler/1, + adding_handler/2, removing_handler/2, changing_config/3, swap_buffer/2]). %%%=================================================================== @@ -223,7 +223,7 @@ check_my_config([]) -> %%%----------------------------------------------------------------- %%% Handler being removed -removing_handler(Name) -> +removing_handler(Name, _Config) -> stop(Name). %%%----------------------------------------------------------------- diff --git a/lib/kernel/src/logger_server.erl b/lib/kernel/src/logger_server.erl index 052036b8d0..a7f302ac8f 100644 --- a/lib/kernel/src/logger_server.erl +++ b/lib/kernel/src/logger_server.erl @@ -158,7 +158,7 @@ handle_call({remove_handler,HandlerId}, _From, #state{tid=Tid}=State) -> Handlers0 = maps:get(handlers,Config,[]), Handlers = lists:delete(HandlerId,Handlers0), %% inform the handler - _ = call_h(Module,removing_handler,[HandlerId],ok), + _ = call_h(Module,removing_handler,[HandlerId,Config],ok), do_set_config(Tid,logger,Config#{handlers=>Handlers}), logger_config:delete(Tid,HandlerId), ok; diff --git a/lib/kernel/src/logger_simple.erl b/lib/kernel/src/logger_simple.erl index 23ff6ccd2e..a1b427b96c 100644 --- a/lib/kernel/src/logger_simple.erl +++ b/lib/kernel/src/logger_simple.erl @@ -19,7 +19,7 @@ %% -module(logger_simple). --export([adding_handler/2, removing_handler/1, log/2]). +-export([adding_handler/2, removing_handler/2, log/2]). -export([get_buffer/0]). %% This module implements a simple handler for logger. It is the @@ -63,7 +63,7 @@ adding_handler(?MODULE,Config) -> {error,{handler_process_name_already_exists,?MODULE}} end. -removing_handler(?MODULE) -> +removing_handler(?MODULE,_Config) -> case whereis(?MODULE) of undefined -> ok; diff --git a/lib/kernel/src/logger_std_h.erl b/lib/kernel/src/logger_std_h.erl index cbc9db372c..31edcfea8b 100644 --- a/lib/kernel/src/logger_std_h.erl +++ b/lib/kernel/src/logger_std_h.erl @@ -35,7 +35,7 @@ terminate/2, code_change/3]). %% logger callbacks --export([log/2, adding_handler/2, removing_handler/1, +-export([log/2, adding_handler/2, removing_handler/2, changing_config/3, swap_buffer/2]). %%%=================================================================== @@ -207,7 +207,7 @@ check_my_config([]) -> %%%----------------------------------------------------------------- %%% Handler being removed -removing_handler(Name) -> +removing_handler(Name,_Config) -> stop(Name). %%%----------------------------------------------------------------- diff --git a/lib/kernel/test/logger_SUITE.erl b/lib/kernel/test/logger_SUITE.erl index 94fd87bdb0..f311a9c7ed 100644 --- a/lib/kernel/test/logger_SUITE.erl +++ b/lib/kernel/test/logger_SUITE.erl @@ -723,7 +723,7 @@ check_maps(Expected,Got,What) -> adding_handler(_Id,Config) -> maybe_send(add), {ok,Config}. -removing_handler(_Id) -> +removing_handler(_Id,_Config) -> maybe_send(remove), ok. changing_config(_Id,_Old,#{call:=Fun}) -> -- cgit v1.2.3