From 395dbad6bcc38c3384840674f40657273b05b14a Mon Sep 17 00:00:00 2001 From: Lukas Larsson Date: Tue, 8 May 2018 16:13:50 +0200 Subject: logger: Rework configuration of logger Most logger configuration that was possible through kernel application variables have been moved into a common 'logger' application environment in kernel. Now all the configuration possible through the logger API can be done as sys config. The handler started by kernel has been renamed to 'default' instead of logger_std_h. There is a new logger:setup_handlers/1 function that given an application name can be used to setup handlers in other applications. --- lib/kernel/doc/src/config.xml | 4 +- lib/kernel/doc/src/kernel_app.xml | 141 ++--- lib/kernel/doc/src/logger.xml | 103 +++- lib/kernel/doc/src/logger_chapter.xml | 101 +++- lib/kernel/doc/src/logger_disk_log_h.xml | 8 +- lib/kernel/doc/src/logger_formatter.xml | 2 +- lib/kernel/doc/src/logger_std_h.xml | 11 +- lib/kernel/doc/src/ref_man.xml | 4 +- lib/kernel/src/file.erl | 2 +- lib/kernel/src/kernel.app.src | 5 +- lib/kernel/src/kernel.erl | 14 +- lib/kernel/src/logger.erl | 271 ++++++---- lib/kernel/src/logger_config.erl | 2 +- lib/kernel/src/logger_internal.hrl | 2 +- lib/kernel/src/logger_server.erl | 24 +- lib/kernel/src/logger_simple.erl | 69 +-- lib/kernel/test/Makefile | 1 + lib/kernel/test/logger_SUITE.erl | 12 +- lib/kernel/test/logger_disk_log_h_SUITE.erl | 28 +- lib/kernel/test/logger_env_var_SUITE.erl | 790 +++++++++++++++++----------- lib/kernel/test/logger_formatter_SUITE.erl | 4 +- lib/kernel/test/logger_simple_SUITE.erl | 203 +++---- lib/kernel/test/logger_std_h_SUITE.erl | 59 +-- lib/kernel/test/logger_test_lib.erl | 82 +++ lib/sasl/test/sasl_report_SUITE.erl | 6 +- 25 files changed, 1159 insertions(+), 789 deletions(-) create mode 100644 lib/kernel/test/logger_test_lib.erl (limited to 'lib') diff --git a/lib/kernel/doc/src/config.xml b/lib/kernel/doc/src/config.xml index fdb2d29f63..8850c1736b 100644 --- a/lib/kernel/doc/src/config.xml +++ b/lib/kernel/doc/src/config.xml @@ -37,10 +37,10 @@ data in the system configuration file Name.config.

Configuration parameter values in the configuration file override the values in the application resource files (see - app(4). + app(4)). The values in the configuration file can be overridden by command-line flags (see - erts:erl(1).

+ erts:erl(1)).

The value of a configuration parameter is retrieved by calling application:get_env/1,2.

diff --git a/lib/kernel/doc/src/kernel_app.xml b/lib/kernel/doc/src/kernel_app.xml index 7894600c21..ebc7962f29 100644 --- a/lib/kernel/doc/src/kernel_app.xml +++ b/lib/kernel/doc/src/kernel_app.xml @@ -165,78 +165,34 @@

Permissions are described in application:permit/2.

- logger_dest = Value + logger = [Config] -

Value is one of:

- - tty -

Installs the standard handler, - logger_std_h(3), with type set - to standard_io. This is the default - option.

 - {file, FileName} -

Installs the standard handler, - logger_std_h(3), with type set - to {file, FileName}, where FileName - is a string. The file is opened with encoding UTF-8.

 - {disk_log, FileName} -

Installs the disk_log handler, - logger_disk_log_h(3), with file set - to FileName (a string), and possibly other disk_log - parameters set by the environment variables - logger_disk_log_type, logger_disk_log_maxfiles and - logger_disk_log_maxbytes, - see below. The - file is opened with encoding UTF-8.

 - false - -

No standard handler is installed, but - the initial, primitive handler is kept, printing - raw event messages to tty.

- - silent - -

No standard handler is started, and the initial, - primitive handler is removed.

- - +

Specifies how logger should be + configured.

+

For more details and examples, see the + Configuration section in the + Logger User's Guide. +

- logger_level = Level + logger_level = Level -

Value = emergency | alert | critical | error | warning | +

Level = emergency | alert | critical | error | warning | notice | info | debug

This parameter specifies which log levels to log. The specified level, and all levels that are more severe, will be logged.

-

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).

+

It is possible to change this variable at run-time + using + logger:set_logger_config(#{ level => error }). + .

The default value is info.

 - - logger_disk_log_type = halt | wrap - - logger_disk_log_maxfiles = integer() - - logger_disk_log_maxbytes = integer() - -

If logger_dest is set to {disk_log,File}, then these - parameters specify the configuration to use when opening the - disk log file. They specify the type of disk log, the - maximum number of files (if the type is wrap) and the - maximum size of each file, respectively.

-

The default values are:

- -logger_disk_log_type = wrap -logger_disk_log_maxfiles = 10 -logger_disk_log_maxbytes = 1048576 - logger_sasl_compatible = boolean() -

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 started, +

If this parameter is set to true, then the default logger handler + will not log any progress-, crash-, or 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 @@ -247,6 +203,8 @@ logger_disk_log_maxbytes = 1048576

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

+

This configuration option only effects the default + and sasl handler. Any other handlers are uneffected.

 logger_log_progress = boolean() @@ -254,51 +212,13 @@ logger_disk_log_maxbytes = 1048576

If logger_sasl_compatible = false, then logger_log_progress specifies if progress reports from supervisor - and application_controller shall be logged or - not.

+ and application_controller shall be logged by the + default logger.

If logger_sasl_compatible = true, then logger_log_progress is ignored.

- - - logger_format_depth = Depth - -

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

- -

Depth is a positive integer representing the maximum - depth to which terms are printed by the logger - handlers included in OTP. This - configuration parameter is used by the default formatter, - logger_formatter(3), - unless the formatter's depth parameter is explicitly set. - (If you have implemented your own formatter, this configuration - parameter has no effect on that.)

- -

Depth is used as follows: Format strings - received by the formatter are rewritten. - The format controls ~p and ~w are replaced with - ~P and ~W, respectively, and Depth is - used as the depth parameter. For details, see - io:format/2 - in STDLIB.

- -

A reasonable starting value for Depth is - 30. We recommend to test crashing various processes in your - application, examine the logs from the crashes, and then - increase or decrease the value.

 - - logger_max_size = integer() | unlimited - -

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() - -

If set to true, the default formatter will display - all dates in Universal Coordinated Time.

+

The default value is false

+

This configuration option only effects the default + and sasl handler. Any other handlers are uneffected.

 global_groups = [GroupTuple] @@ -572,9 +492,20 @@ MaxT = TickTime + TickTime / 4 variables are not set.

error_logger - Replaced by logger_dest + Replaced by setting the type of the default + logger_std_h + to the same value. Example: + +erl -kernel logger '[{handler,default,logger_std_h,#{logger_std_h=>#{type=>{file,"/tmp/erlang.log"}}}}]' + + error_logger_format_depth - Replaced by logger_format_depth + Replaced by setting the depth + parameter of the default handlers formatter. Example: + +erl -kernel logger '[{handler,default,logger_std_h,#{formatter=>{logger_formatter,#{legacy_header=>true,template=>[{logger_formatter,header},"\n",msg,"\n"],depth=>10}}}]' + +

See Backwards compatibility with error_logger for more diff --git a/lib/kernel/doc/src/logger.xml b/lib/kernel/doc/src/logger.xml index d901454e62..239b9553b1 100644 --- a/lib/kernel/doc/src/logger.xml +++ b/lib/kernel/doc/src/logger.xml @@ -33,10 +33,49 @@ logger.xml logger - API module for the logger application. + API module for the logger. - +

+ This module is the main logger API. It contains functions that allow + application to use a single log API and the system to manage those log + events independently. To log events the logger + macros should be used. For instance, + to log a new error log event:

+ +?LOG_ERROR("error happened because: ~p",[Reason]). %% With macro +logger:error("error happened because: ~p",[Reason]). %% Without macro + +

This log event will then be sent to the configured log handlers which + by default means that it will be printed to the console. If you want + your systems logs to be printed to a file instead of the console you + have to configure the default handler to do so. The simplest way is + to include the following in your sys.config.

+ +[{kernel, + [{logger, + [{handler,default,logger_std_h, + #{logger_std_h=>#{type=>{file,"path/to/file.log"}}}}]}]}]. + +

+ For more information about: +

+ + how to use the API, + see the User's Guide. + how to configure logger, + see the Configuration + section in the User's Guide. + the convinience macros in logger.hrl, + see the macro section. + what the builtin formatter can do, + see logger_formatter. + what the builtin handlers can do, + see logger_std_h and + logger_disk_log_h. + what builtin filters are available, + see logger_filters. + @@ -348,16 +387,16 @@ logger:i(print). Current logger configuration: Level: info - FilterDefault: log + Filter Default: log Filters: Handlers: - Id: logger_std_h + Id: default Module: logger_std_h Level: info Formatter: Module: logger_formatter - Config: #{template => [{logger_formatter,header},"\n",msg,"\n"], - legacy_header => true} + Config: #{legacy_header => true,single_line => false, + template => [{logger_formatter,header},"\n",msg,"\n"]} Filter Default: stop Filters: Id: stop_progress @@ -549,6 +588,56 @@ Current logger configuration: + + + Setup logger handlers from the applications configuration parameters. + +

Reads the application configuration parameter logger and + calls logger:add_handlers/1 with it contents.

+ + + + + + Setup logger handlers. + + +

This function should be used by custom logger handlers to make + configuration consistent no matter which handler the system uses. + Normal usage to to add a call to logger:add_handlers/1 + just after the processes that the handler needs are started + and pass the applications logger config as an argument. Eg.

+ +-behaviour(application). +start(_, []) -> + case supervisor:start_link({local, my_sup}, my_sup, []) of + {ok, Pid} -> + ok = logger:add_handlers(my_app), + {ok, Pid, []}; + Error -> Error + end. +

This will read the logger configuration parameter from + the handler application and start the configured handlers. The contents + of the configuration use the same rules as the + logger handler configuration. +

+

If the handler is meant to replace the default handler the kernels + default handlers have to be disabled before the new handler is added. + A sys.config file that disables the kernel handler and adds + a custom handler could looks like this:

+ +[{kernel, + [{logger, + %% Disable the default kernel handler + [{handler,default,undefined}]}]}, + {my_app, + [{logger, + %% Enable this handler as the default + [{handler,default,my_handler,#{}}]}]}]. + + + + Set configuration data for the logger. @@ -650,7 +739,7 @@ Current logger configuration:

If process metadata exists for the current process, this function behaves as if it was implemented as follows:

-logger:set_process_metadata(maps:merge(logger:get_process_metadata(),Meta)) +logger:set_process_metadata(maps:merge(logger:get_process_metadata(),Meta)).

If no process metadata exists, the function behaves as diff --git a/lib/kernel/doc/src/logger_chapter.xml b/lib/kernel/doc/src/logger_chapter.xml index 3150c5adb4..484358f392 100644 --- a/lib/kernel/doc/src/logger_chapter.xml +++ b/lib/kernel/doc/src/logger_chapter.xml @@ -248,11 +248,97 @@

Configuration +

Logger can be configured either when the system starts through + configuration parameters, + or at run-time by using the logger + API. The recommended approach is to do the initial configuration in + the sys.config file and then use the API when some configuration + has to be changed at run-time, such as the logging level.

+
- Application environment variables -

See Kernel(6) for - information about the application environment variables that can - be used for configuring logger.

+ Application configuration parameters +

Logger is best configured by using the configuration parameters + of kernel. There are three possible configuration parameters: + logger, + logger_level, + logger_sasl_compatible and + logger_log_progress. + logger_level, logger_sasl_compatible and logger_log_progress are described in the + Kernel Configuration, + while logger is described below.

+
+ + logger +

The logger application configuration parameter is used to configure + three different logger aspects; handlers, logger filters and module levels. + The configuration is a list containing tagged tuples that look like this:

+ + DisableHandler = {handler,default,undefined} + Disable the default handler. This will allow another application + to add its own default handler. See + logger:add_handlers/1 for more details. + AddHandler = {handler,HandlerId,Module,HandlerConfig} + Add a handler as if + logger:add_handler(HandlerId,Module,HandlerConfig) had been + called. + Filters = {filters, FilterDefault, [Filter]}
+ FilterDefault = log | stop
+ Filter = {FilterId, {FilterFun, FilterConfig}} + Add the specified + logger filters. Only one entry is allowed of this option. + ModuleLevel + {module_level, Level, [Module]}, + this option configures the + module log level to be used. It is possible to have multiple + module_level entries. + +

Examples:

+ + +

Output logs into a the file "logs/erlang.log"

+ +[{kernel, + [{logger, + [{handler, default, logger_std_h, + #{ logger_std_h => #{ type => {file,"log/erlang.log"}}}}]}]}]. + + + +

Output logs in single line format

+ +[{kernel, + [{logger, + [{handler, default, logger_std_h, + #{ formatter => { logger_formatter,#{ single_line => true}}}}]}]}]. + + + +

Add the pid to each log event

+ +[{kernel, + [{logger, + [{handler, default, logger_std_h, + #{ formatter => { logger_formatter, + #{ template => [time," ",pid," ",msg,"\n"]}} + }}]}]}]. + + + +

Use a different file for debug logging

+ +[{kernel, + [{logger, + [{handler, default, logger_std_h, + #{ level => error, + logger_std_h => #{ type => {file, "log/erlang.log"}}}}, + {handler, info, logger_std_h, + #{ level => debug, + logger_std_h => #{ type => {file, "log/debug.log"}}}} + ]}]}]. + + + +
@@ -330,6 +416,13 @@ logger_formatter, and Extra is it's configuration map.

+ HandlerConfig, term() = term() + + Any keys not listed above are considered to be handler specific + configuration. The configuration of the Kernel handlers can be found in + logger_std_h and + logger_disk_log_h. +

Note that level and filters are obeyed by diff --git a/lib/kernel/doc/src/logger_disk_log_h.xml b/lib/kernel/doc/src/logger_disk_log_h.xml index 90cc4fec30..440ae28e5d 100644 --- a/lib/kernel/doc/src/logger_disk_log_h.xml +++ b/lib/kernel/doc/src/logger_disk_log_h.xml @@ -121,11 +121,11 @@ logger:add_handler(my_disk_log_h, logger_disk_log_h, #{filesync_repeat_interval => 1000}}).

In order to use the disk_log handler instead of the default standard - handler when starting en Erlang node, use the kernel configuration parameter - logger_dest with - value {disk_log,FileName}. Example:

+ handler when starting en Erlang node, change the Kernel default logger to + use disk_log. Example:

-erl -kernel logger_dest '{disk_log,"./system_disk_log"}' +erl -kernel logger '[{handler,default,logger_disk_log_h, + #{ disk_log_opts => #{ file => "./system_disk_log"}}}]' diff --git a/lib/kernel/doc/src/logger_formatter.xml b/lib/kernel/doc/src/logger_formatter.xml index 7df4c88f40..5f13e54365 100644 --- a/lib/kernel/doc/src/logger_formatter.xml +++ b/lib/kernel/doc/src/logger_formatter.xml @@ -66,7 +66,7 @@ be truncated by the max_size parameter.

- depth = pos_integer() | unlimited + depth = pos_integer() | unlimited

A positive integer representing the maximum depth to which terms shall be printed by this formatter. Format diff --git a/lib/kernel/doc/src/logger_std_h.xml b/lib/kernel/doc/src/logger_std_h.xml index fe9b9ca5a9..bf23d874c8 100644 --- a/lib/kernel/doc/src/logger_std_h.xml +++ b/lib/kernel/doc/src/logger_std_h.xml @@ -40,7 +40,7 @@ application. Multiple instances of this handler can be added to logger, and each instance will print logs to standard_io, standard_error or to file. The default instance that starts - with kernel is named logger_std_h - which is the name to be used + with kernel is named default - which is the name to be used for reconfiguration.

The handler has an overload protection mechanism that will keep the handler process and the kernel application alive during a high load of log @@ -57,7 +57,7 @@ are stored in a sub map with the key logger_std_h. The following keys and values may be specified:

- type + type

This will have the value standard_io, standard_error, {file,LogFileName}, or {file,LogFileName,LogFileOpts}, @@ -105,11 +105,10 @@ logger:add_handler(my_standard_h, logger_std_h,

In order to configure the default handler (that starts initially with the kernel application) to log to file instead of standard_io, - use the kernel configuration parameter - logger_dest with - value {file,FileName}. Example:

+ change the Kernel default logger to use a file. Example:

-erl -kernel logger_dest '{file,"./erl.log"}' +erl -kernel logger '[{handler,default,logger_std_h, + #{ logger_std_h => #{ type => {file,"./log.log"}}}}]'

An example of how to replace the standard handler with a disk_log handler at startup can be found in the manual of diff --git a/lib/kernel/doc/src/ref_man.xml b/lib/kernel/doc/src/ref_man.xml index a633ae4832..b6c2714664 100644 --- a/lib/kernel/doc/src/ref_man.xml +++ b/lib/kernel/doc/src/ref_man.xml @@ -32,9 +32,11 @@ + + @@ -67,6 +69,4 @@ - - diff --git a/lib/kernel/src/file.erl b/lib/kernel/src/file.erl index 57d8fc7a15..1d4e37196c 100644 --- a/lib/kernel/src/file.erl +++ b/lib/kernel/src/file.erl @@ -69,7 +69,7 @@ %% Types that can be used from other modules -- alphabetically ordered. -export_type([date_time/0, fd/0, file_info/0, filename/0, filename_all/0, - io_device/0, name/0, name_all/0, posix/0]). + io_device/0, mode/0, name/0, name_all/0, posix/0]). %%% Includes and defines -include("file_int.hrl"). diff --git a/lib/kernel/src/kernel.app.src b/lib/kernel/src/kernel.app.src index afffcd156e..23ac5b3444 100644 --- a/lib/kernel/src/kernel.app.src +++ b/lib/kernel/src/kernel.app.src @@ -140,7 +140,10 @@ inet_db, pg2]}, {applications, []}, - {env, []}, + {env, [{logger_level, info}, + {logger_sasl_compatible, false}, + {logger_log_progress, false} + ]}, {mod, {kernel, []}}, {runtime_dependencies, ["erts-10.0", "stdlib-3.5", "sasl-3.0"]} ] diff --git a/lib/kernel/src/kernel.erl b/lib/kernel/src/kernel.erl index ae982c1741..b0e8c00bbf 100644 --- a/lib/kernel/src/kernel.erl +++ b/lib/kernel/src/kernel.erl @@ -30,17 +30,13 @@ %%% Callback functions for the kernel application. %%%----------------------------------------------------------------- start(_, []) -> + %% Setup the logger and configure the kernel logger environment + ok = logger:internal_init_logger(), case supervisor:start_link({local, kernel_sup}, kernel, []) of {ok, Pid} -> ok = erl_signal_handler:start(), - %% add error handler - case logger:setup_standard_handler() of - ok -> {ok, Pid, []}; - Error -> - %% Not necessary since the node will crash anyway: - exit(Pid, shutdown), - Error - end; + ok = logger:add_handlers(kernel), + {ok, Pid, []}; Error -> Error end. @@ -147,7 +143,7 @@ init([]) -> case init:get_argument(mode) of {ok, [["minimal"]]} -> {ok, {SupFlags, - [Code, File, StdError, User, Config, RefC, SafeSup, LoggerSup]}}; + [Code, File, StdError, User, LoggerSup, Config, RefC, SafeSup]}}; _ -> Rpc = #{id => rex, start => {rpc, start_link, []}, diff --git a/lib/kernel/src/logger.erl b/lib/kernel/src/logger.erl index 98a9937111..9a6719923e 100644 --- a/lib/kernel/src/logger.erl +++ b/lib/kernel/src/logger.erl @@ -40,14 +40,17 @@ set_module_level/2, reset_module_level/1, set_logger_config/1, set_logger_config/2, set_handler_config/2, set_handler_config/3, - get_logger_config/0, get_handler_config/1]). + get_logger_config/0, get_handler_config/1, + add_handlers/1]). + +%% Private configuration +-export([internal_init_logger/0]). %% Misc -export([compare_levels/2]). -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]). %% Basic report formatting @@ -93,8 +96,10 @@ term() => term()}. -type timestamp() :: integer(). +-type config_handler() :: {handler, handler_id(), module(), config()}. + -export_type([log/0,level/0,report/0,msg_fun/0,metadata/0,config/0,handler_id/0, - filter_id/0,filter/0,filter_arg/0,filter_return/0]). + filter_id/0,filter/0,filter_arg/0,filter_return/0, config_handler/0]). %%%----------------------------------------------------------------- %%% API @@ -504,118 +509,184 @@ print_module_levels({Module,Level}) -> print_module_levels(ModuleLevels) -> lists:map(fun print_module_levels/1, ModuleLevels). --spec setup_standard_handler() -> ok | {error,term()}. -setup_standard_handler() -> - case get_logger_type() of - {ok,silent} -> - Level = get_logger_level(), - ok = set_logger_config(level,Level), - remove_handler(logger_simple); - {ok,Type} -> - Level = get_logger_level(), - ok = set_logger_config(level,Level), - Filters = get_logger_filters(), - setup_standard_handler(Type,#{level=>Level, - filter_default=>stop, - filters=>Filters}); - Error -> - Error +-spec internal_init_logger() -> ok | {error,term()}. +%% This function is responsible for config of the logger +%% This is done before add_handlers because we want the +%% logger settings to take effect before the kernel supervisor +%% tree is started. +internal_init_logger() -> + try + ok = logger:set_logger_config(level, get_logger_level()), + ok = logger:set_logger_config(filter_default, get_logger_filter_default()), + + [case logger:add_logger_filter(Id, Filter) of + ok -> ok; + {error, Reason} -> throw(Reason) + end || {Id, Filter} <- get_logger_filters()], + + _ = [[case logger:set_module_level(Module, Level) of + ok -> ok; + {error, Reason} -> throw(Reason) + end || Module <- Modules] + || {module_level, Level, Modules} <- get_logger_env()], + + case logger:set_handler_config(logger_simple,filters, + get_default_handler_filters()) of + ok -> ok; + {error,{not_found,logger_simple}} -> ok + end, + + init_kernel_handlers() + catch throw:Reason -> + ?LOG_ERROR("Invalid logger config: ~p", [Reason]), + {error, {bad_config, {kernel, Reason}}} end. --spec setup_standard_handler(Type,Config) -> ok | {error,term()} when - Type :: tty | standard_io | standard_error | {file,File} | - {file,File,Modes} | {disk_log,LogOpts} | false, - File :: file:filename(), - Modes :: [term()], % [file:mode()], or more specific? - Config :: config(), - LogOpts :: map(). -setup_standard_handler(false,#{level:=Level,filters:=Filters}) -> - case set_handler_config(logger_simple,level,Level) of - ok -> - set_handler_config(logger_simple,filters,Filters); - Error -> - Error - end; -setup_standard_handler(Type,Config) -> - {Module,TypeConfig} = get_type_config(Type), - replace_simple_handler(?STANDARD_HANDLER, - Module, - maps:merge(Config,TypeConfig)). - --spec replace_simple_handler(Id,Module,Config) -> ok | {error,term()} when - Id :: handler_id(), - Module :: module(), - Config :: config(). -replace_simple_handler(Id,Module,Config) -> - _ = code:ensure_loaded(Module), - DoBuffer = erlang:function_exported(Module,swap_buffer,2), - case add_handler(Id,Module,Config#{wait_for_buffer=>DoBuffer}) of - ok -> - if DoBuffer -> - {ok,Buffered} = logger_simple:get_buffer(), - _ = remove_handler(logger_simple), - Module:swap_buffer(?STANDARD_HANDLER,Buffered); - true -> - _ = remove_handler(logger_simple), - ok - end, - ok; - Error -> - Error +-spec init_kernel_handlers() -> ok | {error,term()}. +%% Setup the kernel environment variables to be correct +%% The actual handlers are started by a call to add_handlers. +init_kernel_handlers() -> + try + case get_logger_type() of + {ok,silent} -> + ok = logger:remove_handler(logger_simple); + {ok,false} -> + ok; + {ok,Type} -> + init_default_config(Type) + end + catch throw:Reason -> + ?LOG_ERROR("Invalid default handler config: ~p", [Reason]), + {error, {bad_config, {kernel, Reason}}} end. +-spec add_handlers(Application) -> ok | {error,term()} when + Application :: atom(); + (HandlerConfig) -> ok | {error,term()} when + HandlerConfig :: [config_handler()]. +%% This function is responsible for resolving the handler config +%% and then starting the correct handlers. This is done after the +%% kernel supervisor tree has been started as it needs the logger_sup. +add_handlers(App) when is_atom(App) -> + add_handlers(application:get_env(App, logger, [])); +add_handlers(HandlerConfig) -> + try + check_logger_config(HandlerConfig), + DefaultAdded = + lists:foldl( + fun({handler, default = Id, Module, Config}, _) + when not is_map_key(filters, Config) -> + %% The default handler should have a couple of extra filters + %% set on it by default. + DefConfig = #{ filter_default => stop, + filters => get_default_handler_filters()}, + setup_handler(Id, Module, maps:merge(DefConfig,Config)), + true; + ({handler, Id, Module, Config}, Default) -> + setup_handler(Id, Module, Config), + Default orelse Id == default; + (_, Default) -> Default + end, false, HandlerConfig), + %% If a default handler was added we try to remove the simple_logger + %% If the simple logger exists it will replay its log events + %% to the handler(s) added in the fold above. + _ = [case logger:remove_handler(logger_simple) of + ok -> ok; + {error,{not_found,logger_simple}} -> ok + end || DefaultAdded], + ok + catch throw:Reason -> + ?LOG_ERROR("Invalid logger handler config: ~p", [Reason]), + {error, {bad_config, {handler, Reason}}} + end. + +setup_handler(Id, Module, Config) -> + case logger:add_handler(Id, Module, Config) of + ok -> ok; + {error, Reason} -> throw(Reason) + end. + +check_logger_config(_) -> + ok. + +-spec get_logger_type() -> {ok, standard_io | false | silent | + {file, file:name_all()} | + {file, file:name_all(), [file:mode()]}}. get_logger_type() -> - Type0 = - case application:get_env(kernel, logger_dest) of - undefined -> - application:get_env(kernel, error_logger); - T -> - T - end, - case Type0 of + case application:get_env(kernel, error_logger) of {ok, tty} -> - {ok, tty}; + {ok, standard_io}; {ok, {file, File}} when is_list(File) -> {ok, {file, File}}; {ok, {file, File, Modes}} when is_list(File), is_list(Modes) -> {ok, {file, File, Modes}}; - {ok, {disk_log, File}} when is_list(File) -> - {ok, {disk_log, get_disk_log_config(File)}}; {ok, false} -> {ok, false}; {ok, silent} -> {ok, silent}; undefined -> - {ok, tty}; % default value + case lists:member({handler,default,undefined}, get_logger_env()) of + true -> + {ok, false}; + false -> + {ok, standard_io} % default value + end; {ok, Bad} -> - {error,{bad_config, {kernel, {logger_dest, Bad}}}} + throw({error_logger, Bad}) end. -get_disk_log_config(File) -> - Config1 = - case application:get_env(kernel,logger_disk_log_maxfiles) of - undefined -> #{}; - {ok,MF} -> #{max_no_files=>MF} - end, - Config2 = - case application:get_env(kernel,logger_disk_log_maxbytes) of - undefined -> Config1; - {ok,MB} -> Config1#{max_no_bytes=>MB} - end, - Config3 = - case application:get_env(kernel,logger_disk_log_type) of - undefined -> Config2; - {ok,T} -> Config1#{type=>T} - end, - Config3#{file=>File}. - get_logger_level() -> - case application:get_env(kernel,logger_level) of - undefined -> info; - {ok,Level} when ?IS_LEVEL(Level) -> Level + case application:get_env(kernel,logger_level,info) of + Level when ?IS_LEVEL(Level) -> + Level; + Level -> + throw({logger_level, Level}) + end. + +get_logger_filter_default() -> + case lists:keyfind(filters,1,get_logger_env()) of + {filters,Default,_} -> + Default; + false -> + log end. get_logger_filters() -> + lists:foldl( + fun({filters, _, Filters}, _Acc) -> + Filters; + (_, Acc) -> + Acc + end, [], get_logger_env()). + +%% This function looks at the kernel logger environment +%% and updates it so that the correct logger is configured +init_default_config(Type) when Type==standard_io; + Type==standard_error; + element(1,Type)==file -> + Env = get_logger_env(), + DefaultConfig = #{logger_std_h=>#{type=>Type}}, + NewLoggerEnv = + case lists:keyfind(default, 2, Env) of + {handler, default, Module, Config} -> + lists:map( + fun({handler, default, logger_std_h, _}) -> + %% Only want to add the logger_std_h config + %% if not configured by user AND the default + %% handler is still the logger_std_h. + {handler, default, Module, maps:merge(DefaultConfig,Config)}; + (Other) -> + Other + end, Env); + _ -> + %% Nothing has been configured, use default + [{handler, default, logger_std_h, DefaultConfig} | Env] + end, + application:set_env(kernel, logger, NewLoggerEnv, [{timeout,infinity}]); +init_default_config(Type) -> + throw({illegal_logger_type,Type}). + +get_default_handler_filters() -> case application:get_env(kernel, logger_sasl_compatible, false) of true -> ?DEFAULT_HANDLER_FILTERS([beam,erlang,otp]); @@ -631,18 +702,8 @@ get_logger_filters() -> Extra ++ ?DEFAULT_HANDLER_FILTERS([beam,erlang,otp,sasl]) end. -get_type_config({disk_log,LogOpts}) -> - {logger_disk_log_h,#{disk_log_opts=>LogOpts}}; -get_type_config(tty) -> - %% This is only for backwards compatibility with error_logger and - %% old kernel and sasl environment variables - get_type_config(standard_io); -get_type_config(Type) when Type==standard_io; - Type==standard_error; - element(1,Type)==file -> - {logger_std_h,#{logger_std_h=>#{type=>Type}}}; -get_type_config(Type) -> - {error,{illegal_logger_type,Type}}. +get_logger_env() -> + application:get_env(kernel, logger, []). %%%----------------------------------------------------------------- -spec limit_term(term()) -> term(). diff --git a/lib/kernel/src/logger_config.erl b/lib/kernel/src/logger_config.erl index 799aea9617..40dc1b1e1b 100644 --- a/lib/kernel/src/logger_config.erl +++ b/lib/kernel/src/logger_config.erl @@ -31,7 +31,7 @@ -include("logger_internal.hrl"). new(Name) -> - _ = ets:new(Name,[set,protected,named_table]), + _ = ets:new(Name,[set,protected,named_table,{write_concurrency,true}]), ets:whereis(Name). delete(Tid,Id) -> diff --git a/lib/kernel/src/logger_internal.hrl b/lib/kernel/src/logger_internal.hrl index 8c0fc2725d..f9377259f3 100644 --- a/lib/kernel/src/logger_internal.hrl +++ b/lib/kernel/src/logger_internal.hrl @@ -22,7 +22,7 @@ -define(LOGGER_KEY,'$logger_config$'). -define(HANDLER_KEY,'$handler_config$'). -define(LOGGER_META_KEY,'$logger_metadata$'). --define(STANDARD_HANDLER, logger_std_h). +-define(STANDARD_HANDLER, default). -define(DEFAULT_HANDLER_FILTERS, ?DEFAULT_HANDLER_FILTERS([beam,erlang,otp])). -define(DEFAULT_HANDLER_FILTERS(Domain), diff --git a/lib/kernel/src/logger_server.erl b/lib/kernel/src/logger_server.erl index a7f302ac8f..268fd4f2f3 100644 --- a/lib/kernel/src/logger_server.erl +++ b/lib/kernel/src/logger_server.erl @@ -122,8 +122,7 @@ init([]) -> logger_config:create(Tid,logger,LoggerConfig), SimpleConfig0 = maps:merge(default_config(logger_simple), #{filter_default=>stop, - filters=>?DEFAULT_HANDLER_FILTERS, - logger_simple=>#{buffer=>true}}), + filters=>?DEFAULT_HANDLER_FILTERS}), %% If this fails, then the node should crash {ok,SimpleConfig} = logger_simple:adding_handler(logger_simple,SimpleConfig0), @@ -139,12 +138,21 @@ handle_call({add_handler,Id,Module,HConfig}, _From, #state{tid=Tid}=State) -> %% inform the handler case call_h(Module,adding_handler,[Id,HConfig],{ok,HConfig}) of {ok,HConfig1} -> - logger_config:create(Tid,Id,Module,HConfig1), - {ok,Config} = do_get_config(Tid,logger), - Handlers = maps:get(handlers,Config,[]), - do_set_config(Tid,logger, - Config#{handlers=>[Id|Handlers]}), - ok; + %% We know that the call_h would have loaded the module + %% if it existed, so it is safe here to call function_exported + %% to find out if this is a valid handler + case erlang:function_exported(Module, log, 2) of + true -> + logger_config:create(Tid,Id,Module,HConfig1), + {ok,Config} = do_get_config(Tid,logger), + Handlers = maps:get(handlers,Config,[]), + do_set_config(Tid,logger, + Config#{handlers=>[Id|Handlers]}); + false -> + {error,{invalid_handler, + {function_not_exported, + {Module,log,2}}}} + end; {error,HReason} -> {error,{handler_not_added,HReason}} end diff --git a/lib/kernel/src/logger_simple.erl b/lib/kernel/src/logger_simple.erl index a1b427b96c..5272455a2d 100644 --- a/lib/kernel/src/logger_simple.erl +++ b/lib/kernel/src/logger_simple.erl @@ -20,29 +20,10 @@ -module(logger_simple). -export([adding_handler/2, removing_handler/2, log/2]). --export([get_buffer/0]). %% This module implements a simple handler for logger. It is the %% default used during system start. -%%%----------------------------------------------------------------- -%%% API -get_buffer() -> - case whereis(?MODULE) of - undefined -> - {error,noproc}; - Pid -> - Ref = erlang:monitor(process,Pid), - Pid ! {get_buffer,self()}, - receive - {buffer,Buffer} -> - erlang:demonitor(Ref,[flush]), - {ok,Buffer}; - {'DOWN',Ref,process,Pid,Reason} -> - {error,Reason} - end - end. - %%%----------------------------------------------------------------- %%% Logger callback @@ -50,7 +31,7 @@ adding_handler(?MODULE,Config) -> Me = self(), case whereis(?MODULE) of undefined -> - {Pid,Ref} = spawn_opt(fun() -> init(Me,Config) end, + {Pid,Ref} = spawn_opt(fun() -> init(Me) end, [link,monitor,{message_queue_data,off_heap}]), receive {'DOWN',Ref,process,Pid,Reason} -> @@ -102,48 +83,44 @@ log(_,_) -> %%%----------------------------------------------------------------- %%% Process -init(Starter,Config) -> +init(Starter) -> register(?MODULE,self()), Starter ! {self(),started}, - BufferSize = - case Config of - #{?MODULE:=#{buffer:=true}} -> - 10; - _ -> - infinity - end, - loop(#{buffer_size=>BufferSize,dropped=>0,buffer=>[]},infinity). + loop(#{buffer_size=>10,dropped=>0,buffer=>[]}). -loop(Buffer,Timeout) -> +loop(Buffer) -> receive stop -> - ok; - {get_buffer,From} -> - loop(Buffer#{send_to=>From},0); + %% We replay the logger messages of there is + %% a default handler when the simple handler + %% is removed. + case logger:get_handler_config(default) of + {ok, _} -> + replay_buffer(Buffer); + _ -> + ok + end; {log,#{msg:=_,meta:=#{time:=_}}=Log} -> do_log(Log), - loop(update_buffer(Buffer,Log),Timeout); + loop(update_buffer(Buffer,Log)); _ -> %% Unexpected message - flush it! - loop(Buffer,Timeout) - after Timeout -> - #{dropped:=D,buffer:=B,send_to:=Pid} = Buffer, - LogList = lists:reverse(B) ++ drop_msg(D), - Pid ! {buffer,LogList}, - loop(Buffer#{buffer_size=>infinity, - dropped=>0, - buffer=>[], - send_to=>false}, - infinity) + loop(Buffer) end. -update_buffer(#{buffer_size:=infinity}=Buffer,_Log) -> - Buffer; update_buffer(#{buffer_size:=0,dropped:=D}=Buffer,_Log) -> Buffer#{dropped=>D+1}; update_buffer(#{buffer_size:=S,buffer:=B}=Buffer,Log) -> Buffer#{buffer_size=>S-1,buffer=>[Log|B]}. +replay_buffer(#{ dropped := D, buffer := Buffer }) -> + lists:foreach( + fun F(#{msg := {Tag, Msg}} = L) when Tag =:= string; Tag =:= report -> + F(L#{ msg := Msg }); + F(#{ level := Level, msg := Msg, meta := MD}) -> + logger:log(Level, Msg, MD) + end, lists:reverse(Buffer, drop_msg(D))). + drop_msg(0) -> []; drop_msg(N) -> diff --git a/lib/kernel/test/Makefile b/lib/kernel/test/Makefile index 8599a3d814..2f637ca9de 100644 --- a/lib/kernel/test/Makefile +++ b/lib/kernel/test/Makefile @@ -79,6 +79,7 @@ MODULES= \ logger_legacy_SUITE \ logger_simple_SUITE \ logger_std_h_SUITE \ + logger_test_lib \ os_SUITE \ pg2_SUITE \ seq_trace_SUITE \ diff --git a/lib/kernel/test/logger_SUITE.erl b/lib/kernel/test/logger_SUITE.erl index f311a9c7ed..8a757f0078 100644 --- a/lib/kernel/test/logger_SUITE.erl +++ b/lib/kernel/test/logger_SUITE.erl @@ -40,18 +40,18 @@ suite() -> [{timetrap,{seconds,30}}]. init_per_suite(Config) -> - case logger:get_handler_config(logger_std_h) of + case logger:get_handler_config(?STANDARD_HANDLER) of {ok,StdH} -> - ok = logger:remove_handler(logger_std_h), - [{logger_std_h,StdH}|Config]; + ok = logger:remove_handler(?STANDARD_HANDLER), + [{default_handler,StdH}|Config]; _ -> Config end. end_per_suite(Config) -> - case ?config(logger_std_h,Config) of + case ?config(default_handler,Config) of {HMod,HConfig} -> - ok = logger:add_handler(logger_std_h,HMod,HConfig); + ok = logger:add_handler(?STANDARD_HANDLER,HMod,HConfig); _ -> ok end. @@ -434,7 +434,7 @@ handler_failed(_Config) -> logger:add_handler(h1,?MODULE,#{filter_default=>true}), {error,{invalid_formatter,[]}} = logger:add_handler(h1,?MODULE,#{formatter=>[]}), - ok = logger:add_handler(h1,nomodule,#{filter_default=>log}), + {error,{invalid_handler,_}} = logger:add_handler(h1,nomodule,#{filter_default=>log}), logger:info(?map_rep), check_no_log(), #{logger:=#{handlers:=Ids1}, diff --git a/lib/kernel/test/logger_disk_log_h_SUITE.erl b/lib/kernel/test/logger_disk_log_h_SUITE.erl index 7c33c9130c..cdd1e68947 100644 --- a/lib/kernel/test/logger_disk_log_h_SUITE.erl +++ b/lib/kernel/test/logger_disk_log_h_SUITE.erl @@ -31,7 +31,8 @@ end). suite() -> - [{timetrap,{seconds,30}}]. + [{timetrap,{seconds,30}}, + {ct_hooks,[logger_test_lib]}]. init_per_suite(Config) -> timer:start(), % to avoid progress report @@ -725,7 +726,7 @@ write_failure(Config) -> Log = lists:concat([File,".1"]), ct:pal("Log = ~p", [Log]), - Node = start_h_on_new_node(Config, ?FUNCTION_NAME, File), + Node = start_h_on_new_node(Config, File), false = (undefined == rpc:call(Node, ets, whereis, [?TEST_HOOKS_TAB])), rpc:call(Node, ets, insert, [?TEST_HOOKS_TAB,{tester,self()}]), rpc:call(Node, ?MODULE, set_internal_log, [?MODULE,internal_log]), @@ -769,7 +770,7 @@ sync_failure(Config) -> File = filename:join(Dir, FileName), - Node = start_h_on_new_node(Config, ?FUNCTION_NAME, File), + Node = start_h_on_new_node(Config, File), false = (undefined == rpc:call(Node, ets, whereis, [?TEST_HOOKS_TAB])), rpc:call(Node, ets, insert, [?TEST_HOOKS_TAB,{tester,self()}]), rpc:call(Node, ?MODULE, set_internal_log, [?MODULE,internal_log]), @@ -809,21 +810,12 @@ sync_failure(cleanup, _Config) -> Nodes = nodes(), [test_server:stop_node(Node) || Node <- Nodes]. -start_h_on_new_node(_Config, Func, File) -> - Pa = filename:dirname(code:which(?MODULE)), - Dest = - case os:type() of - {win32,_} -> - lists:concat([" {disk_log,\\\"",File,"\\\"}"]); - _ -> - lists:concat([" \'{disk_log,\"",File,"\"}\'"]) - end, - Args = lists:concat([" -kernel ",logger_dest,Dest," -pa ",Pa]), - NodeName = lists:concat([?MODULE,"_",Func]), - ct:pal("Starting ~s with ~tp", [NodeName,Args]), - {ok,Node} = test_server:start_node(NodeName, peer, [{args, Args}]), - Pid = rpc:call(Node,erlang,whereis,[?STANDARD_HANDLER]), - true = is_pid(Pid), +start_h_on_new_node(Config, File) -> + {ok,_,Node} = + logger_test_lib:setup( + Config, + [{logger,[{handler,default,logger_disk_log_h, + #{ disk_log_opts => #{ file => File }}}]}]), ok = rpc:call(Node,logger,set_handler_config,[?STANDARD_HANDLER,formatter, {?MODULE,nl}]), Node. diff --git a/lib/kernel/test/logger_env_var_SUITE.erl b/lib/kernel/test/logger_env_var_SUITE.erl index c2d3364701..e976a10b21 100644 --- a/lib/kernel/test/logger_env_var_SUITE.erl +++ b/lib/kernel/test/logger_env_var_SUITE.erl @@ -1,4 +1,4 @@ -% +%% %% %CopyrightBegin% %% %% Copyright Ericsson AB 2018. All Rights Reserved. @@ -21,83 +21,64 @@ -compile(export_all). --include_lib("common_test/include/ct.hrl"). -include_lib("kernel/include/logger.hrl"). -include_lib("kernel/src/logger_internal.hrl"). --define(all_vars,[{kernel,logger_dest}, - {kernel,logger_level}, - {kernel,logger_log_progress}, - {kernel,logger_sasl_compatible}, - {kernel,error_logger}]). +-import(logger_test_lib,[setup/2,log/3,sync_and_read/3]). suite() -> - [{timetrap,{seconds,30}}]. + [{timetrap,{seconds,60}}, + {ct_hooks,[logger_test_lib]}]. init_per_suite(Config) -> - Env = [{App,Key,application:get_env(App,Key)} || {App,Key} <- ?all_vars], - Removed = cleanup(), - [{env,Env},{logger,Removed}|Config]. - -end_per_suite(Config) -> - [application:set_env(App,Key,Val) || - {App,Key,Val} <- ?config(env,Config), - Val =/= undefined], - Hs = ?config(logger,Config), - [ok = logger:add_handler(Id,Mod,C) || {Id,Mod,C} <- Hs], - ok. - -init_per_group(_Group, Config) -> - Config. - -end_per_group(_Group, _Config) -> - ok. - -init_per_testcase(_TestCase, Config) -> Config. -end_per_testcase(Case, Config) -> - try apply(?MODULE,Case,[cleanup,Config]) - catch error:undef -> ok - end, - cleanup(), +end_per_suite(_Config) -> ok. groups() -> - []. - -all() -> + [{error_logger,[],[error_logger_tty, + error_logger_tty_sasl_compatible, + error_logger_false, + error_logger_false_progress, + error_logger_false_sasl_compatible, + error_logger_silent, + error_logger_silent_sasl_compatible, + error_logger_file]}, + {logger,[],[logger_file, + logger_file_sasl_compatible, + logger_file_log_progress, + logger_file_no_filter, + logger_file_no_filter_level, + logger_file_formatter, + logger_filters, + logger_filters_stop, + logger_module_level, + logger_disk_log, + logger_disk_log_formatter, + logger_undefined, + logger_many_handlers_default_first, + logger_many_handlers_default_last + ]}, + {bad,[],[bad_error_logger, + bad_level, + bad_sasl_compatibility, + bad_progress]}]. + +all() -> [default, default_sasl_compatible, - dest_tty, - dest_tty_sasl_compatible, - dest_false, - dest_false_progress, - dest_false_sasl_compatible, - dest_silent, - dest_silent_sasl_compatible, - dest_file_old, - dest_file, - dest_disk_log, - %% disk_log_vars, % or test this in logger_disk_log_SUITE? sasl_compatible_false, sasl_compatible_false_no_progress, sasl_compatible, - bad_dest%% , - %% bad_level, - %% bad_sasl_compatibility, - %% bad_progress + {group,bad}, + {group,error_logger}, + {group,logger} ]. default(Config) -> - {ok,{_Log,Hs}} = setup(Config,?FUNCTION_NAME, - undefined, - undefined, % dest - undefined, % level - undefined, % sasl comp (default=false) - undefined), % progress (default=false) - {logger_std_h,logger_std_h,StdC} = lists:keyfind(logger_std_h,1,Hs), - true = is_pid(whereis(logger_std_h)), + {ok,#{handlers:=Hs},_Node} = setup(Config,[]), + {?STANDARD_HANDLER,logger_std_h,StdC} = lists:keyfind(?STANDARD_HANDLER,1,Hs), info = maps:get(level,StdC), StdFilters = maps:get(filters,StdC), {domain,{_,{log,prefix_of,[beam,erlang,otp,sasl]}}} = @@ -105,18 +86,12 @@ default(Config) -> true = lists:keymember(stop_progress,1,StdFilters), false = lists:keymember(logger_simple,1,Hs), false = lists:keymember(sasl_h,1,Hs), - false = is_pid(whereis(sasl_h)), ok. default_sasl_compatible(Config) -> - {ok,{_Log,Hs}} = setup(Config,?FUNCTION_NAME, - undefined, - undefined, % dest - undefined, % level - true, % sasl comp (default=false) - undefined), % progress (default=false) - {logger_std_h,logger_std_h,StdC} = lists:keyfind(logger_std_h,1,Hs), - true = is_pid(whereis(logger_std_h)), + {ok,#{handlers:=Hs},_Node} = setup(Config, + [{logger_sasl_compatible,true}]), + {?STANDARD_HANDLER,logger_std_h,StdC} = lists:keyfind(?STANDARD_HANDLER,1,Hs), info = maps:get(level,StdC), StdFilters = maps:get(filters,StdC), {domain,{_,{log,prefix_of,[beam,erlang,otp]}}} = @@ -124,18 +99,11 @@ default_sasl_compatible(Config) -> false = lists:keymember(stop_progress,1,StdFilters), false = lists:keymember(logger_simple,1,Hs), true = lists:keymember(sasl_h,1,Hs), - true = is_pid(whereis(sasl_h)), ok. -dest_tty(Config) -> - {ok,{_Log,Hs}} = setup(Config,?FUNCTION_NAME, - logger_dest, - tty, % dest - undefined, % level - undefined, % sasl comp (default=false) - undefined), % progress (default=false) - {logger_std_h,logger_std_h,StdC} = lists:keyfind(logger_std_h,1,Hs), - true = is_pid(whereis(logger_std_h)), +error_logger_tty(Config) -> + {ok,#{handlers:=Hs},_Node} = setup(Config,[{error_logger,tty}]), + {?STANDARD_HANDLER,logger_std_h,StdC} = lists:keyfind(?STANDARD_HANDLER,1,Hs), info = maps:get(level,StdC), StdFilters = maps:get(filters,StdC), {domain,{_,{log,prefix_of,[beam,erlang,otp,sasl]}}} = @@ -143,18 +111,13 @@ dest_tty(Config) -> true = lists:keymember(stop_progress,1,StdFilters), false = lists:keymember(logger_simple,1,Hs), false = lists:keymember(sasl_h,1,Hs), - false = is_pid(whereis(sasl_h)), ok. -dest_tty_sasl_compatible(Config) -> - {ok,{_Log,Hs}} = setup(Config,?FUNCTION_NAME, - logger_dest, - tty, % dest - undefined, % level - true, % sasl comp (default=false) - undefined), % progress (default=false) - {logger_std_h,logger_std_h,StdC} = lists:keyfind(logger_std_h,1,Hs), - true = is_pid(whereis(logger_std_h)), +error_logger_tty_sasl_compatible(Config) -> + {ok,#{handlers:=Hs},_Node} = setup(Config, + [{error_logger,tty}, + {logger_sasl_compatible,true}]), + {?STANDARD_HANDLER,logger_std_h,StdC} = lists:keyfind(?STANDARD_HANDLER,1,Hs), info = maps:get(level,StdC), StdFilters = maps:get(filters,StdC), {domain,{_,{log,prefix_of,[beam,erlang,otp]}}} = @@ -162,19 +125,17 @@ dest_tty_sasl_compatible(Config) -> false = lists:keymember(stop_progress,1,StdFilters), false = lists:keymember(logger_simple,1,Hs), true = lists:keymember(sasl_h,1,Hs), - true = is_pid(whereis(sasl_h)), ok. -dest_false(Config) -> - {ok,{_Log,Hs}} = setup(Config,?FUNCTION_NAME, - logger_dest, - false, % dest - notice, % level - undefined, % sasl comp (default=false) - undefined), % progress (default=false) - false = lists:keymember(logger_std_h,1,Hs), +error_logger_false(Config) -> + {ok,#{handlers:=Hs,logger:=L},_Node} = + setup(Config, + [{error_logger,false}, + {logger_level,notice}]), + false = lists:keymember(?STANDARD_HANDLER,1,Hs), {logger_simple,logger_simple,SimpleC} = lists:keyfind(logger_simple,1,Hs), - notice = maps:get(level,SimpleC), + info = maps:get(level,SimpleC), + notice = maps:get(level,L), SimpleFilters = maps:get(filters,SimpleC), {domain,{_,{log,prefix_of,[beam,erlang,otp,sasl]}}} = lists:keyfind(domain,1,SimpleFilters), @@ -182,16 +143,16 @@ dest_false(Config) -> false = lists:keymember(sasl_h,1,Hs), ok. -dest_false_progress(Config) -> - {ok,{_Log,Hs}} = setup(Config,?FUNCTION_NAME, - logger_dest, - false, % dest - notice, % level - undefined, % sasl comp (default=false) - true), % progress (default=false) - false = lists:keymember(logger_std_h,1,Hs), +error_logger_false_progress(Config) -> + {ok,#{handlers:=Hs,logger:=L},_Node} = + setup(Config, + [{error_logger,false}, + {logger_level,notice}, + {logger_log_progress,true}]), + false = lists:keymember(?STANDARD_HANDLER,1,Hs), {logger_simple,logger_simple,SimpleC} = lists:keyfind(logger_simple,1,Hs), - notice = maps:get(level,SimpleC), + info = maps:get(level,SimpleC), + notice = maps:get(level,L), SimpleFilters = maps:get(filters,SimpleC), {domain,{_,{log,prefix_of,[beam,erlang,otp,sasl]}}} = lists:keyfind(domain,1,SimpleFilters), @@ -199,253 +160,472 @@ dest_false_progress(Config) -> false = lists:keymember(sasl_h,1,Hs), ok. -dest_false_sasl_compatible(Config) -> - {ok,{_Log,Hs}} = setup(Config,?FUNCTION_NAME, - logger_dest, - false, % dest - notice, % level - true, % sasl comp (default=false) - undefined), % progress (default=false) - false = lists:keymember(logger_std_h,1,Hs), +error_logger_false_sasl_compatible(Config) -> + {ok,#{handlers:=Hs,logger:=L},_Node} = + setup(Config, + [{error_logger,false}, + {logger_level,notice}, + {logger_sasl_compatible,true}]), + false = lists:keymember(?STANDARD_HANDLER,1,Hs), {logger_simple,logger_simple,SimpleC} = lists:keyfind(logger_simple,1,Hs), - notice = maps:get(level,SimpleC), + info = maps:get(level,SimpleC), + notice = maps:get(level,L), SimpleFilters = maps:get(filters,SimpleC), {domain,{_,{log,prefix_of,[beam,erlang,otp]}}} = lists:keyfind(domain,1,SimpleFilters), false = lists:keymember(stop_progress,1,SimpleFilters), true = lists:keymember(sasl_h,1,Hs), - true = is_pid(whereis(sasl_h)), ok. -dest_silent(Config) -> - {ok,{_Log,Hs}} = setup(Config,?FUNCTION_NAME, - logger_dest, - silent, % dest - undefined, % level - undefined, % sasl comp (default=false) - undefined), % progress (default=false) - false = lists:keymember(logger_std_h,1,Hs), +error_logger_silent(Config) -> + {ok,#{handlers:=Hs},_Node} = setup(Config, + [{error_logger,silent}]), + false = lists:keymember(?STANDARD_HANDLER,1,Hs), + false = lists:keymember(logger_simple,1,Hs), + false = lists:keymember(sasl_h,1,Hs), + ok. + +error_logger_silent_sasl_compatible(Config) -> + {ok,#{handlers:=Hs},_Node} = setup(Config, + [{error_logger,silent}, + {logger_sasl_compatible,true}]), + false = lists:keymember(?STANDARD_HANDLER,1,Hs), + false = lists:keymember(logger_simple,1,Hs), + true = lists:keymember(sasl_h,1,Hs), + ok. + + +error_logger_file(Config) -> + Log = file(Config,?FUNCTION_NAME), + {ok,_Hs,Node} = setup(Config, + [{error_logger,{file,Log}}]), + check_default_log(Node,Log, + file,% dest + 0),% progress in std logger + ok. + + +logger_file(Config) -> + Log = file(Config,?FUNCTION_NAME), + {ok,#{handlers:=Hs},Node} + = setup(Config, + [{logger, + [{handler,?STANDARD_HANDLER,logger_std_h, + #{logger_std_h=>#{type=>{file,Log}}}}]}]), + check_default_log(Node,Log, + file,% dest + 0),% progress in std logger + + {?STANDARD_HANDLER,logger_std_h,StdC} = lists:keyfind(?STANDARD_HANDLER,1,Hs), + info = maps:get(level,StdC), + StdFilters = maps:get(filters,StdC), + {domain,{_,{log,prefix_of,[beam,erlang,otp,sasl]}}} = + lists:keyfind(domain,1,StdFilters), + true = lists:keymember(stop_progress,1,StdFilters), false = lists:keymember(logger_simple,1,Hs), false = lists:keymember(sasl_h,1,Hs), + ok. -dest_silent_sasl_compatible(Config) -> - {ok,{_Log,Hs}} = setup(Config,?FUNCTION_NAME, - logger_dest, - silent, % dest - undefined, % level - true, % sasl comp (default=false) - undefined), % progress (default=false) - false = lists:keymember(logger_std_h,1,Hs), +logger_file_sasl_compatible(Config) -> + Log = file(Config,?FUNCTION_NAME), + {ok,#{handlers:=Hs},Node} + = setup(Config, + [{logger_sasl_compatible,true}, + {logger, + [{handler,?STANDARD_HANDLER,logger_std_h, + #{logger_std_h=>#{type=>{file,Log}}}}]}]), + check_default_log(Node,Log, + file,% dest + 0),% progress in std logger + + {?STANDARD_HANDLER,logger_std_h,StdC} = lists:keyfind(?STANDARD_HANDLER,1,Hs), + info = maps:get(level,StdC), + StdFilters = maps:get(filters,StdC), + {domain,{_,{log,prefix_of,[beam,erlang,otp]}}} = + lists:keyfind(domain,1,StdFilters), + false = lists:keymember(stop_progress,1,StdFilters), false = lists:keymember(logger_simple,1,Hs), true = lists:keymember(sasl_h,1,Hs), - true = is_pid(whereis(sasl_h)), + + ok. + +logger_file_log_progress(Config) -> + Log = file(Config,?FUNCTION_NAME), + {ok,#{handlers:=Hs},Node} + = setup(Config, + [{logger_log_progress,true}, + {logger, + [{handler,?STANDARD_HANDLER,logger_std_h, + #{logger_std_h=>#{type=>{file,Log}}}}]}]), + check_default_log(Node,Log, + file,% dest + 6),% progress in std logger + + {?STANDARD_HANDLER,logger_std_h,StdC} = lists:keyfind(?STANDARD_HANDLER,1,Hs), + info = maps:get(level,StdC), + StdFilters = maps:get(filters,StdC), + {domain,{_,{log,prefix_of,[beam,erlang,otp,sasl]}}} = + lists:keyfind(domain,1,StdFilters), + false = lists:keymember(stop_progress,1,StdFilters), + false = lists:keymember(logger_simple,1,Hs), + false = lists:keymember(sasl_h,1,Hs), + ok. +logger_file_no_filter(Config) -> + Log = file(Config,?FUNCTION_NAME), + {ok,#{handlers:=Hs},Node} + = setup(Config, + [{logger, + [{handler,?STANDARD_HANDLER,logger_std_h, + #{filter_default=>log,filters=>[], + logger_std_h=>#{type=>{file,Log}}}}]}]), + check_default_log(Node,Log, + file,% dest + 6),% progress in std logger + + {?STANDARD_HANDLER,logger_std_h,StdC} = lists:keyfind(?STANDARD_HANDLER,1,Hs), + info = maps:get(level,StdC), + [] = maps:get(filters,StdC), + false = lists:keymember(logger_simple,1,Hs), + false = lists:keymember(sasl_h,1,Hs), -dest_file_old(Config) -> - {ok,{Log,_Hs}} = setup(Config,?FUNCTION_NAME, - error_logger, - file, % dest - undefined, % level - undefined, % sasl comp (default=false) - undefined), % progress (default=false) - check_log(Log, - file, % dest - 0), % progress in std logger ok. - - -dest_file(Config) -> - {ok,{Log,_Hs}} = setup(Config,?FUNCTION_NAME, - logger_dest, - file, % dest - undefined, % level - undefined, % sasl comp (default=false) - undefined), % progress (default=false) - check_log(Log, - file, % dest - 0), % progress in std logger + +logger_file_no_filter_level(Config) -> + Log = file(Config,?FUNCTION_NAME), + {ok,#{handlers:=Hs},Node} + = setup(Config, + [{logger, + [{handler,?STANDARD_HANDLER,logger_std_h, + #{filters=>[],level=>error, + logger_std_h=>#{type=>{file,Log}}}}]}]), + check_default_log(Node,Log, + file,% dest + 0,% progress in std logger + error),% level + + {?STANDARD_HANDLER,logger_std_h,StdC} = lists:keyfind(?STANDARD_HANDLER,1,Hs), + error = maps:get(level,StdC), + [] = maps:get(filters,StdC), + false = lists:keymember(logger_simple,1,Hs), + false = lists:keymember(sasl_h,1,Hs), + ok. - - -dest_disk_log(Config) -> - {ok,{Log,_Hs}} = setup(Config,?FUNCTION_NAME, - logger_dest, - disk_log, % dest - undefined, % level - undefined, % sasl comp (default=false) - undefined), % progress (default=false) - check_log(Log, - disk_log, % dest - 0), % progress in std logger + +logger_file_formatter(Config) -> + Log = file(Config,?FUNCTION_NAME), + {ok,#{handlers:=Hs},Node} + = setup(Config, + [{logger, + [{handler,?STANDARD_HANDLER,logger_std_h, + #{filters=>[], + formatter=>{logger_formatter,#{}}, + logger_std_h=>#{type=>{file,Log}}}}]}]), + check_single_log(Node,Log, + file,% dest + 6),% progress in std logger + + {?STANDARD_HANDLER,logger_std_h,StdC} = lists:keyfind(?STANDARD_HANDLER,1,Hs), + info = maps:get(level,StdC), + [] = maps:get(filters,StdC), + false = lists:keymember(logger_simple,1,Hs), + false = lists:keymember(sasl_h,1,Hs), + + ok. + +logger_filters(Config) -> + Log = file(Config,?FUNCTION_NAME), + {ok,#{handlers:=Hs,logger:=Logger},Node} + = setup(Config, + [{logger_log_progress,true}, + {logger, + [{handler,?STANDARD_HANDLER,logger_std_h, + #{logger_std_h=>#{type=>{file,Log}}}}, + {filters,log,[{stop_progress,{fun logger_filters:progress/2,stop}}]} + ]}]), + check_default_log(Node,Log, + file,% dest + 0),% progress in std logger + + {?STANDARD_HANDLER,logger_std_h,StdC} = lists:keyfind(?STANDARD_HANDLER,1,Hs), + info = maps:get(level,StdC), + StdFilters = maps:get(filters,StdC), + {domain,{_,{log,prefix_of,[beam,erlang,otp,sasl]}}} = + lists:keyfind(domain,1,StdFilters), + false = lists:keymember(stop_progress,1,StdFilters), + false = lists:keymember(logger_simple,1,Hs), + false = lists:keymember(sasl_h,1,Hs), + LoggerFilters = maps:get(filters,Logger), + true = lists:keymember(stop_progress,1,LoggerFilters), + + ok. + +logger_filters_stop(Config) -> + Log = file(Config,?FUNCTION_NAME), + {ok,#{handlers:=Hs,logger:=Logger},Node} + = setup(Config, + [{logger_log_progress,true}, + {logger, + [{handler,?STANDARD_HANDLER,logger_std_h, + #{filters=>[], + logger_std_h=>#{type=>{file,Log}}}}, + {filters,stop,[{log_error,{fun logger_filters:level/2,{log,gt,info}}}]} + ]}]), + check_default_log(Node,Log, + file,% dest + 0, + notice),% progress in std logger + + {?STANDARD_HANDLER,logger_std_h,StdC} = lists:keyfind(?STANDARD_HANDLER,1,Hs), + info = maps:get(level,StdC), + [] = maps:get(filters,StdC), + false = lists:keymember(logger_simple,1,Hs), + false = lists:keymember(sasl_h,1,Hs), + LoggerFilters = maps:get(filters,Logger), + true = lists:keymember(log_error,1,LoggerFilters), + + ok. + +logger_module_level(Config) -> + Log = file(Config,?FUNCTION_NAME), + {ok,#{handlers:=Hs,module_levels:=ModuleLevels},Node} + = setup(Config, + [{logger_log_progress,true}, + {logger, + [{handler,?STANDARD_HANDLER,logger_std_h, + #{logger_std_h=>#{type=>{file,Log}}}}, + {module_level,error,[supervisor]} + ]}]), + check_default_log(Node,Log, + file,% dest + 3),% progress in std logger + + {?STANDARD_HANDLER,logger_std_h,StdC} = lists:keyfind(?STANDARD_HANDLER,1,Hs), + info = maps:get(level,StdC), + StdFilters = maps:get(filters,StdC), + {domain,{_,{log,prefix_of,[beam,erlang,otp,sasl]}}} = + lists:keyfind(domain,1,StdFilters), + false = lists:keymember(stop_progress,1,StdFilters), + false = lists:keymember(logger_simple,1,Hs), + false = lists:keymember(sasl_h,1,Hs), + [{supervisor,error}] = ModuleLevels, + ok. + +logger_disk_log(Config) -> + Log = file(Config,?FUNCTION_NAME), + {ok,#{handlers:=Hs},Node} + = setup(Config, + [{logger, + [{handler,?STANDARD_HANDLER,logger_disk_log_h, + #{disk_log_opts=>#{file=>Log}}}]}]), + check_default_log(Node,Log, + disk_log,% dest + 0),% progress in std logger + + {?STANDARD_HANDLER,logger_disk_log_h,StdC} = lists:keyfind(?STANDARD_HANDLER,1,Hs), + info = maps:get(level,StdC), + StdFilters = maps:get(filters,StdC), + {domain,{_,{log,prefix_of,[beam,erlang,otp,sasl]}}} = + lists:keyfind(domain,1,StdFilters), + true = lists:keymember(stop_progress,1,StdFilters), + false = lists:keymember(logger_simple,1,Hs), + false = lists:keymember(sasl_h,1,Hs), + + ok. + +logger_disk_log_formatter(Config) -> + Log = file(Config,?FUNCTION_NAME), + {ok,#{handlers:=Hs},Node} + = setup(Config, + [{logger, + [{handler,?STANDARD_HANDLER,logger_disk_log_h, + #{filters=>[], + formatter=>{logger_formatter,#{}}, + disk_log_opts=>#{file=>Log}}}]}]), + check_single_log(Node,Log, + disk_log,% dest + 6),% progress in std logger + + {?STANDARD_HANDLER,logger_disk_log_h,StdC} = lists:keyfind(?STANDARD_HANDLER,1,Hs), + info = maps:get(level,StdC), + [] = maps:get(filters,StdC), + false = lists:keymember(logger_simple,1,Hs), + false = lists:keymember(sasl_h,1,Hs), + + ok. + +logger_undefined(Config) -> + {ok,#{handlers:=Hs,logger:=L},_Node} = + setup(Config,[{logger,[{handler,?STANDARD_HANDLER,undefined}]}]), + false = lists:keymember(?STANDARD_HANDLER,1,Hs), + {logger_simple,logger_simple,SimpleC} = lists:keyfind(logger_simple,1,Hs), + info = maps:get(level,SimpleC), + info = maps:get(level,L), + SimpleFilters = maps:get(filters,SimpleC), + {domain,{_,{log,prefix_of,[beam,erlang,otp,sasl]}}} = + lists:keyfind(domain,1,SimpleFilters), + true = lists:keymember(stop_progress,1,SimpleFilters), + false = lists:keymember(sasl_h,1,Hs), + ok. + +logger_many_handlers_default_first(Config) -> + LogErr = file(Config,logger_many_handlers_default_first_error), + LogInfo = file(Config,logger_many_handlers_default_first_info), + + logger_many_handlers( + Config,[{logger, + [{handler,?STANDARD_HANDLER,logger_std_h, + #{level=>error, + filters=>[], + formatter=>{logger_formatter,#{}}, + logger_std_h=>#{type=>{file,LogErr}}} + }, + {handler,info,logger_std_h, + #{level=>info, + filters=>[{level,{fun logger_filters:level/2,{stop,gteq,error}}}], + logger_std_h=>#{type=>{file,LogInfo}}} + } + ]}], LogErr, LogInfo, 6). + +%% Test that we can add multiple handlers with the default last +logger_many_handlers_default_last(Config) -> + LogErr = file(Config,logger_many_handlers_default_last_error), + LogInfo = file(Config,logger_many_handlers_default_last_info), + logger_many_handlers( + Config,[{logger, + [{handler,info,logger_std_h, + #{level=>info, + filters=>[{level,{fun logger_filters:level/2,{stop,gteq,error}}}], + logger_std_h=>#{type=>{file,LogInfo}}} + }, + {handler,?STANDARD_HANDLER,logger_std_h, + #{level=>error, + filters=>[], + formatter=>{logger_formatter,#{}}, + logger_std_h=>#{type=>{file,LogErr}}} + } + ]}], LogErr, LogInfo, 7). + +logger_many_handlers(Config, Env, LogErr, LogInfo, NumProgress) -> + {ok,#{handlers:=Hs},Node} = setup(Config,Env), + check_single_log(Node,LogErr, + file,% dest + 0,% progress in std logger + error), % level + ok = rpc:call(Node,logger_std_h,filesync,[info]), + {ok, Bin} = file:read_file(LogInfo), + ct:log("Log content:~n~s",[Bin]), + match(Bin,<<"PROGRESS REPORT">>,NumProgress,info,info), + match(Bin,<<"ALERT REPORT">>,0,alert,info), + ok. - sasl_compatible_false(Config) -> - {ok,{Log,_Hs}} = setup(Config,?FUNCTION_NAME, - logger_dest, - file, % dest - undefined, % level - false, % sasl comp - true), % progress - check_log(Log, - file, % dest - 4), % progress in std logger + Log = file(Config,?FUNCTION_NAME), + {ok,_Hs,Node} = setup(Config, + [{error_logger,{file,Log}}, + {logger_sasl_compatible,false}, + {logger_log_progress,true}]), + check_default_log(Node,Log, + file,% dest + 6),% progress in std logger ok. sasl_compatible_false_no_progress(Config) -> - {ok,{Log,_Hs}} = setup(Config,?FUNCTION_NAME, - logger_dest, - file, % dest - undefined, % level - false, % sasl comp - false), % progress - check_log(Log, - file, % dest - 0), % progress in std logger + Log = file(Config,?FUNCTION_NAME), + {ok,_Hs,Node} = setup(Config, + [{error_logger,{file,Log}}, + {logger_sasl_compatible,false}, + {logger_log_progress,false}]), + check_default_log(Node,Log, + file,% dest + 0),% progress in std logger ok. sasl_compatible(Config) -> - {ok,{Log,_Hs}} = setup(Config,?FUNCTION_NAME, - logger_dest, - file, % dest - undefined, % level - true, % sasl comp - undefined), % progress - check_log(Log, - file, % dest - 0), % progress in std logger + Log = file(Config,?FUNCTION_NAME), + {ok,_Hs,Node} = setup(Config, + [{error_logger,{file,Log}}, + {sasl_compatible,true}]), + check_default_log(Node,Log, + file,% dest + 0),% progress in std logger ok. -bad_dest(Config) -> - {error,{bad_config,{kernel,{logger_dest,baddest}}}} = - setup(Config,?FUNCTION_NAME, - logger_dest, - baddest, - undefined, - undefined, - undefined). +bad_error_logger(Config) -> + error = setup(Config,[{error_logger,baddest}]). bad_level(Config) -> - error = - setup(Config,?FUNCTION_NAME, - logger_dest, - tty, - badlevel, - undefined, - undefined). + error = setup(Config,[{logger_level,badlevel}]). bad_sasl_compatibility(Config) -> - error = - setup(Config,?FUNCTION_NAME, - logger_dest, - tty, - info, - badcomp, - undefined). + error = setup(Config,[{logger_sasl_compatible,badcomp}]). bad_progress(Config) -> - error = - setup(Config,?FUNCTION_NAME, - logger_dest, - tty, - info, - undefined, - badprogress). + error = setup(Config,[{logger_log_progress,badprogress}]). %%%----------------------------------------------------------------- %%% Internal -setup(Config,Func,DestVar,Dest,Level,SaslComp,Progress) -> - ok = logger:add_handler(logger_simple,logger_simple, - #{filter_default=>log, - logger_simple=>#{buffer=>true}}), - Dir = ?config(priv_dir,Config), - File = lists:concat([?MODULE,"_",Func,".log"]), - Log = filename:join(Dir,File), - case Dest of - undefined -> - ok; - F when F==file; F==disk_log -> - application:set_env(kernel,DestVar,{Dest,Log}); - _ -> - application:set_env(kernel,DestVar,Dest) - end, - case Level of - undefined -> - ok; - _ -> - application:set_env(kernel,logger_level,Level) - end, - case SaslComp of - undefined -> - ok; - _ -> - application:set_env(kernel,logger_sasl_compatible,SaslComp) - end, - case Progress of - undefined -> - ok; - _ -> - application:set_env(kernel,logger_log_progress,Progress) - end, - case logger:setup_standard_handler() of - ok -> - application:start(sasl), - StdH = case Dest of - NoH when NoH==false; NoH==silent -> false; - _ -> true - end, - StdH = is_pid(whereis(?STANDARD_HANDLER)), - SaslH = if SaslComp -> true; - true -> false - end, - SaslH = is_pid(whereis(sasl_h)), - {ok,{Log,maps:get(handlers,logger:i())}}; - Error -> - Error - end. +file(Config,Func) -> + filename:join(proplists:get_value(priv_dir,Config), + lists:concat([Func,".log"])). -check_log(Log,Dest,NumProgress) -> - ok = logger:alert("dummy1"), - ok = logger:debug("dummy1"), +check_default_log(Node,Log,Dest,NumProgress) -> + check_default_log(Node,Log,Dest,NumProgress,info). +check_default_log(Node,Log,Dest,NumProgress,Level) -> + + {ok,Bin1,Bin2} = check_log(Node,Log,Dest), + + match(Bin1,<<"PROGRESS REPORT">>,NumProgress,info,Level), + match(Bin1,<<"ALERT REPORT">>,1,alert,Level), + match(Bin1,<<"INFO REPORT">>,0,info,Level), + match(Bin1,<<"DEBUG REPORT">>,0,debug,Level), + + match(Bin2,<<"INFO REPORT">>,1,info,Level), + match(Bin2,<<"DEBUG REPORT">>,0,debug,Level), + ok. + +check_single_log(Node,Log,Dest,NumProgress) -> + check_single_log(Node,Log,Dest,NumProgress,info). +check_single_log(Node,Log,Dest,NumProgress,Level) -> + + {ok,Bin1,Bin2} = check_log(Node,Log,Dest), + + match(Bin1,<<"info:">>,NumProgress,info,Level), + match(Bin1,<<"alert:">>,1,alert,Level), + match(Bin1,<<"debug:">>,0,debug,Level), + + match(Bin2,<<"info:">>,NumProgress+1,info,Level), + match(Bin2,<<"debug:">>,0,debug,Level), + + ok. + +check_log(Node,Log,Dest) -> + + ok = log(Node,alert,["dummy1"]), + ok = log(Node,debug,["dummy1"]), %% Check that there are progress reports (supervisor and %% application_controller) and an error report (the call above) in %% the log. There should not be any info reports yet. - {ok,Bin1} = sync_and_read(Dest,Log), + {ok,Bin1} = sync_and_read(Node,Dest,Log), ct:log("Log content:~n~s",[Bin1]), - match(Bin1,<<"PROGRESS REPORT">>,NumProgress), - match(Bin1,<<"ALERT REPORT">>,1), - match(Bin1,<<"INFO REPORT">>,0), - match(Bin1,<<"DEBUG REPORT">>,0), %% Then stop sasl and see that the info report from %% application_controller is there - ok = application:stop(sasl), - {ok,Bin2} = sync_and_read(Dest,Log), + ok = rpc:call(Node,application,stop,[sasl]), + {ok,Bin2} = sync_and_read(Node,Dest,Log), ct:log("Log content:~n~s",[Bin2]), - match(Bin2,<<"INFO REPORT">>,1), - match(Bin1,<<"DEBUG REPORT">>,0), - ok. + {ok,Bin1,Bin2}. -match(Bin,Pattern,0) -> +match(Bin,Pattern,0,_,_) -> nomatch = re:run(Bin,Pattern,[{capture,none}]); -match(Bin,Pattern,N) -> - {match,M} = re:run(Bin,Pattern,[{capture,all},global]), - N = length(M). - -sync_and_read(disk_log,Log) -> - logger_disk_log_h:disk_log_sync(?STANDARD_HANDLER), - file:read_file(Log ++ ".1"); -sync_and_read(file,Log) -> - logger_std_h:filesync(?STANDARD_HANDLER), - file:read_file(Log). - -cleanup() -> - application:stop(sasl), - [application:unset_env(App,Key) || {App,Key} <- ?all_vars], - #{handlers:=Hs0} = logger:i(), - Hs = lists:keydelete(cth_log_redirect,1,Hs0), - [ok = logger:remove_handler(Id) || {Id,_,_} <- Hs], - Hs. +match(Bin,Pattern,N,LogLevel,ConfLevel) -> + case logger:compare_levels(LogLevel,ConfLevel) of + lt -> match(Bin,Pattern,0,LogLevel,ConfLevel); + _ -> + {match,M} = re:run(Bin,Pattern,[{capture,all},global]), + N = length(M) + end. diff --git a/lib/kernel/test/logger_formatter_SUITE.erl b/lib/kernel/test/logger_formatter_SUITE.erl index 7d1f33746d..c80e5694cf 100644 --- a/lib/kernel/test/logger_formatter_SUITE.erl +++ b/lib/kernel/test/logger_formatter_SUITE.erl @@ -341,7 +341,7 @@ depth(_Config) -> {"~p",[[1,2,3,4,5,6,7,8,9,0,1,2,3,4,5,6,7,8,9,0]]}, #{}, #{template=>Template}), - application:set_env(kernel,logger_format_depth,12), + application:set_env(kernel,error_logger_format_depth,12), "[1,2,3,4,5,6,7,8,9,0,1|...]" = format(info, {"~p",[[1,2,3,4,5,6,7,8,9,0,1,2,3,4,5,6,7,8,9,0]]}, @@ -361,7 +361,7 @@ depth(_Config) -> depth=>unlimited}), ok. depth(cleanup,_Config) -> - application:unset_env(kernel,logger_format_depth), + application:unset_env(kernel,error_logger_format_depth), ok. chars_limit(_Config) -> diff --git a/lib/kernel/test/logger_simple_SUITE.erl b/lib/kernel/test/logger_simple_SUITE.erl index 5d8d32492d..0d505b14f5 100644 --- a/lib/kernel/test/logger_simple_SUITE.erl +++ b/lib/kernel/test/logger_simple_SUITE.erl @@ -25,6 +25,8 @@ -include_lib("kernel/include/logger.hrl"). -include_lib("kernel/src/logger_internal.hrl"). +-import(logger_test_lib, [setup/2, log/3, sync_and_read/3]). + -define(check_no_log,[] = test_server:messages_get()). -define(check(Expected), receive {log,Expected} -> @@ -42,15 +44,15 @@ -define(keyval_rep,[{function,?FUNCTION_NAME}, {line,?LINE}]). suite() -> - [{timetrap,{seconds,30}}]. + [{timetrap,{seconds,30}}, + {ct_hooks, [logger_test_lib]}]. init_per_suite(Config) -> #{handlers:=Hs0} = logger:i(), Hs = lists:keydelete(cth_log_redirect,1,Hs0), [ok = logger:remove_handler(Id) || {Id,_,_} <- Hs], Env = [{App,Key,application:get_env(App,Key)} || - {App,Key} <- [{kernel,logger_dest}, - {kernel,logger_level}]], + {App,Key} <- [{kernel,logger_level}]], [{env,Env},{logger,Hs}|Config]. end_per_suite(Config) -> @@ -79,7 +81,7 @@ groups() -> all() -> [start_stop, - get_buffer, + replace_default, replace_file, replace_disk_log ]. @@ -100,99 +102,46 @@ start_stop(_Config) -> start_stop(cleanup,_Config) -> logger:remove_handler(logger_simple). -get_buffer(_Config) -> - %% Start simple without buffer - ok = logger:add_handler(logger_simple,logger_simple, - #{filter_default=>log}), - logger:emergency(?str), - logger:alert(?str,[]), - logger:error(?map_rep), - logger:info(?keyval_rep), - {ok,[]} = logger_simple:get_buffer(), % no buffer - ok = logger:remove_handler(logger_simple), +%% This testcase just tests that it does not crash, the default handler prints +%% to stdout which we cannot read from in a detached slave. +replace_default(Config) -> - %% Start with buffer - ok = logger:add_handler(logger_simple,logger_simple, - #{filter_default=>log, - logger_simple=>#{buffer=>true}}), - logger:emergency(M1=?str), - logger:alert(M2=?str,[]), - logger:error(M3=?map_rep), - logger:info(M4=?keyval_rep), - logger:info(M41=?keyval_rep++[not_key_val]), - error_logger:error_report(some_type,M5=?map_rep), - error_logger:warning_report("some_type",M6=?map_rep), - logger:critical(M7=?str,[A7=?keyval_rep]), - logger:notice(M8=["fake",string,"line:",?LINE]), - {ok,Buffered1} = logger_simple:get_buffer(), - [#{level:=emergency,msg:={string,M1}}, - #{level:=alert,msg:={M2,[]}}, - #{level:=error,msg:={report,M3}}, - #{level:=info,msg:={report,M4}}, - #{level:=info,msg:={report,M41}}, - #{level:=error,msg:={report,#{label:={error_logger,error_report}, - report:=M5}}}, - #{level:=warning,msg:={report,#{label:={error_logger,warning_report}, - report:=M6}}}, - #{level:=critical,msg:={M7,[A7]}}, - #{level:=notice,msg:={string,M8}}] = Buffered1, - - %% Keep logging - should not buffer any more - logger:emergency(?str), - logger:alert(?str,[]), - logger:error(?map_rep), - logger:info(?keyval_rep), - {ok,[]} = logger_simple:get_buffer(), - ok = logger:remove_handler(logger_simple), + {ok, _, Node} = logger_test_lib:setup(Config, [{logger, [{handler, default, undefined}]}]), + log(Node, emergency, [M1=?str]), + log(Node, alert, [M2=?str,[]]), + log(Node, error, [M3=?map_rep]), + log(Node, info, [M4=?keyval_rep]), + log(Node, info, [M41=?keyval_rep++[not_key_val]]), + rpc:call(Node, error_logger, error_report, [some_type,M5=?map_rep]), + rpc:call(Node, error_logger, warning_report, ["some_type",M6=?map_rep]), + log(Node, critical, [M7=?str,[A7=?keyval_rep]]), + log(Node, notice, [M8=["fake",string,"line:",?LINE]]), + + Env = rpc:call(Node, application, get_env, [kernel, logger, []]), + ok = rpc:call(Node, logger, add_handlers, [Env]), - %% Fill buffer and drop - ok = logger:add_handler(logger_simple,logger_simple, - #{filter_default=>log, - logger_simple=>#{buffer=>true}}), - logger:emergency(M9=?str), - M10=?str, - [logger:info(M10) || _ <- lists:seq(1,8)], - logger:error(M11=?str), - logger:error(?str), - logger:error(?str), - {ok,Buffered3} = logger_simple:get_buffer(), - 11 = length(Buffered3), - [#{level:=emergency,msg:={string,M9}}, - #{level:=info,msg:={string,M10}}, - #{level:=info,msg:={string,M10}}, - #{level:=info,msg:={string,M10}}, - #{level:=info,msg:={string,M10}}, - #{level:=info,msg:={string,M10}}, - #{level:=info,msg:={string,M10}}, - #{level:=info,msg:={string,M10}}, - #{level:=info,msg:={string,M10}}, - #{level:=error,msg:={string,M11}}, - #{level:=info,msg:={"Simple handler buffer full, dropped ~w messages",[2]}}] - = Buffered3, ok. -get_buffer(cleanup,_Config) -> - logger:remove_handler(logger_simple). replace_file(Config) -> - ok = logger:add_handler(logger_simple,logger_simple, - #{filter_default=>log, - logger_simple=>#{buffer=>true}}), - logger:emergency(M1=?str), - logger:alert(M2=?str,[]), - logger:error(?map_rep), - logger:info(?keyval_rep), - undefined = whereis(?STANDARD_HANDLER), - PrivDir = ?config(priv_dir,Config), - File = filename:join(PrivDir,atom_to_list(?FUNCTION_NAME)++".log"), - - application:set_env(kernel,logger_dest,{file,File}), - application:set_env(kernel,logger_level,info), - - ok = logger:setup_standard_handler(), - true = is_pid(whereis(?STANDARD_HANDLER)), - ok = logger_std_h:filesync(?STANDARD_HANDLER), - {ok,Bin} = file:read_file(File), - Lines = [unicode:characters_to_list(L) || + + {ok, _, Node} = logger_test_lib:setup(Config, [{logger, [{handler, default, undefined}]}]), + log(Node, emergency, [M1=?str]), + log(Node, alert, [M2=?str,[]]), + log(Node, error, [M3=?map_rep]), + log(Node, info, [M4=?keyval_rep]), + log(Node, info, [M41=?keyval_rep++[not_key_val]]), + log(Node, critical, [M7=?str,[A7=?keyval_rep]]), + log(Node, notice, [M8=["fake",string,"line:",?LINE]]), + + File = filename:join(proplists:get_value(priv_dir,Config), + atom_to_list(?FUNCTION_NAME)++".log"), + + ok = rpc:call(Node, logger, add_handlers, + [[{handler, default, logger_std_h, + #{ logger_std_h => #{ type => {file, File} }}}]]), + + {ok,Bin} = sync_and_read(Node, file, File), + Lines = [unicode:characters_to_list(L) || L <- binary:split(Bin,<<"\n">>,[global,trim])], ["=EMERGENCY REPORT===="++_, M1, @@ -203,32 +152,38 @@ replace_file(Config) -> _, "=INFO REPORT===="++_, _, - _] = Lines, + _, + "=INFO REPORT===="++_, + _, + _, + _, + "=CRITICAL REPORT===="++_, + _, + _, + "=NOTICE REPORT===="++_, + _ + ] = Lines, ok. -replace_file(cleanup,_Config) -> - logger:remove_handler(?STANDARD_HANDLER), - logger:remove_handler(logger_simple). - + replace_disk_log(Config) -> - ok = logger:add_handler(logger_simple,logger_simple, - #{filter_default=>log, - logger_simple=>#{buffer=>true}}), - logger:emergency(M1=?str), - logger:alert(M2=?str,[]), - logger:error(?map_rep), - logger:info(?keyval_rep), - undefined = whereis(?STANDARD_HANDLER), - PrivDir = ?config(priv_dir,Config), - File = filename:join(PrivDir,atom_to_list(?FUNCTION_NAME)), - - application:set_env(kernel,logger_dest,{disk_log,File}), - application:set_env(kernel,logger_level,info), - - ok = logger:setup_standard_handler(), - true = is_pid(whereis(?STANDARD_HANDLER)), - ok = logger_disk_log_h:disk_log_sync(?STANDARD_HANDLER), - {ok,Bin} = file:read_file(File++".1"), - Lines = [unicode:characters_to_list(L) || + + {ok, _, Node} = logger_test_lib:setup(Config, [{logger, [{handler, default, undefined}]}]), + log(Node, emergency, [M1=?str]), + log(Node, alert, [M2=?str,[]]), + log(Node, error, [M3=?map_rep]), + log(Node, info, [M4=?keyval_rep]), + log(Node, info, [M41=?keyval_rep++[not_key_val]]), + log(Node, critical, [M7=?str,[A7=?keyval_rep]]), + log(Node, notice, [M8=["fake",string,"line:",?LINE]]), + + File = filename:join(proplists:get_value(priv_dir,Config), + atom_to_list(?FUNCTION_NAME)++".log"), + + ok = rpc:call(Node, logger, add_handlers, + [[{handler, default, logger_disk_log_h, + #{ disk_log_opts => #{ file => File }}}]]), + {ok,Bin} = sync_and_read(Node, disk_log, File), + Lines = [unicode:characters_to_list(L) || L <- binary:split(Bin,<<"\n">>,[global,trim])], ["=EMERGENCY REPORT===="++_, M1, @@ -239,9 +194,15 @@ replace_disk_log(Config) -> _, "=INFO REPORT===="++_, _, - _|_] = Lines, % the tail might be an info report about opening the disk log + _, + "=INFO REPORT===="++_, + _, + _, + _, + "=CRITICAL REPORT===="++_, + _, + _, + "=NOTICE REPORT===="++_, + _ + ] = Lines, ok. -replace_disk_log(cleanup,_Config) -> - logger:remove_handler(?STANDARD_HANDLER), - logger:remove_handler(logger_simple). - diff --git a/lib/kernel/test/logger_std_h_SUITE.erl b/lib/kernel/test/logger_std_h_SUITE.erl index 34c3167960..83bc96620f 100644 --- a/lib/kernel/test/logger_std_h_SUITE.erl +++ b/lib/kernel/test/logger_std_h_SUITE.erl @@ -50,11 +50,12 @@ end). suite() -> - [{timetrap,{seconds,30}}]. + [{timetrap,{seconds,30}}, + {ct_hooks,[logger_test_lib]}]. init_per_suite(Config) -> timer:start(), % to avoid progress report - {ok,{?STANDARD_HANDLER,#{formatter:=OrigFormatter}}} = + {ok,{logger_std_h,#{formatter:=OrigFormatter}}} = logger:get_handler_config(?STANDARD_HANDLER), [{formatter,OrigFormatter}|Config]. @@ -322,29 +323,32 @@ config_fail(cleanup,_Config) -> logger:remove_handler(?MODULE). crash_std_h_to_file(Config) -> - crash_std_h(Config,?FUNCTION_NAME,logger_dest,file). + Dir = ?config(priv_dir,Config), + Log = filename:join(Dir,lists:concat([?MODULE,"_",?FUNCTION_NAME,".log"])), + crash_std_h(Config,?FUNCTION_NAME, + [{handler,default,logger_std_h, + #{ logger_std_h => #{ type => {file, Log} }}}], + file, Log). crash_std_h_to_file(cleanup,_Config) -> crash_std_h(cleanup). crash_std_h_to_disk_log(Config) -> - crash_std_h(Config,?FUNCTION_NAME,logger_dest,disk_log). + Dir = ?config(priv_dir,Config), + Log = filename:join(Dir,lists:concat([?MODULE,"_",?FUNCTION_NAME,".log"])), + crash_std_h(Config,?FUNCTION_NAME, + [{handler,default,logger_disk_log_h, + #{ disk_log_opts => #{ file => Log }}}], + disk_log,Log). crash_std_h_to_disk_log(cleanup,_Config) -> crash_std_h(cleanup). -crash_std_h(Config,Func,Var,Type) -> +crash_std_h(Config,Func,Var,Type,Log) -> Dir = ?config(priv_dir,Config), - File = lists:concat([?MODULE,"_",Func,".log"]), - Log = filename:join(Dir,File), + SysConfig = filename:join(Dir,lists:concat([?MODULE,"_",Func,".config"])), + ok = file:write_file(SysConfig, io_lib:format("[{kernel,[{logger,~p}]}].",[Var])), Pa = filename:dirname(code:which(?MODULE)), - TypeAndLog = - case os:type() of - {win32,_} -> - lists:concat([" {",Type,",\\\"",Log,"\\\"}"]); - _ -> - lists:concat([" \'{",Type,",\"",Log,"\"}\'"]) - end, - Args = lists:concat([" -kernel ",Var,TypeAndLog," -pa ",Pa]), Name = lists:concat([?MODULE,"_",Func]), + Args = lists:concat([" -config ",filename:rootname(SysConfig)," -pa ",Pa]), ct:pal("Starting ~p with ~tp", [Name,Args]), %% Start a node which prints kernel logs to the destination specified by Type {ok,Node} = test_server:start_node(Name, peer, [{args, Args}]), @@ -585,7 +589,7 @@ write_failure(Config) -> Dir = ?config(priv_dir, Config), File = lists:concat([?MODULE,"_",?FUNCTION_NAME,".log"]), Log = filename:join(Dir, File), - Node = start_std_h_on_new_node(Config, ?FUNCTION_NAME, Log), + Node = start_std_h_on_new_node(Config, Log), false = (undefined == rpc:call(Node, ets, whereis, [?TEST_HOOKS_TAB])), rpc:call(Node, ets, insert, [?TEST_HOOKS_TAB,{tester,self()}]), rpc:call(Node, ?MODULE, set_internal_log, [?MODULE,internal_log]), @@ -622,7 +626,7 @@ sync_failure(Config) -> Dir = ?config(priv_dir, Config), File = lists:concat([?MODULE,"_",?FUNCTION_NAME,".log"]), Log = filename:join(Dir, File), - Node = start_std_h_on_new_node(Config, ?FUNCTION_NAME, Log), + Node = start_std_h_on_new_node(Config, Log), false = (undefined == rpc:call(Node, ets, whereis, [?TEST_HOOKS_TAB])), rpc:call(Node, ets, insert, [?TEST_HOOKS_TAB,{tester,self()}]), rpc:call(Node, ?MODULE, set_internal_log, [?MODULE,internal_log]), @@ -658,21 +662,12 @@ sync_failure(cleanup, _Config) -> Nodes = nodes(), [test_server:stop_node(Node) || Node <- Nodes]. -start_std_h_on_new_node(_Config, Func, Log) -> - Pa = filename:dirname(code:which(?MODULE)), - Dest = - case os:type() of - {win32,_} -> - lists:concat([" {file,\\\"",Log,"\\\"}"]); - _ -> - lists:concat([" \'{file,\"",Log,"\"}\'"]) - end, - Args = lists:concat([" -kernel ",logger_dest,Dest," -pa ",Pa]), - Name = lists:concat([?MODULE,"_",Func]), - ct:pal("Starting ~s with ~tp", [Name,Args]), - {ok,Node} = test_server:start_node(Name, peer, [{args, Args}]), - Pid = rpc:call(Node,erlang,whereis,[?STANDARD_HANDLER]), - true = is_pid(Pid), +start_std_h_on_new_node(Config, Log) -> + {ok,_,Node} = + logger_test_lib:setup( + Config, + [{logger,[{handler,default,logger_std_h, + #{ logger_std_h => #{ type => {file,Log}}}}]}]), ok = rpc:call(Node,logger,set_handler_config,[?STANDARD_HANDLER,formatter, {?MODULE,nl}]), Node. diff --git a/lib/kernel/test/logger_test_lib.erl b/lib/kernel/test/logger_test_lib.erl new file mode 100644 index 0000000000..4ac05e6480 --- /dev/null +++ b/lib/kernel/test/logger_test_lib.erl @@ -0,0 +1,82 @@ +% +%% %CopyrightBegin% +%% +%% Copyright Ericsson AB 2018. All Rights Reserved. +%% +%% Licensed under the Apache License, Version 2.0 (the "License"); +%% you may not use this file except in compliance with the License. +%% You may obtain a copy of the License at +%% +%% http://www.apache.org/licenses/LICENSE-2.0 +%% +%% Unless required by applicable law or agreed to in writing, software +%% distributed under the License is distributed on an "AS IS" BASIS, +%% WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +%% See the License for the specific language governing permissions and +%% limitations under the License. +%% +%% %CopyrightEnd% +%% +-module(logger_test_lib). + +-include_lib("kernel/src/logger_internal.hrl"). + +-export([setup/2, log/3, sync_and_read/3]). + +-export([init/2, + pre_init_per_suite/3, pre_init_per_testcase/4, + post_end_per_testcase/5, post_end_per_suite/3]). + +setup(Config,Vars) -> + FuncStr = lists:concat([proplists:get_value(suite, Config), "_", + proplists:get_value(tc, Config)]), + ConfigFileName = filename:join(proplists:get_value(priv_dir, Config), FuncStr), + file:write_file(ConfigFileName ++ ".config", io_lib:format("[{kernel, ~p}].",[Vars])), + case test_server:start_node(proplists:get_value(tc, Config), slave, + [{args, ["-pa ",filename:dirname(code:which(?MODULE)), + " -boot start_sasl -kernel start_timer true " + "-config ",ConfigFileName]}]) of + {ok, Node} -> + L = rpc:call(Node, logger, i, []), + ct:log("~p",[L]), + {ok, L, Node}; + {error, Reason} -> + ct:log("Failed to start node: ~p",[Reason]), + error + end. + +log(Node, F, A) -> + log(Node, logger, F, A). +log(Node, M, F, A) -> + MD = #{ gl => rpc:call(Node, erlang, whereis, [logger]) }, + rpc:call(Node, M, F, A ++ [MD]). + +sync_and_read(Node,disk_log,Log) -> + rpc:call(Node,logger_disk_log_h,disk_log_sync,[?STANDARD_HANDLER]), + file:read_file(Log ++ ".1"); +sync_and_read(Node, file,Log) -> + ok = rpc:call(Node,logger_std_h,filesync,[?STANDARD_HANDLER]), + file:read_file(Log). + + +init(_, _) -> + {ok, []}. + +pre_init_per_suite(_Suite, Config, State) -> + {[{nodes, nodes()} | Config], State}. + +pre_init_per_testcase(Suite, TC, Config, State) -> + cleanup(Config), + {[{suite, Suite}, {tc, TC} | Config], State}. + +post_end_per_testcase(_, _TC, Config, Res, State) -> + cleanup(Config), + {Res, State}. + +post_end_per_suite(_, Config, State) -> + cleanup(Config), + {Config, State}. + +cleanup(Config) -> + [test_server:stop_node(N) || N <- nodes(), + not lists:member(N, proplists:get_value(nodes, Config))]. diff --git a/lib/sasl/test/sasl_report_SUITE.erl b/lib/sasl/test/sasl_report_SUITE.erl index 96975aaf69..72ee2f0a10 100644 --- a/lib/sasl/test/sasl_report_SUITE.erl +++ b/lib/sasl/test/sasl_report_SUITE.erl @@ -54,7 +54,7 @@ gen_server_crash_unicode(Config) -> gen_server_crash(Config, Encoding) -> StopFilter = {fun(_,_) -> stop end, ok}, - logger:add_handler_filter(logger_std_h,stop_all,StopFilter), + logger:add_handler_filter(default,stop_all,StopFilter), logger:add_handler_filter(cth_log_redirect,stop_all,StopFilter), try do_gen_server_crash(Config, Encoding) @@ -62,7 +62,7 @@ gen_server_crash(Config, Encoding) -> ok = application:unset_env(kernel, logger_sasl_compatible), ok = application:unset_env(sasl, sasl_error_logger), ok = application:unset_env(kernel, error_logger_format_depth), - logger:remove_handler_filter(logger_std_h,stop_all), + logger:remove_handler_filter(default,stop_all), logger:remove_handler_filter(cth_log_redirect,stop_all) end, ok. @@ -83,9 +83,11 @@ do_gen_server_crash(Config, Encoding) -> error_logger:logfile({open,KernelLog}), application:start(sasl), logger:i(print), + ct:log("error_logger handlers: ~p",[error_logger:which_report_handlers()]), crash_me(), + error_logger:logfile(close), application:stop(sasl), -- cgit v1.2.3 From 3ff770804a27da9add51178b99946ea93d74bd32 Mon Sep 17 00:00:00 2001 From: Lukas Larsson Date: Mon, 14 May 2018 11:39:58 +0200 Subject: kernel: Make all handler callbacks not block logger --- lib/kernel/src/logger_server.erl | 239 ++++++++++++++++++++----------- lib/kernel/test/logger_SUITE.erl | 68 +++++++-- lib/kernel/test/logger_env_var_SUITE.erl | 27 +++- 3 files changed, 236 insertions(+), 98 deletions(-) (limited to 'lib') diff --git a/lib/kernel/src/logger_server.erl b/lib/kernel/src/logger_server.erl index 268fd4f2f3..2a3723177f 100644 --- a/lib/kernel/src/logger_server.erl +++ b/lib/kernel/src/logger_server.erl @@ -36,8 +36,9 @@ -include("logger_internal.hrl"). -define(SERVER, logger). +-define(LOGGER_SERVER_TAG, '$logger_cb_process'). --record(state, {tid}). +-record(state, {tid, async_req, async_req_queue}). %%%=================================================================== %%% API @@ -127,96 +128,93 @@ init([]) -> {ok,SimpleConfig} = logger_simple:adding_handler(logger_simple,SimpleConfig0), logger_config:create(Tid,logger_simple,logger_simple,SimpleConfig), - {ok, #state{tid=Tid}}. - -handle_call({add_handler,Id,Module,HConfig}, _From, #state{tid=Tid}=State) -> - Reply = - case logger_config:exist(Tid,Id) of - true -> - {error,{already_exist,Id}}; - false -> - %% inform the handler - case call_h(Module,adding_handler,[Id,HConfig],{ok,HConfig}) of - {ok,HConfig1} -> - %% We know that the call_h would have loaded the module - %% if it existed, so it is safe here to call function_exported - %% to find out if this is a valid handler - case erlang:function_exported(Module, log, 2) of - true -> - logger_config:create(Tid,Id,Module,HConfig1), - {ok,Config} = do_get_config(Tid,logger), - Handlers = maps:get(handlers,Config,[]), - do_set_config(Tid,logger, - Config#{handlers=>[Id|Handlers]}); - false -> - {error,{invalid_handler, - {function_not_exported, - {Module,log,2}}}} - end; - {error,HReason} -> - {error,{handler_not_added,HReason}} - end - end, - {reply,Reply,State}; -handle_call({remove_handler,HandlerId}, _From, #state{tid=Tid}=State) -> - Reply = - case logger_config:get(Tid,HandlerId) of - {ok,{Module,_}} -> - {ok,Config} = do_get_config(Tid,logger), - Handlers0 = maps:get(handlers,Config,[]), - Handlers = lists:delete(HandlerId,Handlers0), - %% inform the handler - _ = call_h(Module,removing_handler,[HandlerId,Config],ok), - do_set_config(Tid,logger,Config#{handlers=>Handlers}), - logger_config:delete(Tid,HandlerId), - ok; - _ -> - {error,{not_found,HandlerId}} - end, - {reply,Reply,State}; + {ok, #state{tid=Tid, async_req_queue = queue:new()}}. + +handle_call({add_handler,Id,Module,HConfig}, From, #state{tid=Tid}=State) -> + case logger_config:exist(Tid,Id) of + true -> + {reply,{error,{already_exist,Id}},State}; + false -> + call_h_async( + fun() -> + %% inform the handler + call_h(Module,adding_handler,[Id,HConfig],{ok,HConfig}) + end, + fun({ok,HConfig1}) -> + %% We know that the call_h would have loaded the module + %% if it existed, so it is safe here to call function_exported + %% to find out if this is a valid handler + case erlang:function_exported(Module, log, 2) of + true -> + logger_config:create(Tid,Id,Module,HConfig1), + {ok,Config} = do_get_config(Tid,logger), + Handlers = maps:get(handlers,Config,[]), + do_set_config(Tid,logger, + Config#{handlers=>[Id|Handlers]}); + false -> + {error,{invalid_handler, + {function_not_exported, + {Module,log,2}}}} + end; + ({error,HReason}) -> + {error,{handler_not_added,HReason}} + end,From,State) + end; +handle_call({remove_handler,HandlerId}, From, #state{tid=Tid}=State) -> + case logger_config:get(Tid,HandlerId) of + {ok,{Module,HConfig}} -> + {ok,Config} = do_get_config(Tid,logger), + Handlers0 = maps:get(handlers,Config,[]), + Handlers = lists:delete(HandlerId,Handlers0), + call_h_async( + fun() -> + %% inform the handler + call_h(Module,removing_handler,[HandlerId,HConfig],ok) + end, + fun(_Res) -> + do_set_config(Tid,logger,Config#{handlers=>Handlers}), + logger_config:delete(Tid,HandlerId), + ok + end,From,State); + _ -> + {reply,{error,{not_found,HandlerId}},State} + end; handle_call({add_filter,Id,Filter}, _From,#state{tid=Tid}=State) -> Reply = do_add_filter(Tid,Id,Filter), {reply,Reply,State}; handle_call({remove_filter,Id,FilterId}, _From, #state{tid=Tid}=State) -> Reply = do_remove_filter(Tid,Id,FilterId), {reply,Reply,State}; -handle_call({update_config,Id,NewConfig}, _From, #state{tid=Tid}=State) -> - Reply = - case logger_config:get(Tid,Id) of - {ok,{Module,OldConfig}} -> - Config = maps:merge(OldConfig,NewConfig), - case call_h(Module,changing_config,[Id,OldConfig,Config], - {ok,Config}) of - {ok,Config1} -> - do_set_config(Tid,Id,Config1); - Error -> - Error - end; - {ok,OldConfig} -> - Config = maps:merge(OldConfig,NewConfig), - do_set_config(Tid,Id,Config); - Error -> - Error - end, - {reply,Reply,State}; +handle_call({update_config,Id,NewConfig}, From, #state{tid=Tid}=State) -> + case logger_config:get(Tid,Id) of + {ok,{_Module,OldConfig}} -> + Config = maps:merge(OldConfig,NewConfig), + handle_call({set_config,Id,Config}, From, State); + {ok,OldConfig} -> + Config = maps:merge(OldConfig,NewConfig), + {reply,do_set_config(Tid,Id,Config),State}; + Error -> + {reply,Error,State} + end; handle_call({set_config,logger,Config}, _From, #state{tid=Tid}=State) -> Reply = do_set_config(Tid,logger,Config), {reply,Reply,State}; -handle_call({set_config,HandlerId,Config}, _From, #state{tid=Tid}=State) -> - Reply = - case logger_config:get(Tid,HandlerId) of - {ok,{Module,OldConfig}} -> - case call_h(Module,changing_config,[HandlerId,OldConfig,Config], - {ok,Config}) of - {ok,Config1} -> - do_set_config(Tid,HandlerId,Config1); - Error -> - Error - end; - _ -> - {error,{not_found,HandlerId}} - end, - {reply,Reply,State}; +handle_call({set_config,HandlerId,Config}, From, #state{tid=Tid}=State) -> + case logger_config:get(Tid,HandlerId) of + {ok,{Module,OldConfig}} -> + call_h_async( + fun() -> + call_h(Module,changing_config,[HandlerId,OldConfig,Config], + {ok,Config}) + end, + fun({ok,Config1}) -> + do_set_config(Tid,HandlerId,Config1); + (Error) -> + Error + end,From,State); + _ -> + {reply,{error,{not_found,HandlerId}},State} + end; handle_call({set_module_level,Module,Level}, _From, #state{tid=Tid}=State) -> Reply = logger_config:set_module_level(Tid,Module,Level), {reply,Reply,State}; @@ -224,6 +222,8 @@ handle_call({reset_module_level,Module}, _From, #state{tid=Tid}=State) -> Reply = logger_config:reset_module_level(Tid,Module), {reply,Reply,State}. +handle_cast({async_req_reply,_Ref,_Reply} = Reply,State) -> + call_h_reply(Reply,State); handle_cast({cache_module_level,Module}, #state{tid=Tid}=State) -> logger_config:cache_module_level(Tid,Module), {noreply, State}. @@ -243,11 +243,21 @@ handle_info({log,Level,Report,Meta}, State) -> handle_info({Ref,_Reply},State) when is_reference(Ref) -> %% Assuming this is a timed-out gen_server reply - ignoring {noreply, State}; -handle_info(Unexpected,State) -> +handle_info({'DOWN',_Ref,_Proc,_Pid,_Reason} = Down,State) -> + call_h_reply(Down,State); +handle_info(Unexpected,State) when element(1,Unexpected) == 'EXIT' -> + %% The simple logger will send an 'EXIT' message when it is replaced + %% We may as well ignore all 'EXIT' messages that we get ?LOG_INTERNAL(debug, [{logger,got_unexpected_message}, {process,?SERVER}, {message,Unexpected}]), + {noreply,State}; +handle_info(Unexpected,State) -> + ?LOG_INTERNAL(info, + [{logger,got_unexpected_message}, + {process,?SERVER}, + {message,Unexpected}]), {noreply,State}. terminate(_Reason, _State) -> @@ -257,8 +267,11 @@ terminate(_Reason, _State) -> %%% Internal functions %%%=================================================================== call(Request) -> - case whereis(?SERVER) of - Pid when Pid==self() -> + Action = element(1,Request), + case get(?LOGGER_SERVER_TAG) of + true when + Action == add_handler; Action == remove_handler; + Action == update_config; Action == set_config -> {error,{attempting_syncronous_call_to_self,Request}}; _ -> gen_server:call(?SERVER,Request,?DEFAULT_LOGGER_CALL_TIMEOUT) @@ -448,7 +461,59 @@ call_h(Module, Function, Args, DefRet) -> {error,undef,[{Module,Function,Args,_}|_]} -> DefRet; _ -> - {error,{callback_crashed, - {C,R,logger:filter_stacktrace(?MODULE,S)}}} + ST = logger:filter_stacktrace(?MODULE,S), + ?LOG_INTERNAL(error, + [{logger,callback_crashed}, + {process,?SERVER}, + {reason,{C,R,ST}}]), + {error,{callback_crashed,{C,R,ST}}} end end. + +%% There are all sort of API functions that can cause deadlocks if called +%% from the handler callbacks. So we spawn a process that does the request +%% for the logger_server. There are still APIs that will cause problems, +%% namely logger:add_handler +call_h_async(AsyncFun,PostFun,From,#state{ async_req = undefined } = State) -> + Parent = self(), + {Pid, Ref} = spawn_monitor( + fun() -> + put(?LOGGER_SERVER_TAG,true), + receive Ref -> Ref end, + gen_server:cast(Parent, {async_req_reply, Ref, AsyncFun()}) + end), + Pid ! Ref, + {noreply,State#state{ async_req = {Ref,PostFun,From} }}; +call_h_async(AsyncFun,PostFun,From,#state{ async_req_queue = Q } = State) -> + {noreply,State#state{ async_req_queue = queue:in({AsyncFun,PostFun,From},Q) }}. + +call_h_reply({async_req_reply,Ref,Reply}, + #state{ async_req = {Ref,PostFun,From}, async_req_queue = Q} = State) -> + erlang:demonitor(Ref,[flush]), + _ = gen_server:reply(From, PostFun(Reply)), + {Value,NewQ} = queue:out(Q), + NewState = State#state{ async_req = undefined, + async_req_queue = NewQ }, + case Value of + {value,{AsyncFun,NPostFun,NFrom}} -> + call_h_async(AsyncFun,NPostFun,NFrom,NewState); + empty -> + {noreply,NewState} + end; +call_h_reply({'DOWN',Ref,_Proc,Pid,Reason}, #state{ async_req = {Ref,_PostFun,_From}} = State) -> + %% This clause should only be triggered if someone explicitly sends an exit signal + %% to the spawned process. It is only here to make sure that the logger_server does + %% not deadlock if that happens. + ?LOG_INTERNAL(error, + [{logger,process_exited}, + {process,Pid}, + {reason,Reason}]), + call_h_reply( + {async_req_reply,Ref,{error,{logger_process_exited,Pid,Reason}}}, + State); +call_h_reply(Unexpected,State) -> + ?LOG_INTERNAL(info, + [{logger,got_unexpected_message}, + {process,?SERVER}, + {message,Unexpected}]), + {noreply,State}. diff --git a/lib/kernel/test/logger_SUITE.erl b/lib/kernel/test/logger_SUITE.erl index 8a757f0078..8c5d4da70d 100644 --- a/lib/kernel/test/logger_SUITE.erl +++ b/lib/kernel/test/logger_SUITE.erl @@ -218,14 +218,17 @@ change_config(_Config) -> {ok,{?MODULE,#{level:=info,filter_default:=stop}=C2}} = logger:get_handler_config(h1), false = maps:is_key(custom,C2), - {error,fail} = logger:set_handler_config(h1,#{fail=>true}), + {error,fail} = logger:set_handler_config(h1,#{conf_call=>fun() -> {error,fail} end}), {error,{attempting_syncronous_call_to_self,_}} = logger:set_handler_config( - h1,#{call=>fun() -> logger:set_module_level(?MODULE,debug) end}), + h1,#{conf_call=>fun() -> logger:set_handler_config(?MODULE,#{}) end}), + ok = + logger:set_handler_config( + h1,#{conf_call=>fun() -> logger:set_module_level(?MODULE,debug) end}), {ok,{?MODULE,C2}} = logger:get_handler_config(h1), %% Change one key only - {error,fail} = logger:set_handler_config(h1,fail,true), + {error,fail} = logger:set_handler_config(h1,conf_call,fun() -> {error,fail} end), ok = logger:set_handler_config(h1,custom,custom), [changing_config] = test_server:messages_get(), {ok,{?MODULE,#{custom:=custom}=C3}} = logger:get_handler_config(h1), @@ -425,6 +428,7 @@ filter_failed(cleanup,_Config) -> ok. handler_failed(_Config) -> + register(callback_receiver,self()), {error,{invalid_id,1}} = logger:add_handler(1,?MODULE,#{}), {error,{invalid_module,"nomodule"}} = logger:add_handler(h1,"nomodule",#{}), {error,{invalid_handler_config,bad}} = logger:add_handler(h1,?MODULE,bad), @@ -443,17 +447,58 @@ handler_failed(_Config) -> false = lists:keymember(h1,1,H1), {error,{not_found,h1}} = logger:remove_handler(h1), - ok = logger:add_handler(h2,?MODULE,#{filter_default=>log,crash=>true}), + ok = logger:add_handler(h2,?MODULE,#{filter_default=>log,log_call=>fun() -> a = b end}), {error,{already_exist,h2}} = logger:add_handler(h2,othermodule,#{}), + [add] = test_server:messages_get(), logger:info(?map_rep), - check_no_log(), + [remove] = test_server:messages_get(), + #{logger:=#{handlers:=Ids2}, handlers:=H2} = logger:i(), false = lists:member(h2,Ids2), false = lists:keymember(h2,1,H2), {error,{not_found,h2}} = logger:remove_handler(h2), + CallAddHandler = fun() -> logger:add_handler(h2,?MODULE,#{}) end, + CrashHandler = fun() -> a = b end, + KillHandler = fun() -> exit(self(), die) end, + + {error,{handler_not_added,{attempting_syncronous_call_to_self,_}}} = + logger:add_handler(h1,?MODULE,#{add_call=>CallAddHandler}), + {error,{handler_not_added,{callback_crashed,_}}} = + logger:add_handler(h1,?MODULE,#{add_call=>CrashHandler}), + {error,{handler_not_added,{logger_process_exited,_,die}}} = + logger:add_handler(h1,?MODULE,#{add_call=>KillHandler}), + + check_no_log(), + ok = logger:add_handler(h1,?MODULE,#{}), + {error,{attempting_syncronous_call_to_self,_}} = + logger:set_handler_config(h1,#{conf_call=>CallAddHandler}), + {error,{callback_crashed,_}} = + logger:set_handler_config(h1,#{conf_call=>CrashHandler}), + {error,{logger_process_exited,_,die}} = + logger:set_handler_config(h1,#{conf_call=>KillHandler}), + + {error,{attempting_syncronous_call_to_self,_}} = + logger:set_handler_config(h1,conf_call,CallAddHandler), + {error,{callback_crashed,_}} = + logger:set_handler_config(h1,conf_call,CrashHandler), + {error,{logger_process_exited,_,die}} = + logger:set_handler_config(h1,conf_call,KillHandler), + + ok = logger:remove_handler(h1), + [add,remove] = test_server:messages_get(), + + check_no_log(), + ok = logger:add_handler(h1,?MODULE,#{rem_call=>CallAddHandler}), + ok = logger:remove_handler(h1), + ok = logger:add_handler(h1,?MODULE,#{rem_call=>CrashHandler}), + ok = logger:remove_handler(h1), + ok = logger:add_handler(h1,?MODULE,#{rem_call=>KillHandler}), + ok = logger:remove_handler(h1), + [add,add,add] = test_server:messages_get(), + ok. handler_failed(cleanup,_Config) -> @@ -720,16 +765,19 @@ check_maps(Expected,Got,What) -> end. %% Handler +adding_handler(_Id,#{add_call:=Fun}) -> + Fun(); adding_handler(_Id,Config) -> maybe_send(add), {ok,Config}. + +removing_handler(_Id,#{rem_call:=Fun}) -> + Fun(); removing_handler(_Id,_Config) -> maybe_send(remove), ok. -changing_config(_Id,_Old,#{call:=Fun}) -> +changing_config(_Id,_Old,#{conf_call:=Fun}) -> Fun(); -changing_config(_Id,_Old,#{fail:=true}) -> - {error,fail}; changing_config(_Id,_Old,Config) -> maybe_send(changing_config), {ok,Config}. @@ -740,8 +788,8 @@ maybe_send(Msg) -> Pid -> Pid ! Msg end. -log(_Log,#{crash:=true}) -> - a=b; +log(_Log,#{log_call:=Fun}) -> + Fun(); log(Log,Config) -> TcProc = maps:get(tc_proc,Config,self()), TcProc ! {Log,Config}, diff --git a/lib/kernel/test/logger_env_var_SUITE.erl b/lib/kernel/test/logger_env_var_SUITE.erl index e976a10b21..764f443634 100644 --- a/lib/kernel/test/logger_env_var_SUITE.erl +++ b/lib/kernel/test/logger_env_var_SUITE.erl @@ -58,7 +58,8 @@ groups() -> logger_disk_log_formatter, logger_undefined, logger_many_handlers_default_first, - logger_many_handlers_default_last + logger_many_handlers_default_last, + logger_many_handlers_default_last_broken_filter ]}, {bad,[],[bad_error_logger, bad_level, @@ -470,6 +471,8 @@ logger_undefined(Config) -> false = lists:keymember(sasl_h,1,Hs), ok. + +%% Test that we can add multiple handlers with the default first logger_many_handlers_default_first(Config) -> LogErr = file(Config,logger_many_handlers_default_first_error), LogInfo = file(Config,logger_many_handlers_default_first_info), @@ -508,6 +511,28 @@ logger_many_handlers_default_last(Config) -> } ]}], LogErr, LogInfo, 7). +%% Check that we can handle that an added logger has a broken filter +%% This used to cause a deadlock. +logger_many_handlers_default_last_broken_filter(Config) -> + LogErr = file(Config,logger_many_handlers_default_first_broken_filter_error), + LogInfo = file(Config,logger_many_handlers_default_first_broken_filter_info), + + logger_many_handlers( + Config,[{logger, + [{handler,info,logger_std_h, + #{level=>info, + filters=>[{broken,{fun logger_filters:level/2,broken_state}}, + {level,{fun logger_filters:level/2,{stop,gteq,error}}}], + logger_std_h=>#{type=>{file,LogInfo}}} + }, + {handler,?STANDARD_HANDLER,logger_std_h, + #{level=>error, + filters=>[], + formatter=>{logger_formatter,#{}}, + logger_std_h=>#{type=>{file,LogErr}}} + } + ]}], LogErr, LogInfo, 7). + logger_many_handlers(Config, Env, LogErr, LogInfo, NumProgress) -> {ok,#{handlers:=Hs},Node} = setup(Config,Env), check_single_log(Node,LogErr, -- cgit v1.2.3 From 92d93f85e88235f3fa757d300628d382d09c6226 Mon Sep 17 00:00:00 2001 From: Siri Hansen Date: Wed, 9 May 2018 14:28:44 +0200 Subject: Fix some link errors in logger documentation --- lib/kernel/doc/src/error_logger.xml | 18 +++++++++++------- lib/kernel/doc/src/kernel_app.xml | 7 +++---- lib/kernel/doc/src/logger_chapter.xml | 10 +++++----- lib/sasl/doc/src/sasl_app.xml | 12 ++++-------- 4 files changed, 23 insertions(+), 24 deletions(-) (limited to 'lib') diff --git a/lib/kernel/doc/src/error_logger.xml b/lib/kernel/doc/src/error_logger.xml index cb6165c73e..c9fe9484e4 100644 --- a/lib/kernel/doc/src/error_logger.xml +++ b/lib/kernel/doc/src/error_logger.xml @@ -181,17 +181,21 @@ ok Get the value of the Kernel application variable - logger_format_depth. + error_logger_format_depth.

Returns max(10, Depth), where Depth is the - value of - - logger_format_depth + value of error_logger_format_depth in the Kernel application, if Depth is an integer. Otherwise, unlimited is returned.

-

For backwards compatibility, the value - of error_logger_format_depth is used - if logger_format_depth is not set.

+ +

The error_logger_format_depth variable + is + deprecated since + the Logger API was + introduced in OTP-21. The variable, and this function, are + kept for backwards compatibility since they still might be + used by legacy report handlers.

+ diff --git a/lib/kernel/doc/src/kernel_app.xml b/lib/kernel/doc/src/kernel_app.xml index ebc7962f29..7cd05dab14 100644 --- a/lib/kernel/doc/src/kernel_app.xml +++ b/lib/kernel/doc/src/kernel_app.xml @@ -181,11 +181,10 @@

This parameter specifies which log levels to log. The specified level, and all levels that are more severe, will be logged.

-

It is possible to change this variable at run-time - using - logger:set_logger_config(#{ level => error }). - .

The default value is info.

+

To change the global log level at run-time, use + + logger:set_logger_config(level, error).

 logger_sasl_compatible = boolean() diff --git a/lib/kernel/doc/src/logger_chapter.xml b/lib/kernel/doc/src/logger_chapter.xml index 484358f392..4232429589 100644 --- a/lib/kernel/doc/src/logger_chapter.xml +++ b/lib/kernel/doc/src/logger_chapter.xml @@ -136,7 +136,7 @@

Filters can be set on the logger or on a handler. Logger filters are applied first, and if passed, the handler filters - for each handler are applied. The handler plugin is only + for each handler are applied. The handler callback is only called if all handler filters for the handler in question also pass.

@@ -159,7 +159,7 @@ format(Log,Extra) -> unicode:chardata() -

The formatter plugin is called by each handler, and the +

The formatter callback is called by each handler, and the returned string can be printed to the handler's destination (stdout, file, ...).

 @@ -214,8 +214,8 @@ logger_filters:level/2

This filter provides a way of filtering log events based - on the log level. See - logger_filters:domain/2

+ on the log level. See + logger_filters:level/2

 logger_filters:progress/2 @@ -518,7 +518,7 @@ error_logger:add_report_handler/1,2. handler named sasl_h.

All SASL reports have a metadata field domain=>[beam,erlang,otp,sasl], which can be - used, for example, by filters to to stop or allow the + used, for example, by filters to stop or allow the events.

 diff --git a/lib/sasl/doc/src/sasl_app.xml b/lib/sasl/doc/src/sasl_app.xml index 48b0b8eafb..8f92a22cf7 100644 --- a/lib/sasl/doc/src/sasl_app.xml +++ b/lib/sasl/doc/src/sasl_app.xml @@ -119,22 +119,18 @@

Formats and writes supervisor reports, crash reports, and progress reports to stdio. This error logger event handler uses - logger_format_depth + error_logger_format_depth in the Kernel application to limit how much detail is printed - in crash and supervisor reports. If logger_format_depth - is not set, it uses the old error_logger_format_depth - instead.

+ in crash and supervisor reports.

sasl_report_file_h

Formats and writes supervisor reports, crash report, and progress report to a single file. This error logger event handler uses - logger_format_depth + error_logger_format_depth in the Kernel application to limit the details printed in - crash and supervisor reports. If logger_format_depth is - not set, it uses the old error_logger_format_depth - instead.

+ crash and supervisor reports.

A similar behaviour, but still using the new logger API, can be -- cgit v1.2.3 From bfe8a57bb9356415e6438f0deb410b03a7c602d1 Mon Sep 17 00:00:00 2001 From: Siri Hansen Date: Wed, 9 May 2018 17:22:43 +0200 Subject: Remove logger env vars for format_depth, max_size and utc These are replaced by new config handling and must not be used any more. --- lib/kernel/src/error_logger.erl | 8 +++- lib/kernel/src/logger.erl | 60 ------------------------------ lib/kernel/src/logger_formatter.erl | 29 ++++++++++++--- lib/kernel/test/logger_formatter_SUITE.erl | 50 +++++++++++-------------- lib/stdlib/src/gen_server.erl | 4 +- lib/stdlib/src/gen_statem.erl | 2 +- lib/stdlib/src/proc_lib.erl | 8 ++-- 7 files changed, 58 insertions(+), 103 deletions(-) (limited to 'lib') diff --git a/lib/kernel/src/error_logger.erl b/lib/kernel/src/error_logger.erl index 47d0ca5ea3..196c70d05f 100644 --- a/lib/kernel/src/error_logger.erl +++ b/lib/kernel/src/error_logger.erl @@ -540,7 +540,6 @@ tty(false) -> delete_report_handler(error_logger_tty_h). %%%----------------------------------------------------------------- - -spec limit_term(term()) -> term(). limit_term(Term) -> @@ -552,4 +551,9 @@ limit_term(Term) -> -spec get_format_depth() -> 'unlimited' | pos_integer(). get_format_depth() -> - logger:get_format_depth(). + case application:get_env(kernel, error_logger_format_depth) of + {ok, Depth} when is_integer(Depth) -> + max(10, Depth); + undefined -> + unlimited + end. diff --git a/lib/kernel/src/logger.erl b/lib/kernel/src/logger.erl index 9a6719923e..7ce4a80bbd 100644 --- a/lib/kernel/src/logger.erl +++ b/lib/kernel/src/logger.erl @@ -51,7 +51,6 @@ -export([set_process_metadata/1, update_process_metadata/1, unset_process_metadata/0, get_process_metadata/0]). -export([i/0, i/1]). --export([limit_term/1, get_format_depth/0, get_max_size/0, get_utc_config/0]). %% Basic report formatting -export([format_report/1, format_otp_report/1]). @@ -705,65 +704,6 @@ get_default_handler_filters() -> get_logger_env() -> application:get_env(kernel, logger, []). -%%%----------------------------------------------------------------- --spec limit_term(term()) -> term(). - -limit_term(Term) -> - try get_format_depth() of - unlimited -> Term; - D -> io_lib:limit_term(Term, D) - catch error:badarg -> - %% This could happen during system termination, after - %% application_controller process is dead. - unlimited - end. - --spec get_format_depth() -> 'unlimited' | pos_integer(). - -get_format_depth() -> - Depth = - case application:get_env(kernel, logger_format_depth) of - {ok, D} when is_integer(D) -> - D; - undefined -> - case application:get_env(kernel, error_logger_format_depth) of - {ok, D} when is_integer(D) -> - D; - undefined -> - unlimited - end - end, - max(10, Depth). - --spec get_max_size() -> 'unlimited' | pos_integer(). - -get_max_size() -> - case application:get_env(kernel, logger_max_size) of - {ok, Size} when is_integer(Size) -> - max(50, Size); - undefined -> - unlimited - end. - --spec get_utc_config() -> boolean(). - -get_utc_config() -> - %% Kernel's logger_utc configuration overrides SASL utc_log, which - %% in turn overrides stdlib config - in order to have uniform - %% timestamps in log messages - case application:get_env(kernel, logger_utc) of - {ok, Val} -> Val; - undefined -> - case application:get_env(sasl, utc_log) of - {ok, Val} -> Val; - undefined -> - case application:get_env(stdlib, utc_log) of - {ok, Val} -> Val; - undefined -> false - end - end - end. - %%%----------------------------------------------------------------- %%% Internal do_log(warning,Msg,Meta) -> diff --git a/lib/kernel/src/logger_formatter.erl b/lib/kernel/src/logger_formatter.erl index 8e954f8d98..624f523465 100644 --- a/lib/kernel/src/logger_formatter.erl +++ b/lib/kernel/src/logger_formatter.erl @@ -259,17 +259,17 @@ month(12) -> "Dec". utcstr(#{utc:=true}) -> "UTC "; utcstr(_) -> "". -add_default_config(#{utc:=_}=Config0) -> +add_default_config(Config0) -> Default = #{legacy_header=>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)), + Utc = get_utc(maps:get(utc,Config0,false)), add_default_template(maps:merge(Default,Config0#{max_size=>MaxSize, - depth=>Depth})); -add_default_config(Config) -> - add_default_config(Config#{utc=>logger:get_utc_config()}). + depth=>Depth, + utc=>Utc})). add_default_template(#{template:=_}=Config) -> Config; @@ -284,11 +284,28 @@ default_template(_) -> ?DEFAULT_FORMAT_TEMPLATE. get_max_size(false) -> - logger:get_max_size(); + unlimited; get_max_size(S) -> max(10,S). get_depth(false) -> - logger:get_format_depth(); + error_logger:get_format_depth(); get_depth(S) -> max(5,S). + +get_utc(false) -> + get_utc_config(); +get_utc(U) -> + U. + +get_utc_config() -> + %% SASL utc_log overrides stdlib config - in order to have uniform + %% timestamps in log messages + case application:get_env(sasl, utc_log) of + {ok, Val} -> Val; + undefined -> + case application:get_env(stdlib, utc_log) of + {ok, Val} -> Val; + undefined -> false + end + end. diff --git a/lib/kernel/test/logger_formatter_SUITE.erl b/lib/kernel/test/logger_formatter_SUITE.erl index c80e5694cf..bd5bc2d2e4 100644 --- a/lib/kernel/test/logger_formatter_SUITE.erl +++ b/lib/kernel/test/logger_formatter_SUITE.erl @@ -297,22 +297,22 @@ max_size(_Config) -> single_line=>false}, "12345678901234567890" = 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",[]},#{},Cfg), - "12345678901234567890123456789012345678901234567..." = % 50 - format(info, - {"123456789012345678901234567890123456789012345678901234567890", - []}, - #{}, - Cfg), - application:set_env(kernel,logger_max_size,53), - "12345678901234567890123456789012345678901234567890..." = %53 - format(info, - {"123456789012345678901234567890123456789012345678901234567890", - []}, - #{}, - Cfg), + %% application:set_env(kernel,logger_max_size,11), + %% "12345678901234567890" = % min value is 50, so this is not limited + %% format(info,{"12345678901234567890",[]},#{},Cfg), + %% "12345678901234567890123456789012345678901234567..." = % 50 + %% format(info, + %% {"123456789012345678901234567890123456789012345678901234567890", + %% []}, + %% #{}, + %% Cfg), + %% application:set_env(kernel,logger_max_size,53), + %% "12345678901234567890123456789012345678901234567890..." = %53 + %% format(info, + %% {"123456789012345678901234567890123456789012345678901234567890", + %% []}, + %% #{}, + %% Cfg), "123456789012..." = format(info,{"12345678901234567890",[]},#{},Cfg#{max_size=>15}), "12345678901234567890" = @@ -341,12 +341,6 @@ depth(_Config) -> {"~p",[[1,2,3,4,5,6,7,8,9,0,1,2,3,4,5,6,7,8,9,0]]}, #{}, #{template=>Template}), - application:set_env(kernel,error_logger_format_depth,12), - "[1,2,3,4,5,6,7,8,9,0,1|...]" = - format(info, - {"~p",[[1,2,3,4,5,6,7,8,9,0,1,2,3,4,5,6,7,8,9,0]]}, - #{}, - #{template=>Template}), "[1,2,3,4,5,6,7,8,9,0,1,2|...]" = format(info, {"~p",[[1,2,3,4,5,6,7,8,9,0,1,2,3,4,5,6,7,8,9,0]]}, @@ -451,12 +445,12 @@ format_time(_Config) -> ct:log(String2), " 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: term\n" = string:prefix(String3,ExpectedTimestamp3), + %% 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: term\n" = string:prefix(String3,ExpectedTimestamp3), ok. diff --git a/lib/stdlib/src/gen_server.erl b/lib/stdlib/src/gen_server.erl index 035dd871ff..09f77c0810 100644 --- a/lib/stdlib/src/gen_server.erl +++ b/lib/stdlib/src/gen_server.erl @@ -934,14 +934,14 @@ format_log(#{label:={gen_server,terminate}, end end; _ -> - logger:limit_term(Reason) + error_logger:limit_term(Reason) end, {ClientFmt,ClientArgs} = format_client_log(Client), {"** Generic server ~tp terminating \n" "** Last message in was ~tp~n" "** When Server state == ~tp~n" "** Reason for termination == ~n** ~tp~n" ++ ClientFmt, - [Name, Msg, logger:limit_term(State), Reason1] ++ ClientArgs}; + [Name, Msg, error_logger:limit_term(State), Reason1] ++ ClientArgs}; format_log(#{label:={gen_server,no_handle_info}, module:=Mod, message:=Msg}) -> diff --git a/lib/stdlib/src/gen_statem.erl b/lib/stdlib/src/gen_statem.erl index f558f0d33e..b36b8cd5a5 100644 --- a/lib/stdlib/src/gen_statem.erl +++ b/lib/stdlib/src/gen_statem.erl @@ -1938,7 +1938,7 @@ format_log(#{label:={gen_statem,terminate}, _ -> {Reason,Stacktrace} end, [LimitedP, LimitedFmtData, LimitedFixedReason] = - [logger:limit_term(D) || D <- [P, FmtData, FixedReason]], + [error_logger:limit_term(D) || D <- [P, FmtData, FixedReason]], CBMode = case StateEnter of true -> diff --git a/lib/stdlib/src/proc_lib.erl b/lib/stdlib/src/proc_lib.erl index 9094e0c0cd..5f14e78f91 100644 --- a/lib/stdlib/src/proc_lib.erl +++ b/lib/stdlib/src/proc_lib.erl @@ -553,10 +553,10 @@ get_ancestors(Pid) -> %% assumed that all report handlers call proc_lib:format(). get_messages(Pid) -> Messages = get_process_messages(Pid), - {messages, logger:limit_term(Messages)}. + {messages, error_logger:limit_term(Messages)}. get_process_messages(Pid) -> - Depth = logger:get_format_depth(), + Depth = error_logger:get_format_depth(), case Pid =/= self() orelse Depth =:= unlimited of true -> {messages, Messages} = get_process_info(Pid, messages), @@ -586,7 +586,7 @@ get_cleaned_dictionary(Pid) -> cleaned_dict(Dict) -> CleanDict = clean_dict(Dict), - logger:limit_term(CleanDict). + error_logger:limit_term(CleanDict). clean_dict([{'$ancestors',_}|Dict]) -> clean_dict(Dict); @@ -756,7 +756,7 @@ check(Res) -> Res. Args :: [term()]. report_cb(#{label:={proc_lib,crash}, report:=CrashReport}) -> - Depth = logger:get_format_depth(), + Depth = error_logger:get_format_depth(), get_format_and_args(CrashReport, utf8, Depth). -spec format(CrashReport) -> string() when -- cgit v1.2.3 From ee9e7de41ec6b14857a2e32099cf76b425c3b778 Mon Sep 17 00:00:00 2001 From: Siri Hansen Date: Mon, 14 May 2018 17:00:34 +0200 Subject: Add filter to sasl_h which stops log events with remote gl --- lib/sasl/src/sasl.erl | 4 +++- 1 file changed, 3 insertions(+), 1 deletion(-) (limited to 'lib') diff --git a/lib/sasl/src/sasl.erl b/lib/sasl/src/sasl.erl index 2bf11bdcdf..9359bdb30e 100644 --- a/lib/sasl/src/sasl.erl +++ b/lib/sasl/src/sasl.erl @@ -142,7 +142,9 @@ add_sasl_logger(Dest, Level) -> #{level=>Level, filter_default=>stop, filters=> - [{sasl_domain, + [{remote_gl, + {fun logger_filters:remote_gl/2,stop}}, + {sasl_domain, {fun logger_filters:domain/2, {log,equals,[beam,erlang,otp,sasl]}}}], logger_std_h=>#{type=>Dest}, -- cgit v1.2.3 From 033bcc2296d7d79c53d56798ab0ccf232f451574 Mon Sep 17 00:00:00 2001 From: Siri Hansen Date: Mon, 14 May 2018 17:01:15 +0200 Subject: Fix error_logger:tty/1 to turn on/off tty logging This function earlier only added/removed the old error_logger_tty_h report handler. Since it is mostly used for turning off logging to tty in general, it now also checks the default logger handlers. It works as follows: tty(true): * If default handler is logger_std_h of type standard_io, make sure it has no 'error_logger_tty_false filter'. * Else, add a new instance of logger_std_h with type standard_io with id 'error_logger_tty_true'. tty(false): * Remove error_logger_tty_h report handler if it exists. * Remove error_logger_tty_false logger handler if it exists. * If default handler is logger_std_h of type standard_io, add a filter named 'error_logger_tty_false', which stops all events. --- lib/kernel/src/error_logger.erl | 35 ++++++++++++++++++++++++++++------- 1 file changed, 28 insertions(+), 7 deletions(-) (limited to 'lib') diff --git a/lib/kernel/src/error_logger.erl b/lib/kernel/src/error_logger.erl index 196c70d05f..6c3b308308 100644 --- a/lib/kernel/src/error_logger.erl +++ b/lib/kernel/src/error_logger.erl @@ -529,15 +529,36 @@ logfile(filename) -> Flag :: boolean(). tty(true) -> - case lists:member(error_logger_tty_h, which_report_handlers()) of - false -> - add_report_handler(error_logger_tty_h, []); - true -> - ignore - end, + _ = case lists:member(error_logger_tty_h, which_report_handlers()) of + false -> + case logger:get_handler_config(default) of + {ok,{logger_std_h,#{logger_std_h:=#{type:=standard_io}}}} -> + logger:remove_handler_filter(default, + error_logger_tty_false); + _ -> + logger:add_handler(error_logger_tty_true,logger_std_h, + #{filter_default=>stop, + filters=>?DEFAULT_HANDLER_FILTERS( + [beam,erlang,otp]), + formatter=>{?DEFAULT_FORMATTER, + ?DEFAULT_FORMAT_CONFIG}, + logger_std_h=>#{type=>standard_io}}) + end; + true -> + ok + end, ok; tty(false) -> - delete_report_handler(error_logger_tty_h). + delete_report_handler(error_logger_tty_h), + _ = logger:remove_handler(error_logger_tty_true), + _ = case logger:get_handler_config(default) of + {ok,{logger_std_h,#{logger_std_h:=#{type:=standard_io}}}} -> + logger:add_handler_filter(default,error_logger_tty_false, + {fun(_,_) -> stop end, ok}); + _ -> + ok + end, + ok. %%%----------------------------------------------------------------- -spec limit_term(term()) -> term(). -- cgit v1.2.3 From c2c5e22e0c0f67d0c445113b7908dd07e4e8d4c4 Mon Sep 17 00:00:00 2001 From: Siri Hansen Date: Mon, 14 May 2018 18:03:15 +0200 Subject: Improve santiy check of formatter config --- lib/kernel/src/logger_formatter.erl | 45 +++++++++++++++++++++++++++++++ lib/kernel/src/logger_server.erl | 46 +++++++++++--------------------- lib/kernel/test/logger_SUITE.erl | 53 ++++++++++++++++++++++++++++++++----- 3 files changed, 107 insertions(+), 37 deletions(-) (limited to 'lib') diff --git a/lib/kernel/src/logger_formatter.erl b/lib/kernel/src/logger_formatter.erl index 624f523465..0d55244034 100644 --- a/lib/kernel/src/logger_formatter.erl +++ b/lib/kernel/src/logger_formatter.erl @@ -20,6 +20,7 @@ -module(logger_formatter). -export([format/2]). +-export([check_config/1]). -include("logger_internal.hrl"). @@ -309,3 +310,47 @@ get_utc_config() -> undefined -> false end end. + +check_config(Config) when is_map(Config) -> + do_check_config(maps:to_list(Config)); +check_config(Config) -> + {error,{invalid_formatter_config,?MODULE,Config}}. + +do_check_config([{Type,L}|Config]) when Type == chars_limit; + Type == depth; + Type == max_size -> + case check_limit(L) of + ok -> do_check_config(Config); + error -> {error,{invalid_formatter_config,?MODULE,{Type,L}}} + end; +do_check_config([{single_line,SL}|Config]) when is_boolean(SL) -> + do_check_config(Config); +do_check_config([{legacy_header,LH}|Config]) when is_boolean(LH) -> + do_check_config(Config); +do_check_config([{report_cb,RCB}|Config]) when is_function(RCB,1) -> + do_check_config(Config); +do_check_config([{template,T}|Config]) when is_list(T) -> + case lists:all(fun(X) when is_atom(X) -> true; + (X) when is_tuple(X), is_atom(element(1,X)) -> true; + (X) when is_list(X) -> io_lib:printable_unicode_list(X); + (_) -> false + end, + T) of + true -> + do_check_config(Config); + false -> + {error,{invalid_formatter_template,?MODULE,T}} + end; +do_check_config([{utc,Utc}|Config]) when is_boolean(Utc) -> + do_check_config(Config); +do_check_config([C|_]) -> + {error,{invalid_formatter_config,?MODULE,C}}; +do_check_config([]) -> + ok. + +check_limit(L) when is_integer(L), L>0 -> + ok; +check_limit(unlimited) -> + ok; +check_limit(_) -> + error. diff --git a/lib/kernel/src/logger_server.erl b/lib/kernel/src/logger_server.erl index 2a3723177f..f1b4a21c6a 100644 --- a/lib/kernel/src/logger_server.erl +++ b/lib/kernel/src/logger_server.erl @@ -416,40 +416,24 @@ check_filter_default(FD) when FD==stop; FD==log -> check_filter_default(FD) -> throw({invalid_filter_default,FD}). -check_formatter({logger_formatter,Config}) when is_map(Config) -> - check_logger_formatter_config(maps:to_list(Config)); -check_formatter({logger_formatter,Config}) -> - throw({invalid_formatter_config,Config}); -check_formatter({Mod,_}) -> - %% no knowledge of other formatters - check_mod(Mod); +check_formatter({Mod,Config}) -> + check_mod(Mod), + try Mod:check_config(Config) of + ok -> ok; + {error,Error} -> throw(Error) + catch + C:R:S -> + case {C,R,S} of + {error,undef,[{Mod,check_config,[Config],_}|_]} -> + ok; + _ -> + throw({callback_crashed, + {C,R,logger:filter_stacktrace(?MODULE,S)}}) + end + end; check_formatter(Formatter) -> throw({invalid_formatter,Formatter}). - -check_logger_formatter_config([{template,T}|Config]) when is_list(T) -> - case lists:all(fun(X) when is_atom(X) -> true; - (X) when is_tuple(X), is_atom(element(1,X)) -> true; - (X) when is_list(X) -> io_lib:printable_unicode_list(X); - (_) -> false - end, - T) of - true -> - check_logger_formatter_config(Config); - false -> - throw({invalid_formatter_template,T}) - end; -check_logger_formatter_config([{legacy_header,LH}|Config]) when is_boolean(LH) -> - check_logger_formatter_config(Config); -check_logger_formatter_config([{single_line,SL}|Config]) when is_boolean(SL) -> - check_logger_formatter_config(Config); -check_logger_formatter_config([{utc,Utc}|Config]) when is_boolean(Utc) -> - check_logger_formatter_config(Config); -check_logger_formatter_config([C|_]) -> - throw({invalid_formatter_config,C}); -check_logger_formatter_config([]) -> - ok. - call_h(Module, Function, Args, DefRet) -> %% Not calling code:ensure_loaded + erlang:function_exported here, %% since in some rare terminal cases, the code_server might not diff --git a/lib/kernel/test/logger_SUITE.erl b/lib/kernel/test/logger_SUITE.erl index 8c5d4da70d..9fea92ee0d 100644 --- a/lib/kernel/test/logger_SUITE.erl +++ b/lib/kernel/test/logger_SUITE.erl @@ -544,28 +544,64 @@ config_sanity_check(_Config) -> logger:set_handler_config(h1,formatter,bad), {error,{invalid_module,{bad}}} = logger:set_handler_config(h1,formatter,{{bad},cfg}), - {error,{invalid_formatter_config,bad}} = + {error,{invalid_formatter_config,logger_formatter,bad}} = logger:set_handler_config(h1,formatter,{logger_formatter,bad}), - {error,{invalid_formatter_config,{bad,bad}}} = + {error,{invalid_formatter_config,logger_formatter,{bad,bad}}} = logger:set_handler_config(h1,formatter,{logger_formatter,#{bad=>bad}}), - {error,{invalid_formatter_config,{template,bad}}} = + {error,{invalid_formatter_config,logger_formatter,{template,bad}}} = logger:set_handler_config(h1,formatter,{logger_formatter, #{template=>bad}}), - {error,{invalid_formatter_template,[1]}} = + {error,{invalid_formatter_template,logger_formatter,[1]}} = logger:set_handler_config(h1,formatter,{logger_formatter, #{template=>[1]}}), ok = logger:set_handler_config(h1,formatter,{logger_formatter, #{template=>[]}}), - {error,{invalid_formatter_config,{single_line,bad}}} = + {error,{invalid_formatter_config,logger_formatter,{single_line,bad}}} = logger:set_handler_config(h1,formatter,{logger_formatter, #{single_line=>bad}}), ok = logger:set_handler_config(h1,formatter,{logger_formatter, #{single_line=>true}}), - {error,{invalid_formatter_config,{legacy_header,bad}}} = + {error,{invalid_formatter_config,logger_formatter,{legacy_header,bad}}} = logger:set_handler_config(h1,formatter,{logger_formatter, #{legacy_header=>bad}}), ok = logger:set_handler_config(h1,formatter,{logger_formatter, #{legacy_header=>true}}), + {error,{invalid_formatter_config,logger_formatter,{report_cb,bad}}} = + logger:set_handler_config(h1,formatter,{logger_formatter, + #{report_cb=>bad}}), + ok = logger:set_handler_config(h1,formatter,{logger_formatter, + #{report_cb=>fun(R) -> + {"~p",[R]} + end}}), + {error,{invalid_formatter_config,logger_formatter,{utc,bad}}} = + logger:set_handler_config(h1,formatter,{logger_formatter, + #{utc=>bad}}), + ok = logger:set_handler_config(h1,formatter,{logger_formatter, + #{utc=>true}}), + {error,{invalid_formatter_config,logger_formatter,{chars_limit,bad}}} = + logger:set_handler_config(h1,formatter,{logger_formatter, + #{chars_limit=>bad}}), + ok = logger:set_handler_config(h1,formatter,{logger_formatter, + #{chars_limit=>unlimited}}), + ok = logger:set_handler_config(h1,formatter,{logger_formatter, + #{chars_limit=>4}}), + {error,{invalid_formatter_config,logger_formatter,{depth,bad}}} = + logger:set_handler_config(h1,formatter,{logger_formatter, + #{depth=>bad}}), + ok = logger:set_handler_config(h1,formatter,{logger_formatter, + #{depth=>unlimited}}), + ok = logger:set_handler_config(h1,formatter,{logger_formatter, + #{depth=>4}}), + {error,{invalid_formatter_config,logger_formatter,{max_size,bad}}} = + logger:set_handler_config(h1,formatter,{logger_formatter, + #{max_size=>bad}}), + ok = logger:set_handler_config(h1,formatter,{logger_formatter, + #{max_size=>unlimited}}), + ok = logger:set_handler_config(h1,formatter,{logger_formatter, + #{max_size=>4}}), + ok = logger:set_handler_config(h1,formatter,{module,config}), + {error,{callback_crashed,{error,{badmatch,3},[{?MODULE,check_config,1,_}]}}} = + logger:set_handler_config(h1,formatter,{?MODULE,crash}), ok = logger:set_handler_config(h1,custom,custom), ok. @@ -877,3 +913,8 @@ test_macros(emergency=Level) -> %%% Called by macro ?TRY(X) my_try(Fun) -> try Fun() catch C:R -> {C,R} end. + +check_config(crash) -> + erlang:error({badmatch,3}); +check_config(_) -> + ok. -- cgit v1.2.3 From d29fca17a0c053fca2e5961fb146e9aeefb55aa9 Mon Sep 17 00:00:00 2001 From: Siri Hansen Date: Mon, 14 May 2018 19:06:22 +0200 Subject: Hide handlers field in logger config map from the API This field contains the index of all installed handlers. It is internal and can not be altered by the user, and should therefore not be visible. --- lib/kernel/src/logger.erl | 17 +++++------ lib/kernel/src/logger_server.erl | 44 +++++++++-------------------- lib/kernel/test/logger_SUITE.erl | 34 ++++++++++------------ lib/kernel/test/logger_disk_log_h_SUITE.erl | 6 ++-- lib/kernel/test/logger_std_h_SUITE.erl | 6 ++-- 5 files changed, 46 insertions(+), 61 deletions(-) (limited to 'lib') diff --git a/lib/kernel/src/logger.erl b/lib/kernel/src/logger.erl index 7ce4a80bbd..2c7466fdf6 100644 --- a/lib/kernel/src/logger.erl +++ b/lib/kernel/src/logger.erl @@ -364,7 +364,8 @@ set_handler_config(HandlerId,Config) -> -spec get_logger_config() -> {ok,Config} when Config :: config(). get_logger_config() -> - logger_config:get(?LOGGER_TABLE,logger). + {ok,Config} = logger_config:get(?LOGGER_TABLE,logger), + {ok,maps:remove(handlers,Config)}. -spec get_handler_config(HandlerId) -> {ok,{Module,Config}} | {error,term()} when HandlerId :: handler_id(), @@ -445,8 +446,9 @@ i() -> i(_Action = print) -> io:put_chars(i(string)); i(_Action = string) -> - #{logger := #{level := Level, handlers := Handlers, - filters := Filters, filter_default := FilterDefault}, + #{logger := #{level := Level, + filters := Filters, + filter_default := FilterDefault}, handlers := HandlerConfigs, module_levels := Modules} = i(term), [io_lib:format("Current logger configuration:~n", []), @@ -455,16 +457,15 @@ i(_Action = string) -> io_lib:format(" Filters: ~n", []), print_filters(4, Filters), io_lib:format(" Handlers: ~n", []), - print_handlers([C || {Id, _, _} = C <- HandlerConfigs, - lists:member(Id, Handlers)]), + print_handlers(HandlerConfigs), io_lib:format(" Level set per module: ~n", []), print_module_levels(Modules) ]; i(_Action = term) -> {Logger, Handlers, Modules} = logger_config:get(tid()), - #{logger=>Logger, - handlers=>Handlers, - module_levels=>Modules}. + #{logger=>maps:remove(handlers,Logger), + handlers=>lists:keysort(1,Handlers), + module_levels=>lists:keysort(1,Modules)}. print_filters(Indent, {Id, {Fun, Config}}) -> io_lib:format("~sId: ~p~n" diff --git a/lib/kernel/src/logger_server.erl b/lib/kernel/src/logger_server.erl index f1b4a21c6a..bd0c325f2b 100644 --- a/lib/kernel/src/logger_server.erl +++ b/lib/kernel/src/logger_server.erl @@ -48,23 +48,18 @@ start_link() -> gen_server:start_link({local, ?SERVER}, ?MODULE, [], []). add_handler(Id,Module,Config0) -> - case sanity_check(logger,handlers,[Id]) of - ok -> - try check_mod(Module) of + try {check_id(Id),check_mod(Module)} of + {ok,ok} -> + case sanity_check(Id,Config0) of ok -> - case sanity_check(Id,Config0) of - ok -> - Default = default_config(Id), - Config = maps:merge(Default,Config0), - call({add_handler,Id,Module,Config}); - Error -> - Error - end - catch throw:Error -> - {error,Error} - end; - Error -> - Error + Default = default_config(Id), + Config = maps:merge(Default,Config0), + call({add_handler,Id,Module,Config}); + Error -> + Error + end + catch throw:Error -> + {error,Error} end. remove_handler(HandlerId) -> @@ -197,7 +192,8 @@ handle_call({update_config,Id,NewConfig}, From, #state{tid=Tid}=State) -> {reply,Error,State} end; handle_call({set_config,logger,Config}, _From, #state{tid=Tid}=State) -> - Reply = do_set_config(Tid,logger,Config), + {ok,#{handlers:=Handlers}} = logger_config:get(Tid,logger), + Reply = do_set_config(Tid,logger,Config#{handlers=>Handlers}), {reply,Reply,State}; handle_call({set_config,HandlerId,Config}, From, #state{tid=Tid}=State) -> case logger_config:get(Tid,HandlerId) of @@ -322,8 +318,7 @@ do_set_config(Tid,Id,Config) -> default_config(logger) -> #{level=>info, filters=>[], - filter_default=>log, - handlers=>[]}; + filter_default=>log}; default_config(_) -> #{level=>info, filters=>[], @@ -354,9 +349,6 @@ get_type(Id) -> check_config(Owner,[{level,Level}|Config]) -> check_level(Level), check_config(Owner,Config); -check_config(logger,[{handlers,Handlers}|Config]) -> - check_handlers(Handlers), - check_config(logger,Config); check_config(Owner,[{filters,Filters}|Config]) -> check_filters(Filters), check_config(Owner,Config); @@ -394,14 +386,6 @@ check_level(Level) -> throw({invalid_level,Level}) end. -check_handlers([Id|Handlers]) -> - check_id(Id), - check_handlers(Handlers); -check_handlers([]) -> - ok; -check_handlers(Handlers) -> - throw({invalid_handlers,Handlers}). - check_filters([{Id,{Fun,_Args}}|Filters]) when is_atom(Id), is_function(Fun,2) -> check_filters(Filters); check_filters([Filter|_]) -> diff --git a/lib/kernel/test/logger_SUITE.erl b/lib/kernel/test/logger_SUITE.erl index 9fea92ee0d..1b75d8278e 100644 --- a/lib/kernel/test/logger_SUITE.erl +++ b/lib/kernel/test/logger_SUITE.erl @@ -105,12 +105,12 @@ start_stop(_Config) -> add_remove_handler(_Config) -> register(callback_receiver,self()), - {ok,#{handlers:=Hs0}} = logger:get_logger_config(), + #{handlers:=Hs0} = logger:i(), {error,{not_found,h1}} = logger:get_handler_config(h1), ok = logger:add_handler(h1,?MODULE,#{}), [add] = test_server:messages_get(), - {ok,#{handlers:=Hs}} = logger:get_logger_config(), - [h1|Hs0] = Hs, + #{handlers:=Hs} = logger:i(), + {value,_,Hs0} = lists:keytake(h1,1,Hs), {ok,{?MODULE,#{level:=info,filters:=[],filter_default:=log}}} = % defaults logger:get_handler_config(h1), ok = logger:set_handler_config(h1,filter_default,stop), @@ -124,7 +124,7 @@ add_remove_handler(_Config) -> ok = check_logged(info,"hello",[],?MY_LOC(1)), ok = logger:remove_handler(h1), [remove] = test_server:messages_get(), - {ok,#{handlers:=Hs0}} = logger:get_logger_config(), + #{handlers:=Hs0} = logger:i(), {error,{not_found,h1}} = logger:get_handler_config(h1), {error,{not_found,h1}} = logger:remove_handler(h1), logger:info("hello",[]), @@ -237,13 +237,18 @@ change_config(_Config) -> %% Overwrite logger config - check that defaults are added {ok,LConfig} = logger:get_logger_config(), ok = logger:set_logger_config(#{filter_default=>stop}), - {ok,#{level:=info,filters:=[],handlers:=[],filter_default:=stop}=LC1} = + {ok,#{level:=info,filters:=[],filter_default:=stop}=LC1} = logger:get_logger_config(), - 4 = maps:size(LC1), + 3 = maps:size(LC1), + %% Check that internal 'handlers' field has not been changed + #{handlers:=HCs} = logger:i(), + HIds1 = [Id || {Id,_,_} <- HCs], + {ok,#{handlers:=HIds2}} = logger_config:get(?LOGGER_TABLE,logger), + HIds1 = lists:sort(HIds2), %% Change one key only - ok = logger:set_logger_config(handlers,[h1]), - {ok,#{level:=info,filters:=[],handlers:=[h1],filter_default:=stop}} = + ok = logger:set_logger_config(level,warning), + {ok,#{level:=warning,filters:=[],filter_default:=stop}} = logger:get_logger_config(), %% Cleanup @@ -441,9 +446,7 @@ handler_failed(_Config) -> {error,{invalid_handler,_}} = logger:add_handler(h1,nomodule,#{filter_default=>log}), logger:info(?map_rep), check_no_log(), - #{logger:=#{handlers:=Ids1}, - handlers:=H1} = logger:i(), - false = lists:member(h1,Ids1), + #{handlers:=H1} = logger:i(), false = lists:keymember(h1,1,H1), {error,{not_found,h1}} = logger:remove_handler(h1), @@ -453,10 +456,7 @@ handler_failed(_Config) -> logger:info(?map_rep), [remove] = test_server:messages_get(), - - #{logger:=#{handlers:=Ids2}, - handlers:=H2} = logger:i(), - false = lists:member(h2,Ids2), + #{handlers:=H2} = logger:i(), false = lists:keymember(h2,1,H2), {error,{not_found,h2}} = logger:remove_handler(h2), @@ -511,10 +511,6 @@ config_sanity_check(_Config) -> {error,{invalid_filter_default,bad}} = logger:set_logger_config(filter_default,bad), {error,{invalid_level,bad}} = logger:set_logger_config(level,bad), - {error,{invalid_handlers,bad}} = logger:set_logger_config(handlers,bad), - {error,{invalid_id,{bad,bad}}} = - logger:set_logger_config(handlers,[{bad,bad}]), - {error,{invalid_id,"bad"}} = logger:set_logger_config(handlers,["bad"]), {error,{invalid_filters,bad}} = logger:set_logger_config(filters,bad), {error,{invalid_filter,bad}} = logger:set_logger_config(filters,[bad]), {error,{invalid_filter,{_,_}}} = diff --git a/lib/kernel/test/logger_disk_log_h_SUITE.erl b/lib/kernel/test/logger_disk_log_h_SUITE.erl index cdd1e68947..3aa1c3557b 100644 --- a/lib/kernel/test/logger_disk_log_h_SUITE.erl +++ b/lib/kernel/test/logger_disk_log_h_SUITE.erl @@ -328,7 +328,8 @@ formatter_fail(Config) -> logger:add_handler(Name, logger_disk_log_h, HConfig), Pid = whereis(Name), true = is_pid(Pid), - {ok,#{handlers:=H}} = logger:get_logger_config(), + #{handlers:=HC1} = logger:i(), + H = [Id || {Id,_,_} <- HC1], true = lists:member(Name,H), %% Formatter is added automatically @@ -357,7 +358,8 @@ formatter_fail(Config) -> %% Check that handler is still alive and was never dead Pid = whereis(Name), - {ok,#{handlers:=H}} = logger:get_logger_config(), + #{handlers:=HC2} = logger:i(), + H = [Id || {Id,_,_} <- HC2], ok. formatter_fail(cleanup,_Config) -> diff --git a/lib/kernel/test/logger_std_h_SUITE.erl b/lib/kernel/test/logger_std_h_SUITE.erl index 83bc96620f..fc59d393e0 100644 --- a/lib/kernel/test/logger_std_h_SUITE.erl +++ b/lib/kernel/test/logger_std_h_SUITE.erl @@ -242,7 +242,8 @@ formatter_fail(Config) -> filters=>?DEFAULT_HANDLER_FILTERS([?MODULE])}), Pid = whereis(?MODULE), true = is_pid(Pid), - {ok,#{handlers:=H}} = logger:get_logger_config(), + #{handlers:=HC1} = logger:i(), + H = [Id || {Id,_,_} <- HC1], true = lists:member(?MODULE,H), %% Formatter is added automatically @@ -271,7 +272,8 @@ formatter_fail(Config) -> %% Check that handler is still alive and was never dead Pid = whereis(?MODULE), - {ok,#{handlers:=H}} = logger:get_logger_config(), + #{handlers:=HC2} = logger:i(), + H = [Id || {Id,_,_} <- HC2], ok. -- cgit v1.2.3 From 5d49f8a25005945b7260facc1a985c294746616b Mon Sep 17 00:00:00 2001 From: Siri Hansen Date: Mon, 14 May 2018 20:27:55 +0200 Subject: Add update_logger_config/1 and update_handler_config/2 to logger --- lib/kernel/doc/src/logger.xml | 54 ++++++++++++++++++++++++++++++++-------- lib/kernel/src/logger.erl | 12 +++++++++ lib/kernel/src/logger_server.erl | 15 +++++++---- lib/kernel/test/logger_SUITE.erl | 27 ++++++++++++++------ 4 files changed, 85 insertions(+), 23 deletions(-) (limited to 'lib') diff --git a/lib/kernel/doc/src/logger.xml b/lib/kernel/doc/src/logger.xml index 239b9553b1..183102f240 100644 --- a/lib/kernel/doc/src/logger.xml +++ b/lib/kernel/doc/src/logger.xml @@ -645,11 +645,12 @@ start(_, []) ->

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 + use + update_logger_config/1, or, if a more + complex merge is needed, read the current configuration with get_logger_config/0 - , then merge in your added or updated - associations before writing it back.

+ , then do the merge before writing the new + configuration back with this function.

If a key is removed compared to the current configuration, the default value is used.

@@ -662,7 +663,23 @@ start(_, []) ->

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

+ does not exist, it will be added.

+ + + + + + Update configuration data for the logger. + +

Update configuration data for the logger. This function + behaves as if it was implemented as follows:

+ +{ok,Old} = logger:get_logger_config(), +logger:set_logger_config(maps:merge(Old,Config)). + +

To overwrite the existing configuration without any merge, + use set_logger_config/1 + .

 @@ -673,11 +690,12 @@ start(_, []) ->

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 + use + update_handler_config/2, or, if a more + complex merge is needed, read the current configuration with get_handler_config/1 - , then merge in your added or updated - associations before writing it back.

+ , then do the merge before writing the new + configuration back with this function.

If a key is removed compared to the current configuration, and the key is know by Logger, the default value is used. If it is a custom key, then it is up to the handler @@ -694,11 +712,27 @@ start(_, []) ->

Add or update configuration data for the specified handler. If the given Key already exists, its associated value will be changed - to Value. If it doesn't exist, it will + to Value. If it does not exist, it will be added.

+ + + Update configuration data for the specified handler. + +

Update configuration data for the specified handler. This function + behaves as if it was implemented as follows:

+ +{ok,{_,Old}} = logger:get_handler_config(HandlerId), +logger:set_handler_config(HandlerId,maps:merge(Old,Config)). + +

To overwrite the existing configuration without any merge, + use set_handler_config/2 + .

+ + + Compare the severity of two log levels. diff --git a/lib/kernel/src/logger.erl b/lib/kernel/src/logger.erl index 2c7466fdf6..a839f97e62 100644 --- a/lib/kernel/src/logger.erl +++ b/lib/kernel/src/logger.erl @@ -40,6 +40,7 @@ set_module_level/2, reset_module_level/1, set_logger_config/1, set_logger_config/2, set_handler_config/2, set_handler_config/3, + update_logger_config/1, update_handler_config/2, get_logger_config/0, get_handler_config/1, add_handlers/1]). @@ -361,6 +362,17 @@ set_handler_config(HandlerId,Key,Value) -> set_handler_config(HandlerId,Config) -> logger_server:set_config(HandlerId,Config). +-spec update_logger_config(Config) -> ok | {error,term()} when + Config :: config(). +update_logger_config(Config) -> + logger_server:update_config(logger,Config). + +-spec update_handler_config(HandlerId,Config) -> ok | {error,term()} when + HandlerId :: handler_id(), + Config :: config(). +update_handler_config(HandlerId,Config) -> + logger_server:update_config(HandlerId,Config). + -spec get_logger_config() -> {ok,Config} when Config :: config(). get_logger_config() -> diff --git a/lib/kernel/src/logger_server.erl b/lib/kernel/src/logger_server.erl index bd0c325f2b..275b9c476f 100644 --- a/lib/kernel/src/logger_server.erl +++ b/lib/kernel/src/logger_server.erl @@ -27,7 +27,7 @@ add_filter/2, remove_filter/2, set_module_level/2, reset_module_level/1, cache_module_level/1, - set_config/2, set_config/3]). + set_config/2, set_config/3, update_config/2]). %% gen_server callbacks -export([init/1, handle_call/3, handle_cast/2, handle_info/2, @@ -92,10 +92,7 @@ cache_module_level(Module) -> set_config(Owner,Key,Value) -> - case sanity_check(Owner,Key,Value) of - ok -> call({update_config,Owner,#{Key=>Value}}); - Error -> Error - end. + update_config(Owner,#{Key=>Value}). set_config(Owner,Config0) -> case sanity_check(Owner,Config0) of @@ -106,6 +103,14 @@ set_config(Owner,Config0) -> Error end. +update_config(Owner, Config) -> + case sanity_check(Owner,Config) of + ok -> + call({update_config,Owner,Config}); + Error -> + Error + end. + %%%=================================================================== %%% gen_server callbacks %%%=================================================================== diff --git a/lib/kernel/test/logger_SUITE.erl b/lib/kernel/test/logger_SUITE.erl index 1b75d8278e..64968cbca2 100644 --- a/lib/kernel/test/logger_SUITE.erl +++ b/lib/kernel/test/logger_SUITE.erl @@ -227,15 +227,31 @@ change_config(_Config) -> h1,#{conf_call=>fun() -> logger:set_module_level(?MODULE,debug) end}), {ok,{?MODULE,C2}} = logger:get_handler_config(h1), - %% Change one key only + %% Change handler config: Single key {error,fail} = logger:set_handler_config(h1,conf_call,fun() -> {error,fail} end), ok = logger:set_handler_config(h1,custom,custom), [changing_config] = test_server:messages_get(), {ok,{?MODULE,#{custom:=custom}=C3}} = logger:get_handler_config(h1), C2 = maps:remove(custom,C3), + %% Change handler config: Map + ok = logger:update_handler_config(h1,#{custom=>new_custom}), + [changing_config] = test_server:messages_get(), + {ok,{_,C4}} = logger:get_handler_config(h1), + C4 = C3#{custom:=new_custom}, + + %% Change logger config: Single key + {ok,LConfig0} = logger:get_logger_config(), + ok = logger:set_logger_config(level,warning), + {ok,LConfig1} = logger:get_logger_config(), + LConfig1 = LConfig0#{level:=warning}, + + %% Change logger config: Map + ok = logger:update_logger_config(#{level=>error}), + {ok,LConfig2} = logger:get_logger_config(), + LConfig2 = LConfig1#{level:=error}, + %% Overwrite logger config - check that defaults are added - {ok,LConfig} = logger:get_logger_config(), ok = logger:set_logger_config(#{filter_default=>stop}), {ok,#{level:=info,filters:=[],filter_default:=stop}=LC1} = logger:get_logger_config(), @@ -246,13 +262,8 @@ change_config(_Config) -> {ok,#{handlers:=HIds2}} = logger_config:get(?LOGGER_TABLE,logger), HIds1 = lists:sort(HIds2), - %% Change one key only - ok = logger:set_logger_config(level,warning), - {ok,#{level:=warning,filters:=[],filter_default:=stop}} = - logger:get_logger_config(), - %% Cleanup - ok = logger:set_logger_config(LConfig), + ok = logger:set_logger_config(LConfig0), [] = test_server:messages_get(), ok. -- cgit v1.2.3 From 0afab64f105c09976c7c07a64f54bf962ff9a18f Mon Sep 17 00:00:00 2001 From: Siri Hansen Date: Wed, 16 May 2018 14:12:23 +0200 Subject: Format logger timestamps according to RFC3339 --- lib/kernel/doc/src/logger_formatter.xml | 53 +++++++++--- lib/kernel/src/logger_formatter.erl | 125 +++++++++++++++++++--------- lib/kernel/test/error_logger_warn_SUITE.erl | 14 +++- lib/kernel/test/logger_SUITE.erl | 41 +++++++-- lib/kernel/test/logger_formatter_SUITE.erl | 102 ++++++++++++++--------- lib/sasl/doc/src/sasl_app.xml | 12 +-- 6 files changed, 243 insertions(+), 104 deletions(-) (limited to 'lib') diff --git a/lib/kernel/doc/src/logger_formatter.xml b/lib/kernel/doc/src/logger_formatter.xml index 5f13e54365..370d61d338 100644 --- a/lib/kernel/doc/src/logger_formatter.xml +++ b/lib/kernel/doc/src/logger_formatter.xml @@ -155,11 +155,40 @@ and single_line. See Default Templates for more information

- utc = boolean() + time_designator = byte() -

If set to true, all dates are displayed in Universal - Coordinated Time.

-

Default is false.

+

Timestamps are formatted according to RFC3339, and the time + designator is the character used as date and time + separator.

+

Default is $T.

+

The value of this parameter is used as + the time_designator option + to + calendar:system_time_to_rcf3339/2.

+ + time_offset = integer() | [byte()] + +

The time offset, either a string or an integer, to be + used when formatting the timestamp.

+

An empty string is interpreted as local time. The + values "Z", "z" or 0 are interpreted as + Universal Coordinated Time (UTC).

+

Strings, other than "Z", "z", or "", + must be on the form ±[hh]:[mm], for + example "-02:00" or "+00:00".

+

Integers must be in microseconds, meaning that the + offset 7200000000 is equivalent + to "+02:00".

+

The default value is an empty string, meaning that + timestamps are displayed in local time. However, for + backwards compatibility, if the SASL environment + variable + utc_log=true, the default is + changed to "Z", meaning that timestamps are displayed + in UTC.

+

The value of this parameter is used as the offset + option to + calendar:system_time_to_rcf3339/2.
@@ -174,7 +203,7 @@

The log event used in the examples is:

-?LOG_ERROR("name: ~p~nexit_reason: ~p",[my_reg_name,"It crashed"]) +?LOG_ERROR("name: ~p~nexit_reason: ~p",[my_name,"It crashed"]) legacy_header=true @@ -182,9 +211,9 @@

Default template: [{logger_formatter,header},"\n",msg,"\n"]

Example log entry:

- -=ERROR REPORT==== 29-Dec-2017::13:30:51.245123 === -name: my_reg_name + +2018-05-16T11:55:50.448382+02:00 error: +name: my_name exit_reason: "It crashed"

Notice that all eight levels might occur in the heading, @@ -198,7 +227,7 @@ exit_reason: "It crashed"

Default template: [time," ",level,": ",msg,"\n"]

Example log entry:

- 2017-12-29 13:31:49.640317 error: name: my_reg_name, exit_reason: "It crashed" + 2018-05-16T11:55:50.448382+02:00 error: name: my_name, exit_reason: "It crashed" legacy_header=false, single_line=false @@ -206,9 +235,9 @@ exit_reason: "It crashed"

Default template: [time," ",level,":\n",msg,"\n"]

Example log entry:

- -2017-12-29 13:32:25.191925 error: -name: my_reg_name + +2018-05-16T11:55:50.448382+02:00 error: +name: my_name exit_reason: "It crashed" diff --git a/lib/kernel/src/logger_formatter.erl b/lib/kernel/src/logger_formatter.erl index 0d55244034..602c666cc7 100644 --- a/lib/kernel/src/logger_formatter.erl +++ b/lib/kernel/src/logger_formatter.erl @@ -39,7 +39,8 @@ max_size=>pos_integer() | unlimited, depth=>pos_integer() | unlimited, template=>template(), - utc=>boolean()}. + time_designator=>byte(), + time_offset=>integer()|[byte()]}. format(#{level:=Level,msg:=Msg0,meta:=Meta},Config0) when is_map(Config0) -> Config = add_default_config(Config0), @@ -196,16 +197,12 @@ truncate(String,Size) -> String end. -format_time(Timestamp,Config) when is_integer(Timestamp) -> - {Date,Time,Micro} = timestamp_to_datetimemicro(Timestamp,Config), - format_time(Date,Time,Micro); -format_time(Other,_Config) -> - %% E.g. a string - to_string(Other). - -format_time({Y,M,D},{H,Min,S},Micro) -> - io_lib:format("~4w-~2..0w-~2..0w ~2w:~2..0w:~2..0w.~6..0w", - [Y,M,D,H,Min,S,Micro]). +format_time(Timestamp,#{time_offset:=Offset,time_designator:=Des}) + when is_integer(Timestamp) -> + SysTime = Timestamp + erlang:time_offset(microsecond), + calendar:system_time_to_rfc3339(SysTime,[{unit,microsecond}, + {offset,Offset}, + {time_designator,Des}]). %% Assuming this is monotonic time in microseconds timestamp_to_datetimemicro(Timestamp,Config) when is_integer(Timestamp) -> @@ -213,12 +210,12 @@ timestamp_to_datetimemicro(Timestamp,Config) when is_integer(Timestamp) -> Micro = SysTime rem 1000000, Sec = SysTime div 1000000, UniversalTime = erlang:posixtime_to_universaltime(Sec), - {Date,Time} = - case Config of - #{utc:=true} -> UniversalTime; - _ -> erlang:universaltime_to_localtime(UniversalTime) + {{Date,Time},UtcStr} = + case offset_to_utc(maps:get(time_offset,Config)) of + true -> {UniversalTime,"UTC "}; + _ -> {erlang:universaltime_to_localtime(UniversalTime),""} end, - {Date,Time,Micro}. + {Date,Time,Micro,UtcStr}. format_mfa({M,F,A}) when is_atom(M), is_atom(F), is_integer(A) -> atom_to_list(M)++":"++atom_to_list(F)++"/"++integer_to_list(A); @@ -231,9 +228,11 @@ maybe_add_legacy_header(Level, #{time:=Timestamp}=Meta, #{legacy_header:=true}=Config) -> #{title:=Title}=MyMeta = add_legacy_title(Level,maps:get(?MODULE,Meta,#{})), - {{Y,Mo,D},{H,Mi,S},Micro} = timestamp_to_datetimemicro(Timestamp,Config), - Header = io_lib:format("=~ts==== ~w-~s-~4w::~2..0w:~2..0w:~2..0w.~6..0w ~s===", - [Title,D,month(Mo),Y,H,Mi,S,Micro,utcstr(Config)]), + {{Y,Mo,D},{H,Mi,S},Micro,UtcStr} = + timestamp_to_datetimemicro(Timestamp,Config), + Header = + io_lib:format("=~ts==== ~w-~s-~4w::~2..0w:~2..0w:~2..0w.~6..0w ~s===", + [Title,D,month(Mo),Y,H,Mi,S,Micro,UtcStr]), Meta#{?MODULE=>MyMeta#{header=>Header}}; maybe_add_legacy_header(_,Meta,_) -> Meta. @@ -257,20 +256,20 @@ month(10) -> "Oct"; month(11) -> "Nov"; month(12) -> "Dec". -utcstr(#{utc:=true}) -> "UTC "; -utcstr(_) -> "". - +%% Ensure that all valid configuration parameters exist in the final +%% configuration map add_default_config(Config0) -> Default = #{legacy_header=>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)), - Utc = get_utc(maps:get(utc,Config0,false)), + chars_limit=>unlimited, + time_designator=>$T}, + MaxSize = get_max_size(maps:get(max_size,Config0,undefined)), + Depth = get_depth(maps:get(depth,Config0,undefined)), + Offset = get_offset(maps:get(time_offset,Config0,undefined)), add_default_template(maps:merge(Default,Config0#{max_size=>MaxSize, depth=>Depth, - utc=>Utc})). + time_offset=>Offset})). add_default_template(#{template:=_}=Config) -> Config; @@ -284,33 +283,50 @@ default_template(#{single_line:=true}) -> default_template(_) -> ?DEFAULT_FORMAT_TEMPLATE. -get_max_size(false) -> +get_max_size(undefined) -> unlimited; get_max_size(S) -> max(10,S). -get_depth(false) -> +get_depth(undefined) -> error_logger:get_format_depth(); get_depth(S) -> max(5,S). -get_utc(false) -> - get_utc_config(); -get_utc(U) -> - U. +get_offset(undefined) -> + utc_to_offset(get_utc_config()); +get_offset(Offset) -> + Offset. + +utc_to_offset(true) -> + "Z"; +utc_to_offset(false) -> + "". get_utc_config() -> %% SASL utc_log overrides stdlib config - in order to have uniform %% timestamps in log messages case application:get_env(sasl, utc_log) of - {ok, Val} -> Val; - undefined -> + {ok, Val} when is_boolean(Val) -> Val; + _ -> case application:get_env(stdlib, utc_log) of - {ok, Val} -> Val; - undefined -> false + {ok, Val} when is_boolean(Val) -> Val; + _ -> false end end. +offset_to_utc(Z) when Z=:=0; Z=:="z"; Z=:="Z" -> + true; +offset_to_utc([$+|Tz]) -> + case io_lib:fread("~d:~d", Tz) of + {ok, [0, 0], []} -> + true; + _ -> + false + end; +offset_to_utc(_) -> + false. + check_config(Config) when is_map(Config) -> do_check_config(maps:to_list(Config)); check_config(Config) -> @@ -341,8 +357,20 @@ do_check_config([{template,T}|Config]) when is_list(T) -> false -> {error,{invalid_formatter_template,?MODULE,T}} end; -do_check_config([{utc,Utc}|Config]) when is_boolean(Utc) -> - do_check_config(Config); +do_check_config([{time_offset,Offset}|Config]) -> + case check_offset(Offset) of + ok -> + do_check_config(Config); + error -> + {error,{invalid_formatter_config,?MODULE,{time_offset,Offset}}} + end; +do_check_config([{time_designator,Char}|Config]) when Char>=0, Char=<255 -> + case io_lib:printable_latin1_list([Char]) of + true -> + do_check_config(Config); + false -> + {error,{invalid_formatter_config,?MODULE,{time_designator,Char}}} + end; do_check_config([C|_]) -> {error,{invalid_formatter_config,?MODULE,C}}; do_check_config([]) -> @@ -354,3 +382,22 @@ check_limit(unlimited) -> ok; check_limit(_) -> error. + +check_offset(I) when is_integer(I) -> + ok; +check_offset(Tz) when Tz=:=""; Tz=:="Z"; Tz=:="z" -> + ok; +check_offset([Sign|Tz]) when Sign=:=$+; Sign=:=$- -> + check_timezone(Tz); +check_offset(_) -> + error. + +check_timezone(Tz) -> + try io_lib:fread("~d:~d", Tz) of + {ok, [_, _], []} -> + ok; + _ -> + error + catch _:_ -> + error + end. diff --git a/lib/kernel/test/error_logger_warn_SUITE.erl b/lib/kernel/test/error_logger_warn_SUITE.erl index a8087e11f9..ef55a2d339 100644 --- a/lib/kernel/test/error_logger_warn_SUITE.erl +++ b/lib/kernel/test/error_logger_warn_SUITE.erl @@ -480,9 +480,12 @@ rb_utc() -> UtcLog=case application:get_env(sasl,utc_log) of {ok,true} -> true; - _AllOthers -> + {ok,false} -> application:set_env(sasl,utc_log,true), - false + false; + undefined -> + application:set_env(sasl,utc_log,true), + undefined end, application:start(sasl), rb:start([{report_dir, rd()}]), @@ -494,7 +497,12 @@ rb_utc() -> Sum=one_rb_findstr([],"UTC"), rb:stop(), application:stop(sasl), - application:set_env(sasl,utc_log,UtcLog), + case UtcLog of + undefined -> + application:unset_env(sasl,utc_log); + _ -> + application:set_env(sasl,utc_log,UtcLog) + end, stop_node(Node), ok. diff --git a/lib/kernel/test/logger_SUITE.erl b/lib/kernel/test/logger_SUITE.erl index 64968cbca2..e602fa2576 100644 --- a/lib/kernel/test/logger_SUITE.erl +++ b/lib/kernel/test/logger_SUITE.erl @@ -580,11 +580,6 @@ config_sanity_check(_Config) -> #{report_cb=>fun(R) -> {"~p",[R]} end}}), - {error,{invalid_formatter_config,logger_formatter,{utc,bad}}} = - logger:set_handler_config(h1,formatter,{logger_formatter, - #{utc=>bad}}), - ok = logger:set_handler_config(h1,formatter,{logger_formatter, - #{utc=>true}}), {error,{invalid_formatter_config,logger_formatter,{chars_limit,bad}}} = logger:set_handler_config(h1,formatter,{logger_formatter, #{chars_limit=>bad}}), @@ -610,6 +605,42 @@ config_sanity_check(_Config) -> {error,{callback_crashed,{error,{badmatch,3},[{?MODULE,check_config,1,_}]}}} = logger:set_handler_config(h1,formatter,{?MODULE,crash}), ok = logger:set_handler_config(h1,custom,custom), + + %% Old utc parameter is no longer allowed (replaced by time_offset) + {error,{invalid_formatter_config,logger_formatter,{utc,true}}} = + logger:set_handler_config(h1,formatter,{logger_formatter, + #{utc=>true}}), + {error,{invalid_formatter_config,logger_formatter,{time_offset,bad}}} = + logger:set_handler_config(h1,formatter,{logger_formatter, + #{time_offset=>bad}}), + ok = logger:set_handler_config(h1,formatter,{logger_formatter, + #{time_offset=>0}}), + ok = logger:set_handler_config(h1,formatter,{logger_formatter, + #{time_offset=>""}}), + ok = logger:set_handler_config(h1,formatter,{logger_formatter, + #{time_offset=>"Z"}}), + ok = logger:set_handler_config(h1,formatter,{logger_formatter, + #{time_offset=>"z"}}), + ok = logger:set_handler_config(h1,formatter,{logger_formatter, + #{time_offset=>"-0:0"}}), + ok = logger:set_handler_config(h1,formatter,{logger_formatter, + #{time_offset=>"+10:13"}}), + + {error,{invalid_formatter_config,logger_formatter,{time_offset,"+0"}}} = + logger:set_handler_config(h1,formatter,{logger_formatter, + #{time_offset=>"+0"}}), + + {error,{invalid_formatter_config,logger_formatter,{time_designator,bad}}} = + logger:set_handler_config(h1,formatter,{logger_formatter, + #{time_designator=>bad}}), + {error,{invalid_formatter_config,logger_formatter,{time_designator,"s"}}} = + logger:set_handler_config(h1,formatter,{logger_formatter, + #{time_designator=>"s"}}), + {error,{invalid_formatter_config,logger_formatter,{time_designator,0}}} = + logger:set_handler_config(h1,formatter,{logger_formatter, + #{time_designator=>0}}), + ok = logger:set_handler_config(h1,formatter,{logger_formatter, + #{time_designator=>$\s}}), ok. config_sanity_check(cleanup,_Config) -> diff --git a/lib/kernel/test/logger_formatter_SUITE.erl b/lib/kernel/test/logger_formatter_SUITE.erl index bd5bc2d2e4..9baadfd65a 100644 --- a/lib/kernel/test/logger_formatter_SUITE.erl +++ b/lib/kernel/test/logger_formatter_SUITE.erl @@ -73,7 +73,7 @@ all() -> default(_Config) -> String1 = format(info,{"~p",[term]},#{},#{}), ct:log(String1), - [_Date,_Time,"info:","term\n"] = string:lexemes(String1," "), + [_DateTime,"info:","term\n"] = string:lexemes(String1," "), Time = timestamp(), ExpectedTimestamp = default_time_format(Time), @@ -364,7 +364,7 @@ chars_limit(_Config) -> lists:seq(1,100), maps:from_list(lists:zip(lists:seq(1,100), lists:duplicate(100,value)))]}, - Meta = #{time=>"2018-04-26 9:15:40.449879"}, + Meta = #{time=>timestamp()}, Template = [time," - ", msg, "\n"], FC = #{template=>Template, depth=>unlimited, @@ -376,7 +376,7 @@ chars_limit(_Config) -> L1 = string:length(String1), ct:log("String1: ~p~nLength1: ~p~n",[lists:flatten(String1),L1]), true = L1 > CL1, - true = L1 < CL1 + 10, + true = L1 < CL1 + 15, String2 = format(info,FA,Meta,FC#{chars_limit=>CL1,depth=>10}), L2 = string:length(String2), @@ -388,13 +388,13 @@ chars_limit(_Config) -> L3 = string:length(String3), ct:log("String3: ~p~nLength3: ~p~n",[lists:flatten(String3),L3]), true = L3 > CL3, - true = L3 < CL3 + 10, + true = L3 < CL3 + 15, String4 = format(info,FA,Meta,FC#{chars_limit=>CL3,depth=>10}), L4 = string:length(String4), ct:log("String4: ~p~nLength4: ~p~n",[lists:flatten(String4),L4]), true = L4 > CL3, - true = L4 < CL3 + 10, + true = L4 < CL3 + 15, %% Test that max_size truncates the string which is limited by %% depth and chars_limit @@ -433,29 +433,58 @@ format_mfa(_Config) -> ok. format_time(_Config) -> - Time1 = timestamp(), - ExpectedTimestamp1 = default_time_format(Time1), - String1 = format(info,{"~p",[term]},#{time=>Time1},#{}), - ct:log(String1), - " 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: 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: term\n" = string:prefix(String3,ExpectedTimestamp3), + Time = timestamp(), + Meta = #{time=>Time}, + FC = #{template=>[time]}, + Msg = {string,""}, + ExpectedLocal = default_time_format(Time,false), + ExpectedUtc = default_time_format(Time,true), + + %% default - local time + ExpectedLocal = format(info,Msg,Meta,FC), + + %% time_offset config parameter to formatter + ExpectedLocal = format(info,Msg,Meta,FC#{time_offset=>""}), + ExpectedUtc = format(info,Msg,Meta,FC#{time_offset=>"Z"}), + + %% stdlib utc_log works when time_offset parameter is not set + application:set_env(stdlib,utc_log,true), + ExpectedUtc = format(info,Msg,Meta,FC), + + %% sasl utc_log overwrites stdlib utc_log + application:set_env(sasl,utc_log,false), + ExpectedLocal = format(info,Msg,Meta,FC), + + %% sasl utc_log overwrites stdlib utc_log + application:set_env(sasl,utc_log,true), + application:set_env(stdlib,utc_log,false), + ExpectedUtc = format(info,Msg,Meta,FC), + + %% time_offset config parameter to formatter + %% overwrites sasl and stdlib utc_log + application:set_env(sasl,utc_log,false), + ExpectedUtc = format(info,Msg,Meta,FC#{time_offset=>"Z"}), + + %% time_offset config parameter to formatter + %% overwrites sasl and stdlib utc_log + application:set_env(sasl,utc_log,true), + application:set_env(stdlib,utc_log,true), + ExpectedLocal = format(info,Msg,Meta,FC#{time_offset=>""}), + + %% time_designator config parameter to formatter + ExpectedLocalS = default_time_format(Time,false,$\s), + ExpectedUtcS = default_time_format(Time,true,$\s), + + ExpectedLocalS = format(info,Msg,Meta,FC#{time_offset=>"", + time_designator=>$\s}), + ExpectedUtcS = format(info,Msg,Meta,FC#{time_offset=>"Z", + time_designator=>$\s}), ok. format_time(cleanup,_Config) -> - application:unset_env(kernel,logger_utc), + application:unset_env(sasl,utc_log), + application:unset_env(stdlib,utc_log), ok. level_or_msg_in_meta(_Config) -> @@ -514,22 +543,17 @@ format(Log,Config) -> default_time_format(Timestamp) -> default_time_format(Timestamp,false). -default_time_format(Timestamp0,Utc) when is_integer(Timestamp0) -> +default_time_format(Timestamp,Utc) -> + default_time_format(Timestamp,Utc,$T). + +default_time_format(Timestamp0,Utc,Sep) -> Timestamp=Timestamp0+erlang:time_offset(microsecond), - %% calendar:system_time_to_rfc3339(Time,[{unit,microsecond}]). - Micro = Timestamp rem 1000000, - Sec = Timestamp div 1000000, - UniversalTime = erlang:posixtime_to_universaltime(Sec), - {Date,Time} = - if Utc -> UniversalTime; - true -> erlang:universaltime_to_localtime(UniversalTime) - end, - default_time_format(Date,Time,Micro). - -default_time_format({Y,M,D},{H,Min,S},Micro) -> - lists:flatten( - io_lib:format("~4w-~2..0w-~2..0w ~2w:~2..0w:~2..0w.~6..0w", - [Y,M,D,H,Min,S,Micro])). + Offset = if Utc -> "Z"; + true -> "" + end, + calendar:system_time_to_rfc3339(Timestamp,[{unit,microsecond}, + {time_designator,Sep}, + {offset,Offset}]). integer(Str) -> is_integer(list_to_integer(Str)). diff --git a/lib/sasl/doc/src/sasl_app.xml b/lib/sasl/doc/src/sasl_app.xml index 8f92a22cf7..26b9bece2a 100644 --- a/lib/sasl/doc/src/sasl_app.xml +++ b/lib/sasl/doc/src/sasl_app.xml @@ -86,12 +86,6 @@ RELDIR is used. By default, this is $OTP_ROOT/releases.

- - -

If set to true, all dates in textual log outputs are - displayed in Universal Coordinated Time with the string - UTC appended.

-
@@ -175,6 +169,12 @@ sasl_error_logger to error reports or progress reports, or both. Default is all.

 + + +

If set to true, all dates in textual log outputs are + displayed in Universal Coordinated Time with the string + UTC appended.

+

The error logger event handler log_mf_h can also still -- cgit v1.2.3 From 4e9f0492fd46d1ba6d919883cbdd5caaff8a949b Mon Sep 17 00:00:00 2001 From: Siri Hansen Date: Wed, 16 May 2018 14:58:03 +0200 Subject: Add Action=differs to logger_filters:domain/2 --- lib/kernel/doc/src/logger_filters.xml | 4 ++++ lib/kernel/src/logger_filters.erl | 6 +++++- lib/kernel/test/logger_filters_SUITE.erl | 25 +++++++++++++++++++------ 3 files changed, 28 insertions(+), 7 deletions(-) (limited to 'lib') diff --git a/lib/kernel/doc/src/logger_filters.xml b/lib/kernel/doc/src/logger_filters.xml index c34ec7d14c..1bbae8be21 100644 --- a/lib/kernel/doc/src/logger_filters.xml +++ b/lib/kernel/doc/src/logger_filters.xml @@ -78,6 +78,10 @@ Compare = equals

The filter matches if Domain is equal to MatchDomain.

 + Compare = differs +

The filter matches if Domain differs + from MatchDomain, or if there is no domain field + in metadata.

 Compare = no_domain

The filter matches if there is no domain field in metadata. In this case MatchDomain shall diff --git a/lib/kernel/src/logger_filters.erl b/lib/kernel/src/logger_filters.erl index 85928f0fd6..592ff28cc2 100644 --- a/lib/kernel/src/logger_filters.erl +++ b/lib/kernel/src/logger_filters.erl @@ -38,6 +38,7 @@ domain(#{meta:=Meta}=Log,{Action,Compare,MatchDomain}) (Compare==prefix_of orelse Compare==starts_with orelse Compare==equals orelse + Compare==differs orelse Compare==no_domain) andalso is_list(MatchDomain) -> filter_domain(Compare,Meta,MatchDomain,on_match(Action,Log)); @@ -87,9 +88,12 @@ filter_domain(starts_with,#{domain:=Domain},MatchDomain,OnMatch) -> is_prefix(MatchDomain,Domain,OnMatch); filter_domain(equals,#{domain:=Domain},Domain,OnMatch) -> OnMatch; +filter_domain(differs,#{domain:=Domain},MatchDomain,OnMatch) + when Domain=/=MatchDomain -> + OnMatch; filter_domain(Action,Meta,_,OnMatch) -> case maps:is_key(domain,Meta) of - false when Action==no_domain -> OnMatch; + false when Action==no_domain; Action==differs -> OnMatch; _ -> ignore end. diff --git a/lib/kernel/test/logger_filters_SUITE.erl b/lib/kernel/test/logger_filters_SUITE.erl index 21f14bbc02..c4b31370ff 100644 --- a/lib/kernel/test/logger_filters_SUITE.erl +++ b/lib/kernel/test/logger_filters_SUITE.erl @@ -81,6 +81,8 @@ domain(_Config) -> stop = logger_filters:domain(?dlog([]),{stop,starts_with,[]}), L3 = logger_filters:domain(L3=?dlog([]),{log,equals,[]}), stop = logger_filters:domain(?dlog([]),{stop,equals,[]}), + ignore = logger_filters:domain(?dlog([]),{log,differs,[]}), + ignore = logger_filters:domain(?dlog([]),{stop,differs,[]}), ignore = logger_filters:domain(?dlog([]),{log,no_domain,[]}), ignore = logger_filters:domain(?dlog([]),{stop,no_domain,[]}), @@ -90,15 +92,19 @@ domain(_Config) -> ignore = logger_filters:domain(?dlog([a]),{stop,starts_with,[a,b]}), ignore = logger_filters:domain(?dlog([a]),{log,equals,[a,b]}), ignore = logger_filters:domain(?dlog([a]),{stop,equals,[a,b]}), + L5 = logger_filters:domain(L5=?dlog([a]),{log,differs,[a,b]}), + stop = logger_filters:domain(?dlog([a]),{stop,differs,[a,b]}), ignore = logger_filters:domain(?dlog([a]),{log,no_domain,[a,b]}), ignore = logger_filters:domain(?dlog([a]),{stop,no_domain,[a,b]}), ignore = logger_filters:domain(?dlog([a,b]),{log,prefix_of,[a]}), ignore = logger_filters:domain(?dlog([a,b]),{stop,prefix_of,[a]}), - L5 = logger_filters:domain(L5=?dlog([a,b]),{log,starts_with,[a]}), + L6 = logger_filters:domain(L6=?dlog([a,b]),{log,starts_with,[a]}), stop = logger_filters:domain(?dlog([a,b]),{stop,starts_with,[a]}), ignore = logger_filters:domain(?dlog([a,b]),{log,equals,[a]}), ignore = logger_filters:domain(?dlog([a,b]),{stop,equals,[a]}), + L7 = logger_filters:domain(L7=?dlog([a,b]),{log,differs,[a]}), + stop = logger_filters:domain(?dlog([a,b]),{stop,differs,[a]}), ignore = logger_filters:domain(?dlog([a,b]),{log,no_domain,[a]}), ignore = logger_filters:domain(?dlog([a,b]),{stop,no_domain,[a]}), @@ -108,26 +114,33 @@ domain(_Config) -> ignore = logger_filters:domain(?ndlog,{stop,starts_with,[a]}), ignore = logger_filters:domain(?ndlog,{log,equals,[a]}), ignore = logger_filters:domain(?ndlog,{stop,equals,[a]}), - L6 = logger_filters:domain(L6=?ndlog,{log,no_domain,[a]}), + L8 = logger_filters:domain(L8=?ndlog,{log,differs,[a]}), + stop = logger_filters:domain(?ndlog,{stop,differs,[a]}), + L9 = logger_filters:domain(L9=?ndlog,{log,no_domain,[a]}), stop = logger_filters:domain(?ndlog,{stop,no_domain,[a]}), - L7 = logger_filters:domain(L7=?dlog([a,b,c,d]),{log,prefix_of,[a,b,c,d]}), + L10 = logger_filters:domain(L10=?dlog([a,b,c,d]),{log,prefix_of,[a,b,c,d]}), stop = logger_filters:domain(?dlog([a,b,c,d]),{stop,prefix_of,[a,b,c,d]}), - L8 = logger_filters:domain(L8=?dlog([a,b,c,d]),{log,starts_with,[a,b,c,d]}), + L11 = logger_filters:domain(L11=?dlog([a,b,c,d]),{log,starts_with,[a,b,c,d]}), stop = logger_filters:domain(?dlog([a,b,c,d]),{stop,starts_with,[a,b,c,d]}), - L9 = logger_filters:domain(L9=?dlog([a,b,c,d]),{log,equals,[a,b,c,d]}), + L12 = logger_filters:domain(L12=?dlog([a,b,c,d]),{log,equals,[a,b,c,d]}), stop = logger_filters:domain(?dlog([a,b,c,d]),{stop,equals,[a,b,c,d]}), + ignore = logger_filters:domain(?dlog([a,b,c,d]),{log,differs,[a,b,c,d]}), + ignore = logger_filters:domain(?dlog([a,b,c,d]),{stop,differs,[a,b,c,d]}), ignore = logger_filters:domain(?dlog([a,b,c,d]),{log,no_domain,[a,b,c,d]}), ignore = logger_filters:domain(?dlog([a,b,c,d]),{stop,no_domain,[a,b,c,d]}), %% A domain field in meta which is not a list is allowed by the - %% filter, but it will never match. + %% filter, but since MatchDomain is always a list of atoms, only + %% Action=differs can ever match. ignore = logger_filters:domain(?dlog(dummy),{log,prefix_of,[a,b,c,d]}), ignore = logger_filters:domain(?dlog(dummy),{stop,prefix_of,[a,b,c,d]}), ignore = logger_filters:domain(?dlog(dummy),{log,starts_with,[a,b,c,d]}), ignore = logger_filters:domain(?dlog(dummy),{stop,starts_with,[a,b,c,d]}), ignore = logger_filters:domain(?dlog(dummy),{log,equals,[a,b,c,d]}), ignore = logger_filters:domain(?dlog(dummy),{stop,equals,[a,b,c,d]}), + L13 = logger_filters:domain(L13=?dlog(dummy),{log,differs,[a,b,c,d]}), + stop = logger_filters:domain(?dlog(dummy),{stop,differs,[a,b,c,d]}), ignore = logger_filters:domain(?dlog(dummy),{log,no_domain,[a,b,c,d]}), ignore = logger_filters:domain(?dlog(dummy),{stop,no_domain,[a,b,c,d]}), -- cgit v1.2.3