From 0fb9b241d11588bdae29aa64ff96d1eb67d230af Mon Sep 17 00:00:00 2001 From: Siri Hansen Date: Fri, 22 Feb 2019 16:03:08 +0100 Subject: [logger] Refactor logger_std_h --- lib/kernel/test/logger_std_h_SUITE.erl | 8 ++++---- 1 file changed, 4 insertions(+), 4 deletions(-) (limited to 'lib/kernel/test') diff --git a/lib/kernel/test/logger_std_h_SUITE.erl b/lib/kernel/test/logger_std_h_SUITE.erl index b2c2c8ba67..ba491ac5fa 100644 --- a/lib/kernel/test/logger_std_h_SUITE.erl +++ b/lib/kernel/test/logger_std_h_SUITE.erl @@ -646,7 +646,7 @@ sync(Config) -> formatter=>{?MODULE,nl}}), %% check repeated filesync happens - start_tracer([{logger_std_h, write_to_dev, 5}, + start_tracer([{logger_std_h, write_to_dev, 2}, {file, datasync, 1}], [{logger_std_h, write_to_dev, <<"first\n">>}, {file,datasync}]), @@ -656,7 +656,7 @@ sync(Config) -> check_tracer(filesync_rep_int()*2), %% check that explicit filesync is only done once - start_tracer([{logger_std_h, write_to_dev, 5}, + start_tracer([{logger_std_h, write_to_dev, 2}, {file, datasync, 1}], [{logger_std_h, write_to_dev, <<"second\n">>}, {file,datasync}, @@ -675,7 +675,7 @@ sync(Config) -> #{filesync_repeat_interval => no_repeat}), no_repeat = maps:get(filesync_repeat_interval, maps:get(cb_state, logger_olp:info(h_proc_name()))), - start_tracer([{logger_std_h, write_to_dev, 5}, + start_tracer([{logger_std_h, write_to_dev, 2}, {file, datasync, 1}], [{logger_std_h, write_to_dev, <<"third\n">>}, {file,datasync}, @@ -1658,7 +1658,7 @@ tpl([]) -> tracer({trace,_,call,{logger_h_common,handle_cast,[Op|_]}}, {Pid,[{Mod,Func,Op}|Expected]}) -> maybe_tracer_done(Pid,Expected,{Mod,Func,Op}); -tracer({trace,_,call,{Mod=logger_std_h,Func=write_to_dev,[_,Data,_,_,_]}}, +tracer({trace,_,call,{Mod=logger_std_h,Func=write_to_dev,[Data,_]}}, {Pid,[{Mod,Func,Data}|Expected]}) -> maybe_tracer_done(Pid,Expected,{Mod,Func,Data}); tracer({trace,_,call,{Mod,Func,_}}, {Pid,[{Mod,Func}|Expected]}) -> -- cgit v1.2.3 From e03c2bd640e1fc1503e92dfd74991f4205973c61 Mon Sep 17 00:00:00 2001 From: Siri Hansen Date: Tue, 5 Mar 2019 11:25:00 +0100 Subject: [logger] Add better control of file modes in logger_std_h OTP-15602 It is allowed to set file modes for the handler to use when opening its log file. The given modes were earlier accepted without any checks, which could make the handler behave unexpectedly. This commit makes sure that * if none of write, append or exclusive is given, then append is added * if raw is not given, it is added * if delayed_write or {delayed_write,_,_} is not given, then delayed_write is added --- lib/kernel/test/logger_SUITE.erl | 11 ++++++----- lib/kernel/test/logger_std_h_SUITE.erl | 23 ++++++++++++++--------- 2 files changed, 20 insertions(+), 14 deletions(-) (limited to 'lib/kernel/test') diff --git a/lib/kernel/test/logger_SUITE.erl b/lib/kernel/test/logger_SUITE.erl index 2dad651f9c..ce0c2efa10 100644 --- a/lib/kernel/test/logger_SUITE.erl +++ b/lib/kernel/test/logger_SUITE.erl @@ -1047,8 +1047,9 @@ kernel_config(Config) -> ok = rpc:call(Node,application,unset_env,[kernel,logger]), ok = rpc:call(Node,logger,internal_init_logger,[]), ok = rpc:call(Node,logger,add_handlers,[kernel]), + DefModes = [raw,append,delayed_write], #{primary:=#{filter_default:=log,filters:=[]}, - handlers:=[#{id:=default,filters:=DF,config:=#{type:={file,F}}}], + handlers:=[#{id:=default,filters:=DF,config:=#{type:={file,F,DefModes}}}], module_levels:=[]} = rpc:call(Node,logger,get_config,[]), %% Same, but using 'logger' parameter instead of 'error_logger' @@ -1060,26 +1061,26 @@ kernel_config(Config) -> ok = rpc:call(Node,logger,internal_init_logger,[]), ok = rpc:call(Node,logger,add_handlers,[kernel]), #{primary:=#{filter_default:=log,filters:=[]}, - handlers:=[#{id:=default,filters:=DF,config:=#{type:={file,F}}}], + handlers:=[#{id:=default,filters:=DF,config:=#{type:={file,F,DefModes}}}], module_levels:=[]} = rpc:call(Node,logger,get_config,[]), %% Same, but with type={file,File,Modes} ok = rpc:call(Node,logger,remove_handler,[default]),% so it can be added again ok = rpc:call(Node,application,unset_env,[kernel,error_logger]), - M = [raw,write,delayed_write], + M = [raw,write], ok = rpc:call(Node,application,set_env,[kernel,logger, [{handler,default,logger_std_h, #{config=>#{type=>{file,F,M}}}}]]), ok = rpc:call(Node,logger,internal_init_logger,[]), ok = rpc:call(Node,logger,add_handlers,[kernel]), #{primary:=#{filter_default:=log,filters:=[]}, - handlers:=[#{id:=default,filters:=DF,config:=#{type:={file,F,M}}}], + handlers:=[#{id:=default,filters:=DF, + config:=#{type:={file,F,[delayed_write|M]}}}], module_levels:=[]} = rpc:call(Node,logger,get_config,[]), %% Same, but with disk_log handler ok = rpc:call(Node,logger,remove_handler,[default]),% so it can be added again ok = rpc:call(Node,application,unset_env,[kernel,error_logger]), - M = [raw,write,delayed_write], ok = rpc:call(Node,application,set_env,[kernel,logger, [{handler,default,logger_disk_log_h, #{config=>#{file=>F}}}]]), diff --git a/lib/kernel/test/logger_std_h_SUITE.erl b/lib/kernel/test/logger_std_h_SUITE.erl index ba491ac5fa..8cadb1083b 100644 --- a/lib/kernel/test/logger_std_h_SUITE.erl +++ b/lib/kernel/test/logger_std_h_SUITE.erl @@ -257,9 +257,10 @@ errors(Config) -> end, {error, - {handler_not_added,{open_failed,Log,_}}} = + {handler_not_added, + {invalid_config,logger_std_h,#{type:={file,Log,bad_file_opt}}}}} = logger:add_handler(myh3,logger_std_h, - #{config=>#{type=>{file,Log,[bad_file_opt]}}}), + #{config=>#{type=>{file,Log,bad_file_opt}}}), ok = logger:notice(?msg). @@ -607,11 +608,14 @@ reconfig(cleanup, _Config) -> file_opts(Config) -> Dir = ?config(priv_dir,Config), Log = filename:join(Dir, lists:concat([?FUNCTION_NAME,".log"])), - BadFileOpts = [raw], - BadType = {file,Log,BadFileOpts}, - {error,{handler_not_added,{open_failed,Log,enoent}}} = - logger:add_handler(?MODULE, logger_std_h, - #{config => #{type => BadType}}), + MissingAccess = [raw], + Type1 = {file,Log,MissingAccess}, + ok = logger:add_handler(?MODULE, logger_std_h, + #{config => #{type => Type1}}), + {ok,#{config:=#{type:={file,Log,Modes1}}}} = + logger:get_handler_config(?MODULE), + [append,delayed_write,raw] = lists:sort(Modes1), + ok = logger:remove_handler(?MODULE), OkFileOpts = [raw,append], OkType = {file,Log,OkFileOpts}, @@ -622,9 +626,10 @@ file_opts(Config) -> filters=>?DEFAULT_HANDLER_FILTERS([?MODULE]), formatter=>{?MODULE,self()}}), - #{cb_state := #{handler_state := #{type := OkType}}} = + ModType = {file,Log,[delayed_write|OkFileOpts]}, + #{cb_state := #{handler_state := #{type := ModType}}} = logger_olp:info(h_proc_name()), - {ok,#{config := #{type := OkType}}} = logger:get_handler_config(?MODULE), + {ok,#{config := #{type := ModType}}} = logger:get_handler_config(?MODULE), logger:notice(M1=?msg,?domain), ?check(M1), B1 = ?bin(M1), -- cgit v1.2.3 From 56cacefda4f18c8fdc45839b6bec1d07d0d2d78e Mon Sep 17 00:00:00 2001 From: Siri Hansen Date: Thu, 28 Feb 2019 20:49:08 +0100 Subject: [logger] Add log file rotation by options to logger_std_h OTP-15479 OTP-15662 New configuration map for logger_std_h: #{type => file, file => file:filename(), modes => [file:mode()], max_no_bytes => pos_integer() | infinity, max_no_files => non_neg_integer(), compress_on_rotate => boolean()} For backwards compatibility, the old variant for specifying the file name via the 'type' parameter is still supported, i.e. {file,FileName} and {file,FileName,Modes}, but it is no longer documented. Rotation scheme: The current log file always has the same name, and the archived files get extensions ".0", ".1", ... The newest archive has extension ".0", and the oldest archive has the highest number. If 'compress_on_rotate' is set to true, the archived files are gzipped and get the additional extension ".gz", e.g. error.log.0.gz. Rotation is turned off by setting 'max_no_bytes' to infinity. Setting 'max_no_files' to 0 does not turn off rotation, but only specifies that no archives are to be saved. --- lib/kernel/test/logger_SUITE.erl | 11 +- lib/kernel/test/logger_std_h_SUITE.erl | 408 +++++++++++++++++++++++++++++++-- 2 files changed, 399 insertions(+), 20 deletions(-) (limited to 'lib/kernel/test') diff --git a/lib/kernel/test/logger_SUITE.erl b/lib/kernel/test/logger_SUITE.erl index ce0c2efa10..b7439a3fa8 100644 --- a/lib/kernel/test/logger_SUITE.erl +++ b/lib/kernel/test/logger_SUITE.erl @@ -1047,10 +1047,12 @@ kernel_config(Config) -> ok = rpc:call(Node,application,unset_env,[kernel,logger]), ok = rpc:call(Node,logger,internal_init_logger,[]), ok = rpc:call(Node,logger,add_handlers,[kernel]), - DefModes = [raw,append,delayed_write], #{primary:=#{filter_default:=log,filters:=[]}, - handlers:=[#{id:=default,filters:=DF,config:=#{type:={file,F,DefModes}}}], + handlers:=[#{id:=default,filters:=DF, + config:=#{type:=file,file:=F,modes:=Modes}}], module_levels:=[]} = rpc:call(Node,logger,get_config,[]), + [append,delayed_write,raw] = lists:sort(Modes), + %% Same, but using 'logger' parameter instead of 'error_logger' ok = rpc:call(Node,logger,remove_handler,[default]),% so it can be added again @@ -1061,7 +1063,8 @@ kernel_config(Config) -> ok = rpc:call(Node,logger,internal_init_logger,[]), ok = rpc:call(Node,logger,add_handlers,[kernel]), #{primary:=#{filter_default:=log,filters:=[]}, - handlers:=[#{id:=default,filters:=DF,config:=#{type:={file,F,DefModes}}}], + handlers:=[#{id:=default,filters:=DF, + config:=#{type:=file,file:=F,modes:=Modes}}], module_levels:=[]} = rpc:call(Node,logger,get_config,[]), %% Same, but with type={file,File,Modes} @@ -1075,7 +1078,7 @@ kernel_config(Config) -> ok = rpc:call(Node,logger,add_handlers,[kernel]), #{primary:=#{filter_default:=log,filters:=[]}, handlers:=[#{id:=default,filters:=DF, - config:=#{type:={file,F,[delayed_write|M]}}}], + config:=#{type:=file,file:=F,modes:=[delayed_write|M]}}], module_levels:=[]} = rpc:call(Node,logger,get_config,[]), %% Same, but with disk_log handler diff --git a/lib/kernel/test/logger_std_h_SUITE.erl b/lib/kernel/test/logger_std_h_SUITE.erl index 8cadb1083b..c3cae49ce8 100644 --- a/lib/kernel/test/logger_std_h_SUITE.erl +++ b/lib/kernel/test/logger_std_h_SUITE.erl @@ -112,6 +112,8 @@ all() -> add_remove_instance_standard_error, add_remove_instance_file1, add_remove_instance_file2, + add_remove_instance_file3, + add_remove_instance_file4, default_formatter, filter_config, errors, @@ -142,7 +144,12 @@ all() -> restart_after, handler_requests_under_load, recreate_deleted_log, - reopen_changed_log + reopen_changed_log, + rotate_size, + rotate_size_compressed, + rotate_size_reopen, + rotation_opts, + rotation_opts_restart_handler ]. add_remove_instance_tty(_Config) -> @@ -179,10 +186,27 @@ add_remove_instance_file2(Config) -> add_remove_instance_file2(cleanup,_Config) -> logger_std_h_remove(). -add_remove_instance_file(Log, Type) -> +add_remove_instance_file3(_Config) -> + Log = atom_to_list(?MODULE), + StdHConfig = #{type=>file}, + add_remove_instance_file(Log, StdHConfig). +add_remove_instance_file3(cleanup,_Config) -> + logger_std_h_remove(). + +add_remove_instance_file4(Config) -> + Dir = ?config(priv_dir,Config), + Log = filename:join(Dir,"stdlog4.txt"), + StdHConfig = #{file=>Log,modes=>[]}, + add_remove_instance_file(Log, StdHConfig). +add_remove_instance_file4(cleanup,_Config) -> + logger_std_h_remove(). + +add_remove_instance_file(Log, Type) when not is_map(Type) -> + add_remove_instance_file(Log,#{type=>Type}); +add_remove_instance_file(Log, StdHConfig) when is_map(StdHConfig) -> ok = logger:add_handler(?MODULE, logger_std_h, - #{config => #{type => Type}, + #{config => StdHConfig, filter_default=>stop, filters=>?DEFAULT_HANDLER_FILTERS([?MODULE]), formatter=>{?MODULE,self()}}), @@ -258,7 +282,7 @@ errors(Config) -> {error, {handler_not_added, - {invalid_config,logger_std_h,#{type:={file,Log,bad_file_opt}}}}} = + {invalid_config,logger_std_h,#{modes:=bad_file_opt}}}} = logger:add_handler(myh3,logger_std_h, #{config=>#{type=>{file,Log,bad_file_opt}}}), @@ -608,11 +632,11 @@ reconfig(cleanup, _Config) -> file_opts(Config) -> Dir = ?config(priv_dir,Config), Log = filename:join(Dir, lists:concat([?FUNCTION_NAME,".log"])), - MissingAccess = [raw], - Type1 = {file,Log,MissingAccess}, + MissingOpts = [raw], + Type1 = {file,Log,MissingOpts}, ok = logger:add_handler(?MODULE, logger_std_h, #{config => #{type => Type1}}), - {ok,#{config:=#{type:={file,Log,Modes1}}}} = + {ok,#{config:=#{type:=file,file:=Log,modes:=Modes1}}} = logger:get_handler_config(?MODULE), [append,delayed_write,raw] = lists:sort(Modes1), ok = logger:remove_handler(?MODULE), @@ -621,15 +645,38 @@ file_opts(Config) -> OkType = {file,Log,OkFileOpts}, ok = logger:add_handler(?MODULE, logger_std_h, - #{config => #{type => OkType}, + #{config => #{type => OkType}, % old format + filter_default=>log, + filters=>?DEFAULT_HANDLER_FILTERS([?MODULE]), + formatter=>{?MODULE,self()}}), + + ModOpts = [delayed_write|OkFileOpts], + #{cb_state := #{handler_state := #{type:=file, + file:=Log, + modes:=ModOpts}}} = + logger_olp:info(h_proc_name()), + {ok,#{config := #{type:=file, + file:=Log, + modes:=ModOpts}}} = logger:get_handler_config(?MODULE), + ok = logger:remove_handler(?MODULE), + + ok = logger:add_handler(?MODULE, + logger_std_h, + #{config => #{type => file, + file => Log, + modes => OkFileOpts}, % new format filter_default=>log, filters=>?DEFAULT_HANDLER_FILTERS([?MODULE]), formatter=>{?MODULE,self()}}), - ModType = {file,Log,[delayed_write|OkFileOpts]}, - #{cb_state := #{handler_state := #{type := ModType}}} = + #{cb_state := #{handler_state := #{type:=file, + file:=Log, + modes:=ModOpts}}} = logger_olp:info(h_proc_name()), - {ok,#{config := #{type := ModType}}} = logger:get_handler_config(?MODULE), + {ok,#{config := #{type:=file, + file:=Log, + modes:=ModOpts}}} = + logger:get_handler_config(?MODULE), logger:notice(M1=?msg,?domain), ?check(M1), B1 = ?bin(M1), @@ -1290,6 +1337,331 @@ reopen_changed_log(Config) -> reopen_changed_log(cleanup, _Config) -> ok = stop_handler(?MODULE). +rotate_size(Config) -> + {Log,_HConfig,_StdHConfig} = + start_handler(?MODULE, ?FUNCTION_NAME, Config), + ok = logger:update_handler_config(?MODULE,#{config=>#{max_no_bytes=>1000, + max_no_files=>2}}), + + Str = lists:duplicate(19,$a), + [logger:notice(Str,?domain) || _ <- lists:seq(1,50)], + logger_std_h:filesync(?MODULE), + {ok,#file_info{size=1000}} = file:read_file_info(Log), + {error,enoent} = file:read_file_info(Log++".0"), + + logger:notice(Str,?domain), + logger_std_h:filesync(?MODULE), + {ok,#file_info{size=0}} = file:read_file_info(Log), + {ok,#file_info{size=1020}} = file:read_file_info(Log++".0"), + {error,enoent} = file:read_file_info(Log++".1"), + + [logger:notice(Str,?domain) || _ <- lists:seq(1,51)], + logger_std_h:filesync(?MODULE), + {ok,#file_info{size=0}} = file:read_file_info(Log), + {ok,#file_info{size=1020}} = file:read_file_info(Log++".0"), + {ok,#file_info{size=1020}} = file:read_file_info(Log++".1"), + {error,enoent} = file:read_file_info(Log++".2"), + + [logger:notice(Str,?domain) || _ <- lists:seq(1,50)], + logger_std_h:filesync(?MODULE), + {ok,#file_info{size=1000}} = file:read_file_info(Log), + {ok,#file_info{size=1020}} = file:read_file_info(Log++".0"), + {ok,#file_info{size=1020}} = file:read_file_info(Log++".1"), + {error,enoent} = file:read_file_info(Log++".2"), + + logger:notice("bbbb",?domain), + logger_std_h:filesync(?MODULE), + {ok,#file_info{size=0}} = file:read_file_info(Log), + {ok,#file_info{size=1005}} = file:read_file_info(Log++".0"), + {ok,#file_info{size=1020}} = file:read_file_info(Log++".1"), + {error,enoent} = file:read_file_info(Log++".2"), + + ok. +rotate_size(cleanup,_Config) -> + ok = stop_handler(?MODULE). + +rotate_size_compressed(Config) -> + {Log,_HConfig,_StdHConfig} = + start_handler(?MODULE, ?FUNCTION_NAME, Config), + ok = logger:update_handler_config(?MODULE, + #{config=>#{max_no_bytes=>1000, + max_no_files=>2, + compress_on_rotate=>true}}), + Str = lists:duplicate(19,$a), + [logger:notice(Str,?domain) || _ <- lists:seq(1,50)], + logger_std_h:filesync(?MODULE), + {ok,#file_info{size=1000}} = file:read_file_info(Log), + {error,enoent} = file:read_file_info(Log++".0"), + {error,enoent} = file:read_file_info(Log++".0.gz"), + + logger:notice(Str,?domain), + logger_std_h:filesync(?MODULE), + {ok,#file_info{size=0}} = file:read_file_info(Log), + {error,enoent} = file:read_file_info(Log++".0"), + {ok,#file_info{size=35}} = file:read_file_info(Log++".0.gz"), + {error,enoent} = file:read_file_info(Log++".1"), + {error,enoent} = file:read_file_info(Log++".1.gz"), + + [logger:notice(Str,?domain) || _ <- lists:seq(1,51)], + logger_std_h:filesync(?MODULE), + {ok,#file_info{size=0}} = file:read_file_info(Log), + {error,enoent} = file:read_file_info(Log++".0"), + {ok,#file_info{size=35}} = file:read_file_info(Log++".0.gz"), + {error,enoent} = file:read_file_info(Log++".1"), + {ok,#file_info{size=35}} = file:read_file_info(Log++".1.gz"), + {error,enoent} = file:read_file_info(Log++".2"), + {error,enoent} = file:read_file_info(Log++".2.gz"), + + [logger:notice(Str,?domain) || _ <- lists:seq(1,50)], + logger_std_h:filesync(?MODULE), + {ok,#file_info{size=1000}} = file:read_file_info(Log), + {error,enoent} = file:read_file_info(Log++".0"), + {ok,#file_info{size=35}} = file:read_file_info(Log++".0.gz"), + {error,enoent} = file:read_file_info(Log++".1"), + {ok,#file_info{size=35}} = file:read_file_info(Log++".1.gz"), + {error,enoent} = file:read_file_info(Log++".2"), + {error,enoent} = file:read_file_info(Log++".2.gz"), + + logger:notice("bbbb",?domain), + logger_std_h:filesync(?MODULE), + {ok,#file_info{size=0}} = file:read_file_info(Log), + {error,enoent} = file:read_file_info(Log++".0"), + {ok,#file_info{size=38}} = file:read_file_info(Log++".0.gz"), + {error,enoent} = file:read_file_info(Log++".1"), + {ok,#file_info{size=35}} = file:read_file_info(Log++".1.gz"), + {error,enoent} = file:read_file_info(Log++".2"), + {error,enoent} = file:read_file_info(Log++".2.gz"), + + ok. +rotate_size_compressed(cleanup,_Config) -> + ok = stop_handler(?MODULE). + +rotate_size_reopen(Config) -> + {Log,_HConfig,_StdHConfig} = + start_handler(?MODULE, ?FUNCTION_NAME, Config), + ok = logger:update_handler_config(?MODULE,#{config=>#{max_no_bytes=>1000, + max_no_files=>2}}), + + Str = lists:duplicate(19,$a), + [logger:notice(Str,?domain) || _ <- lists:seq(1,40)], + logger_std_h:filesync(?MODULE), + {ok,#file_info{size=800}} = file:read_file_info(Log), + + {ok,HConfig} = logger:get_handler_config(?MODULE), + ok = logger:remove_handler(?MODULE), + ok = logger:add_handler(?MODULE,maps:get(module,HConfig),HConfig), + {ok,#file_info{size=800}} = file:read_file_info(Log), + + [logger:notice(Str,?domain) || _ <- lists:seq(1,40)], + logger_std_h:filesync(?MODULE), + {ok,#file_info{size=580}} = file:read_file_info(Log), + {ok,#file_info{size=1020}} = file:read_file_info(Log++".0"), + ok. +rotate_size_reopen(cleanup,Config) -> + ok = stop_handler(?MODULE). + +rotation_opts(Config) -> + {Log,_HConfig,StdHConfig} = + start_handler(?MODULE, ?FUNCTION_NAME, Config), + #{max_no_bytes:=infinity, + max_no_files:=0, + compress_on_rotate:=false} = StdHConfig, + + %% Test bad rotation config + {error,{invalid_config,_,_}} = + logger:update_handler_config(?MODULE,config,#{max_no_bytes=>0}), + {error,{invalid_config,_,_}} = + logger:update_handler_config(?MODULE,config,#{max_no_files=>infinity}), + {error,{invalid_config,_,_}} = + logger:update_handler_config(?MODULE,config, + #{compress_on_rotate=>undefined}), + + + %% Test good rotation config - start with no rotation + Str = lists:duplicate(19,$a), + [logger:notice(Str,?domain) || _ <- lists:seq(1,10)], + logger_std_h:filesync(?MODULE), + {ok,#file_info{size=200}} = file:read_file_info(Log), + [] = filelib:wildcard(Log++".*"), + + %% Turn on rotation, check that existing file is rotated since its + %% size exceeds max_no_bytes + ok = logger:update_handler_config(?MODULE, + config, + #{max_no_bytes=>100, + max_no_files=>2}), + timer:sleep(100), % give some time to execute config_changed + {ok,#file_info{size=0}} = file:read_file_info(Log), + Log0 = Log++".0", + {ok,#file_info{size=200}} = file:read_file_info(Log0), + [Log0] = filelib:wildcard(Log++".*"), + + %% Fill all logs + [logger:notice(Str,?domain) || _ <- lists:seq(1,13)], + logger_std_h:filesync(?MODULE), + {ok,#file_info{size=20}} = file:read_file_info(Log), + {ok,#file_info{size=120}} = file:read_file_info(Log0), + {ok,#file_info{size=120}} = file:read_file_info(Log++".1"), + [_,_] = filelib:wildcard(Log++".*"), + + %% Extend size and count and check that nothing changes with existing files + ok = logger:update_handler_config(?MODULE, + config, + #{max_no_bytes=>200, + max_no_files=>3}), + timer:sleep(100), % give some time to execute config_changed + {ok,#file_info{size=20}} = file:read_file_info(Log), + {ok,#file_info{size=120}} = file:read_file_info(Log0), + {ok,#file_info{size=120}} = file:read_file_info(Log++".1"), + [_,_] = filelib:wildcard(Log++".*"), + + %% Add more log events and see that extended size and count works + [logger:notice(Str,?domain) || _ <- lists:seq(1,10)], + logger_std_h:filesync(?MODULE), + {ok,#file_info{size=0}} = file:read_file_info(Log), + {ok,#file_info{size=220}} = file:read_file_info(Log0), + {ok,#file_info{size=120}} = file:read_file_info(Log++".1"), + {ok,#file_info{size=120}} = file:read_file_info(Log++".2"), + [_,_,_] = filelib:wildcard(Log++".*"), + + %% Reduce count and check that archive files that exceed the new + %% count are moved + ok = logger:update_handler_config(?MODULE, + config, + #{max_no_files=>1}), + timer:sleep(100), % give some time to execute config_changed + {ok,#file_info{size=0}} = file:read_file_info(Log), + {ok,#file_info{size=220}} = file:read_file_info(Log0), + [Log0] = filelib:wildcard(Log++".*"), + + %% Extend size and count again, and turn on compression. Check + %% that archives are compressed + ok = logger:update_handler_config(?MODULE, + config, + #{max_no_bytes=>100, + max_no_files=>2, + compress_on_rotate=>true}), + timer:sleep(100), % give some time to execute config_changed + {ok,#file_info{size=0}} = file:read_file_info(Log), + Log0gz = Log0++".gz", + {ok,#file_info{size=29}} = file:read_file_info(Log0gz), + [Log0gz] = filelib:wildcard(Log++".*"), + + %% Fill all logs + [logger:notice(Str,?domain) || _ <- lists:seq(1,13)], + logger_std_h:filesync(?MODULE), + {ok,#file_info{size=20}} = file:read_file_info(Log), + {ok,#file_info{size=29}} = file:read_file_info(Log0gz), + {ok,#file_info{size=29}} = file:read_file_info(Log++".1.gz"), + [_,_] = filelib:wildcard(Log++".*"), + + %% Reduce count and turn off compression. Check that archives that + %% exceeds the new count are removed, and the rest are + %% uncompressed. + ok = logger:update_handler_config(?MODULE, + config, + #{max_no_files=>1, + compress_on_rotate=>false}), + timer:sleep(100), % give some time to execute config_changed + {ok,#file_info{size=20}} = file:read_file_info(Log), + {ok,#file_info{size=120}} = file:read_file_info(Log0), + [Log0] = filelib:wildcard(Log++".*"), + + %% Check that config and handler state agree on the current rotation settings + {ok,#{config:=#{max_no_bytes:=100, + max_no_files:=1, + compress_on_rotate:=false}}} = + logger:get_handler_config(?MODULE), + #{cb_state:=#{handler_state:=#{max_no_bytes:=100, + max_no_files:=1, + compress_on_rotate:=false}}} = + logger_olp:info(h_proc_name()), + ok. +rotation_opts(cleanup,Config) -> + ok = stop_handler(?MODULE). + +rotation_opts_restart_handler(Config) -> + {Log,_HConfig,_StdHConfig} = + start_handler(?MODULE, ?FUNCTION_NAME, Config), + ok = logger:update_handler_config(?MODULE, + config, + #{max_no_bytes=>100, + max_no_files=>2}), + + %% Fill all logs + Str = lists:duplicate(19,$a), + [logger:notice(Str,?domain) || _ <- lists:seq(1,15)], + logger_std_h:filesync(?MODULE), + {ok,#file_info{size=60}} = file:read_file_info(Log), + {ok,#file_info{size=120}} = file:read_file_info(Log++".0"), + {ok,#file_info{size=120}} = file:read_file_info(Log++".1"), + [_,_] = filelib:wildcard(Log++".*"), + + %% Stop/start handler and turn off rotation. Check that archives are removed. + {ok,#{config:=StdHConfig1}=HConfig1} = logger:get_handler_config(?MODULE), + ok = logger:remove_handler(?MODULE), + ok = logger:add_handler( + ?MODULE,logger_std_h, + HConfig1#{config=>StdHConfig1#{max_no_bytes=>infinity}}), + timer:sleep(100), + {ok,#file_info{size=60}} = file:read_file_info(Log), + [] = filelib:wildcard(Log++".*"), + + %% Add some log events and check that file is no longer rotated. + [logger:notice(Str,?domain) || _ <- lists:seq(1,10)], + logger_std_h:filesync(?MODULE), + {ok,#file_info{size=260}} = file:read_file_info(Log), + [] = filelib:wildcard(Log++".*"), + + %% Stop/start handler and trun on rotation. Check that file is rotated. + {ok,#{config:=StdHConfig2}=HConfig2} = logger:get_handler_config(?MODULE), + ok = logger:remove_handler(?MODULE), + ok = logger:add_handler( + ?MODULE,logger_std_h, + HConfig2#{config=>StdHConfig2#{max_no_bytes=>100, + max_no_files=>2}}), + timer:sleep(100), + {ok,#file_info{size=0}} = file:read_file_info(Log), + {ok,#file_info{size=260}} = file:read_file_info(Log++".0"), + [_] = filelib:wildcard(Log++".*"), + + %% Fill all logs + [logger:notice(Str,?domain) || _ <- lists:seq(1,10)], + logger_std_h:filesync(?MODULE), + {ok,#file_info{size=80}} = file:read_file_info(Log), + {ok,#file_info{size=120}} = file:read_file_info(Log++".0"), + {ok,#file_info{size=260}} = file:read_file_info(Log++".1"), + + %% Stop/start handler, reduce count and turn on compression. Check + %% that excess archives are removed, and the rest compressed. + {ok,#{config:=StdHConfig3}=HConfig3} = logger:get_handler_config(?MODULE), + ok = logger:remove_handler(?MODULE), + ok = logger:add_handler( + ?MODULE,logger_std_h, + HConfig3#{config=>StdHConfig3#{max_no_bytes=>75, + max_no_files=>1, + compress_on_rotate=>true}}), + timer:sleep(100), + {ok,#file_info{size=0}} = file:read_file_info(Log), + {ok,#file_info{size=29}} = file:read_file_info(Log++".0.gz"), + [_] = filelib:wildcard(Log++".*"), + + %% Stop/start handler and turn off compression. Check that achives + %% are decompressed. + {ok,#{config:=StdHConfig4}=HConfig4} = logger:get_handler_config(?MODULE), + ok = logger:remove_handler(?MODULE), + ok = logger:add_handler( + ?MODULE,logger_std_h, + HConfig4#{config=>StdHConfig4#{compress_on_rotate=>false}}), + timer:sleep(100), + {ok,#file_info{size=0}} = file:read_file_info(Log), + {ok,#file_info{size=80}} = file:read_file_info(Log++".0"), + [_] = filelib:wildcard(Log++".*"), + + ok. +rotation_opts_restart_handler(cleanup,Config) -> + ok = stop_handler(?MODULE). + %%%----------------------------------------------------------------- %%% send_requests(TO, Reqs = [{Mod,Func,Args,Res}|Rs]) -> @@ -1310,8 +1682,8 @@ start_handler(Name, TTY, _Config) when TTY == standard_io; ok = logger:add_handler(Name, logger_std_h, #{config => #{type => TTY}, - filter_default=>log, - filters=>?DEFAULT_HANDLER_FILTERS([Name]), + filter_default=>stop, + filters=>filter_only_this_domain(Name), formatter=>{?MODULE,op}}), {ok,HConfig = #{config := StdHConfig}} = logger:get_handler_config(Name), {HConfig,StdHConfig}; @@ -1325,12 +1697,17 @@ start_handler(Name, FuncName, Config) -> ok = logger:add_handler(Name, logger_std_h, #{config => #{type => Type}, - filter_default=>log, - filters=>?DEFAULT_HANDLER_FILTERS([Name]), + filter_default=>stop, + filters=>filter_only_this_domain(Name), formatter=>{?MODULE,op}}), {ok,HConfig = #{config := StdHConfig}} = logger:get_handler_config(Name), {Log,HConfig,StdHConfig}. + +filter_only_this_domain(Name) -> + [{remote_gl,{fun logger_filters:remote_gl/2,stop}}, + {domain,{fun logger_filters:domain/2,{log,super,[Name]}}}]. + stop_handler(Name) -> R = logger:remove_handler(Name), ct:pal("Handler ~p stopped! Result: ~p", [Name,R]), @@ -1747,4 +2124,3 @@ filesync_rep_int() -> file_delete(Log) -> file:delete(Log). - -- cgit v1.2.3 From e2af137524ac6a645689daf309871893dcc655a1 Mon Sep 17 00:00:00 2001 From: Siri Hansen Date: Mon, 4 Mar 2019 19:15:24 +0100 Subject: [logger] Add option file_check to logger_std_h OTP-15663 This option indicates how often the handler shall check if the log file still exists and if the inode is changed. --- lib/kernel/test/logger_std_h_SUITE.erl | 11 ++++++----- 1 file changed, 6 insertions(+), 5 deletions(-) (limited to 'lib/kernel/test') diff --git a/lib/kernel/test/logger_std_h_SUITE.erl b/lib/kernel/test/logger_std_h_SUITE.erl index c3cae49ce8..0c5516f82b 100644 --- a/lib/kernel/test/logger_std_h_SUITE.erl +++ b/lib/kernel/test/logger_std_h_SUITE.erl @@ -650,7 +650,7 @@ file_opts(Config) -> filters=>?DEFAULT_HANDLER_FILTERS([?MODULE]), formatter=>{?MODULE,self()}}), - ModOpts = [delayed_write|OkFileOpts], + ModOpts = [delayed_write|OkFileOpts], #{cb_state := #{handler_state := #{type:=file, file:=Log, modes:=ModOpts}}} = @@ -692,7 +692,8 @@ sync(Config) -> Type = {file,Log}, ok = logger:add_handler(?MODULE, logger_std_h, - #{config => #{type => Type}, + #{config => #{type => Type, + file_check => 10000}, filter_default=>log, filters=>?DEFAULT_HANDLER_FILTERS([?MODULE]), formatter=>{?MODULE,nl}}), @@ -1457,7 +1458,7 @@ rotate_size_reopen(Config) -> {ok,#file_info{size=580}} = file:read_file_info(Log), {ok,#file_info{size=1020}} = file:read_file_info(Log++".0"), ok. -rotate_size_reopen(cleanup,Config) -> +rotate_size_reopen(cleanup,_Config) -> ok = stop_handler(?MODULE). rotation_opts(Config) -> @@ -1577,7 +1578,7 @@ rotation_opts(Config) -> compress_on_rotate:=false}}} = logger_olp:info(h_proc_name()), ok. -rotation_opts(cleanup,Config) -> +rotation_opts(cleanup,_Config) -> ok = stop_handler(?MODULE). rotation_opts_restart_handler(Config) -> @@ -1659,7 +1660,7 @@ rotation_opts_restart_handler(Config) -> [_] = filelib:wildcard(Log++".*"), ok. -rotation_opts_restart_handler(cleanup,Config) -> +rotation_opts_restart_handler(cleanup,_Config) -> ok = stop_handler(?MODULE). %%%----------------------------------------------------------------- -- cgit v1.2.3