diff options
author | Siri Hansen <[email protected]> | 2018-09-17 12:45:07 +0200 |
---|---|---|
committer | Siri Hansen <[email protected]> | 2018-09-17 12:45:07 +0200 |
commit | 926bfd6f0bd71a8942f268cf23a37b55776600d2 (patch) | |
tree | 0f8d6c9101815eb4245035dd5e43cb93676b8fdd /lib/kernel/test/logger_disk_log_h_SUITE.erl | |
parent | 3a33f5ffe2d130789a7ebc45df75dbb56988016e (diff) | |
parent | 6073d37a5a0691704d0fa1a5ff9289ba9e35c8ed (diff) | |
download | otp-926bfd6f0bd71a8942f268cf23a37b55776600d2.tar.gz otp-926bfd6f0bd71a8942f268cf23a37b55776600d2.tar.bz2 otp-926bfd6f0bd71a8942f268cf23a37b55776600d2.zip |
Merge branch 'siri/logger/post-21-continues/OTP-15132' into maint
* siri/logger/post-21-continues/OTP-15132:
[logger] Read config before terminating handler process
[error_logger] Handle report_cb with arity 2
[proc_lib] Improve crash reports for single line logging
[logger] Include single_line option to report_cb
[logger] Check for deadlock when removing filters
[logger] Fix spec for handler callbacks to always return ok
[logger] Increase timetrap timer for handler_requests_under_load test
[logger] Improve code coverage in test
[logger] Refactor, and add error detection for configuration
[logger] Fix logger_disk_log_h_SUITE:sync and add som debug info
[logger] Update doc about file options in logger_std_h
[logger] Remove encoding option from logger_formatter
Remove outdated reference to error loggers
[logger] Refactor some logger internals
Diffstat (limited to 'lib/kernel/test/logger_disk_log_h_SUITE.erl')
-rw-r--r-- | lib/kernel/test/logger_disk_log_h_SUITE.erl | 66 |
1 files changed, 29 insertions, 37 deletions
diff --git a/lib/kernel/test/logger_disk_log_h_SUITE.erl b/lib/kernel/test/logger_disk_log_h_SUITE.erl index a4b15c841b..a815db14e9 100644 --- a/lib/kernel/test/logger_disk_log_h_SUITE.erl +++ b/lib/kernel/test/logger_disk_log_h_SUITE.erl @@ -367,7 +367,7 @@ formatter_fail(Config) -> ok = logger:set_handler_config(Name,formatter,{?MODULE,bad_return}), logger:notice(?msg,?domain), try_match_file(?log_no(LogFile,1), - escape(Got3)++"FORMATTER ERROR: bad_return_value", + escape(Got3)++"FORMATTER ERROR: bad return value", 5000), %% Check that handler is still alive and was never dead @@ -524,27 +524,14 @@ sync(Config) -> formatter=>{?MODULE,nl}}), start_tracer([{disk_log,blog,2}, - {disk_log,sync,1}], + {logger_disk_log_h,disk_log_sync,2}], [{disk_log,blog,<<"first\n">>}, - {disk_log,sync}]), + {logger_disk_log_h,disk_log_sync}]), logger:notice("first", ?domain), %% wait for automatic disk_log_sync check_tracer(?FILESYNC_REPEAT_INTERVAL*2), - start_tracer([{disk_log,blog,2}, - {disk_log,sync,1}], - [{disk_log,blog,<<"second\n">>}, - {disk_log,blog,<<"third\n">>}, - {disk_log,sync}]), - %% two log requests in fast succession will make the handler skip - %% an automatic disk log sync - logger:notice("second", ?domain), - logger:notice("third", ?domain), - %% do explicit sync - logger_disk_log_h:filesync(?MODULE), - check_tracer(100), - %% check that if there's no repeated disk_log_sync active, %% a disk_log_sync is still performed when handler goes idle {ok,#{config := HConfig}} = logger:get_handler_config(?MODULE), @@ -553,20 +540,25 @@ sync(Config) -> no_repeat = maps:get(filesync_repeat_interval, logger_disk_log_h:info(?MODULE)), + %% The following timer is to make sure the time from last log + %% ("first") to next ("second") is long enough, so the a flush is + %% triggered by the idle timeout between "fourth" and "fifth". + timer:sleep(?IDLE_DETECT_TIME_MSEC*2), start_tracer([{disk_log,blog,2}, - {disk_log,sync,1}], - [{disk_log,blog,<<"fourth\n">>}, - {disk_log,blog,<<"fifth\n">>}, - {disk_log,sync}]), + {logger_disk_log_h,disk_log_sync,2}], + [{disk_log,blog,<<"second\n">>}, + {logger_disk_log_h,disk_log_sync}, + {disk_log,blog,<<"third\n">>}, + {logger_disk_log_h,disk_log_sync}]), - logger:notice("fourth", ?domain), + logger:notice("second", ?domain), timer:sleep(?IDLE_DETECT_TIME_MSEC*2), - logger:notice("fifth", ?domain), + logger:notice("third", ?domain), %% wait for automatic disk_log_sync check_tracer(?IDLE_DETECT_TIME_MSEC*2), - try_read_file(Log, {ok,<<"first\nsecond\nthird\nfourth\nfifth\n">>}, 1000), + try_read_file(Log, {ok,<<"first\nsecond\nthird\n">>}, 1000), %% switch repeated disk_log_sync on and verify that the looping works SyncInt = 1000, @@ -1194,7 +1186,7 @@ restart_after(cleanup, _Config) -> %% during high load to verify that sync, dropping and flushing is %% handled correctly. handler_requests_under_load() -> - [{timetrap,{minutes,3}}]. + [{timetrap,{minutes,5}}]. handler_requests_under_load(Config) -> {Log,HConfig,DLHConfig} = start_handler(?MODULE, ?FUNCTION_NAME, Config), NewHConfig = @@ -1494,7 +1486,7 @@ start_tracer(Trace,Expected) -> ok. tpl([{M,F,A}|Trace]) -> - {ok,Match} = dbg:tpl(M,F,A,[]), + {ok,Match} = dbg:tpl(M,F,A,c), case lists:keyfind(matched,1,Match) of {_,_,1} -> ok; @@ -1507,23 +1499,23 @@ tpl([{M,F,A}|Trace]) -> tpl([]) -> ok. -tracer({trace,_,call,{logger_disk_log_h,handle_cast,[Op|_]}}, +tracer({trace,_,call,{logger_disk_log_h,handle_cast,[Op|_]},Caller}, {Pid,[{Mod,Func,Op}|Expected]}) -> - maybe_tracer_done(Pid,Expected,{Mod,Func,Op}); -tracer({trace,_,call,{Mod=disk_log,Func=blog,[_,Data]}}, {Pid,[{Mod,Func,Data}|Expected]}) -> - maybe_tracer_done(Pid,Expected,{Mod,Func,Data}); -tracer({trace,_,call,{Mod,Func,_}}, {Pid,[{Mod,Func}|Expected]}) -> - maybe_tracer_done(Pid,Expected,{Mod,Func}); -tracer({trace,_,call,Call}, {Pid,Expected}) -> - ct:log("Tracer got unexpected: ~p~nExpected: ~p~n",[Call,Expected]), + maybe_tracer_done(Pid,Expected,{Mod,Func,Op},Caller); +tracer({trace,_,call,{Mod=disk_log,Func=blog,[_,Data]},Caller}, {Pid,[{Mod,Func,Data}|Expected]}) -> + maybe_tracer_done(Pid,Expected,{Mod,Func,Data},Caller); +tracer({trace,_,call,{Mod,Func,_},Caller}, {Pid,[{Mod,Func}|Expected]}) -> + maybe_tracer_done(Pid,Expected,{Mod,Func},Caller); +tracer({trace,_,call,Call,Caller}, {Pid,Expected}) -> + ct:log("Tracer got unexpected: ~p~nCaller: ~p~nExpected: ~p~n",[Call,Caller,Expected]), Pid ! {tracer_got_unexpected,Call,Expected}, {Pid,Expected}. -maybe_tracer_done(Pid,[],Got) -> - ct:log("Tracer got: ~p~n",[Got]), +maybe_tracer_done(Pid,[],Got,Caller) -> + ct:log("Tracer got: ~p~nCaller: ~p~n",[Got,Caller]), Pid ! tracer_done; -maybe_tracer_done(Pid,Expected,Got) -> - ct:log("Tracer got: ~p~n",[Got]), +maybe_tracer_done(Pid,Expected,Got,Caller) -> + ct:log("Tracer got: ~p~nCaller: ~p~n",[Got,Caller]), {Pid,Expected}. check_tracer(T) -> |