From 291cf6d8530f4e0ad2f22f199b5ae6975135bbb3 Mon Sep 17 00:00:00 2001 From: Siri Hansen Date: Tue, 24 Apr 2018 15:18:31 +0200 Subject: Test cuddle for logger --- lib/common_test/test/ct_hooks_SUITE.erl | 21 ++++++---- .../cth/tests/cth_log_SUITE.erl | 2 +- lib/common_test/test/ct_pre_post_test_io_SUITE.erl | 4 +- lib/kernel/test/application_SUITE.erl | 3 +- lib/kernel/test/error_logger_SUITE.erl | 46 ++++++++++++++++++++-- lib/kernel/test/init_SUITE.erl | 6 +-- lib/kernel/test/wrap_log_reader_SUITE.erl | 17 ++++---- .../wrap_log_reader_SUITE_data/wrap_log_test.erl | 24 +++++------ lib/sasl/test/sasl_SUITE.erl | 14 +++++++ lib/sasl/test/sasl_report_SUITE.erl | 18 +++++---- lib/stdlib/test/error_logger_h_SUITE.erl | 5 ++- lib/stdlib/test/proc_lib_SUITE.erl | 11 +++--- 12 files changed, 119 insertions(+), 52 deletions(-) (limited to 'lib') diff --git a/lib/common_test/test/ct_hooks_SUITE.erl b/lib/common_test/test/ct_hooks_SUITE.erl index 3c1e887f65..6228524a88 100644 --- a/lib/common_test/test/ct_hooks_SUITE.erl +++ b/lib/common_test/test/ct_hooks_SUITE.erl @@ -258,15 +258,20 @@ cth_log(Config) when is_list(Config) -> fun(UnexpIoLog) -> {ok,Bin} = file:read_file(UnexpIoLog), Ts = string:lexemes(binary_to_list(Bin),[$\n]), - Matches = lists:foldl(fun([$=,$E,$R,$R,$O,$R|_], N) -> - N+1; - ([$L,$o,$g,$g,$e,$r|_], N) -> - N+1; + Matches = lists:foldl(fun([$=,$E,$R,$R,$O,$R|_], {E,I,L}) -> + {E+1,I,L}; + ([$=,$I,$N,$F,$O|_], {E,I,L}) -> + {E,I+1,L}; + ([$L,$o,$g,$g,$e,$r|_], {E,I,L}) -> + {E,I,L+1}; (_, N) -> N - end, 0, Ts), - ct:pal("~p matches in ~tp", [Matches,UnexpIoLog]), - if Matches > 10 -> ok; - true -> exit({no_unexpected_io_found,UnexpIoLog}) + end, {0,0,0}, Ts), + ct:pal("~p ({Error,Info,Log}) matches in ~tp", + [Matches,UnexpIoLog]), + MatchList = tuple_to_list(Matches), + case [N || N <- MatchList, N<3] of + [] -> ok; + _ -> exit({missing_unexpected_io,UnexpIoLog}) end end, UnexpIoLogs), ok. diff --git a/lib/common_test/test/ct_hooks_SUITE_data/cth/tests/cth_log_SUITE.erl b/lib/common_test/test/ct_hooks_SUITE_data/cth/tests/cth_log_SUITE.erl index bd1ac54781..a0cd77b88b 100644 --- a/lib/common_test/test/ct_hooks_SUITE_data/cth/tests/cth_log_SUITE.erl +++ b/lib/common_test/test/ct_hooks_SUITE_data/cth/tests/cth_log_SUITE.erl @@ -124,6 +124,6 @@ gen() -> gen_loop(N) -> ct:log("Logger iteration: ~p", [N]), error_logger:error_report(N), - error_logger:info_report(progress, N), + error_logger:info_report(N), ct:sleep(150), gen_loop(N+1). diff --git a/lib/common_test/test/ct_pre_post_test_io_SUITE.erl b/lib/common_test/test/ct_pre_post_test_io_SUITE.erl index 0b85392009..538fd822c1 100644 --- a/lib/common_test/test/ct_pre_post_test_io_SUITE.erl +++ b/lib/common_test/test/ct_pre_post_test_io_SUITE.erl @@ -241,7 +241,7 @@ try_loop(_Fun, 0) -> gave_up; try_loop(Fun, N) -> try Fun() of - {error,_} -> + {Error,_} when Error==error; Error==badrpc -> timer:sleep(10), try_loop(Fun, N-1); Result -> @@ -257,7 +257,7 @@ try_loop(M, F, _A, 0) -> gave_up; try_loop(M, F, A, N) -> try apply(M, F, A) of - {error,_} -> + {Error,_Reason} when Error==error; Error==badrpc -> timer:sleep(10), try_loop(M, F, A, N-1); Result -> diff --git a/lib/kernel/test/application_SUITE.erl b/lib/kernel/test/application_SUITE.erl index 866043cfb4..c00fb44c46 100644 --- a/lib/kernel/test/application_SUITE.erl +++ b/lib/kernel/test/application_SUITE.erl @@ -1568,7 +1568,8 @@ loop5606(Pid) -> %% Tests get_env/* functions. get_env(Conf) when is_list(Conf) -> - {ok, _} = application:get_env(kernel, error_logger), + ok = application:set_env(kernel, new_var, new_val), + {ok, new_val} = application:get_env(kernel, new_var), undefined = application:get_env(undefined_app, a), undefined = application:get_env(kernel, error_logger_xyz), default = application:get_env(kernel, error_logger_xyz, default), diff --git a/lib/kernel/test/error_logger_SUITE.erl b/lib/kernel/test/error_logger_SUITE.erl index 2d26a7246c..6c4526d0cf 100644 --- a/lib/kernel/test/error_logger_SUITE.erl +++ b/lib/kernel/test/error_logger_SUITE.erl @@ -32,7 +32,8 @@ init_per_group/2,end_per_group/2, off_heap/1, error_report/1, info_report/1, error/1, info/1, - emulator/1, tty/1, logfile/1, add/1, delete/1]). + emulator/1, via_logger_process/1, other_node/1, + tty/1, logfile/1, add/1, delete/1]). -export([generate_error/2]). @@ -46,16 +47,19 @@ suite() -> {timetrap,{minutes,1}}]. all() -> - [off_heap, error_report, info_report, error, info, emulator, tty, - logfile, add, delete]. + [off_heap, error_report, info_report, error, info, emulator, + via_logger_process, other_node, tty, logfile, add, delete]. groups() -> []. init_per_suite(Config) -> + logger:add_handler(error_logger,error_logger, + #{level=>info,filter_default=>log}), Config. end_per_suite(_Config) -> + logger:remove_handler(error_logger), ok. init_per_group(_GroupName, Config) -> @@ -225,6 +229,40 @@ emulator(Config) when is_list(Config) -> generate_error(Error, Stack) -> erlang:raise(error, Error, Stack). +%%----------------------------------------------------------------- + +via_logger_process(Config) -> + case os:type() of + {win32,_} -> + {skip,"Skip on windows - cant change file mode"}; + _ -> + error_logger:add_report_handler(?MODULE, self()), + Dir = filename:join(?config(priv_dir,Config),"dummydir"), + Msg = "File operation error: eacces. Target: " ++ + Dir ++ ". Function: list_dir. ", + ok = file:make_dir(Dir), + ok = file:change_mode(Dir,8#0222), + error = erl_prim_loader:list_dir(Dir), + ok = file:change_mode(Dir,8#0664), + _ = file:del_dir(Dir), + reported(error_report, std_error, Msg), + my_yes = error_logger:delete_report_handler(?MODULE), + ok + end. + +%%----------------------------------------------------------------- + +other_node(_Config) -> + error_logger:add_report_handler(?MODULE, self()), + {ok,Node} = test_server:start_node(?FUNCTION_NAME,slave,[]), + ok = rpc:call(Node,logger,add_handler,[error_logger,error_logger, + #{level=>info,filter_default=>log}]), + rpc:call(Node,error_logger,error_report,[hi_from_remote]), + reported(error_report,std_error,hi_from_remote), + test_server:stop_node(Node), + ok. + + %%----------------------------------------------------------------- %% We don't enables or disables tty error logging here. We do not %% want to interact with the test run. @@ -279,7 +317,7 @@ reported(Tag, Type, Report) -> test_server:messages_get(), ok after 1000 -> - ct:fail(no_report_received) + ct:fail({no_report_received,test_server:messages_get()}) end. %%----------------------------------------------------------------- diff --git a/lib/kernel/test/init_SUITE.erl b/lib/kernel/test/init_SUITE.erl index c8415b34e5..6a006cdc01 100644 --- a/lib/kernel/test/init_SUITE.erl +++ b/lib/kernel/test/init_SUITE.erl @@ -299,7 +299,7 @@ many_restarts() -> many_restarts(Config) when is_list(Config) -> {ok, Node} = loose_node:start(init_test, "", ?DEFAULT_TIMEOUT_SEC), - loop_restart(50,Node,rpc:call(Node,erlang,whereis,[error_logger])), + loop_restart(50,Node,rpc:call(Node,erlang,whereis,[logger])), loose_node:stop(Node), ok. @@ -316,13 +316,13 @@ loop_restart(N,Node,EHPid) -> ct:fail(not_stopping) end, ok = wait_for(30, Node, EHPid), - loop_restart(N-1,Node,rpc:call(Node,erlang,whereis,[error_logger])). + loop_restart(N-1,Node,rpc:call(Node,erlang,whereis,[logger])). wait_for(0,Node,_) -> loose_node:stop(Node), error; wait_for(N,Node,EHPid) -> - case rpc:call(Node, erlang, whereis, [error_logger]) of + case rpc:call(Node, erlang, whereis, [logger]) of Pid when is_pid(Pid), Pid =/= EHPid -> %% erlang:display(ok), ok; diff --git a/lib/kernel/test/wrap_log_reader_SUITE.erl b/lib/kernel/test/wrap_log_reader_SUITE.erl index 40a016aed0..b1ee29a11f 100644 --- a/lib/kernel/test/wrap_log_reader_SUITE.erl +++ b/lib/kernel/test/wrap_log_reader_SUITE.erl @@ -428,13 +428,14 @@ stop() -> ok = wrap_log_test:stop(), dl_wait(). -%% Give disk logs opened by 'logger' and 'wlt' time to close after +%% Give disk logs opened by 'wlr_logger' and 'wlt' time to close after %% receiving EXIT signals. dl_wait() -> case disk_log:accessible_logs() of {[], []} -> ok; - _ -> + _X -> + erlang:display(_X), timer:sleep(100), dl_wait() end. @@ -507,27 +508,27 @@ add_ext(Name, Ext) -> %% disk_log. open(Log, File, Where) -> - logger ! {open, self(), Log, File}, + wlr_logger ! {open, self(), Log, File}, rec1(ok, Where). open_ext(Log, File, Where) -> - logger ! {open_ext, self(), Log, File}, + wlr_logger ! {open_ext, self(), Log, File}, rec1(ok, Where). close(Log) -> - logger ! {close, self(), Log}, + wlr_logger ! {close, self(), Log}, rec(ok, ?LINE). sync(Log) -> - logger ! {sync, self(), Log}, + wlr_logger ! {sync, self(), Log}, rec(ok, ?LINE). log_terms(File, Terms) -> - logger ! {log_terms, self(), File, Terms}, + wlr_logger ! {log_terms, self(), File, Terms}, rec(ok, ?LINE). blog_terms(File, Terms) -> - logger ! {blog_terms, self(), File, Terms}, + wlr_logger ! {blog_terms, self(), File, Terms}, rec(ok, ?LINE). rec1(M, Where) -> diff --git a/lib/kernel/test/wrap_log_reader_SUITE_data/wrap_log_test.erl b/lib/kernel/test/wrap_log_reader_SUITE_data/wrap_log_test.erl index 38449b6bb3..2b24ccc66f 100644 --- a/lib/kernel/test/wrap_log_reader_SUITE_data/wrap_log_test.erl +++ b/lib/kernel/test/wrap_log_reader_SUITE_data/wrap_log_test.erl @@ -36,9 +36,9 @@ -endif. init() -> - spawn(fun() -> start(logger) end), + spawn(fun() -> start(wlr_logger) end), spawn(fun() -> start2(wlt) end), - wait_registered(logger), + wait_registered(wlr_logger), wait_registered(wlt), ok. @@ -52,9 +52,9 @@ wait_registered(Name) -> end. stop() -> - catch logger ! exit, + catch wlr_logger ! exit, catch wlt ! exit, - wait_unregistered(logger), + wait_unregistered(wlr_logger), wait_unregistered(wlt), ok. @@ -82,47 +82,47 @@ loop() -> {open, Pid, Name, File} -> R = disk_log:open([{name, Name}, {type, wrap}, {file, File}, {size, {?fsize, ?fno}}]), - ?format("logger: open ~p -> ~p~n", [Name, R]), + ?format("wlr_logger: open ~p -> ~p~n", [Name, R]), Pid ! R, loop(); {open_ext, Pid, Name, File} -> R = disk_log:open([{name, Name}, {type, wrap}, {file, File}, {format, external}, {size, {?fsize, ?fno}}]), - ?format("logger: open ~p -> ~p~n", [Name, R]), + ?format("wlr_logger: open ~p -> ~p~n", [Name, R]), Pid ! R, loop(); {close, Pid, Name} -> R = disk_log:close(Name), - ?format("logger: close ~p -> ~p~n", [Name, R]), + ?format("wlr_logger: close ~p -> ~p~n", [Name, R]), Pid ! R, loop(); {sync, Pid, Name} -> R = disk_log:sync(Name), - ?format("logger: sync ~p -> ~p~n", [Name, R]), + ?format("wlr_logger: sync ~p -> ~p~n", [Name, R]), Pid ! R, loop(); {log_terms, Pid, Name, Terms} -> R = disk_log:log_terms(Name, Terms), - ?format("logger: log_terms ~p -> ~p~n", [Name, R]), + ?format("wlr_logger: log_terms ~p -> ~p~n", [Name, R]), Pid ! R, loop(); {blog_terms, Pid, Name, Terms} -> R = disk_log:blog_terms(Name, Terms), - ?format("logger: blog_terms ~p -> ~p~n", [Name, R]), + ?format("wlr_logger: blog_terms ~p -> ~p~n", [Name, R]), Pid ! R, loop(); exit -> - ?format("Stopping logger~n", []), + ?format("Stopping wlr_logger~n", []), exit(normal); _Else -> - ?format("logger: ignored: ~p~n", [_Else]), + ?format("wlr_logger: ignored: ~p~n", [_Else]), loop() end. diff --git a/lib/sasl/test/sasl_SUITE.erl b/lib/sasl/test/sasl_SUITE.erl index f12bde9b3d..7b63684c53 100644 --- a/lib/sasl/test/sasl_SUITE.erl +++ b/lib/sasl/test/sasl_SUITE.erl @@ -21,6 +21,7 @@ -include_lib("common_test/include/ct.hrl"). %% Test server specific exports +-export([init_per_suite/1,end_per_suite/1]). -export([all/0,groups/0,init_per_group/2,end_per_group/2]). -export([init_per_testcase/2, end_per_testcase/2]). @@ -37,6 +38,19 @@ all() -> groups() -> []. +init_per_suite(Config) -> + S = application:get_env(kernel,logger_sasl_compatible), + application:set_env(kernel,logger_sasl_compatible,true), + [{sasl_compatible,S}|Config]. + +end_per_suite(Config) -> + case ?config(sasl_compatible,Config) of + {ok,X} -> + application:set_env(kernel,logger_sasl_compatible,X); + undefined -> + application:unset_env(kernel,logger_sasl_compatible) + end. + init_per_group(_GroupName, Config) -> Config. diff --git a/lib/sasl/test/sasl_report_SUITE.erl b/lib/sasl/test/sasl_report_SUITE.erl index 92df5e6e40..96975aaf69 100644 --- a/lib/sasl/test/sasl_report_SUITE.erl +++ b/lib/sasl/test/sasl_report_SUITE.erl @@ -53,13 +53,17 @@ gen_server_crash_unicode(Config) -> gen_server_crash(Config, unicode). gen_server_crash(Config, Encoding) -> + StopFilter = {fun(_,_) -> stop end, ok}, + logger:add_handler_filter(logger_std_h,stop_all,StopFilter), + logger:add_handler_filter(cth_log_redirect,stop_all,StopFilter), try do_gen_server_crash(Config, Encoding) after - error_logger:tty(true), + ok = application:unset_env(kernel, logger_sasl_compatible), ok = application:unset_env(sasl, sasl_error_logger), ok = application:unset_env(kernel, error_logger_format_depth), - error_logger:add_report_handler(cth_log_redirect) + logger:remove_handler_filter(logger_std_h,stop_all), + logger:remove_handler_filter(cth_log_redirect,stop_all) end, ok. @@ -70,26 +74,26 @@ do_gen_server_crash(Config, Encoding) -> SaslLog = filename:join(LogDir, "sasl.log"), ok = filelib:ensure_dir(SaslLog), - error_logger:delete_report_handler(cth_log_redirect), - error_logger:tty(false), application:stop(sasl), Modes = [write, {encoding, Encoding}], + ok = application:set_env(kernel, logger_sasl_compatible, true), ok = application:set_env(sasl, sasl_error_logger, {file,SaslLog,Modes}, [{persistent,true}]), application:set_env(kernel, error_logger_format_depth, 30), error_logger:logfile({open,KernelLog}), application:start(sasl), - io:format("~p\n", [gen_event:which_handlers(error_logger)]), + logger:i(print), crash_me(), error_logger:logfile(close), + application:stop(sasl), check_file(KernelLog, utf8, 70000, 150000), check_file(SaslLog, Encoding, 70000, 150000), - %% ok = file:delete(KernelLog), - %% ok = file:delete(SaslLog), + ok = file:delete(KernelLog), + ok = file:delete(SaslLog), ok. check_file(File, Encoding, Min, Max) -> diff --git a/lib/stdlib/test/error_logger_h_SUITE.erl b/lib/stdlib/test/error_logger_h_SUITE.erl index 9dc04f27a1..d533305939 100644 --- a/lib/stdlib/test/error_logger_h_SUITE.erl +++ b/lib/stdlib/test/error_logger_h_SUITE.erl @@ -62,6 +62,7 @@ logfile(Config) -> error_logger:logfile({open,Log}), ok = rpc:call(Node, erlang, apply, [fun gen_events/1,[Ev]]), AtNode = iolist_to_binary(["** at node ",atom_to_list(Node)," **"]), + timer:sleep(1000), % some time get all log events in the log error_logger:logfile(close), analyse_events(Log, Ev, [AtNode], unlimited), @@ -124,6 +125,7 @@ tty(Config) -> ok = rpc:call(Node, erlang, apply, [fun gen_events/1,[Ev]]), tty_log_close(), AtNode = iolist_to_binary(["** at node ",atom_to_list(Node)," **"]), + timer:sleep(1000), % some time get all log events in the log analyse_events(Log, Ev, [AtNode], unlimited), test_server:stop_node(Node), @@ -207,7 +209,7 @@ event_templates() -> gen_events(Ev) -> io:format("node = ~p\n", [node()]), io:format("group leader = ~p\n", [group_leader()]), - io:format("~p\n", [gen_event:which_handlers(error_logger)]), + io:format("~p\n", [error_logger:which_report_handlers()]), call_error_logger(Ev), {Pid,Ref} = spawn_monitor(fun() -> error(ouch) end), @@ -240,6 +242,7 @@ analyse_events(Log, Ev, AtNode, Depth) -> call_error_logger([{F,Args}|T]) -> apply(error_logger, F, Args), + timer:sleep(10), call_error_logger(T); call_error_logger([]) -> ok. diff --git a/lib/stdlib/test/proc_lib_SUITE.erl b/lib/stdlib/test/proc_lib_SUITE.erl index fbdcb518b2..81bf9020b8 100644 --- a/lib/stdlib/test/proc_lib_SUITE.erl +++ b/lib/stdlib/test/proc_lib_SUITE.erl @@ -542,16 +542,17 @@ system_terminate(Reason,_Parent,_Deb,_State) -> t_format(_Config) -> - error_logger:tty(false), + logger:add_handler_filter(logger_std_h,stop_all,{fun(_,_) -> stop end,ok}), + error_logger:add_report_handler(?MODULE, self()), try t_format() after - error_logger:tty(true) + error_logger:delete_report_handler(?MODULE), + logger:remove_handler_filter(logger_std_h,stop_all) end, ok. t_format() -> - error_logger:add_report_handler(?MODULE, self()), Pid = proc_lib:spawn(fun '\x{aaa}t_format_looper'/0), HugeData = gb_sets:from_list(lists:seq(1, 100)), SomeData1 = list_to_atom([246]), @@ -584,11 +585,11 @@ t_format() -> ok. t_format_arbitrary(_Config) -> - error_logger:tty(false), + logger:add_handler_filter(logger_std_h,stop_all,{fun(_,_) -> stop end,ok}), try t_format_arbitrary() after - error_logger:tty(true) + logger:remove_handler_filter(logger_std_h,stop_all) end, ok. -- cgit v1.2.3