From c026109009942d7a877242f161860cc824223cf1 Mon Sep 17 00:00:00 2001 From: Siri Hansen Date: Thu, 7 Jun 2018 16:23:19 +0200 Subject: [logger] Change default primary log level to 'notice' Log events issued via error_logger:info_msg or error_logger:info_report are now forwarded to Logger with level 'notice' instead of 'info'. Log events issued by gen_* behaviours are also changed from level 'info' to level 'notice'. Progress reports are still 'info', and can therefore easily be included/excluded by changing the primary log level. By default, they are not logged. --- lib/kernel/src/application_controller.erl | 14 +-- lib/kernel/src/error_logger.erl | 6 +- lib/kernel/src/kernel.app.src | 5 +- lib/kernel/src/logger.erl | 17 +-- lib/kernel/src/logger_formatter.erl | 26 ++++- lib/kernel/src/logger_server.erl | 2 +- lib/kernel/test/logger_SUITE.erl | 154 ++++++++++++++-------------- lib/kernel/test/logger_disk_log_h_SUITE.erl | 91 ++++++++-------- lib/kernel/test/logger_env_var_SUITE.erl | 121 +++++++++++----------- lib/kernel/test/logger_formatter_SUITE.erl | 62 +++++++++-- lib/kernel/test/logger_legacy_SUITE.erl | 13 ++- lib/kernel/test/logger_simple_h_SUITE.erl | 16 +-- lib/kernel/test/logger_std_h_SUITE.erl | 74 ++++++------- lib/sasl/src/sasl.erl | 12 +++ 14 files changed, 342 insertions(+), 271 deletions(-) diff --git a/lib/kernel/src/application_controller.erl b/lib/kernel/src/application_controller.erl index d5a632ef6f..36479f4be6 100644 --- a/lib/kernel/src/application_controller.erl +++ b/lib/kernel/src/application_controller.erl @@ -1920,13 +1920,13 @@ info_started(Name, Node) -> error_logger=>#{tag=>info_report,type=>progress}}). info_exited(Name, Reason, Type) -> - ?LOG_INFO(#{label=>{application_controller,exit}, - report=>[{application, Name}, - {exited, Reason}, - {type, Type}]}, - #{domain=>[otp], - report_cb=>fun logger:format_otp_report/1, - error_logger=>#{tag=>info_report,type=>std_info}}). + ?LOG_NOTICE(#{label=>{application_controller,exit}, + report=>[{application, Name}, + {exited, Reason}, + {type, Type}]}, + #{domain=>[otp], + report_cb=>fun logger:format_otp_report/1, + error_logger=>#{tag=>info_report,type=>std_info}}). %%----------------------------------------------------------------- %% Reply to all processes waiting this application to be started. diff --git a/lib/kernel/src/error_logger.erl b/lib/kernel/src/error_logger.erl index ef930317b1..a0bf87796b 100644 --- a/lib/kernel/src/error_logger.erl +++ b/lib/kernel/src/error_logger.erl @@ -317,7 +317,7 @@ info_report(Report) -> Report :: report(). info_report(Type, Report) -> - logger:log(info, + logger:log(notice, #{label=>{?MODULE,info_report}, report=>Report}, meta(info_report,Type)). @@ -338,7 +338,7 @@ info_msg(Format) -> Data :: list(). info_msg(Format, Args) -> - logger:log(info, + logger:log(notice, #{label=>{?MODULE,info_msg}, format=>Format, args=>Args}, @@ -358,7 +358,7 @@ error_info(Error) -> false -> {"~p",[Error]} end, MyMeta = #{tag=>info,type=>Error}, - logger:log(info, Format, Args, #{?MODULE=>MyMeta,domain=>[Error]}). + logger:log(notice, Format, Args, #{?MODULE=>MyMeta,domain=>[Error]}). %%----------------------------------------------------------------- %% Create metadata diff --git a/lib/kernel/src/kernel.app.src b/lib/kernel/src/kernel.app.src index d873178f55..390f1fa42a 100644 --- a/lib/kernel/src/kernel.app.src +++ b/lib/kernel/src/kernel.app.src @@ -140,9 +140,8 @@ inet_db, pg2]}, {applications, []}, - {env, [{logger_level, info}, - {logger_sasl_compatible, false}, - {logger_progress_reports, stop} + {env, [{logger_level, notice}, + {logger_sasl_compatible, false} ]}, {mod, {kernel, []}}, {runtime_dependencies, ["erts-10.0", "stdlib-3.5", "sasl-3.0"]} diff --git a/lib/kernel/src/logger.erl b/lib/kernel/src/logger.erl index f6dc8ea397..e0832bf31c 100644 --- a/lib/kernel/src/logger.erl +++ b/lib/kernel/src/logger.erl @@ -710,15 +710,7 @@ get_default_handler_filters() -> true -> ?DEFAULT_HANDLER_FILTERS([otp]); false -> - Extra = - case application:get_env(kernel, logger_progress_reports, stop) of - log -> - []; - stop -> - [{stop_progress, - {fun logger_filters:progress/2,stop}}] - end, - Extra ++ ?DEFAULT_HANDLER_FILTERS([otp,sasl]) + ?DEFAULT_HANDLER_FILTERS([otp,sasl]) end. get_logger_env() -> @@ -726,17 +718,14 @@ get_logger_env() -> %%%----------------------------------------------------------------- %%% Internal -do_log(Level,Msg,Meta) -> - do_log_1(Level,Msg,Meta). - -do_log_1(Level,Msg,#{mfa:={Module,_,_}}=Meta) -> +do_log(Level,Msg,#{mfa:={Module,_,_}}=Meta) -> case logger_config:allow(?LOGGER_TABLE,Level,Module) of true -> log_allowed(#{},Level,Msg,Meta); false -> ok end; -do_log_1(Level,Msg,Meta) -> +do_log(Level,Msg,Meta) -> case logger_config:allow(?LOGGER_TABLE,Level) of true -> log_allowed(#{},Level,Msg,Meta); diff --git a/lib/kernel/src/logger_formatter.erl b/lib/kernel/src/logger_formatter.erl index 6eeac994ea..4ebd88ac2d 100644 --- a/lib/kernel/src/logger_formatter.erl +++ b/lib/kernel/src/logger_formatter.erl @@ -234,7 +234,7 @@ format_mfa(MFA) -> maybe_add_legacy_header(Level, #{time:=Timestamp}=Meta, #{legacy_header:=true}=Config) -> - #{title:=Title}=MyMeta = add_legacy_title(Level,maps:get(?MODULE,Meta,#{})), + #{title:=Title}=MyMeta = add_legacy_title(Level,Meta,Config), {{Y,Mo,D},{H,Mi,S},Micro,UtcStr} = timestamp_to_datetimemicro(Timestamp,Config), Header = @@ -244,11 +244,23 @@ maybe_add_legacy_header(Level, maybe_add_legacy_header(_,Meta,_) -> Meta. -add_legacy_title(_Level,#{title:=_}=MyMeta) -> +add_legacy_title(_Level,#{?MODULE:=#{title:=_}=MyMeta},_) -> MyMeta; -add_legacy_title(Level,MyMeta) -> - Title = string:uppercase(atom_to_list(Level)) ++ " REPORT", - MyMeta#{title=>Title}. +add_legacy_title(Level,Meta,Config) -> + case maps:get(?MODULE,Meta,#{}) of + #{title:=_}=MyMeta -> + MyMeta; + MyMeta -> + TitleLevel = + case (Level=:=notice andalso maps:find(error_logger,Meta)) of + {ok,_} -> + maps:get(error_logger_notice_header,Config); + _ -> + Level + end, + Title = string:uppercase(atom_to_list(TitleLevel)) ++ " REPORT", + MyMeta#{title=>Title} + end. month(1) -> "Jan"; month(2) -> "Feb"; @@ -268,6 +280,7 @@ month(12) -> "Dec". add_default_config(Config0) -> Default = #{legacy_header=>false, + error_logger_notice_header=>info, single_line=>true, chars_limit=>unlimited, time_designator=>$T}, @@ -352,6 +365,9 @@ 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([{error_logger_notice_header,ELNH}|Config]) when ELNH == info; + ELNH == notice -> + 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]) -> diff --git a/lib/kernel/src/logger_server.erl b/lib/kernel/src/logger_server.erl index 6d4ab0925d..5da8f71420 100644 --- a/lib/kernel/src/logger_server.erl +++ b/lib/kernel/src/logger_server.erl @@ -357,7 +357,7 @@ do_set_config(Tid,Id,Config) -> ok. default_config(primary) -> - #{level=>info, + #{level=>notice, filters=>[], filter_default=>log}; default_config(Id) -> diff --git a/lib/kernel/test/logger_SUITE.erl b/lib/kernel/test/logger_SUITE.erl index da3345524a..f837c31e64 100644 --- a/lib/kernel/test/logger_SUITE.erl +++ b/lib/kernel/test/logger_SUITE.erl @@ -116,19 +116,19 @@ add_remove_handler(_Config) -> logger:get_handler_config(h1), ok = logger:set_handler_config(h1,filter_default,stop), [changing_config] = test_server:messages_get(), - ?LOG_INFO("hello",[]), + ?LOG_NOTICE("hello",[]), ok = check_no_log(), ok = logger:set_handler_config(h1,filter_default,log), [changing_config] = test_server:messages_get(), {ok,#{filter_default:=log}} = logger:get_handler_config(h1), - ?LOG_INFO("hello",[]), - ok = check_logged(info,"hello",[],?MY_LOC(1)), + ?LOG_NOTICE("hello",[]), + ok = check_logged(notice,"hello",[],?MY_LOC(1)), ok = logger:remove_handler(h1), [remove] = test_server:messages_get(), Hs0 = logger:get_handler_config(), {error,{not_found,h1}} = logger:get_handler_config(h1), {error,{not_found,h1}} = logger:remove_handler(h1), - logger:info("hello",[]), + logger:notice("hello",[]), ok = check_no_log(), ok. @@ -137,13 +137,13 @@ add_remove_handler(cleanup,_Config) -> ok. multiple_handlers(_Config) -> - ok = logger:add_handler(h1,?MODULE,#{level=>info,filter_default=>log}), + ok = logger:add_handler(h1,?MODULE,#{level=>notice,filter_default=>log}), ok = logger:add_handler(h2,?MODULE,#{level=>error,filter_default=>log}), ?LOG_ERROR("hello",[]), ok = check_logged(error,"hello",[],?MY_LOC(1)), ok = check_logged(error,"hello",[],?MY_LOC(2)), - ?LOG_INFO("hello",[]), - ok = check_logged(info,"hello",[],?MY_LOC(1)), + ?LOG_NOTICE("hello",[]), + ok = check_logged(notice,"hello",[],?MY_LOC(1)), ok = check_no_log(), ok. @@ -153,18 +153,18 @@ multiple_handlers(cleanup,_Config) -> ok. add_remove_filter(_Config) -> - ok = logger:add_handler(h1,?MODULE,#{level=>info,filter_default=>log}), + ok = logger:add_handler(h1,?MODULE,#{level=>notice,filter_default=>log}), LF = {fun(Log,_) -> Log#{level=>error} end, []}, ok = logger:add_primary_filter(lf,LF), {error,{already_exist,lf}} = logger:add_primary_filter(lf,LF), {error,{already_exist,lf}} = logger:add_primary_filter(lf,{fun(Log,_) -> Log end, []}), - ?LOG_INFO("hello",[]), + ?LOG_NOTICE("hello",[]), ok = check_logged(error,"hello",[],?MY_LOC(1)), ok = check_no_log(), - ok = logger:add_handler(h2,?MODULE,#{level=>info,filter_default=>log}), + ok = logger:add_handler(h2,?MODULE,#{level=>notice,filter_default=>log}), HF = {fun(#{level:=error}=Log,_) -> Log#{level=>mylevel}; (_,_) -> @@ -176,16 +176,16 @@ add_remove_filter(_Config) -> {error,{already_exist,hf}} = logger:add_handler_filter(h1,hf,{fun(Log,_) -> Log end, []}), - ?LOG_INFO("hello",[]), + ?LOG_NOTICE("hello",[]), ok = check_logged(mylevel,"hello",[],?MY_LOC(1)), ok = check_logged(error,"hello",[],?MY_LOC(2)), ok = logger:remove_primary_filter(lf), {error,{not_found,lf}} = logger:remove_primary_filter(lf), - ?LOG_INFO("hello",[]), - ok = check_logged(info,"hello",[],?MY_LOC(1)), - ok = check_logged(info,"hello",[],?MY_LOC(2)), + ?LOG_NOTICE("hello",[]), + ok = check_logged(notice,"hello",[],?MY_LOC(1)), + ok = check_logged(notice,"hello",[],?MY_LOC(2)), ?LOG_ERROR("hello",[]), ok = check_logged(mylevel,"hello",[],?MY_LOC(1)), @@ -193,9 +193,9 @@ add_remove_filter(_Config) -> ok = logger:remove_handler_filter(h1,hf), {error,{not_found,hf}} = logger:remove_handler_filter(h1,hf), - ?LOG_INFO("hello",[]), - ok = check_logged(info,"hello",[],?MY_LOC(1)), - ok = check_logged(info,"hello",[],?MY_LOC(2)), + ?LOG_NOTICE("hello",[]), + ok = check_logged(notice,"hello",[],?MY_LOC(1)), + ok = check_logged(notice,"hello",[],?MY_LOC(2)), ?LOG_ERROR("hello",[]), ok = check_logged(error,"hello",[],?MY_LOC(1)), @@ -210,8 +210,8 @@ add_remove_filter(cleanup,_Config) -> change_config(_Config) -> %% Overwrite handler config - check that defaults are added - ok = logger:add_handler(h1,?MODULE,#{level=>info,custom=>custom}), - {ok,#{module:=?MODULE,level:=info,filter_default:=log,custom:=custom}} = + ok = logger:add_handler(h1,?MODULE,#{level=>notice,custom=>custom}), + {ok,#{module:=?MODULE,level:=notice,filter_default:=log,custom:=custom}} = logger:get_handler_config(h1), register(callback_receiver,self()), ok = logger:set_handler_config(h1,#{filter_default=>stop}), @@ -254,7 +254,7 @@ change_config(_Config) -> %% Overwrite primary config - check that defaults are added ok = logger:set_primary_config(#{filter_default=>stop}), - #{level:=info,filters:=[],filter_default:=stop}=PC1 = + #{level:=notice,filters:=[],filter_default:=stop}=PC1 = logger:get_primary_config(), 3 = maps:size(PC1), %% Check that internal 'handlers' field has not been changed @@ -277,9 +277,9 @@ change_config(cleanup,Config) -> set_formatter(_Config) -> {error,{not_found,h1}}=logger:set_handler_config(h1,formatter,{?MODULE,[]}), - ok = logger:add_handler(h1,?MODULE,#{level=>info,filter_default=>log}), + ok = logger:add_handler(h1,?MODULE,#{level=>notice,filter_default=>log}), ok = logger:set_handler_config(h1,formatter,{?MODULE,[]}), - logger:info("hello",[]), + logger:notice("hello",[]), receive {_Log,#{formatter:={?MODULE,[]}}} -> ok @@ -349,7 +349,7 @@ log_all_levels_api(_Config) -> log_all_levels_api(cleanup,_Config) -> logger:remove_handler(h1), - logger:set_primary_config(level,info), + logger:set_primary_config(level,notice), ok. macros(_Config) -> @@ -366,8 +366,8 @@ set_level(_Config) -> ok = logger:add_handler(h1,?MODULE,#{level=>all,filter_default=>log}), logger:debug(?map_rep), ok = check_no_log(), - logger:info(M1=?map_rep), - ok = check_logged(info,M1,#{}), + logger:notice(M1=?map_rep), + ok = check_logged(notice,M1,#{}), ok = logger:set_primary_config(level,debug), logger:debug(M2=?map_rep), ok = check_logged(debug,M2,#{}), @@ -375,7 +375,7 @@ set_level(_Config) -> set_level(cleanup,_Config) -> logger:remove_handler(h1), - logger:set_primary_config(level,info), + logger:set_primary_config(level,notice), ok. set_module_level(_Config) -> @@ -383,7 +383,7 @@ set_module_level(_Config) -> [] = logger:get_module_level(?MODULE), [] = logger:get_module_level(), - ok = logger:add_handler(h1,?MODULE,#{level=>info,filter_default=>log}), + ok = logger:add_handler(h1,?MODULE,#{level=>notice,filter_default=>log}), {error,{invalid_level,bad}} = logger:set_module_level(?MODULE,bad), {error,{not_a_list_of_modules,{bad}}} = logger:set_module_level({bad},warning), @@ -391,16 +391,16 @@ set_module_level(_Config) -> [{?MODULE,warning}] = logger:get_module_level([?MODULE,other]), [{?MODULE,warning}] = logger:get_module_level(?MODULE), [{?MODULE,warning}] = logger:get_module_level(), - logger:info(?map_rep,?MY_LOC(0)), + logger:notice(?map_rep,?MY_LOC(0)), ok = check_no_log(), logger:warning(M1=?map_rep,?MY_LOC(0)), ok = check_logged(warning,M1,?MY_LOC(1)), - ok = logger:set_module_level(?MODULE,info), - [{?MODULE,info}] = logger:get_module_level([?MODULE,other]), - [{?MODULE,info}] = logger:get_module_level(?MODULE), - [{?MODULE,info}] = logger:get_module_level(), - logger:info(M2=?map_rep,?MY_LOC(0)), - ok = check_logged(info,M2,?MY_LOC(1)), + ok = logger:set_module_level(?MODULE,notice), + [{?MODULE,notice}] = logger:get_module_level([?MODULE,other]), + [{?MODULE,notice}] = logger:get_module_level(?MODULE), + [{?MODULE,notice}] = logger:get_module_level(), + logger:notice(M2=?map_rep,?MY_LOC(0)), + ok = check_logged(notice,M2,?MY_LOC(1)), {error,{not_a_list_of_modules,{bad}}} = logger:unset_module_level({bad}), ok = logger:unset_module_level(?MODULE), @@ -408,10 +408,10 @@ set_module_level(_Config) -> [] = logger:get_module_level(?MODULE), [] = logger:get_module_level(), - ok = logger:set_module_level([m1,m2,m3],info), - [{m1,info},{m2,info},{m3,info}] = logger:get_module_level(), + ok = logger:set_module_level([m1,m2,m3],notice), + [{m1,notice},{m2,notice},{m3,notice}] = logger:get_module_level(), ok = logger:unset_module_level(m2), - [{m1,info},{m3,info}] = logger:get_module_level(), + [{m1,notice},{m3,notice}] = logger:get_module_level(), ok = logger:unset_module_level(), [] = logger:get_module_level(), @@ -425,7 +425,7 @@ set_module_level(cleanup,_Config) -> cache_module_level(_Config) -> ok = logger:unset_module_level(?MODULE), [] = ets:lookup(?LOGGER_TABLE,?MODULE), %dirty - add API in logger_config? - ?LOG_INFO(?map_rep), + ?LOG_NOTICE(?map_rep), %% Caching is done asynchronously, so wait a bit for the update timer:sleep(100), [_] = ets:lookup(?LOGGER_TABLE,?MODULE), %dirty - add API in logger_config? @@ -464,21 +464,21 @@ format_report(_Config) -> ok. filter_failed(_Config) -> - ok = logger:add_handler(h1,?MODULE,#{level=>info,filter_default=>log}), + ok = logger:add_handler(h1,?MODULE,#{level=>notice,filter_default=>log}), %% Logger filters {error,{invalid_filter,_}} = logger:add_primary_filter(lf,{fun(_) -> ok end,args}), ok = logger:add_primary_filter(lf,{fun(_,_) -> a=b end,args}), #{filters:=[_]} = logger:get_primary_config(), - ok = logger:info(M1=?map_rep), - ok = check_logged(info,M1,#{}), + ok = logger:notice(M1=?map_rep), + ok = check_logged(notice,M1,#{}), {error,{not_found,lf}} = logger:remove_primary_filter(lf), ok = logger:add_primary_filter(lf,{fun(_,_) -> faulty_return end,args}), #{filters:=[_]} = logger:get_primary_config(), - ok = logger:info(M2=?map_rep), - ok = check_logged(info,M2,#{}), + ok = logger:notice(M2=?map_rep), + ok = check_logged(notice,M2,#{}), {error,{not_found,lf}} = logger:remove_primary_filter(lf), %% Handler filters @@ -489,14 +489,14 @@ filter_failed(_Config) -> logger:add_handler_filter(h1,hf,{fun(_) -> ok end,args}), ok = logger:add_handler_filter(h1,hf,{fun(_,_) -> a=b end,args}), {ok,#{filters:=[_]}} = logger:get_handler_config(h1), - ok = logger:info(M3=?map_rep), - ok = check_logged(info,M3,#{}), + ok = logger:notice(M3=?map_rep), + ok = check_logged(notice,M3,#{}), {error,{not_found,hf}} = logger:remove_handler_filter(h1,hf), ok = logger:add_handler_filter(h1,hf,{fun(_,_) -> faulty_return end,args}), {ok,#{filters:=[_]}} = logger:get_handler_config(h1), - ok = logger:info(M4=?map_rep), - ok = check_logged(info,M4,#{}), + ok = logger:notice(M4=?map_rep), + ok = check_logged(notice,M4,#{}), {error,{not_found,hf}} = logger:remove_handler_filter(h1,hf), ok. @@ -517,7 +517,7 @@ handler_failed(_Config) -> {error,{invalid_formatter,[]}} = logger:add_handler(h1,?MODULE,#{formatter=>[]}), {error,{invalid_handler,_}} = logger:add_handler(h1,nomodule,#{filter_default=>log}), - logger:info(?map_rep), + logger:notice(?map_rep), check_no_log(), H1 = logger:get_handler_config(), false = lists:search(fun(#{id:=h1}) -> true; (_) -> false end,H1), @@ -527,7 +527,7 @@ handler_failed(_Config) -> {error,{already_exist,h2}} = logger:add_handler(h2,othermodule,#{}), [add] = test_server:messages_get(), - logger:info(?map_rep), + logger:notice(?map_rep), [remove] = test_server:messages_get(), H2 = logger:get_handler_config(), false = lists:search(fun(#{id:=h2}) -> true; (_) -> false end,H2), @@ -710,30 +710,30 @@ config_sanity_check(cleanup,_Config) -> ok. log_failed(_Config) -> - ok = logger:add_handler(h1,?MODULE,#{level=>info,filter_default=>log}), + ok = logger:add_handler(h1,?MODULE,#{level=>notice,filter_default=>log}), {error,function_clause} = ?TRY(logger:log(bad,?map_rep)), - {error,function_clause} = ?TRY(logger:log(info,?map_rep,bad)), - {error,function_clause} = ?TRY(logger:log(info,fun() -> ?map_rep end,bad)), - {error,function_clause} = ?TRY(logger:log(info,fun() -> ?map_rep end,bad,#{})), - {error,function_clause} = ?TRY(logger:log(info,bad,bad,bad)), - {error,function_clause} = ?TRY(logger:log(info,bad,bad,#{})), + {error,function_clause} = ?TRY(logger:log(notice,?map_rep,bad)), + {error,function_clause} = ?TRY(logger:log(notice,fun() -> ?map_rep end,bad)), + {error,function_clause} = ?TRY(logger:log(notice,fun() -> ?map_rep end,bad,#{})), + {error,function_clause} = ?TRY(logger:log(notice,bad,bad,bad)), + {error,function_clause} = ?TRY(logger:log(notice,bad,bad,#{})), check_no_log(), - ok = logger:log(info,M1=?str,#{}), - check_logged(info,M1,#{}), - ok = logger:log(info,M2=?map_rep,#{}), - check_logged(info,M2,#{}), - ok = logger:log(info,M3=?keyval_rep,#{}), - check_logged(info,M3,#{}), + ok = logger:log(notice,M1=?str,#{}), + check_logged(notice,M1,#{}), + ok = logger:log(notice,M2=?map_rep,#{}), + check_logged(notice,M2,#{}), + ok = logger:log(notice,M3=?keyval_rep,#{}), + check_logged(notice,M3,#{}), %% Should we check report input more thoroughly? - ok = logger:log(info,M4=?keyval_rep++[other,stuff,in,list],#{}), - check_logged(info,M4,#{}), + ok = logger:log(notice,M4=?keyval_rep++[other,stuff,in,list],#{}), + check_logged(notice,M4,#{}), %% This might break a handler since it is assumed to be a format %% string and args, so it depends how the handler protects itself %% against something like io_lib:format("ok","ok") - ok = logger:log(info,"ok","ok",#{}), - check_logged(info,"ok","ok",#{}), + ok = logger:log(notice,"ok","ok",#{}), + check_logged(notice,"ok","ok",#{}), ok. @@ -742,7 +742,7 @@ log_failed(cleanup,_Config) -> ok. emulator(_Config) -> - ok = logger:add_handler(h1,?MODULE,#{level=>info,filter_default=>log, + ok = logger:add_handler(h1,?MODULE,#{level=>notice,filter_default=>log, tc_proc=>self()}), Msg = "Error in process ~p on node ~p with exit value:~n~p~n", Error = {badmatch,4}, @@ -761,7 +761,7 @@ generate_error(Error, Stack) -> erlang:raise(error, Error, Stack). via_logger_process(Config) -> - ok = logger:add_handler(h1,?MODULE,#{level=>info,filter_default=>log, + ok = logger:add_handler(h1,?MODULE,#{level=>notice,filter_default=>log, tc_proc=>self()}), %% Explicitly send a message to the logger process @@ -798,7 +798,7 @@ via_logger_process(cleanup, Config) -> ok. other_node(_Config) -> - ok = logger:add_handler(h1,?MODULE,#{level=>info,filter_default=>log, + ok = logger:add_handler(h1,?MODULE,#{level=>notice,filter_default=>log, tc_proc=>self()}), {ok,Node} = test_server:start_node(?FUNCTION_NAME,slave,[]), rpc:call(Node,logger,error,[Msg=?str,#{}]), @@ -815,8 +815,8 @@ compare_levels(_Config) -> Levels = [emergency,alert,critical,error,warning,notice,info,debug], ok = compare(Levels), {error,badarg} = ?TRY(logger:compare_levels(bad,bad)), - {error,badarg} = ?TRY(logger:compare_levels({bad},info)), - {error,badarg} = ?TRY(logger:compare_levels(info,"bad")), + {error,badarg} = ?TRY(logger:compare_levels({bad},notice)), + {error,badarg} = ?TRY(logger:compare_levels(notice,"bad")), ok. compare([L|Rest]) -> @@ -830,21 +830,21 @@ compare([]) -> process_metadata(_Config) -> undefined = logger:get_process_metadata(), {error,badarg} = ?TRY(logger:set_process_metadata(bad)), - ok = logger:add_handler(h1,?MODULE,#{level=>info,filter_default=>log}), + ok = logger:add_handler(h1,?MODULE,#{level=>notice,filter_default=>log}), Time = erlang:system_time(microsecond), ProcMeta = #{time=>Time,line=>0,custom=>proc}, ok = logger:set_process_metadata(ProcMeta), S1 = ?str, - ?LOG_INFO(S1,#{custom=>macro}), - check_logged(info,S1,#{time=>Time,line=>0,custom=>macro}), + ?LOG_NOTICE(S1,#{custom=>macro}), + check_logged(notice,S1,#{time=>Time,line=>0,custom=>macro}), Time2 = erlang:system_time(microsecond), S2 = ?str, - ?LOG_INFO(S2,#{time=>Time2,line=>1,custom=>macro}), - check_logged(info,S2,#{time=>Time2,line=>1,custom=>macro}), + ?LOG_NOTICE(S2,#{time=>Time2,line=>1,custom=>macro}), + check_logged(notice,S2,#{time=>Time2,line=>1,custom=>macro}), - logger:info(S3=?str,#{custom=>func}), - check_logged(info,S3,#{time=>Time,line=>0,custom=>func}), + logger:notice(S3=?str,#{custom=>func}), + check_logged(notice,S3,#{time=>Time,line=>0,custom=>func}), ProcMeta = logger:get_process_metadata(), ok = logger:update_process_metadata(#{custom=>changed,custom2=>added}), diff --git a/lib/kernel/test/logger_disk_log_h_SUITE.erl b/lib/kernel/test/logger_disk_log_h_SUITE.erl index 2b3551c3f7..3f3b483b7d 100644 --- a/lib/kernel/test/logger_disk_log_h_SUITE.erl +++ b/lib/kernel/test/logger_disk_log_h_SUITE.erl @@ -123,7 +123,7 @@ create_log(Config) -> filters=>?DEFAULT_HANDLER_FILTERS([?MODULE]), formatter=>{?MODULE,self()}}, #{file=>LogFile1}), - logger:info("hello", ?domain), + logger:notice("hello", ?domain), logger_disk_log_h:sync(Name1), ct:pal("Checking contents of ~p", [?log_no(LogFile1,1)]), try_read_file(?log_no(LogFile1,1), {ok,<<"hello\n">>}, 5000), @@ -136,7 +136,7 @@ create_log(Config) -> filters=>?DEFAULT_HANDLER_FILTERS([?MODULE]), formatter=>{?MODULE,self()}}, #{file=>LogFile2}), - logger:info("dummy", ?domain), + logger:notice("dummy", ?domain), logger_disk_log_h:sync(Name2), ct:pal("Checking contents of ~p", [?log_no(LogFile2,1)]), try_read_file(?log_no(LogFile2,1), {ok,<<"dummy\n">>}, 5000), @@ -157,21 +157,21 @@ open_existing_log(Config) -> filters=>?DEFAULT_HANDLER_FILTERS([?MODULE]), formatter=>{?MODULE,self()}}, #{file=>LogFile1}), - logger:info("one", ?domain), + logger:notice("one", ?domain), logger_disk_log_h:sync(HName), ct:pal("Checking contents of ~p", [?log_no(LogFile1,1)]), try_read_file(?log_no(LogFile1,1), {ok,<<"one\n">>}, 5000), - logger:info("two", ?domain), + logger:notice("two", ?domain), ok = remove_and_stop(HName), try_read_file(?log_no(LogFile1,1), {ok,<<"one\ntwo\n">>}, 5000), - logger:info("two and a half", ?domain), + logger:notice("two and a half", ?domain), ok = start_and_add(HName, #{filter_default=>stop, filters=>?DEFAULT_HANDLER_FILTERS([?MODULE]), formatter=>{?MODULE,self()}}, #{file=>LogFile1}), - logger:info("three", ?domain), + logger:notice("three", ?domain), logger_disk_log_h:sync(HName), try_read_file(?log_no(LogFile1,1), {ok,<<"one\ntwo\nthree\n">>}, 5000), remove_and_stop(HName), @@ -196,22 +196,22 @@ disk_log_opts(Config) -> ct:log("Fullname = ~s", [WFileFull]), {WFileFull,wrap,{Size,2},1} = {Get(file,WInfo1),Get(type,WInfo1), Get(size,WInfo1),Get(current_file,WInfo1)}, - logger:info("123", ?domain), + logger:notice("123", ?domain), logger_disk_log_h:sync(WName), timer:sleep(500), 1 = Get(current_file, disk_log:info(WName)), - logger:info("45", ?domain), + logger:notice("45", ?domain), logger_disk_log_h:sync(WName), timer:sleep(500), 1 = Get(current_file, disk_log:info(WName)), - logger:info("6", ?domain), + logger:notice("6", ?domain), logger_disk_log_h:sync(WName), timer:sleep(500), 2 = Get(current_file, disk_log:info(WName)), - logger:info("7890", ?domain), + logger:notice("7890", ?domain), logger_disk_log_h:sync(WName), timer:sleep(500), 2 = Get(current_file, disk_log:info(WName)), @@ -229,7 +229,7 @@ disk_log_opts(Config) -> ct:log("Fullname = ~s", [HFile1Full]), {HFile1Full,halt,infinity} = {Get(file,HInfo1),Get(type,HInfo1), Get(size,HInfo1)}, - logger:info("12345", ?domain), + logger:notice("12345", ?domain), logger_disk_log_h:sync(HName1), timer:sleep(500), 1 = Get(no_written_items, disk_log:info(HName1)), @@ -260,10 +260,10 @@ default_formatter(Config) -> ok = logger:set_handler_config(?MODULE,formatter, {?DEFAULT_FORMATTER,?DEFAULT_FORMAT_CONFIG}), LogName = lists:concat([LogFile, ".1"]), - logger:info("dummy"), + logger:notice("dummy"), wait_until_written(LogName), {ok,Bin} = file:read_file(LogName), - match = re:run(Bin, "=INFO REPORT====.*\ndummy", [{capture,none}]), + match = re:run(Bin, "=NOTICE REPORT====.*\ndummy", [{capture,none}]), ok. default_formatter(cleanup, _Config) -> logger:remove_handler(?MODULE). @@ -277,8 +277,8 @@ logging(Config) -> formatter=>{?MODULE,self()}}, #{file => LogFile}), MsgFormatter = fun(Term) -> {io_lib:format("Term:~p",[Term]),[]} end, - logger:info([{x,y}], #{report_cb => MsgFormatter}), - logger:info([{x,y}], #{}), + logger:notice([{x,y}], #{report_cb => MsgFormatter}), + logger:notice([{x,y}], #{}), ct:pal("Checking contents of ~p", [?log_no(LogFile,1)]), try_read_file(?log_no(LogFile,1), {ok,<<"Term:[{x,y}]\n x: y\n">>}, 5000). @@ -333,23 +333,23 @@ formatter_fail(Config) -> %% Formatter is added automatically {ok,#{formatter:={logger_formatter,_}}} = logger:get_handler_config(Name), - logger:info(M1=?msg,?domain), - Got1 = try_match_file(?log_no(LogFile,1),"[0-9\\+\\-T:\\.]* info: "++M1,5000), + logger:notice(M1=?msg,?domain), + Got1 = try_match_file(?log_no(LogFile,1),"[0-9\\+\\-T:\\.]* notice: "++M1,5000), ok = logger:set_handler_config(Name,formatter,{nonexistingmodule,#{}}), - logger:info(M2=?msg,?domain), + logger:notice(M2=?msg,?domain), Got2 = try_match_file(?log_no(LogFile,1), - escape(Got1)++"[0-9\\+\\-T:\\.]* info: FORMATTER CRASH: .*"++M2, + escape(Got1)++"[0-9\\+\\-T:\\.]* notice: FORMATTER CRASH: .*"++M2, 5000), ok = logger:set_handler_config(Name,formatter,{?MODULE,crash}), - logger:info(M3=?msg,?domain), + logger:notice(M3=?msg,?domain), Got3 = try_match_file(?log_no(LogFile,1), - escape(Got2)++"[0-9\\+\\-T:\\.]* info: FORMATTER CRASH: .*"++M3, + escape(Got2)++"[0-9\\+\\-T:\\.]* notice: FORMATTER CRASH: .*"++M3, 5000), ok = logger:set_handler_config(Name,formatter,{?MODULE,bad_return}), - logger:info(?msg,?domain), + logger:notice(?msg,?domain), try_match_file(?log_no(LogFile,1), escape(Got3)++"FORMATTER ERROR: bad_return_value", 5000), @@ -510,7 +510,7 @@ sync(Config) -> [{disk_log,blog,<<"first\n">>}, {disk_log,sync}]), - logger:info("first", ?domain), + logger:notice("first", ?domain), %% wait for automatic disk_log_sync check_tracer(?FILESYNC_REPEAT_INTERVAL*2), @@ -521,8 +521,8 @@ sync(Config) -> {disk_log,sync}]), %% two log requests in fast succession will make the handler skip %% an automatic disk log sync - logger:info("second", ?domain), - logger:info("third", ?domain), + logger:notice("second", ?domain), + logger:notice("third", ?domain), %% do explicit sync logger_disk_log_h:sync(?MODULE), check_tracer(100), @@ -540,9 +540,9 @@ sync(Config) -> {disk_log,blog,<<"fifth\n">>}, {disk_log,sync}]), - logger:info("fourth", ?domain), + logger:notice("fourth", ?domain), timer:sleep(?IDLE_DETECT_TIME_MSEC*2), - logger:info("fifth", ?domain), + logger:notice("fifth", ?domain), %% wait for automatic disk_log_sync check_tracer(?IDLE_DETECT_TIME_MSEC*2), @@ -603,7 +603,7 @@ disk_log_wrap(Config) -> %% fill first file lists:foreach(fun(N) -> Log = lists:concat([File,".",N]), - logger:info(Text, ?domain), + logger:notice(Text, ?domain), wait_until_written(Log), ct:pal("N = ~w", [N = Get(current_file, @@ -654,7 +654,7 @@ disk_log_full(Config) -> NoOfChars = 5, Text = [34 + rand:uniform(126-34) || _ <- lists:seq(1,NoOfChars)], - [logger:info(Text, ?domain) || _ <- lists:seq(1,trunc(MaxBytes/NoOfChars)+1)], + [logger:notice(Text, ?domain) || _ <- lists:seq(1,trunc(MaxBytes/NoOfChars)+1)], %% wait for trace messages timer:sleep(2000), @@ -822,7 +822,7 @@ start_h_on_new_node(Config, File) -> log_on_remote_node(Node,Msg) -> _ = spawn_link(Node, fun() -> erlang:group_leader(whereis(user),self()), - logger:info(Msg) + logger:notice(Msg) end), ok. @@ -854,7 +854,7 @@ op_switch_to_sync(Config) -> flush_reqs_qlen => 2*NumOfReqs, enable_burst_limit => false}}, ok = logger:set_handler_config(?MODULE, NewHConfig), - send_burst({n,NumOfReqs}, seq, {chars,79}, info), + send_burst({n,NumOfReqs}, seq, {chars,79}, notice), Lines = count_lines(Log), ok = file_delete(Log), NumOfReqs = Lines, @@ -883,7 +883,7 @@ op_switch_to_drop(Config) -> %% the requests in a slow enough pace so that dropping %% never occurs. Therefore, lets generate a number of %% bursts to increase the chance of message buildup. - [send_burst({n,NumOfReqs}, {spawn,Procs,0}, {chars,79}, info) || + [send_burst({n,NumOfReqs}, {spawn,Procs,0}, {chars,79}, notice) || _ <- lists:seq(1, Bursts)], Logged = count_lines(Log), ok = stop_handler(?MODULE), @@ -935,7 +935,7 @@ op_switch_to_flush(Config) -> %% sync messages gets tested). Therefore, lets %% generate a number of bursts to increase the chance %% of message buildup in some random fashion. - [send_burst({n,NumOfReqs}, {spawn,Procs,0}, {chars,79}, info) || + [send_burst({n,NumOfReqs}, {spawn,Procs,0}, {chars,79}, notice) || _ <- lists:seq(1,Bursts)], Logged = count_lines(Log), ok= stop_handler(?MODULE), @@ -968,7 +968,7 @@ limit_burst_disabled(Config) -> flush_reqs_qlen => 300}}, ok = logger:set_handler_config(?MODULE, NewHConfig), NumOfReqs = 100, - send_burst({n,NumOfReqs}, seq, {chars,79}, info), + send_burst({n,NumOfReqs}, seq, {chars,79}, notice), Logged = count_lines(Log), ct:pal("Number of messages logged = ~w", [Logged]), ok = file_delete(Log), @@ -987,7 +987,7 @@ limit_burst_enabled_one(Config) -> flush_reqs_qlen => 300}}, ok = logger:set_handler_config(?MODULE, NewHConfig), NumOfReqs = 100, - send_burst({n,NumOfReqs}, seq, {chars,79}, info), + send_burst({n,NumOfReqs}, seq, {chars,79}, notice), Logged = count_lines(Log), ct:pal("Number of messages logged = ~w", [Logged]), ok = file_delete(Log), @@ -1008,7 +1008,7 @@ limit_burst_enabled_period(Config) -> ok = logger:set_handler_config(?MODULE, NewHConfig), Windows = 3, - Sent = send_burst({t,BurstTWin*Windows}, seq, {chars,79}, info), + Sent = send_burst({t,BurstTWin*Windows}, seq, {chars,79}, notice), Logged = count_lines(Log), ct:pal("Number of messages sent = ~w~nNumber of messages logged = ~w", [Sent,Logged]), @@ -1026,7 +1026,7 @@ kill_disabled(Config) -> handler_overloaded_mem=>100}}, ok = logger:set_handler_config(?MODULE, NewHConfig), NumOfReqs = 100, - send_burst({n,NumOfReqs}, seq, {chars,79}, info), + send_burst({n,NumOfReqs}, seq, {chars,79}, notice), Logged = count_lines(Log), ct:pal("Number of messages logged = ~w", [Logged]), ok = file_delete(Log), @@ -1050,8 +1050,8 @@ qlen_kill_new(Config) -> MRef = erlang:monitor(process, Pid0), NumOfReqs = 100, Procs = 2, - send_burst({n,NumOfReqs}, {spawn,Procs,0}, {chars,79}, info), - %% send_burst({n,NumOfReqs}, seq, {chars,79}, info), + send_burst({n,NumOfReqs}, {spawn,Procs,0}, {chars,79}, notice), + %% send_burst({n,NumOfReqs}, seq, {chars,79}, notice), receive {'DOWN', MRef, _, _, Info} -> case Info of @@ -1087,8 +1087,8 @@ mem_kill_new(Config) -> MRef = erlang:monitor(process, Pid0), NumOfReqs = 100, Procs = 2, - send_burst({n,NumOfReqs}, {spawn,Procs,0}, {chars,79}, info), - %% send_burst({n,NumOfReqs}, seq, {chars,79}, info), + send_burst({n,NumOfReqs}, {spawn,Procs,0}, {chars,79}, notice), + %% send_burst({n,NumOfReqs}, seq, {chars,79}, notice), receive {'DOWN', MRef, _, _, Info} -> case Info of @@ -1118,7 +1118,7 @@ restart_after(Config) -> ok = logger:set_handler_config(?MODULE, NewHConfig1), MRef1 = erlang:monitor(process, whereis(h_proc_name())), %% kill handler - send_burst({n,100}, {spawn,2,0}, {chars,79}, info), + send_burst({n,100}, {spawn,2,0}, {chars,79}, notice), receive {'DOWN', MRef1, _, _, _Info1} -> timer:sleep(?HANDLER_RESTART_AFTER + 1000), @@ -1139,7 +1139,7 @@ restart_after(Config) -> Pid0 = whereis(h_proc_name()), MRef2 = erlang:monitor(process, Pid0), %% kill handler - send_burst({n,100}, {spawn,2,0}, {chars,79}, info), + send_burst({n,100}, {spawn,2,0}, {chars,79}, notice), receive {'DOWN', MRef2, _, _, _Info2} -> timer:sleep(RestartAfter + 2000), @@ -1174,7 +1174,7 @@ handler_requests_under_load(Config) -> {change_config,[]}]) end), Procs = 100, - Sent = Procs * send_burst({n,5000}, {spawn,Procs,10}, {chars,79}, info), + Sent = Procs * send_burst({n,5000}, {spawn,Procs,10}, {chars,79}, notice), Pid ! {self(),finish}, ReqResult = receive {Pid,Result} -> Result end, Logged = count_lines(Log), @@ -1222,8 +1222,7 @@ start_handler(Name, FuncName, Config) -> max_no_bytes => 100000000}, filter_default=>log, filters=>?DEFAULT_HANDLER_FILTERS([Name]), - formatter=>{?MODULE,op}, - level => info}), + formatter=>{?MODULE,op}}), {ok,HConfig = #{config := DLHConfig}} = logger:get_handler_config(Name), {lists:concat([File,".1"]),HConfig,DLHConfig}. diff --git a/lib/kernel/test/logger_env_var_SUITE.erl b/lib/kernel/test/logger_env_var_SUITE.erl index 329b4c4b88..4f052b456e 100644 --- a/lib/kernel/test/logger_env_var_SUITE.erl +++ b/lib/kernel/test/logger_env_var_SUITE.erl @@ -63,8 +63,7 @@ groups() -> ]}, {bad,[],[bad_error_logger, bad_level, - bad_sasl_compatibility, - bad_progress]}]. + bad_sasl_compatibility]}]. all() -> [default, @@ -78,54 +77,60 @@ all() -> ]. default(Config) -> - {ok,#{handlers:=Hs},_Node} = setup(Config,[]), + {ok,#{primary:=P,handlers:=Hs,module_levels:=ML},_Node} = setup(Config,[]), + notice = maps:get(level,P), #{module:=logger_std_h} = StdC = find(?STANDARD_HANDLER,Hs), all = maps:get(level,StdC), StdFilters = maps:get(filters,StdC), {domain,{_,{log,super,[otp,sasl]}}} = lists:keyfind(domain,1,StdFilters), - true = lists:keymember(stop_progress,1,StdFilters), false = exists(simple,Hs), false = exists(sasl,Hs), + [] = ML, ok. default_sasl_compatible(Config) -> - {ok,#{handlers:=Hs},_Node} = setup(Config, - [{logger_sasl_compatible,true}]), + {ok,#{primary:=P,handlers:=Hs,module_levels:=ML},_Node} = + setup(Config,[{logger_sasl_compatible,true}]), + info = maps:get(level,P), #{module:=logger_std_h} = StdC = find(?STANDARD_HANDLER,Hs), all = maps:get(level,StdC), StdFilters = maps:get(filters,StdC), {domain,{_,{log,super,[otp]}}} = lists:keyfind(domain,1,StdFilters), - false = lists:keymember(stop_progress,1,StdFilters), false = exists(simple,Hs), true = exists(sasl,Hs), + [] = ML, ok. error_logger_tty(Config) -> - {ok,#{handlers:=Hs},_Node} = setup(Config,[{error_logger,tty}]), + {ok,#{primary:=P,handlers:=Hs,module_levels:=ML},_Node} = + setup(Config,[{error_logger,tty}]), + notice = maps:get(level,P), #{module:=logger_std_h} = StdC = find(?STANDARD_HANDLER,Hs), all = maps:get(level,StdC), StdFilters = maps:get(filters,StdC), {domain,{_,{log,super,[otp,sasl]}}} = lists:keyfind(domain,1,StdFilters), - true = lists:keymember(stop_progress,1,StdFilters), false = exists(simple,Hs), false = exists(sasl,Hs), + [] = ML, ok. error_logger_tty_sasl_compatible(Config) -> - {ok,#{handlers:=Hs},_Node} = setup(Config, - [{error_logger,tty}, - {logger_sasl_compatible,true}]), + {ok,#{primary:=P,handlers:=Hs,module_levels:=ML},_Node} = + setup(Config, + [{error_logger,tty}, + {logger_sasl_compatible,true}]), + info = maps:get(level,P), #{module:=logger_std_h} = StdC = find(?STANDARD_HANDLER,Hs), all = maps:get(level,StdC), StdFilters = maps:get(filters,StdC), {domain,{_,{log,super,[otp]}}} = lists:keyfind(domain,1,StdFilters), - false = lists:keymember(stop_progress,1,StdFilters), false = exists(simple,Hs), true = exists(sasl,Hs), + [] = ML, ok. error_logger_false(Config) -> - {ok,#{handlers:=Hs,primary:=P},_Node} = + {ok,#{handlers:=Hs,primary:=P,module_levels:=ML},_Node} = setup(Config, [{error_logger,false}, {logger_level,notice}]), @@ -135,28 +140,27 @@ error_logger_false(Config) -> notice = maps:get(level,P), SimpleFilters = maps:get(filters,SimpleC), {domain,{_,{log,super,[otp,sasl]}}} = lists:keyfind(domain,1,SimpleFilters), - true = lists:keymember(stop_progress,1,SimpleFilters), false = exists(sasl,Hs), + [] = ML, ok. error_logger_false_progress(Config) -> - {ok,#{handlers:=Hs,primary:=P},_Node} = + {ok,#{handlers:=Hs,primary:=P,module_levels:=ML},_Node} = setup(Config, [{error_logger,false}, - {logger_level,notice}, - {logger_progress_reports,log}]), + {logger_level,notice}]), false = exists(?STANDARD_HANDLER,Hs), #{module:=logger_simple_h} = SimpleC = find(simple,Hs), all = maps:get(level,SimpleC), notice = maps:get(level,P), SimpleFilters = maps:get(filters,SimpleC), {domain,{_,{log,super,[otp,sasl]}}} = lists:keyfind(domain,1,SimpleFilters), - false = lists:keymember(stop_progress,1,SimpleFilters), false = exists(sasl,Hs), + [] = ML, ok. error_logger_false_sasl_compatible(Config) -> - {ok,#{handlers:=Hs,primary:=P},_Node} = + {ok,#{handlers:=Hs,primary:=P,module_levels:=ML},_Node} = setup(Config, [{error_logger,false}, {logger_level,notice}, @@ -164,11 +168,11 @@ error_logger_false_sasl_compatible(Config) -> false = exists(?STANDARD_HANDLER,Hs), #{module:=logger_simple_h} = SimpleC = find(simple,Hs), all = maps:get(level,SimpleC), - notice = maps:get(level,P), + info = maps:get(level,P), SimpleFilters = maps:get(filters,SimpleC), {domain,{_,{log,super,[otp]}}} = lists:keyfind(domain,1,SimpleFilters), - false = lists:keymember(stop_progress,1,SimpleFilters), true = exists(sasl,Hs), + [] = ML, ok. error_logger_silent(Config) -> @@ -201,7 +205,7 @@ error_logger_file(Config) -> logger_file(Config) -> Log = file(Config,?FUNCTION_NAME), - {ok,#{handlers:=Hs},Node} + {ok,#{primary:=P,handlers:=Hs,module_levels:=ML},Node} = setup(Config, [{logger, [{handler,?STANDARD_HANDLER,logger_std_h, @@ -214,15 +218,14 @@ logger_file(Config) -> all = maps:get(level,StdC), StdFilters = maps:get(filters,StdC), {domain,{_,{log,super,[otp,sasl]}}} = lists:keyfind(domain,1,StdFilters), - true = lists:keymember(stop_progress,1,StdFilters), false = exists(simple,Hs), false = exists(sasl,Hs), - + [] = ML, ok. logger_file_sasl_compatible(Config) -> Log = file(Config,?FUNCTION_NAME), - {ok,#{handlers:=Hs},Node} + {ok,#{primary:=P,handlers:=Hs,module_levels:=ML},Node} = setup(Config, [{logger_sasl_compatible,true}, {logger, @@ -232,36 +235,37 @@ logger_file_sasl_compatible(Config) -> file,% dest 0),% progress in std logger + info = maps:get(level,P), #{module:=logger_std_h} = StdC = find(?STANDARD_HANDLER,Hs), all = maps:get(level,StdC), StdFilters = maps:get(filters,StdC), {domain,{_,{log,super,[otp]}}} = lists:keyfind(domain,1,StdFilters), - false = lists:keymember(stop_progress,1,StdFilters), false = exists(simple,Hs), true = exists(sasl,Hs), - + [] = ML, ok. logger_file_log_progress(Config) -> Log = file(Config,?FUNCTION_NAME), - {ok,#{handlers:=Hs},Node} + {ok,#{primary:=P,handlers:=Hs,module_levels:=ML},Node} = setup(Config, - [{logger_progress_reports,log}, + [{logger_level,info}, {logger, [{handler,?STANDARD_HANDLER,logger_std_h, #{config=>#{type=>{file,Log}}}}]}]), check_default_log(Node,Log, file,% dest - 6),% progress in std logger + 6,% progress in std logger + info), + info = maps:get(level,P), #{module:=logger_std_h} = StdC = find(?STANDARD_HANDLER,Hs), all = maps:get(level,StdC), StdFilters = maps:get(filters,StdC), {domain,{_,{log,super,[otp,sasl]}}} = lists:keyfind(domain,1,StdFilters), - false = lists:keymember(stop_progress,1,StdFilters), false = exists(simple,Hs), false = exists(sasl,Hs), - + [] = ML, ok. logger_file_no_filter(Config) -> @@ -330,7 +334,7 @@ logger_filters(Config) -> Log = file(Config,?FUNCTION_NAME), {ok,#{handlers:=Hs,primary:=P},Node} = setup(Config, - [{logger_progress_reports,log}, + [{logger_level,info}, {logger, [{handler,?STANDARD_HANDLER,logger_std_h, #{config=>#{type=>{file,Log}}}}, @@ -338,13 +342,13 @@ logger_filters(Config) -> ]}]), check_default_log(Node,Log, file,% dest - 0),% progress in std logger + 0,% progress in std logger + info), #{module:=logger_std_h} = StdC = find(?STANDARD_HANDLER,Hs), all = maps:get(level,StdC), StdFilters = maps:get(filters,StdC), {domain,{_,{log,super,[otp,sasl]}}} = lists:keyfind(domain,1,StdFilters), - false = lists:keymember(stop_progress,1,StdFilters), false = exists(simple,Hs), false = exists(sasl,Hs), LoggerFilters = maps:get(filters,P), @@ -356,7 +360,7 @@ logger_filters_stop(Config) -> Log = file(Config,?FUNCTION_NAME), {ok,#{handlers:=Hs,primary:=P},Node} = setup(Config, - [{logger_progress_reports,log}, + [{logger_level,info}, {logger, [{handler,?STANDARD_HANDLER,logger_std_h, #{filters=>[], @@ -366,7 +370,7 @@ logger_filters_stop(Config) -> check_default_log(Node,Log, file,% dest 0,% progress in std logger - notice), + info), #{module:=logger_std_h} = StdC = find(?STANDARD_HANDLER,Hs), all = maps:get(level,StdC), @@ -382,7 +386,7 @@ logger_module_level(Config) -> Log = file(Config,?FUNCTION_NAME), {ok,#{handlers:=Hs,module_levels:=ModuleLevels},Node} = setup(Config, - [{logger_progress_reports,log}, + [{logger_level,info}, {logger, [{handler,?STANDARD_HANDLER,logger_std_h, #{config=>#{type=>{file,Log}}}}, @@ -390,13 +394,13 @@ logger_module_level(Config) -> ]}]), check_default_log(Node,Log, file,% dest - 3),% progress in std logger + 3,% progress in std logger + info), #{module:=logger_std_h} = StdC = find(?STANDARD_HANDLER,Hs), all = maps:get(level,StdC), StdFilters = maps:get(filters,StdC), {domain,{_,{log,super,[otp,sasl]}}} = lists:keyfind(domain,1,StdFilters), - false = lists:keymember(stop_progress,1,StdFilters), false = exists(simple,Hs), false = exists(sasl,Hs), [{supervisor,error}] = ModuleLevels, @@ -417,7 +421,6 @@ logger_disk_log(Config) -> all = maps:get(level,StdC), StdFilters = maps:get(filters,StdC), {domain,{_,{log,super,[otp,sasl]}}} = lists:keyfind(domain,1,StdFilters), - true = lists:keymember(stop_progress,1,StdFilters), false = exists(simple,Hs), false = exists(sasl,Hs), @@ -450,10 +453,9 @@ logger_undefined(Config) -> false = exists(?STANDARD_HANDLER,Hs), #{module:=logger_simple_h} = SimpleC = find(simple,Hs), all = maps:get(level,SimpleC), - info = maps:get(level,P), + notice = maps:get(level,P), SimpleFilters = maps:get(filters,SimpleC), {domain,{_,{log,super,[otp,sasl]}}} = lists:keyfind(domain,1,SimpleFilters), - true = lists:keymember(stop_progress,1,SimpleFilters), false = exists(sasl,Hs), ok. @@ -476,7 +478,8 @@ logger_many_handlers_default_first(Config) -> filters=>[{level,{fun logger_filters:level/2,{stop,gteq,error}}}], config=>#{type=>{file,LogInfo}}} } - ]}], LogErr, LogInfo, 6). + ]}, + {logger_level,info}], LogErr, LogInfo, 6). %% Test that we can add multiple handlers with the default last logger_many_handlers_default_last(Config) -> @@ -495,7 +498,8 @@ logger_many_handlers_default_last(Config) -> formatter=>{logger_formatter,#{}}, config=>#{type=>{file,LogErr}}} } - ]}], LogErr, LogInfo, 7). + ]}, + {logger_level,info}], LogErr, LogInfo, 7). %% Check that we can handle that an added logger has a broken filter %% This used to cause a deadlock. @@ -517,7 +521,8 @@ logger_many_handlers_default_last_broken_filter(Config) -> formatter=>{logger_formatter,#{}}, config=>#{type=>{file,LogErr}}} } - ]}], LogErr, LogInfo, 7). + ]}, + {logger_level,info}], LogErr, LogInfo, 7). logger_many_handlers(Config, Env, LogErr, LogInfo, NumProgress) -> {ok,#{handlers:=Hs},Node} = setup(Config,Env), @@ -528,7 +533,8 @@ logger_many_handlers(Config, Env, LogErr, LogInfo, NumProgress) -> ok = rpc:call(Node,logger_std_h,sync,[info]), {ok, Bin} = file:read_file(LogInfo), ct:log("Log content:~n~s",[Bin]), - match(Bin,<<"info:">>,NumProgress+1,info,info), + match(Bin,<<"info:">>,NumProgress,info,info), + match(Bin,<<"notice:">>,1,notice,info), match(Bin,<<"alert:">>,0,alert,info), ok. @@ -538,18 +544,18 @@ sasl_compatible_false(Config) -> {ok,_,Node} = setup(Config, [{error_logger,{file,Log}}, {logger_sasl_compatible,false}, - {logger_progress_reports,log}]), + {logger_level,info}]), % to get progress check_default_log(Node,Log, file,% dest - 6),% progress in std logger + 6,% progress in std logger + info), ok. sasl_compatible_false_no_progress(Config) -> Log = file(Config,?FUNCTION_NAME), {ok,_,Node} = setup(Config, [{error_logger,{file,Log}}, - {logger_sasl_compatible,false}, - {logger_progress_reports,stop}]), + {logger_sasl_compatible,false}]), check_default_log(Node,Log, file,% dest 0),% progress in std logger @@ -574,9 +580,6 @@ bad_level(Config) -> bad_sasl_compatibility(Config) -> error = setup(Config,[{logger_sasl_compatible,badcomp}]). -bad_progress(Config) -> - error = setup(Config,[{logger_progress_reports,badprogress}]). - %%%----------------------------------------------------------------- %%% Internal file(Config,Func) -> @@ -584,22 +587,22 @@ file(Config,Func) -> lists:concat([Func,".log"])). check_default_log(Node,Log,Dest,NumProgress) -> - check_default_log(Node,Log,Dest,NumProgress,info). + check_default_log(Node,Log,Dest,NumProgress,notice). 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,<<"INFO REPORT">>,0,notice,Level), match(Bin1,<<"DEBUG REPORT">>,0,debug,Level), - match(Bin2,<<"INFO REPORT">>,1,info,Level), + match(Bin2,<<"INFO REPORT">>,1,notice,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,notice). check_single_log(Node,Log,Dest,NumProgress,Level) -> {ok,Bin1,Bin2} = check_log(Node,Log,Dest), diff --git a/lib/kernel/test/logger_formatter_SUITE.erl b/lib/kernel/test/logger_formatter_SUITE.erl index 00fa89271b..864a40b618 100644 --- a/lib/kernel/test/logger_formatter_SUITE.erl +++ b/lib/kernel/test/logger_formatter_SUITE.erl @@ -56,6 +56,7 @@ groups() -> all() -> [default, legacy_header, + error_logger_notice_header, single_line, template, format_msg, @@ -125,6 +126,34 @@ legacy_header(_Config) -> "=INFO REPORT==== "++_ = String5, ok. +error_logger_notice_header(_Config) -> + Meta1 = #{error_logger=>#{tag => info_report,type => std_info}}, + String1 = format(notice,{"~p",[term]},Meta1, + #{legacy_header=>true, + error_logger_notice_header=>notice}), + ct:log(String1), + "=NOTICE REPORT==== "++_ = String1, + + String2 = format(notice,{"~p",[term]},Meta1, + #{legacy_header=>true, + error_logger_notice_header=>info}), + ct:log(String2), + "=INFO REPORT==== "++_ = String2, + + String3 = format(notice,{"~p",[term]},#{}, + #{legacy_header=>true, + error_logger_notice_header=>notice}), + ct:log(String3), + "=NOTICE REPORT==== "++_ = String3, + + String4 = format(notice,{"~p",[term]},#{}, + #{legacy_header=>true, + error_logger_notice_header=>info}), + ct:log(String4), + "=NOTICE REPORT==== "++_ = String4, + + ok. + single_line(_Config) -> Time = timestamp(), ExpectedTimestamp = default_time_format(Time), @@ -581,6 +610,7 @@ check_config(_Config) -> C1 = #{chars_limit => 1, depth => 1, legacy_header => true, + error_logger_notice_header => info, max_size => 1, report_cb => fun(R) -> {"~p",[R]} end, single_line => false, @@ -601,6 +631,10 @@ check_config(_Config) -> ?cfgerr({legacy_header,bad}) = logger_formatter:check_config(#{legacy_header => bad}), + ok = logger_formatter:check_config(#{error_logger_notice_header => notice}), + ?cfgerr({error_logger_notice_header,bad}) = + logger_formatter:check_config(#{error_logger_notice_header => bad}), + ok = logger_formatter:check_config(#{max_size => unlimited}), ?cfgerr({max_size,bad}) = logger_formatter:check_config(#{max_size => bad}), @@ -664,17 +698,17 @@ update_config(_Config) -> logger:add_handler_filter(default,silence,{fun(_,_) -> stop end,ok}), ok = logger:add_handler(?MODULE,?MODULE,#{}), D = lists:seq(1,1000), - logger:info("~p~n",[D]), + logger:notice("~p~n",[D]), {Lines1,C1} = check_log(), [ct:log(L) || L <- Lines1], ct:log("~p",[C1]), [Line1] = Lines1, - [_Time,"info: "++D1] = string:split(Line1," "), + [_Time,"notice: "++D1] = string:split(Line1," "), true = length(D1)>3000, true = #{}==C1, ok = logger:update_formatter_config(?MODULE,single_line,false), - logger:info("~p~n",[D]), + logger:notice("~p~n",[D]), {Lines2,C2} = check_log(), [ct:log(L) || L <- Lines2], ct:log("~p",[C2]), @@ -682,23 +716,37 @@ update_config(_Config) -> true = #{single_line=>false}==C2, ok = logger:update_formatter_config(?MODULE,#{legacy_header=>true}), - logger:info("~p~n",[D]), + logger:notice("~p~n",[D]), {Lines3,C3} = check_log(), [ct:log(L) || L <- Lines3], ct:log("~p",[C3]), - ["=INFO REPORT==== "++_|D3] = Lines3, + ["=NOTICE REPORT==== "++_|D3] = Lines3, true = length(D3)>50, true = #{legacy_header=>true,single_line=>false}==C3, ok = logger:update_formatter_config(?MODULE,single_line,true), - logger:info("~p~n",[D]), + logger:notice("~p~n",[D]), {Lines4,C4} = check_log(), [ct:log(L) || L <- Lines4], ct:log("~p",[C4]), - ["=INFO REPORT==== "++_,D4] = Lines4, + ["=NOTICE REPORT==== "++_,D4] = Lines4, true = length(D4)>3000, true = #{legacy_header=>true,single_line=>true}==C4, + %% Finally, check that error_logger_notice_header works, default=info + error_logger:info_msg("~p",[D]), + {Lines5,C5} = check_log(), + [ct:log(L) || L <- Lines5], + ct:log("~p",[C5]), + ["=INFO REPORT==== "++_,_D5] = Lines5, + + ok=logger:update_formatter_config(?MODULE,error_logger_notice_header,notice), + error_logger:info_msg("~p",[D]), + {Lines6,C6} = check_log(), + [ct:log(L) || L <- Lines6], + ct:log("~p",[C6]), + ["=NOTICE REPORT==== "++_,_D6] = Lines6, + ok. update_config(cleanup,_Config) -> diff --git a/lib/kernel/test/logger_legacy_SUITE.erl b/lib/kernel/test/logger_legacy_SUITE.erl index 180db9f51a..de73b6152a 100644 --- a/lib/kernel/test/logger_legacy_SUITE.erl +++ b/lib/kernel/test/logger_legacy_SUITE.erl @@ -70,6 +70,10 @@ init_per_group(std, Config) -> [{domain,{fun logger_filters:domain/2,{log,super,[otp]}}}]), Config; init_per_group(sasl, Config) -> + %% Since default level is notice, and progress reports are info, + %% we need to raise the global logger level to info in order to + %% receive these. + ok = logger:set_primary_config(level,info), ok = logger:set_handler_config( error_logger,filters, [{domain,{fun logger_filters:domain/2,{log,super,[otp,sasl]}}}]), @@ -77,13 +81,14 @@ init_per_group(sasl, Config) -> %% cth_log_redirect checks if sasl is started before displaying %% any sasl reports - so just to see the real sasl reports in tc %% log: - application:start(sasl), - Config; + {ok,Apps} = application:ensure_all_started(sasl), + [{stop_apps,Apps}|Config]; init_per_group(_Group, Config) -> Config. -end_per_group(sasl, _Config) -> - application:stop(sasl), +end_per_group(sasl, Config) -> + Apps = ?config(stop_apps,Config), + [application:stop(App) || App <- Apps], ok; end_per_group(_Group, _Config) -> ok. diff --git a/lib/kernel/test/logger_simple_h_SUITE.erl b/lib/kernel/test/logger_simple_h_SUITE.erl index 9f34bbbe34..3a761a257a 100644 --- a/lib/kernel/test/logger_simple_h_SUITE.erl +++ b/lib/kernel/test/logger_simple_h_SUITE.erl @@ -128,8 +128,8 @@ replace_file(Config) -> 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, warning, [M4=?keyval_rep]), + log(Node, warning, [M41=?keyval_rep++[not_key_val]]), log(Node, critical, [M7=?str,[A7=?keyval_rep]]), log(Node, notice, [M8=["fake",string,"line:",?LINE]]), @@ -151,10 +151,10 @@ replace_file(Config) -> "=ERROR REPORT===="++_, _, _, - "=INFO REPORT===="++_, + "=WARNING REPORT===="++_, _, _, - "=INFO REPORT===="++_, + "=WARNING REPORT===="++_, _, _, _, @@ -172,8 +172,8 @@ replace_disk_log(Config) -> 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, warning, [M4=?keyval_rep]), + log(Node, warning, [M41=?keyval_rep++[not_key_val]]), log(Node, critical, [M7=?str,[A7=?keyval_rep]]), log(Node, notice, [M8=["fake",string,"line:",?LINE]]), @@ -194,10 +194,10 @@ replace_disk_log(Config) -> "=ERROR REPORT===="++_, _, _, - "=INFO REPORT===="++_, + "=WARNING REPORT===="++_, _, _, - "=INFO REPORT===="++_, + "=WARNING REPORT===="++_, _, _, _, diff --git a/lib/kernel/test/logger_std_h_SUITE.erl b/lib/kernel/test/logger_std_h_SUITE.erl index a67b55eee1..e71b75fe66 100644 --- a/lib/kernel/test/logger_std_h_SUITE.erl +++ b/lib/kernel/test/logger_std_h_SUITE.erl @@ -172,14 +172,14 @@ add_remove_instance_file(Log, Type) -> formatter=>{?MODULE,self()}}), Pid = whereis(h_proc_name()), true = is_pid(Pid), - logger:info(M1=?msg,?domain), + logger:notice(M1=?msg,?domain), ?check(M1), B1 = ?bin(M1), try_read_file(Log, {ok,B1}, ?FILESYNC_REP_INT), ok = logger:remove_handler(?MODULE), timer:sleep(500), undefined = whereis(h_proc_name()), - logger:info(?msg,?domain), + logger:notice(?msg,?domain), ?check_no_log, try_read_file(Log, {ok,B1}, ?FILESYNC_REP_INT), ok. @@ -188,11 +188,11 @@ default_formatter(_Config) -> ok = logger:set_handler_config(?STANDARD_HANDLER,formatter, {?DEFAULT_FORMATTER,?DEFAULT_FORMAT_CONFIG}), ct:capture_start(), - logger:info(M1=?msg), + logger:notice(M1=?msg), timer:sleep(100), ct:capture_stop(), [Msg] = ct:capture_get(), - match = re:run(Msg,"=INFO REPORT====.*\n"++M1,[{capture,none}]), + match = re:run(Msg,"=NOTICE REPORT====.*\n"++M1,[{capture,none}]), ok. errors(Config) -> @@ -225,7 +225,7 @@ errors(Config) -> logger:add_handler(myh3,logger_std_h, #{config=>#{type=>{file,Log,[bad_file_opt]}}}), - ok = logger:info(?msg). + ok = logger:notice(?msg). errors(cleanup,_Config) -> logger:remove_handler(?MODULE). @@ -247,23 +247,23 @@ formatter_fail(Config) -> %% Formatter is added automatically {ok,#{formatter:={logger_formatter,_}}} = logger:get_handler_config(?MODULE), - logger:info(M1=?msg,?domain), - Got1 = try_match_file(Log,"[0-9\\+\\-T:\\.]* info: "++M1,5000), + logger:notice(M1=?msg,?domain), + Got1 = try_match_file(Log,"[0-9\\+\\-T:\\.]* notice: "++M1,5000), ok = logger:set_handler_config(?MODULE,formatter,{nonexistingmodule,#{}}), - logger:info(M2=?msg,?domain), + logger:notice(M2=?msg,?domain), Got2 = try_match_file(Log, - escape(Got1)++"[0-9\\+\\-T:\\.]* info: FORMATTER CRASH: .*"++M2, + escape(Got1)++"[0-9\\+\\-T:\\.]* notice: FORMATTER CRASH: .*"++M2, 5000), ok = logger:set_handler_config(?MODULE,formatter,{?MODULE,crash}), - logger:info(M3=?msg,?domain), + logger:notice(M3=?msg,?domain), Got3 = try_match_file(Log, - escape(Got2)++"[0-9\\+\\-T:\\.]* info: FORMATTER CRASH: .*"++M3, + escape(Got2)++"[0-9\\+\\-T:\\.]* notice: FORMATTER CRASH: .*"++M3, 5000), ok = logger:set_handler_config(?MODULE,formatter,{?MODULE,bad_return}), - logger:info(?msg,?domain), + logger:notice(?msg,?domain), try_match_file(Log, escape(Got3)++"FORMATTER ERROR: bad_return_value", 5000), @@ -383,7 +383,7 @@ crash_std_h(Config,Func,Var,Type,Log) -> log_on_remote_node(Node,Msg) -> _ = spawn_link(Node, fun() -> erlang:group_leader(whereis(user),self()), - logger:info(Msg) + logger:notice(Msg) end), ok. @@ -496,7 +496,7 @@ file_opts(Config) -> formatter=>{?MODULE,self()}}), #{type := OkType} = logger_std_h:info(?MODULE), - logger:info(M1=?msg,?domain), + logger:notice(M1=?msg,?domain), ?check(M1), B1 = ?bin(M1), try_read_file(Log, {ok,B1}, ?FILESYNC_REP_INT), @@ -524,7 +524,7 @@ sync(Config) -> {logger_std_h, sync_dev}, {file,datasync}]), - logger:info("first", ?domain), + logger:notice("first", ?domain), %% wait for automatic filesync check_tracer(?FILESYNC_REP_INT*2), @@ -537,7 +537,7 @@ sync(Config) -> {file,datasync}, {no_more,500} ]), - logger:info("second", ?domain), + logger:notice("second", ?domain), %% do explicit sync logger_std_h:sync(?MODULE), %% a second sync should be ignored @@ -562,10 +562,10 @@ sync(Config) -> {logger_std_h, write_to_dev, <<"fourth\n">>}, {logger_std_h, sync_dev}, {file,datasync}]), - logger:info("third", ?domain), + logger:notice("third", ?domain), %% wait for automatic filesync timer:sleep(?IDLE_DETECT_TIME_MSEC*2), - logger:info("fourth", ?domain), + logger:notice("fourth", ?domain), %% wait for automatic filesync check_tracer(?IDLE_DETECT_TIME_MSEC*2), @@ -705,7 +705,7 @@ op_switch_to_sync_file(Config) -> enable_burst_limit => false}}, ok = logger:set_handler_config(?MODULE, NewHConfig), %% TRecvPid = start_op_trace(), - send_burst({n,NumOfReqs}, seq, {chars,79}, info), + send_burst({n,NumOfReqs}, seq, {chars,79}, notice), Lines = count_lines(Log), ok = file_delete(Log), %% true = analyse_trace(TRecvPid, @@ -733,7 +733,7 @@ op_switch_to_sync_tty(Config) -> flush_reqs_qlen => 2*NumOfReqs, enable_burst_limit => false}}, ok = logger:set_handler_config(?MODULE, NewHConfig), - send_burst({n,NumOfReqs}, seq, {chars,79}, info), + send_burst({n,NumOfReqs}, seq, {chars,79}, notice), ok. op_switch_to_sync_tty(cleanup, _Config) -> ok = stop_handler(?MODULE). @@ -760,7 +760,7 @@ op_switch_to_drop_file(Config) -> %% requests in a slow enough pace so that dropping %% never occurs. Therefore, lets generate a number of %% bursts to increase the chance of message buildup. - [send_burst({n,NumOfReqs}, {spawn,Procs,0}, {chars,79}, info) || + [send_burst({n,NumOfReqs}, {spawn,Procs,0}, {chars,79}, notice) || _ <- lists:seq(1, Bursts)], Logged = count_lines(Log), ok = stop_handler(?MODULE), @@ -793,7 +793,7 @@ op_switch_to_drop_tty(Config) -> Procs*NumOfReqs+1, enable_burst_limit => false}}, ok = logger:set_handler_config(?MODULE, NewHConfig), - send_burst({n,NumOfReqs}, {spawn,Procs,0}, {chars,79}, info), + send_burst({n,NumOfReqs}, {spawn,Procs,0}, {chars,79}, notice), ok. op_switch_to_drop_tty(cleanup, _Config) -> ok = stop_handler(?MODULE). @@ -828,7 +828,7 @@ op_switch_to_flush_file(Config) -> %% sync messages gets tested). Therefore, lets %% generate a number of bursts to increase the chance %% of message buildup in some random fashion. - [send_burst({n,NumOfReqs}, {spawn,Procs,0}, {chars,79}, info) || + [send_burst({n,NumOfReqs}, {spawn,Procs,0}, {chars,79}, notice) || _ <- lists:seq(1,Bursts)], Logged = count_lines(Log), ok = stop_handler(?MODULE), @@ -867,7 +867,7 @@ op_switch_to_flush_tty(Config) -> ok = logger:set_handler_config(?MODULE, NewHConfig), NumOfReqs = 1000, Procs = 100, - send_burst({n,NumOfReqs}, {spawn,Procs,0}, {chars,79}, info), + send_burst({n,NumOfReqs}, {spawn,Procs,0}, {chars,79}, notice), ok. op_switch_to_flush_tty(cleanup, _Config) -> ok = stop_handler(?MODULE). @@ -882,7 +882,7 @@ limit_burst_disabled(Config) -> flush_reqs_qlen => 300}}, ok = logger:set_handler_config(?MODULE, NewHConfig), NumOfReqs = 100, - send_burst({n,NumOfReqs}, seq, {chars,79}, info), + send_burst({n,NumOfReqs}, seq, {chars,79}, notice), Logged = count_lines(Log), ct:pal("Number of messages logged = ~w", [Logged]), ok = file_delete(Log), @@ -901,7 +901,7 @@ limit_burst_enabled_one(Config) -> flush_reqs_qlen => 300}}, ok = logger:set_handler_config(?MODULE, NewHConfig), NumOfReqs = 100, - send_burst({n,NumOfReqs}, seq, {chars,79}, info), + send_burst({n,NumOfReqs}, seq, {chars,79}, notice), Logged = count_lines(Log), ct:pal("Number of messages logged = ~w", [Logged]), ok = file_delete(Log), @@ -922,7 +922,7 @@ limit_burst_enabled_period(Config) -> ok = logger:set_handler_config(?MODULE, NewHConfig), Windows = 3, - Sent = send_burst({t,BurstTWin*Windows}, seq, {chars,79}, info), + Sent = send_burst({t,BurstTWin*Windows}, seq, {chars,79}, notice), Logged = count_lines(Log), ct:pal("Number of messages sent = ~w~nNumber of messages logged = ~w", [Sent,Logged]), @@ -940,7 +940,7 @@ kill_disabled(Config) -> handler_overloaded_mem=>100}}, ok = logger:set_handler_config(?MODULE, NewHConfig), NumOfReqs = 100, - send_burst({n,NumOfReqs}, seq, {chars,79}, info), + send_burst({n,NumOfReqs}, seq, {chars,79}, notice), Logged = count_lines(Log), ct:pal("Number of messages logged = ~w", [Logged]), ok = file_delete(Log), @@ -963,8 +963,8 @@ qlen_kill_new(Config) -> MRef = erlang:monitor(process, Pid0), NumOfReqs = 100, Procs = 2, - send_burst({n,NumOfReqs}, {spawn,Procs,0}, {chars,79}, info), - %% send_burst({n,NumOfReqs}, seq, {chars,79}, info), + send_burst({n,NumOfReqs}, {spawn,Procs,0}, {chars,79}, notice), + %% send_burst({n,NumOfReqs}, seq, {chars,79}, notice), receive {'DOWN', MRef, _, _, Info} -> case Info of @@ -1014,8 +1014,8 @@ mem_kill_new(Config) -> MRef = erlang:monitor(process, Pid0), NumOfReqs = 100, Procs = 2, - send_burst({n,NumOfReqs}, {spawn,Procs,0}, {chars,79}, info), - %% send_burst({n,NumOfReqs}, seq, {chars,79}, info), + send_burst({n,NumOfReqs}, {spawn,Procs,0}, {chars,79}, notice), + %% send_burst({n,NumOfReqs}, seq, {chars,79}, notice), receive {'DOWN', MRef, _, _, Info} -> case Info of @@ -1050,7 +1050,7 @@ restart_after(Config) -> ok = logger:set_handler_config(?MODULE, NewHConfig1), MRef1 = erlang:monitor(process, whereis(h_proc_name())), %% kill handler - send_burst({n,100}, {spawn,2,0}, {chars,79}, info), + send_burst({n,100}, {spawn,2,0}, {chars,79}, notice), receive {'DOWN', MRef1, _, _, _Info1} -> timer:sleep(?HANDLER_RESTART_AFTER + 1000), @@ -1071,7 +1071,7 @@ restart_after(Config) -> Pid0 = whereis(h_proc_name()), MRef2 = erlang:monitor(process, Pid0), %% kill handler - send_burst({n,100}, {spawn,2,0}, {chars,79}, info), + send_burst({n,100}, {spawn,2,0}, {chars,79}, notice), receive {'DOWN', MRef2, _, _, _Info2} -> timer:sleep(RestartAfter + 2000), @@ -1106,7 +1106,7 @@ handler_requests_under_load(Config) -> {reset,[]}, {change_config,[]}]) end), - Sent = send_burst({t,10000}, seq, {chars,79}, info), + Sent = send_burst({t,10000}, seq, {chars,79}, notice), Pid ! {self(),finish}, ReqResult = receive {Pid,Result} -> Result end, Logged = count_lines(Log), @@ -1297,14 +1297,14 @@ add_remove_instance_nofile(Type) -> Pid = whereis(h_proc_name()), true = is_pid(Pid), group_leader(group_leader(),Pid), % to get printouts in test log - logger:info(M1=?msg,?domain), + logger:notice(M1=?msg,?domain), ?check(M1), %% check that sync doesn't do damage even if not relevant ok = logger_std_h:sync(?MODULE), ok = logger:remove_handler(?MODULE), timer:sleep(500), undefined = whereis(h_proc_name()), - logger:info(?msg,?domain), + logger:notice(?msg,?domain), ?check_no_log, ok. diff --git a/lib/sasl/src/sasl.erl b/lib/sasl/src/sasl.erl index ab041dbab8..5db3d75cfb 100644 --- a/lib/sasl/src/sasl.erl +++ b/lib/sasl/src/sasl.erl @@ -131,6 +131,10 @@ add_sasl_logger(std, undefined) -> ok; add_sasl_logger(Dest, Level) -> FC = #{legacy_header=>true, single_line=>false}, + case Level of + info -> allow_progress(); + _ -> ok + end, ok = logger:add_handler(sasl,logger_std_h, #{level=>Level, filter_default=>stop, @@ -151,6 +155,7 @@ delete_sasl_logger(_Type) -> add_error_logger_mf(undefined) -> ok; add_error_logger_mf({Dir, MaxB, MaxF}) -> + allow_progress(), error_logger:add_report_handler( log_mf_h, log_mf_h:init(Dir, MaxB, MaxF, fun pred/1)). @@ -161,6 +166,13 @@ delete_error_logger_mf(_) -> pred({_Type, GL, _Msg}) when node(GL) =/= node() -> false; pred(_) -> true. +allow_progress() -> + #{level:=PL} = logger:get_primary_config(), + case logger:compare_levels(info,PL) of + lt -> ok = logger:set_primary_config(level,info); + _ -> ok + end. + %%%----------------------------------------------------------------- %%% supervisor functionality %%%----------------------------------------------------------------- -- cgit v1.2.3