aboutsummaryrefslogtreecommitdiffstats
path: root/lib/kernel/test
diff options
context:
space:
mode:
Diffstat (limited to 'lib/kernel/test')
-rw-r--r--lib/kernel/test/Makefile3
-rw-r--r--lib/kernel/test/code_SUITE.erl12
-rw-r--r--lib/kernel/test/file_SUITE.erl31
-rw-r--r--lib/kernel/test/gen_tcp_misc_SUITE.erl200
-rw-r--r--lib/kernel/test/inet_SUITE.erl172
-rw-r--r--lib/kernel/test/inet_sockopt_SUITE.erl9
-rw-r--r--lib/kernel/test/init_SUITE.erl25
-rw-r--r--lib/kernel/test/kernel_bench.spec1
-rw-r--r--lib/kernel/test/logger.cover5
-rw-r--r--lib/kernel/test/logger.spec2
-rw-r--r--lib/kernel/test/logger_SUITE.erl70
-rw-r--r--lib/kernel/test/logger_disk_log_h_SUITE.erl408
-rw-r--r--lib/kernel/test/logger_env_var_SUITE.erl16
-rw-r--r--lib/kernel/test/logger_olp_SUITE.erl90
-rw-r--r--lib/kernel/test/logger_proxy_SUITE.erl274
-rw-r--r--lib/kernel/test/logger_std_h_SUITE.erl354
-rw-r--r--lib/kernel/test/logger_stress_SUITE.erl456
-rw-r--r--lib/kernel/test/logger_test_lib.erl10
-rw-r--r--lib/kernel/test/prim_file_SUITE.erl3
-rw-r--r--lib/kernel/test/sendfile_SUITE.erl26
-rw-r--r--lib/kernel/test/seq_trace_SUITE.erl46
21 files changed, 1812 insertions, 401 deletions
diff --git a/lib/kernel/test/Makefile b/lib/kernel/test/Makefile
index 4a86265a4a..8a6ffe7e72 100644
--- a/lib/kernel/test/Makefile
+++ b/lib/kernel/test/Makefile
@@ -76,8 +76,11 @@ MODULES= \
logger_filters_SUITE \
logger_formatter_SUITE \
logger_legacy_SUITE \
+ logger_olp_SUITE \
+ logger_proxy_SUITE \
logger_simple_h_SUITE \
logger_std_h_SUITE \
+ logger_stress_SUITE \
logger_test_lib \
os_SUITE \
pg2_SUITE \
diff --git a/lib/kernel/test/code_SUITE.erl b/lib/kernel/test/code_SUITE.erl
index 1314316c13..64e0b9d8dd 100644
--- a/lib/kernel/test/code_SUITE.erl
+++ b/lib/kernel/test/code_SUITE.erl
@@ -525,7 +525,7 @@ upgrade(Config) ->
T = [beam, hipe],
[upgrade_do(DataDir, Client, T) || Client <- T],
- case hipe:llvm_support_available() of
+ case hipe:erllvm_is_supported() of
false -> ok;
true ->
T2 = [beam, hipe_llvm],
@@ -1021,6 +1021,13 @@ mult_lib_remove_prefix([H|T1], [H|T2]) ->
mult_lib_remove_prefix([$/|T], []) -> T.
bad_erl_libs(Config) when is_list(Config) ->
+ %% Preserve ERL_LIBS if set.
+ BadLibs0 = "/no/such/dir",
+ BadLibs =
+ case os:getenv("ERL_LIBS") of
+ false -> BadLibs0;
+ Libs -> BadLibs0 ++ ":" ++ Libs
+ end,
{ok,Node} =
test_server:start_node(bad_erl_libs, slave, []),
Code = rpc:call(Node,code,get_path,[]),
@@ -1028,10 +1035,9 @@ bad_erl_libs(Config) when is_list(Config) ->
{ok,Node2} =
test_server:start_node(bad_erl_libs, slave,
- [{args,"-env ERL_LIBS /no/such/dir"}]),
+ [{args,"-env ERL_LIBS " ++ BadLibs}]),
Code2 = rpc:call(Node,code,get_path,[]),
test_server:stop_node(Node2),
-
%% Test that code path is not affected by the faulty ERL_LIBS
Code = Code2,
diff --git a/lib/kernel/test/file_SUITE.erl b/lib/kernel/test/file_SUITE.erl
index e784c06865..a51025cba6 100644
--- a/lib/kernel/test/file_SUITE.erl
+++ b/lib/kernel/test/file_SUITE.erl
@@ -100,7 +100,7 @@
-export([unicode_mode/1]).
--export([volume_relative_paths/1]).
+-export([volume_relative_paths/1,unc_paths/1]).
-export([tiny_writes/1, tiny_writes_delayed/1,
large_writes/1, large_writes_delayed/1,
@@ -129,7 +129,7 @@ suite() ->
all() ->
[unicode, altname, read_write_file, {group, dirs},
- {group, files}, delete, rename, names, volume_relative_paths,
+ {group, files}, delete, rename, names, volume_relative_paths, unc_paths,
{group, errors}, {group, compression}, {group, links}, copy,
delayed_write, read_ahead, segment_read, segment_write,
ipread, pid2name, interleaved_read_write, otp_5814, otp_10852,
@@ -2182,6 +2182,30 @@ volume_relative_paths(Config) when is_list(Config) ->
{skip, "This test is Windows-specific."}
end.
+unc_paths(Config) when is_list(Config) ->
+ case os:type() of
+ {win32, _} ->
+ %% We assume administrative shares are set up and reachable, and we
+ %% settle for testing presence as some of the returned data is
+ %% different.
+ {ok, _} = file:read_file_info("C:\\Windows\\explorer.exe"),
+ {ok, _} = file:read_file_info("\\\\localhost\\c$\\Windows\\explorer.exe"),
+
+ {ok, Cwd} = file:get_cwd(),
+
+ try
+ ok = file:set_cwd("\\\\localhost\\c$\\Windows\\"),
+ {ok, _} = file:read_file_info("explorer.exe")
+ after
+ file:set_cwd(Cwd)
+ end,
+
+ [] = flush(),
+ ok;
+ _ ->
+ {skip, "This test is Windows-specific."}
+ end.
+
%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%
@@ -2210,7 +2234,8 @@ e_delete(Config) when is_list(Config) ->
case os:type() of
{win32, _} ->
%% Remove a character device.
- {error, eacces} = ?FILE_MODULE:delete("nul");
+ expect({error, eacces}, {error, einval},
+ ?FILE_MODULE:delete("nul"));
_ ->
?FILE_MODULE:write_file_info(
Base, #file_info {mode=0}),
diff --git a/lib/kernel/test/gen_tcp_misc_SUITE.erl b/lib/kernel/test/gen_tcp_misc_SUITE.erl
index 358ca872f7..52edfaee29 100644
--- a/lib/kernel/test/gen_tcp_misc_SUITE.erl
+++ b/lib/kernel/test/gen_tcp_misc_SUITE.erl
@@ -52,7 +52,8 @@
several_accepts_in_one_go/1, accept_system_limit/1,
active_once_closed/1, send_timeout/1, send_timeout_active/1,
otp_7731/1, zombie_sockets/1, otp_7816/1, otp_8102/1,
- wrapping_oct/0, wrapping_oct/1, otp_9389/1, otp_13939/1]).
+ wrapping_oct/0, wrapping_oct/1, otp_9389/1, otp_13939/1,
+ otp_12242/1, delay_send_error/1]).
%% Internal exports.
-export([sender/3, not_owner/1, passive_sockets_server/2, priority_server/1,
@@ -95,7 +96,8 @@ all() ->
killing_multi_acceptors2, several_accepts_in_one_go, accept_system_limit,
active_once_closed, send_timeout, send_timeout_active, otp_7731,
wrapping_oct,
- zombie_sockets, otp_7816, otp_8102, otp_9389].
+ zombie_sockets, otp_7816, otp_8102, otp_9389,
+ otp_12242, delay_send_error].
groups() ->
[].
@@ -1967,22 +1969,22 @@ recvtclass(_Config) ->
{skip,{ipv6_not_supported,IFs}}
end.
-%% These version numbers are the highest noted in daily tests
-%% where the test fails for a plausible reason, so
-%% skip on that platform.
+%% These version numbers are above the highest noted
+%% in daily tests where the test fails for a plausible reason,
+%% so skip on platforms of lower version, i.e they are future
+%% versions where it is possible that it might not fail.
%%
-%% On newer versions it might be fixed, but we'll see about that
-%% when machines with newer versions gets installed...
-%% If the test still fails for a plausible reason these
+%% When machines with newer versions gets installed,
+%% if the test still fails for a plausible reason these
%% version numbers simply should be increased.
%% Or maybe we should change to only test on known good
%% platforms - change {unix,_} to false?
%% pktoptions is not supported for IPv4
recvtos_ok({unix,openbsd}, OSVer) -> not semver_lt(OSVer, {6,4,0});
-recvtos_ok({unix,darwin}, OSVer) -> not semver_lt(OSVer, {17,6,0});
-recvtos_ok({unix,freebsd}, OSVer) -> not semver_lt(OSVer, {11,2,0});
+recvtos_ok({unix,darwin}, OSVer) -> not semver_lt(OSVer, {19,0,0});
%% Using the option returns einval, so it is not implemented.
+recvtos_ok({unix,freebsd}, OSVer) -> not semver_lt(OSVer, {11,2,0});
recvtos_ok({unix,sunos}, OSVer) -> not semver_lt(OSVer, {5,12,0});
%% Does not return any value - not implemented for pktoptions
recvtos_ok({unix,linux}, OSVer) -> not semver_lt(OSVer, {3,1,0});
@@ -1992,18 +1994,19 @@ recvtos_ok(_, _) -> false.
%% pktoptions is not supported for IPv4
recvttl_ok({unix,openbsd}, OSVer) -> not semver_lt(OSVer, {6,4,0});
-recvttl_ok({unix,darwin}, OSVer) -> not semver_lt(OSVer, {17,6,0});
-recvttl_ok({unix,freebsd}, OSVer) -> not semver_lt(OSVer, {11,2,0});
+recvttl_ok({unix,darwin}, OSVer) -> not semver_lt(OSVer, {19,0,0});
%% Using the option returns einval, so it is not implemented.
+recvttl_ok({unix,freebsd}, OSVer) -> not semver_lt(OSVer, {11,2,0});
recvttl_ok({unix,sunos}, OSVer) -> not semver_lt(OSVer, {5,12,0});
+%% Does not return any value - not implemented for pktoptions
+recvttl_ok({unix,linux}, OSVer) -> not semver_lt(OSVer, {2,7,0});
%%
-recvttl_ok({unix,linux}, _) -> true;
recvttl_ok({unix,_}, _) -> true;
recvttl_ok(_, _) -> false.
%% pktoptions is not supported for IPv6
recvtclass_ok({unix,openbsd}, OSVer) -> not semver_lt(OSVer, {6,4,0});
-recvtclass_ok({unix,darwin}, OSVer) -> not semver_lt(OSVer, {17,6,0});
+recvtclass_ok({unix,darwin}, OSVer) -> not semver_lt(OSVer, {19,0,0});
recvtclass_ok({unix,sunos}, OSVer) -> not semver_lt(OSVer, {5,12,0});
%% Using the option returns einval, so it is not implemented.
recvtclass_ok({unix,freebsd}, OSVer) -> not semver_lt(OSVer, {11,2,0});
@@ -3284,3 +3287,172 @@ otp_13939(Config) when is_list(Config) ->
exit(Pid, normal),
ct:fail("Server process blocked on send.")
end.
+
+otp_12242(Config) when is_list(Config) ->
+ case os:type() of
+ {win32,_} ->
+ %% Even if we set sndbuf and recbuf to small sizes
+ %% Windows either happily accepts to send GBytes of data
+ %% in no time, so the second send below that is supposed
+ %% to time out just succedes, or the first send that
+ %% is supposed to fill the inet_drv I/O queue and
+ %% start waiting for when more data can be sent
+ %% instead sends all data but suffers a send
+ %% failure that closes the socket
+ {skipped,backpressure_broken_on_win32};
+ _ ->
+ %% Find the IPv4 address of an up and running interface
+ %% that is not loopback nor pointtopoint
+ {ok,IFList} = inet:getifaddrs(),
+ ct:pal("IFList ~p~n", [IFList]),
+ case
+ lists:flatten(
+ [lists:filtermap(
+ fun ({addr,Addr}) when tuple_size(Addr) =:= 4 ->
+ {true,Addr};
+ (_) ->
+ false
+ end, Opts)
+ || {_,Opts} <- IFList,
+ case lists:keyfind(flags, 1, Opts) of
+ {_,Flags} ->
+ lists:member(up, Flags)
+ andalso
+ lists:member(running, Flags)
+ andalso
+ not lists:member(loopback, Flags)
+ andalso
+ not lists:member(pointtopoint, Flags);
+ false ->
+ false
+ end])
+ of
+ [Addr|_] ->
+ otp_12242(Addr);
+ Other ->
+ {skipped,{no_external_address,Other}}
+ end
+ end;
+%%
+otp_12242(Addr) when tuple_size(Addr) =:= 4 ->
+ ct:timetrap(30000),
+ ct:pal("Using address ~p~n", [Addr]),
+ Bufsize = 16 * 1024,
+ Datasize = 128 * 1024 * 1024, % At least 1 s on GBit interface
+ Blob = binary:copy(<<$x>>, Datasize),
+ LOpts =
+ [{backlog,4},{reuseaddr,true},{ip,Addr},
+ binary,{active,false},
+ {recbuf,Bufsize},{sndbuf,Bufsize},{buffer,Bufsize}],
+ COpts =
+ [binary,{active,false},{ip,Addr},
+ {linger,{true,1}}, % 1 s
+ {send_timeout,500},
+ {recbuf,Bufsize},{sndbuf,Bufsize},{buffer,Bufsize}],
+ Dir = filename:dirname(code:which(?MODULE)),
+ {ok,ListenerNode} =
+ test_server:start_node(
+ ?UNIQ_NODE_NAME, slave, [{args,"-pa " ++ Dir}]),
+ Tester = self(),
+ Listener =
+ spawn(
+ ListenerNode,
+ fun () ->
+ {ok,L} = gen_tcp:listen(0, LOpts),
+ {ok,LPort} = inet:port(L),
+ Tester ! {self(),port,LPort},
+ {ok,A} = gen_tcp:accept(L),
+ ok = gen_tcp:close(L),
+ receive
+ {Tester,stop} ->
+ ok = gen_tcp:close(A)
+ end
+ end),
+ ListenerMref = monitor(process, Listener),
+ LPort = receive {Listener,port,P} -> P end,
+ {ok,C} = gen_tcp:connect(Addr, LPort, COpts, infinity),
+ {ok,ReadCOpts} = inet:getopts(C, [recbuf,sndbuf,buffer]),
+ ct:pal("ReadCOpts ~p~n", [ReadCOpts]),
+ %%
+ %% Fill the buffers
+ ct:pal("Sending ~p bytes~n", [Datasize]),
+ ok = gen_tcp:send(C, Blob),
+ ct:pal("Sent ~p bytes~n", [Datasize]),
+ %% Spawn the Closer,
+ %% try to ensure that the close call is in progress
+ %% before the owner proceeds with sending
+ Owner = self(),
+ {_Closer,CloserMref} =
+ spawn_opt(
+ fun () ->
+ Owner ! {tref, erlang:start_timer(50, Owner, closing)},
+ ct:pal("Calling gen_tcp:close(C)~n"),
+ try gen_tcp:close(C) of
+ Result ->
+ ct:pal("gen_tcp:close(C) -> ~p~n", [Result]),
+ ok = Result
+ catch
+ Class:Reason:Stacktrace ->
+ ct:pal(
+ "gen_tcp:close(C) >< ~p:~p~n ~p~n",
+ [Class,Reason,Stacktrace]),
+ erlang:raise(Class, Reason, Stacktrace)
+ end
+ end, [link,monitor]),
+ receive
+ {tref,Tref} ->
+ receive {timeout,Tref,_} -> ok end,
+ ct:pal("Sending ~p bytes again~n", [Datasize]),
+ %% Now should the close be in progress...
+ %% All buffers are full, remote end is not reading,
+ %% and the send timeout is 1 s so this will timeout:
+ {error,timeout} = gen_tcp:send(C, Blob),
+ ct:pal("Sending ~p bytes again timed out~n", [Datasize]),
+ ok = inet:setopts(C, [{send_timeout,10000}]),
+ %% There is a hidden timeout here. Port close is sampled
+ %% every 5 s by prim_inet:send_recv_reply.
+ %% Linger is 3 s so the Closer will finish this send:
+ ct:pal("Sending ~p bytes with 10 s timeout~n", [Datasize]),
+ {error,closed} = gen_tcp:send(C, Blob),
+ ct:pal("Sending ~p bytes with 10 s timeout was closed~n",
+ [Datasize]),
+ normal = wait(CloserMref),
+ ct:pal("The Closer has exited~n"),
+ Listener ! {Tester,stop},
+ receive {'DOWN',ListenerMref,_,_,_} -> ok end,
+ ct:pal("The Listener has exited~n"),
+ test_server:stop_node(ListenerNode),
+ ok
+ end.
+
+wait(Mref) ->
+ receive {'DOWN',Mref,_,_,Reason} -> Reason end.
+
+%% OTP-15536
+%% Test that send error works correctly for delay_send
+delay_send_error(Config) ->
+ {ok, LS} = gen_tcp:listen(0, [{reuseaddr, true}, {packet, 1}, {active, false}]),
+ {ok,{{0,0,0,0},PortNum}}=inet:sockname(LS),
+ P = spawn_link(
+ fun() ->
+ {ok, S} = gen_tcp:accept(LS),
+ receive die -> gen_tcp:close(S) end
+ end),
+ erlang:monitor(process, P),
+ {ok, S} = gen_tcp:connect("localhost", PortNum,
+ [{packet, 1}, {active, false}, {delay_send, true}]),
+
+ %% Do a couple of sends first to see that it works
+ ok = gen_tcp:send(S, "hello"),
+ ok = gen_tcp:send(S, "hello"),
+ ok = gen_tcp:send(S, "hello"),
+
+ %% Make the receiver close
+ P ! die,
+ receive _Down -> ok end,
+
+ ok = gen_tcp:send(S, "hello"),
+ timer:sleep(500), %% Sleep in order for delay_send to have time to trigger
+
+ %% This used to result in a double free
+ {error, closed} = gen_tcp:send(S, "hello").
diff --git a/lib/kernel/test/inet_SUITE.erl b/lib/kernel/test/inet_SUITE.erl
index 713de8c9a8..8b33f4a679 100644
--- a/lib/kernel/test/inet_SUITE.erl
+++ b/lib/kernel/test/inet_SUITE.erl
@@ -1060,28 +1060,26 @@ getservbyname_overflow(Config) when is_list(Config) ->
getifaddrs(Config) when is_list (Config) ->
{ok,IfAddrs} = inet:getifaddrs(),
io:format("IfAddrs = ~p.~n", [IfAddrs]),
- case
- {os:type(),
- [If ||
- {If,Opts} <- IfAddrs,
- lists:keymember(hwaddr, 1, Opts)]} of
- {{unix,sunos},[]} -> ok;
- {OT,[]} ->
- ct:fail({should_have_hwaddr,OT});
- _ -> ok
+ case [If || {If,Opts} <- IfAddrs, lists:keymember(hwaddr, 1, Opts)] of
+ [] ->
+ case os:type() of
+ {unix,sunos} -> ok;
+ OT ->
+ ct:fail({should_have_hwaddr,OT})
+ end;
+ [_|_] -> ok
end,
- Addrs =
- [element(1, A) || A <- ifaddrs(IfAddrs)],
+ Addrs = ifaddrs(IfAddrs),
io:format("Addrs = ~p.~n", [Addrs]),
[check_addr(Addr) || Addr <- Addrs],
ok.
-check_addr({addr,Addr})
+check_addr(Addr)
when tuple_size(Addr) =:= 8,
element(1, Addr) band 16#FFC0 =:= 16#FE80 ->
io:format("Addr: ~p link local; SKIPPED!~n", [Addr]),
ok;
-check_addr({addr,Addr}) ->
+check_addr(Addr) ->
io:format("Addr: ~p.~n", [Addr]),
Ping = "ping",
Pong = "pong",
@@ -1097,78 +1095,86 @@ check_addr({addr,Addr}) ->
ok = gen_tcp:close(S2),
ok = gen_tcp:close(L).
--record(ifopts, {name,flags,addrs=[],hwaddr}).
-
-ifaddrs([]) -> [];
-ifaddrs([{If,Opts}|IOs]) ->
- #ifopts{flags=F} = Ifopts = check_ifopts(Opts, #ifopts{name=If}),
- case F of
- {flags,Flags} ->
- case lists:member(running, Flags) of
- true -> Ifopts#ifopts.addrs;
- false -> []
- end ++ ifaddrs(IOs);
- undefined ->
- ifaddrs(IOs)
+ifaddrs(IfOpts) ->
+ IfMap = collect_ifopts(IfOpts),
+ ChkFun =
+ fun Self({{_,Flags} = Key, Opts}, ok) ->
+ Broadcast = lists:member(broadcast, Flags),
+ P2P = lists:member(pointtopoint, Flags),
+ case Opts of
+ [{addr,_},{netmask,_},{broadaddr,_}|Os]
+ when Broadcast ->
+ Self({Key, Os}, ok);
+ [{addr,_},{netmask,_},{dstaddr,_}|Os]
+ when P2P ->
+ Self({Key, Os}, ok);
+ [{addr,_},{netmask,_}|Os] ->
+ Self({Key, Os}, ok);
+ [{hwaddr,_}|Os] ->
+ Self({Key, Os}, ok);
+ [] ->
+ ok
+ end
+ end,
+ fold_ifopts(ChkFun, ok, IfMap),
+ AddrsFun =
+ fun ({{_,Flags}, Opts}, Acc) ->
+ case
+ lists:member(running, Flags)
+ andalso (not lists:member(pointtopoint, Flags))
+ of
+ true ->
+ lists:reverse(
+ [Addr || {addr,Addr} <- Opts],
+ Acc);
+ false ->
+ Acc
+ end
+ end,
+ fold_ifopts(AddrsFun, [], IfMap).
+
+collect_ifopts(IfOpts) ->
+ collect_ifopts(IfOpts, #{}).
+%%
+collect_ifopts(IfOpts, IfMap) ->
+ case IfOpts of
+ [{If,[{flags,Flags}|Opts]}|IfOs] ->
+ Key = {If,Flags},
+ case maps:is_key(Key, IfMap) of
+ true ->
+ ct:fail({unexpected_ifopts,IfOpts,IfMap});
+ false ->
+ collect_ifopts(IfOs, IfMap, Opts, Key, [])
+ end;
+ [] ->
+ IfMap;
+ _ ->
+ ct:fail({unexpected_ifopts,IfOpts,IfMap})
+ end.
+%%
+collect_ifopts(IfOpts, IfMap, Opts, Key, R) ->
+ case Opts of
+ [{flags,_}|_] ->
+ {If,_} = Key,
+ collect_ifopts(
+ [{If,Opts}|IfOpts], maps:put(Key, lists:reverse(R), IfMap));
+ [OptVal|Os] ->
+ collect_ifopts(IfOpts, IfMap, Os, Key, [OptVal|R]);
+ [] ->
+ collect_ifopts(IfOpts, maps:put(Key, lists:reverse(R), IfMap))
end.
-check_ifopts([], #ifopts{flags=F,addrs=Raddrs}=Ifopts) ->
- Addrs = lists:reverse(Raddrs),
- R = Ifopts#ifopts{addrs=Addrs},
- io:format("~p.~n", [R]),
- %% See how we did...
- {flags,Flags} = F,
- case lists:member(broadcast, Flags) of
- true ->
- [case A of
- {{addr,_},{netmask,_},{broadaddr,_}} ->
- A;
- {{addr,T},{netmask,_}} when tuple_size(T) =:= 8 ->
- A
- end || A <- Addrs];
- false ->
- case lists:member(pointtopoint, Flags) of
- true ->
- [case A of
- {{addr,_},{netmask,_},{dstaddr,_}} ->
- A
- end || A <- Addrs];
- false ->
- [case A of
- {{addr,_},{netmask,_}} ->
- A
- end || A <- Addrs]
- end
- end,
- R;
-check_ifopts([{flags,_}=F|Opts], #ifopts{flags=undefined}=Ifopts) ->
- check_ifopts(Opts, Ifopts#ifopts{flags=F});
-check_ifopts([{flags,_}=F|Opts], #ifopts{flags=Flags}=Ifopts) ->
- case F of
- Flags ->
- check_ifopts(Opts, Ifopts);
- _ ->
- ct:fail({multiple_flags,F,Ifopts})
- end;
-check_ifopts(
- [{addr,_}=A,{netmask,_}=N,{dstaddr,_}=D|Opts],
- #ifopts{addrs=Addrs}=Ifopts) ->
- check_ifopts(Opts, Ifopts#ifopts{addrs=[{A,N,D}|Addrs]});
-check_ifopts(
- [{addr,_}=A,{netmask,_}=N,{broadaddr,_}=B|Opts],
- #ifopts{addrs=Addrs}=Ifopts) ->
- check_ifopts(Opts, Ifopts#ifopts{addrs=[{A,N,B}|Addrs]});
-check_ifopts(
- [{addr,_}=A,{netmask,_}=N|Opts],
- #ifopts{addrs=Addrs}=Ifopts) ->
- check_ifopts(Opts, Ifopts#ifopts{addrs=[{A,N}|Addrs]});
-check_ifopts([{addr,_}=A|Opts], #ifopts{addrs=Addrs}=Ifopts) ->
- check_ifopts(Opts, Ifopts#ifopts{addrs=[{A}|Addrs]});
-check_ifopts([{hwaddr,Hwaddr}=H|Opts], #ifopts{hwaddr=undefined}=Ifopts)
- when is_list(Hwaddr) ->
- check_ifopts(Opts, Ifopts#ifopts{hwaddr=H});
-check_ifopts([{hwaddr,_}=H|_], #ifopts{}=Ifopts) ->
- ct:fail({multiple_hwaddrs,H,Ifopts}).
+fold_ifopts(Fun, Acc, IfMap) ->
+ fold_ifopts(Fun, Acc, IfMap, maps:keys(IfMap)).
+%%
+fold_ifopts(Fun, Acc, IfMap, Keys) ->
+ case Keys of
+ [Key|Ks] ->
+ Opts = maps:get(Key, IfMap),
+ fold_ifopts(Fun, Fun({Key,Opts}, Acc), IfMap, Ks);
+ [] ->
+ Acc
+ end.
%% Works just like lists:member/2, except that any {127,_,_,_} tuple
%% matches any other {127,_,_,_}. We do this to handle Linux systems
diff --git a/lib/kernel/test/inet_sockopt_SUITE.erl b/lib/kernel/test/inet_sockopt_SUITE.erl
index ada9c2689c..27ff74e309 100644
--- a/lib/kernel/test/inet_sockopt_SUITE.erl
+++ b/lib/kernel/test/inet_sockopt_SUITE.erl
@@ -110,9 +110,14 @@ simple(Config) when is_list(Config) ->
{S1,S2} = create_socketpair(Opt, Opt),
{ok,Opt} = inet:getopts(S1,OptTags),
{ok,Opt} = inet:getopts(S2,OptTags),
- COpt = [{X,case X of nodelay -> false;_ -> Y end} || {X,Y} <- Opt],
+ NoPushOpt = case os:type() of
+ {unix, Osname} when Osname =:= linux; Osname =:= freebsd -> {nopush, true};
+ {_,_} -> {nopush, false}
+ end,
+ COpt = [{X,case X of nodelay -> false;_ -> Y end} || {X,Y} <- [NoPushOpt|Opt]],
+ COptTags = [X || {X,_} <- COpt],
inet:setopts(S1,COpt),
- {ok,COpt} = inet:getopts(S1,OptTags),
+ {ok,COpt} = inet:getopts(S1,COptTags),
{ok,Opt} = inet:getopts(S2,OptTags),
gen_tcp:close(S1),
gen_tcp:close(S2),
diff --git a/lib/kernel/test/init_SUITE.erl b/lib/kernel/test/init_SUITE.erl
index 6a006cdc01..a0154b2694 100644
--- a/lib/kernel/test/init_SUITE.erl
+++ b/lib/kernel/test/init_SUITE.erl
@@ -295,7 +295,7 @@ is_real_system(KernelVsn, StdlibVsn) ->
%% before restart.
%% ------------------------------------------------
many_restarts() ->
- [{timetrap,{minutes,8}}].
+ [{timetrap,{minutes,16}}].
many_restarts(Config) when is_list(Config) ->
{ok, Node} = loose_node:start(init_test, "", ?DEFAULT_TIMEOUT_SEC),
@@ -315,7 +315,7 @@ loop_restart(N,Node,EHPid) ->
loose_node:stop(Node),
ct:fail(not_stopping)
end,
- ok = wait_for(30, Node, EHPid),
+ ok = wait_for(60, Node, EHPid),
loop_restart(N-1,Node,rpc:call(Node,erlang,whereis,[logger])).
wait_for(0,Node,_) ->
@@ -367,7 +367,8 @@ restart(Config) when is_list(Config) ->
SysProcs0 = rpc:call(Node, ?MODULE, find_system_processes, []),
io:format("SysProcs0=~p~n", [SysProcs0]),
[InitPid, PurgerPid, LitCollectorPid,
- DirtySigNPid, DirtySigHPid, DirtySigMPid] = SysProcs0,
+ DirtySigNPid, DirtySigHPid, DirtySigMPid,
+ PrimFilePid] = SysProcs0,
InitPid = rpc:call(Node, erlang, whereis, [init]),
PurgerPid = rpc:call(Node, erlang, whereis, [erts_code_purger]),
Procs = rpc:call(Node, erlang, processes, []),
@@ -385,7 +386,8 @@ restart(Config) when is_list(Config) ->
SysProcs1 = rpc:call(Node, ?MODULE, find_system_processes, []),
io:format("SysProcs1=~p~n", [SysProcs1]),
[InitPid1, PurgerPid1, LitCollectorPid1,
- DirtySigNPid1, DirtySigHPid1, DirtySigMPid1] = SysProcs1,
+ DirtySigNPid1, DirtySigHPid1, DirtySigMPid1,
+ PrimFilePid1] = SysProcs1,
%% Still the same init process!
InitPid1 = rpc:call(Node, erlang, whereis, [init]),
@@ -411,6 +413,10 @@ restart(Config) when is_list(Config) ->
DirtySigMP = pid_to_list(DirtySigMPid),
DirtySigMP = pid_to_list(DirtySigMPid1),
+ %% and same prim_file helper process!
+ PrimFileP = pid_to_list(PrimFilePid),
+ PrimFileP = pid_to_list(PrimFilePid1),
+
NewProcs0 = rpc:call(Node, erlang, processes, []),
NewProcs = NewProcs0 -- SysProcs1,
case check_processes(NewProcs, MaxPid) of
@@ -437,7 +443,8 @@ restart(Config) when is_list(Config) ->
literal_collector,
dirty_sig_handler_normal,
dirty_sig_handler_high,
- dirty_sig_handler_max}).
+ dirty_sig_handler_max,
+ prim_file}).
find_system_processes() ->
find_system_procs(processes(), #sys_procs{}).
@@ -448,10 +455,11 @@ find_system_procs([], SysProcs) ->
SysProcs#sys_procs.literal_collector,
SysProcs#sys_procs.dirty_sig_handler_normal,
SysProcs#sys_procs.dirty_sig_handler_high,
- SysProcs#sys_procs.dirty_sig_handler_max];
+ SysProcs#sys_procs.dirty_sig_handler_max,
+ SysProcs#sys_procs.prim_file];
find_system_procs([P|Ps], SysProcs) ->
case process_info(P, [initial_call, priority]) of
- [{initial_call,{otp_ring0,start,2}},_] ->
+ [{initial_call,{erl_init,start,2}},_] ->
undefined = SysProcs#sys_procs.init,
find_system_procs(Ps, SysProcs#sys_procs{init = P});
[{initial_call,{erts_code_purger,start,0}},_] ->
@@ -472,6 +480,9 @@ find_system_procs([P|Ps], SysProcs) ->
{priority,max}] ->
undefined = SysProcs#sys_procs.dirty_sig_handler_max,
find_system_procs(Ps, SysProcs#sys_procs{dirty_sig_handler_max = P});
+ [{initial_call,{prim_file,start,0}},_] ->
+ undefined = SysProcs#sys_procs.prim_file,
+ find_system_procs(Ps, SysProcs#sys_procs{prim_file = P});
_ ->
find_system_procs(Ps, SysProcs)
end.
diff --git a/lib/kernel/test/kernel_bench.spec b/lib/kernel/test/kernel_bench.spec
index 4de133f21b..898ceb59e0 100644
--- a/lib/kernel/test/kernel_bench.spec
+++ b/lib/kernel/test/kernel_bench.spec
@@ -1,2 +1,3 @@
{groups,"../kernel_test",zlib_SUITE,[bench]}.
{groups,"../kernel_test",file_SUITE,[bench]}.
+{suites,"../kernel_test",[logger_stress_SUITE]}.
diff --git a/lib/kernel/test/logger.cover b/lib/kernel/test/logger.cover
index 960bc0abff..9691aa295e 100644
--- a/lib/kernel/test/logger.cover
+++ b/lib/kernel/test/logger.cover
@@ -4,9 +4,12 @@
logger_backend,
logger_config,
logger_disk_log_h,
- logger_h_common,
logger_filters,
logger_formatter,
+ logger_handler_watcher,
+ logger_h_common,
+ logger_olp,
+ logger_proxy,
logger_server,
logger_simple_h,
logger_std_h,
diff --git a/lib/kernel/test/logger.spec b/lib/kernel/test/logger.spec
index 1ab90b3e93..3aec37951d 100644
--- a/lib/kernel/test/logger.spec
+++ b/lib/kernel/test/logger.spec
@@ -7,5 +7,7 @@
logger_filters_SUITE,
logger_formatter_SUITE,
logger_legacy_SUITE,
+ logger_olp_SUITE,
+ logger_proxy_SUITE,
logger_simple_h_SUITE,
logger_std_h_SUITE]}.
diff --git a/lib/kernel/test/logger_SUITE.erl b/lib/kernel/test/logger_SUITE.erl
index b7ccba8e70..2dad651f9c 100644
--- a/lib/kernel/test/logger_SUITE.erl
+++ b/lib/kernel/test/logger_SUITE.erl
@@ -101,7 +101,8 @@ all() ->
compare_levels,
process_metadata,
app_config,
- kernel_config].
+ kernel_config,
+ pretty_print].
start_stop(_Config) ->
S = whereis(logger),
@@ -246,6 +247,18 @@ change_config(_Config) ->
{ok,C4} = logger:get_handler_config(h1),
C4 = C3#{custom:=new_custom},
+ %% Change handler config: Id and module can not be changed
+ {error,{illegal_config_change,Old,New}} =
+ logger:set_handler_config(h1,id,newid),
+ %% Check that only the faulty field is included in return
+ [{id,h1}] = maps:to_list(Old),
+ [{id,newid}] = maps:to_list(New),
+ %% Check that both fields are included when both are changed
+ {error,{illegal_config_change,
+ #{id:=h1,module:=?MODULE},
+ #{id:=newid,module:=newmodule}}} =
+ logger:set_handler_config(h1,#{id=>newid,module=>newmodule}),
+
%% Change primary config: Single key
PConfig0 = logger:get_primary_config(),
ok = logger:set_primary_config(level,warning),
@@ -1129,6 +1142,61 @@ kernel_config(Config) ->
ok.
+pretty_print(Config) ->
+ ok = logger:add_handler(?FUNCTION_NAME,logger_std_h,#{}),
+ ok = logger:set_module_level([module1,module2],debug),
+
+ ct:capture_start(),
+ logger:i(),
+ ct:capture_stop(),
+ I0 = ct:capture_get(),
+
+ ct:capture_start(),
+ logger:i(primary),
+ ct:capture_stop(),
+ IPrim = ct:capture_get(),
+
+ ct:capture_start(),
+ logger:i(handlers),
+ ct:capture_stop(),
+ IHs = ct:capture_get(),
+
+ ct:capture_start(),
+ logger:i(proxy),
+ ct:capture_stop(),
+ IProxy = ct:capture_get(),
+
+ ct:capture_start(),
+ logger:i(modules),
+ ct:capture_stop(),
+ IMs = ct:capture_get(),
+
+ I02 = lists:append([IPrim,IHs,IProxy,IMs]),
+ %% ct:log("~p~n",[I0]),
+ %% ct:log("~p~n",[I02]),
+ I0 = I02,
+
+ ct:capture_start(),
+ logger:i(handlers),
+ ct:capture_stop(),
+ IHs = ct:capture_get(),
+
+ Ids = logger:get_handler_ids(),
+ IHs2 =
+ lists:append(
+ [begin
+ ct:capture_start(),
+ logger:i(Id),
+ ct:capture_stop(),
+ [_|IH] = ct:capture_get(),
+ IH
+ end || Id <- Ids]),
+
+ %% ct:log("~p~n",[IHs]),
+ %% ct:log("~p~n",[["Handler configuration: \n"|IHs2]]),
+ IHs = ["Handler configuration: \n"|IHs2],
+ ok.
+
%%%-----------------------------------------------------------------
%%% Internal
check_logged(Level,Format,Args,Meta) ->
diff --git a/lib/kernel/test/logger_disk_log_h_SUITE.erl b/lib/kernel/test/logger_disk_log_h_SUITE.erl
index 767d80b8e4..13b30835a1 100644
--- a/lib/kernel/test/logger_disk_log_h_SUITE.erl
+++ b/lib/kernel/test/logger_disk_log_h_SUITE.erl
@@ -24,6 +24,7 @@
-include_lib("common_test/include/ct.hrl").
-include_lib("kernel/include/logger.hrl").
-include_lib("kernel/src/logger_internal.hrl").
+-include_lib("kernel/src/logger_olp.hrl").
-include_lib("kernel/src/logger_h_common.hrl").
-include_lib("stdlib/include/ms_transform.hrl").
-include_lib("kernel/include/file.hrl").
@@ -92,11 +93,11 @@ all() ->
disk_log_opts,
default_formatter,
logging,
+ filter_config,
errors,
formatter_fail,
config_fail,
bad_input,
- info_and_reset,
reconfig,
sync,
disk_log_full,
@@ -302,6 +303,20 @@ logging(cleanup, _Config) ->
Name = list_to_atom(lists:concat([?FUNCTION_NAME,"_1"])),
remove_and_stop(Name).
+filter_config(_Config) ->
+ ok = logger:add_handler(?MODULE,logger_disk_log_h,#{}),
+ {ok,#{config:=HConfig}=Config} = logger:get_handler_config(?MODULE),
+ HConfig = maps:without([olp],HConfig),
+
+ FakeFullHConfig = HConfig#{olp=>{regname,self(),erlang:make_ref()}},
+ #{config:=HConfig} =
+ logger_disk_log_h:filter_config(Config#{config=>FakeFullHConfig}),
+ ok.
+
+filter_config(cleanup,_Config) ->
+ logger:remove_handler(?MODULE),
+ ok.
+
errors(Config) ->
PrivDir = ?config(priv_dir,Config),
Name1 = list_to_atom(lists:concat([?FUNCTION_NAME,"_1"])),
@@ -316,13 +331,29 @@ errors(Config) ->
%%! TODO:
%%! Check how bad log_opts are handled!
- {error,{illegal_config_change,_,_}} =
- logger:set_handler_config(Name1,
- config,
- #{file=>LogFile1,
- type=>halt}),
- {error,{illegal_config_change,_,_}} =
- logger:set_handler_config(Name1,id,new),
+ {error,{illegal_config_change,
+ logger_disk_log_h,
+ #{type:=wrap},
+ #{type:=halt}}} =
+ logger:update_handler_config(Name1,
+ config,
+ #{type=>halt,
+ file=>LogFile1}),
+
+ {error,{illegal_config_change,
+ logger_disk_log_h,
+ #{file:=LogFile1},
+ #{file:="newfilename"}}} =
+ logger:update_handler_config(Name1,
+ config,
+ #{file=>"newfilename"}),
+
+ %% Read-only fields may (accidentially) be included in the change,
+ %% but it won't take effect
+ {ok,C} = logger:get_handler_config(Name1),
+ ok = logger:set_handler_config(Name1,config,#{olp=>dummyvalue}),
+ {ok,C} = logger:get_handler_config(Name1),
+
ok = logger:remove_handler(Name1),
{error,{not_found,Name1}} = logger:remove_handler(Name1),
@@ -380,20 +411,22 @@ formatter_fail(cleanup,_Config) ->
ok.
config_fail(_Config) ->
- {error,{handler_not_added,{invalid_config,logger_disk_log_h,{bad,bad}}}} =
+ {error,{handler_not_added,{invalid_config,logger_disk_log_h,#{bad:=bad}}}} =
logger:add_handler(?MODULE,logger_disk_log_h,
#{config => #{bad => bad},
filter_default=>log,
formatter=>{?MODULE,self()}}),
- {error,{handler_not_added,{invalid_levels,{_,1,_}}}} =
+ {error,{handler_not_added,{invalid_olp_levels,#{drop_mode_qlen:=1}}}} =
logger:add_handler(?MODULE,logger_disk_log_h,
#{config => #{drop_mode_qlen=>1}}),
- {error,{handler_not_added,{invalid_levels,{43,42,_}}}} =
+ {error,{handler_not_added,{invalid_olp_levels,#{sync_mode_qlen:=43,
+ drop_mode_qlen:=42}}}} =
logger:add_handler(?MODULE,logger_disk_log_h,
#{config => #{sync_mode_qlen=>43,
drop_mode_qlen=>42}}),
- {error,{handler_not_added,{invalid_levels,{_,43,42}}}} =
+ {error,{handler_not_added,{invalid_olp_levels,#{drop_mode_qlen:=43,
+ flush_qlen:=42}}}} =
logger:add_handler(?MODULE,logger_disk_log_h,
#{config => #{drop_mode_qlen=>43,
flush_qlen=>42}}),
@@ -402,40 +435,26 @@ config_fail(_Config) ->
#{filter_default=>log,
formatter=>{?MODULE,self()}}),
%% can't change the disk log options for a log already in use
- {error,{illegal_config_change,_,_}} =
- logger:set_handler_config(?MODULE,config,
- #{max_no_files=>2}),
- %% can't change name of an existing handler
- {error,{illegal_config_change,_,_}} =
- logger:set_handler_config(?MODULE,id,bad),
+ {error,{illegal_config_change,logger_disk_log_h,_,_}} =
+ logger:update_handler_config(?MODULE,config,
+ #{max_no_files=>2}),
%% incorrect values of OP params
{ok,#{config := HConfig}} = logger:get_handler_config(?MODULE),
- {error,{invalid_levels,_}} =
- logger:set_handler_config(?MODULE,config,
- HConfig#{sync_mode_qlen=>100,
- flush_qlen=>99}),
+ {error,{invalid_olp_levels,_}} =
+ logger:update_handler_config(?MODULE,config,
+ HConfig#{sync_mode_qlen=>100,
+ flush_qlen=>99}),
%% invalid name of config parameter
- {error,{invalid_config,logger_disk_log_h,{filesync_rep_int,2000}}} =
- logger:set_handler_config(?MODULE, config,
- HConfig#{filesync_rep_int => 2000}),
+ {error,{invalid_config,logger_disk_log_h,#{filesync_rep_int:=2000}}} =
+ logger:update_handler_config(?MODULE, config,
+ HConfig#{filesync_rep_int => 2000}),
ok.
config_fail(cleanup,_Config) ->
logger:remove_handler(?MODULE).
bad_input(_Config) ->
{error,{badarg,{filesync,["BadType"]}}} =
- logger_disk_log_h:filesync("BadType"),
- {error,{badarg,{info,["BadType"]}}} = logger_disk_log_h:info("BadType"),
- {error,{badarg,{reset,["BadType"]}}} = logger_disk_log_h:reset("BadType").
-
-info_and_reset(_Config) ->
- ok = logger:add_handler(?MODULE,logger_disk_log_h,
- #{filter_default=>log,
- formatter=>{?MODULE,self()}}),
- #{id := ?MODULE} = logger_disk_log_h:info(?MODULE),
- ok = logger_disk_log_h:reset(?MODULE).
-info_and_reset(cleanup,_Config) ->
- logger:remove_handler(?MODULE).
+ logger_disk_log_h:filesync("BadType").
reconfig(Config) ->
Dir = ?config(priv_dir,Config),
@@ -444,7 +463,7 @@ reconfig(Config) ->
#{filter_default=>log,
filters=>?DEFAULT_HANDLER_FILTERS([?MODULE]),
formatter=>{?MODULE,self()}}),
- #{id := ?MODULE,
+ #{%id := ?MODULE,
sync_mode_qlen := ?SYNC_MODE_QLEN,
drop_mode_qlen := ?DROP_MODE_QLEN,
flush_qlen := ?FLUSH_QLEN,
@@ -455,14 +474,32 @@ reconfig(Config) ->
overload_kill_qlen := ?OVERLOAD_KILL_QLEN,
overload_kill_mem_size := ?OVERLOAD_KILL_MEM_SIZE,
overload_kill_restart_after := ?OVERLOAD_KILL_RESTART_AFTER,
- filesync_repeat_interval := ?FILESYNC_REPEAT_INTERVAL,
- log_opts := #{type := ?DISK_LOG_TYPE,
- max_no_files := ?DISK_LOG_MAX_NO_FILES,
- max_no_bytes := ?DISK_LOG_MAX_NO_BYTES,
- file := _DiskLogFile}} =
- logger_disk_log_h:info(?MODULE),
-
- {ok,#{config := HConfig0}} = logger:get_handler_config(?MODULE),
+ cb_state :=
+ #{handler_state :=
+ #{log_opts := #{type := ?DISK_LOG_TYPE,
+ max_no_files := ?DISK_LOG_MAX_NO_FILES,
+ max_no_bytes := ?DISK_LOG_MAX_NO_BYTES,
+ file := DiskLogFile}},
+ filesync_repeat_interval := ?FILESYNC_REPEAT_INTERVAL}} =
+ logger_olp:info(h_proc_name()),
+ {ok,#{config :=
+ #{sync_mode_qlen := ?SYNC_MODE_QLEN,
+ drop_mode_qlen := ?DROP_MODE_QLEN,
+ flush_qlen := ?FLUSH_QLEN,
+ burst_limit_enable := ?BURST_LIMIT_ENABLE,
+ burst_limit_max_count := ?BURST_LIMIT_MAX_COUNT,
+ burst_limit_window_time := ?BURST_LIMIT_WINDOW_TIME,
+ overload_kill_enable := ?OVERLOAD_KILL_ENABLE,
+ overload_kill_qlen := ?OVERLOAD_KILL_QLEN,
+ overload_kill_mem_size := ?OVERLOAD_KILL_MEM_SIZE,
+ overload_kill_restart_after := ?OVERLOAD_KILL_RESTART_AFTER,
+ filesync_repeat_interval := ?FILESYNC_REPEAT_INTERVAL,
+ file := DiskLogFile,
+ max_no_files := ?DISK_LOG_MAX_NO_FILES,
+ max_no_bytes := ?DISK_LOG_MAX_NO_BYTES,
+ type := wrap} = HConfig0}} =
+ logger:get_handler_config(?MODULE),
+
HConfig1 = HConfig0#{sync_mode_qlen => 1,
drop_mode_qlen => 2,
flush_qlen => 3,
@@ -475,7 +512,7 @@ reconfig(Config) ->
overload_kill_restart_after => infinity,
filesync_repeat_interval => no_repeat},
ok = logger:set_handler_config(?MODULE, config, HConfig1),
- #{id := ?MODULE,
+ #{%id := ?MODULE,
sync_mode_qlen := 1,
drop_mode_qlen := 2,
flush_qlen := 3,
@@ -486,8 +523,31 @@ reconfig(Config) ->
overload_kill_qlen := 100000,
overload_kill_mem_size := 10000000,
overload_kill_restart_after := infinity,
- filesync_repeat_interval := no_repeat} =
- logger_disk_log_h:info(?MODULE),
+ cb_state := #{filesync_repeat_interval := no_repeat}} =
+ logger_olp:info(h_proc_name()),
+ {ok,#{config:=HConfig1}} = logger:get_handler_config(?MODULE),
+
+ ok = logger:update_handler_config(?MODULE, config,
+ #{flush_qlen => ?FLUSH_QLEN}),
+ {ok,#{config:=C1}} = logger:get_handler_config(?MODULE),
+ ct:log("C1: ~p",[C1]),
+ C1 = HConfig1#{flush_qlen => ?FLUSH_QLEN},
+
+ ok = logger:set_handler_config(?MODULE, config, #{sync_mode_qlen => 1}),
+ {ok,#{config:=C2}} = logger:get_handler_config(?MODULE),
+ ct:log("C2: ~p",[C2]),
+ C2 = HConfig0#{sync_mode_qlen => 1},
+
+ ok = logger:set_handler_config(?MODULE, config, #{drop_mode_qlen => 100}),
+ {ok,#{config:=C3}} = logger:get_handler_config(?MODULE),
+ ct:log("C3: ~p",[C3]),
+ C3 = HConfig0#{drop_mode_qlen => 100},
+
+ ok = logger:update_handler_config(?MODULE, config, #{sync_mode_qlen => 1}),
+ {ok,#{config:=C4}} = logger:get_handler_config(?MODULE),
+ ct:log("C4: ~p",[C4]),
+ C4 = HConfig0#{sync_mode_qlen => 1,
+ drop_mode_qlen => 100},
ok = logger:remove_handler(?MODULE),
@@ -502,11 +562,50 @@ reconfig(Config) ->
max_no_files => 1,
max_no_bytes => 1024,
file => File}}),
- #{log_opts := #{type := halt,
- max_no_files := 1,
- max_no_bytes := 1024,
- file := File}} =
- logger_disk_log_h:info(?MODULE),
+ #{cb_state :=
+ #{handler_state :=
+ #{log_opts := #{type := halt,
+ max_no_files := 1,
+ max_no_bytes := 1024,
+ file := File}}}} =
+ logger_olp:info(h_proc_name()),
+ {ok,#{config :=
+ #{type := halt,
+ max_no_files := 1,
+ max_no_bytes := 1024,
+ file := File}=HaltHConfig} = Config2} =
+ logger:get_handler_config(?MODULE),
+
+ ok = logger:update_handler_config(?MODULE, level, notice),
+ {ok,C5} = logger:get_handler_config(?MODULE),
+ ct:log("C5: ~p",[C5]),
+ C5 = Config2#{level => notice},
+
+ ok = logger:set_handler_config(?MODULE, level, info),
+ {ok,C6} = logger:get_handler_config(?MODULE),
+ ct:log("C6: ~p",[C6]),
+ C6 = Config2#{level => info},
+
+ %% You are not allowed to actively set the write once fields
+ %% (type, max_no_files, max_no_bytes, file) in runtime.
+ {error, {illegal_config_change,_,_,_}} =
+ logger:set_handler_config(?MODULE,config,#{type=>wrap}),
+ {error, {illegal_config_change,_,_,_}} =
+ logger:set_handler_config(?MODULE,config,#{max_no_files=>2}),
+ {error, {illegal_config_change,_,_,_}} =
+ logger:set_handler_config(?MODULE,config,#{max_no_bytes=>2048}),
+ {error, {illegal_config_change,_,_,_}} =
+ logger:set_handler_config(?MODULE,config,#{file=>"otherfile.log"}),
+ {ok,C7} = logger:get_handler_config(?MODULE),
+ ct:log("C7: ~p",[C7]),
+ C7 = C6,
+
+ %% ... but if you don't specify the write once fields, then
+ %% set_handler_config shall NOT reset them to their default value
+ ok = logger:set_handler_config(?MODULE,config,#{sync_mode_qlen=>1}),
+ {ok,#{config:=C8}} = logger:get_handler_config(?MODULE),
+ ct:log("C8: ~p",[C8]),
+ C8 = HaltHConfig#{sync_mode_qlen=>1},
ok.
reconfig(cleanup, _Config) ->
@@ -523,59 +622,55 @@ sync(Config) ->
filters=>?DEFAULT_HANDLER_FILTERS([?MODULE]),
formatter=>{?MODULE,nl}}),
- start_tracer([{disk_log,blog,2},
- {logger_disk_log_h,disk_log_sync,2}],
- [{disk_log,blog,<<"first\n">>},
- {logger_disk_log_h,disk_log_sync}]),
+ start_tracer([{logger_disk_log_h,disk_log_write,3},
+ {disk_log,sync,1}],
+ [{logger_disk_log_h,disk_log_write,<<"first\n">>},
+ {disk_log,sync}]),
logger:notice("first", ?domain),
%% wait for automatic disk_log_sync
check_tracer(?FILESYNC_REPEAT_INTERVAL*2),
- %% check that if there's no repeated disk_log_sync active,
+ %% check that if there's no repeated filesync active,
%% a disk_log_sync is still performed when handler goes idle
{ok,#{config := HConfig}} = logger:get_handler_config(?MODULE),
HConfig1 = HConfig#{filesync_repeat_interval => no_repeat},
- ok = logger:set_handler_config(?MODULE, config, HConfig1),
-
+ ok = logger:update_handler_config(?MODULE, config, HConfig1),
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},
- {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}]),
+ maps:get(cb_state,logger_olp:info(h_proc_name()))),
+
+ start_tracer([{logger_disk_log_h,disk_log_write,3},
+ {disk_log,sync,1}],
+ [{logger_disk_log_h,disk_log_write,<<"second\n">>},
+ {disk_log,sync},
+ {logger_disk_log_h,disk_log_write,<<"third\n">>},
+ {disk_log,sync}]),
logger:notice("second", ?domain),
- timer:sleep(?IDLE_DETECT_TIME_MSEC*2),
+ timer:sleep(?IDLE_DETECT_TIME*2),
logger:notice("third", ?domain),
%% wait for automatic disk_log_sync
- check_tracer(?IDLE_DETECT_TIME_MSEC*2),
+ check_tracer(?IDLE_DETECT_TIME*2),
try_read_file(Log, {ok,<<"first\nsecond\nthird\n">>}, 1000),
- %% switch repeated disk_log_sync on and verify that the looping works
+ %% switch repeated filesync on and verify that the looping works
SyncInt = 1000,
WaitT = 4500,
- OneSync = {logger_disk_log_h,handle_cast,repeated_disk_log_sync},
- %% receive 1 initial repeated_disk_log_sync, then 1 per sec
- start_tracer([{logger_disk_log_h,handle_cast,2}],
- [OneSync || _ <- lists:seq(1, 1 + trunc(WaitT/SyncInt))]),
+ OneSync = {logger_h_common,handle_cast,repeated_filesync},
+ %% receive 1 repeated_filesync per sec
+ start_tracer([{{logger_h_common,handle_cast,2},
+ [{[repeated_filesync,'_'],[],[{message,{caller}}]}]}],
+ [OneSync || _ <- lists:seq(1, trunc(WaitT/SyncInt))]),
HConfig2 = HConfig#{filesync_repeat_interval => SyncInt},
- ok = logger:set_handler_config(?MODULE, config, HConfig2),
+ ok = logger:update_handler_config(?MODULE, config, HConfig2),
SyncInt = maps:get(filesync_repeat_interval,
- logger_disk_log_h:info(?MODULE)),
+ maps:get(cb_state,logger_olp:info(h_proc_name()))),
timer:sleep(WaitT),
HConfig3 = HConfig#{filesync_repeat_interval => no_repeat},
- ok = logger:set_handler_config(?MODULE, config, HConfig3),
+ ok = logger:update_handler_config(?MODULE, config, HConfig3),
check_tracer(100),
ok.
sync(cleanup,_Config) ->
@@ -609,7 +704,7 @@ disk_log_wrap(Config) ->
end,
{ok,_} = dbg:tracer(process, {TraceFun, Tester}),
{ok,_} = dbg:p(whereis(h_proc_name()), [c]),
- {ok,_} = dbg:tp(logger_disk_log_h, handle_info, 2, []),
+ {ok,_} = dbg:tp(logger_disk_log_h, handle_info, 3, []),
Text = [34 + rand:uniform(126-34) || _ <- lists:seq(1,MaxBytes)],
ct:pal("String = ~p (~w)", [Text, erts_debug:size(Text)]),
@@ -627,7 +722,7 @@ disk_log_wrap(Config) ->
timer:sleep(1000),
dbg:stop_clear(),
Received = lists:flatmap(fun({trace,_M,handle_info,
- [{disk_log,_Node,_Name,What},_]}) ->
+ [_,{disk_log,_Node,_Name,What},_]}) ->
[{trace,What}];
({log,_}) ->
[]
@@ -663,7 +758,7 @@ disk_log_full(Config) ->
end,
{ok,_} = dbg:tracer(process, {TraceFun, Tester}),
{ok,_} = dbg:p(whereis(h_proc_name()), [c]),
- {ok,_} = dbg:tp(logger_disk_log_h, handle_info, 2, []),
+ {ok,_} = dbg:tp(logger_disk_log_h, handle_info, 3, []),
NoOfChars = 5,
Text = [34 + rand:uniform(126-34) || _ <- lists:seq(1,NoOfChars)],
@@ -673,20 +768,24 @@ disk_log_full(Config) ->
timer:sleep(2000),
dbg:stop_clear(),
Received = lists:flatmap(fun({trace,_M,handle_info,
- [{disk_log,_Node,_Name,What},_]}) ->
+ [_,{disk_log,_Node,_Name,What},_]}) ->
[{trace,What}];
({log,_}) ->
[]
end, test_server:messages_get()),
ct:pal("Trace =~n~p", [Received]),
- [{trace,full},
- {trace,{error_status,{error,{full,_}}}}] = Received,
+
+ %% The tail here could be an error_status notification, if the
+ %% last write was synchronous, but in most cases it will not be
+ [{trace,full}|_] = Received,
+ %% [{trace,full},
+ %% {trace,{error_status,{error,{full,_}}}}] = Received,
ok.
disk_log_full(cleanup, _Config) ->
dbg:stop_clear(),
logger:remove_handler(?MODULE).
-disk_log_events(Config) ->
+disk_log_events(_Config) ->
Node = node(),
Log = ?MODULE,
ok = logger:add_handler(?MODULE,
@@ -712,14 +811,14 @@ disk_log_events(Config) ->
end,
{ok,_} = dbg:tracer(process, {TraceFun, Tester}),
{ok,_} = dbg:p(whereis(h_proc_name()), [c]),
- {ok,_} = dbg:tp(logger_disk_log_h, handle_info, 2, []),
+ {ok,_} = dbg:tp(logger_disk_log_h, handle_info, 3, []),
[whereis(h_proc_name()) ! E || E <- Events],
%% wait for trace messages
timer:sleep(2000),
dbg:stop_clear(),
Received = lists:map(fun({trace,_M,handle_info,
- [Got,_]}) -> Got
+ [_,Got,_]}) -> Got
end, test_server:messages_get()),
ct:pal("Trace =~n~p", [Received]),
NoOfEvents = length(Events),
@@ -742,13 +841,17 @@ write_failure(Config) ->
false = (undefined == rpc:call(Node, ets, whereis, [?TEST_HOOKS_TAB])),
rpc:call(Node, ets, insert, [?TEST_HOOKS_TAB,{tester,self()}]),
rpc:call(Node, ?MODULE, set_internal_log, [?MODULE,internal_log]),
- rpc:call(Node, ?MODULE, set_result, [disk_log_blog,ok]),
- HState = rpc:call(Node, logger_disk_log_h, info, [?STANDARD_HANDLER]),
- ct:pal("LogOpts = ~p", [LogOpts = maps:get(log_opts, HState)]),
-
+ rpc:call(Node, ?MODULE, set_result, [disk_log_write,ok]),
+ HState = rpc:call(Node, logger_olp, info, [h_proc_name(?STANDARD_HANDLER)]),
+ LogOpts = maps:get(log_opts,
+ maps:get(handler_state,
+ maps:get(cb_state,HState))),
+ ct:pal("LogOpts = ~p", [LogOpts]),
+
+ %% ?check and ?check_no_log in this test only check for internal log events
ok = log_on_remote_node(Node, "Logged1"),
rpc:call(Node, logger_disk_log_h, filesync, [?STANDARD_HANDLER]),
- ?check_no_log,
+ ?check_no_log, % no internal log when write ok
SyncRepInt = case (fun() -> is_atom(?FILESYNC_REPEAT_INTERVAL) end)() of
true -> 5500;
@@ -757,24 +860,26 @@ write_failure(Config) ->
try_read_file(Log, {ok,<<"Logged1\n">>}, SyncRepInt),
- rpc:call(Node, ?MODULE, set_result, [disk_log_blog,{error,no_such_log}]),
+ rpc:call(Node, ?MODULE, set_result, [disk_log_write,{error,no_such_log}]),
ok = log_on_remote_node(Node, "Cause simple error printout"),
+ %% this should have caused an internal log
?check({error,{?STANDARD_HANDLER,log,LogOpts,{error,no_such_log}}}),
-
+
ok = log_on_remote_node(Node, "No second error printout"),
- ?check_no_log,
+ ?check_no_log, % but don't log same error twice
- rpc:call(Node, ?MODULE, set_result, [disk_log_blog,
+ rpc:call(Node, ?MODULE, set_result, [disk_log_write,
{error,{full,?STANDARD_HANDLER}}]),
ok = log_on_remote_node(Node, "Cause simple error printout"),
+ %% this was a different error, so it should be logged
?check({error,{?STANDARD_HANDLER,log,LogOpts,
{error,{full,?STANDARD_HANDLER}}}}),
- rpc:call(Node, ?MODULE, set_result, [disk_log_blog,ok]),
+ rpc:call(Node, ?MODULE, set_result, [disk_log_write,ok]),
ok = log_on_remote_node(Node, "Logged2"),
rpc:call(Node, logger_disk_log_h, filesync, [?STANDARD_HANDLER]),
- ?check_no_log,
+ ?check_no_log, % no internal log when write ok
try_read_file(Log, {ok,<<"Logged1\nLogged2\n">>}, SyncRepInt),
ok.
write_failure(cleanup, _Config) ->
@@ -793,15 +898,16 @@ sync_failure(Config) ->
rpc:call(Node, ets, insert, [?TEST_HOOKS_TAB,{tester,self()}]),
rpc:call(Node, ?MODULE, set_internal_log, [?MODULE,internal_log]),
rpc:call(Node, ?MODULE, set_result, [disk_log_sync,ok]),
- HState = rpc:call(Node, logger_disk_log_h, info, [?STANDARD_HANDLER]),
- LogOpts = maps:get(log_opts, HState),
+ HState = rpc:call(Node, logger_olp, info, [h_proc_name(?STANDARD_HANDLER)]),
+ LogOpts = maps:get(log_opts, maps:get(handler_state,
+ maps:get(cb_state,HState))),
SyncInt = 500,
- ok = rpc:call(Node, logger, set_handler_config,
+ ok = rpc:call(Node, logger, update_handler_config,
[?STANDARD_HANDLER, config,
#{filesync_repeat_interval => SyncInt}]),
- Info = rpc:call(Node, logger_disk_log_h, info, [?STANDARD_HANDLER]),
- SyncInt = maps:get(filesync_repeat_interval, Info),
+ Info = rpc:call(Node, logger_olp, info, [h_proc_name(?STANDARD_HANDLER)]),
+ SyncInt = maps:get(filesync_repeat_interval, maps:get(cb_state, Info)),
ok = log_on_remote_node(Node, "Logged1"),
?check_no_log,
@@ -872,7 +978,7 @@ op_switch_to_sync(Config) ->
drop_mode_qlen => NumOfReqs+1,
flush_qlen => 2*NumOfReqs,
burst_limit_enable => false}},
- ok = logger:set_handler_config(?MODULE, NewHConfig),
+ ok = logger:update_handler_config(?MODULE, NewHConfig),
send_burst({n,NumOfReqs}, seq, {chars,79}, notice),
Lines = count_lines(Log),
NumOfReqs = Lines,
@@ -897,7 +1003,7 @@ op_switch_to_drop(Config) ->
drop_mode_qlen => 2,
flush_qlen => Procs*NumOfReqs*Bursts,
burst_limit_enable => false}},
- ok = logger:set_handler_config(?MODULE, NewHConfig),
+ ok = logger:update_handler_config(?MODULE, NewHConfig),
%% It sometimes happens that the handler either gets
%% the requests in a slow enough pace so that dropping
%% never occurs. Therefore, lets generate a number of
@@ -943,7 +1049,7 @@ op_switch_to_flush(Config) ->
drop_mode_qlen => 300,
flush_qlen => 300,
burst_limit_enable => false}},
- ok = logger:set_handler_config(?MODULE, NewHConfig),
+ ok = logger:update_handler_config(?MODULE, NewHConfig),
NumOfReqs = 1500,
Procs = 10,
Bursts = 10,
@@ -985,7 +1091,7 @@ limit_burst_disabled(Config) ->
burst_limit_window_time => 2000,
drop_mode_qlen => 200,
flush_qlen => 300}},
- ok = logger:set_handler_config(?MODULE, NewHConfig),
+ ok = logger:update_handler_config(?MODULE, NewHConfig),
NumOfReqs = 100,
send_burst({n,NumOfReqs}, seq, {chars,79}, notice),
Logged = count_lines(Log),
@@ -1005,7 +1111,7 @@ limit_burst_enabled_one(Config) ->
burst_limit_window_time => 2000,
drop_mode_qlen => 200,
flush_qlen => 300}},
- ok = logger:set_handler_config(?MODULE, NewHConfig),
+ ok = logger:update_handler_config(?MODULE, NewHConfig),
NumOfReqs = 100,
send_burst({n,NumOfReqs}, seq, {chars,79}, notice),
Logged = count_lines(Log),
@@ -1026,7 +1132,7 @@ limit_burst_enabled_period(Config) ->
burst_limit_window_time => BurstTWin,
drop_mode_qlen => 20000,
flush_qlen => 20001}},
- ok = logger:set_handler_config(?MODULE, NewHConfig),
+ ok = logger:update_handler_config(?MODULE, NewHConfig),
Windows = 3,
Sent = send_burst({t,BurstTWin*Windows}, seq, {chars,79}, notice),
@@ -1046,7 +1152,7 @@ kill_disabled(Config) ->
HConfig#{config=>DLHConfig#{overload_kill_enable=>false,
overload_kill_qlen=>10,
overload_kill_mem_size=>100}},
- ok = logger:set_handler_config(?MODULE, NewHConfig),
+ ok = logger:update_handler_config(?MODULE, NewHConfig),
NumOfReqs = 100,
send_burst({n,NumOfReqs}, seq, {chars,79}, notice),
Logged = count_lines(Log),
@@ -1068,7 +1174,7 @@ qlen_kill_new(Config) ->
overload_kill_qlen=>10,
overload_kill_mem_size=>Mem0+50000,
overload_kill_restart_after=>RestartAfter}},
- ok = logger:set_handler_config(?MODULE, NewHConfig),
+ ok = logger:update_handler_config(?MODULE, NewHConfig),
MRef = erlang:monitor(process, Pid0),
NumOfReqs = 100,
Procs = 4,
@@ -1077,7 +1183,7 @@ qlen_kill_new(Config) ->
receive
{'DOWN', MRef, _, _, Info} ->
case Info of
- {shutdown,{overloaded,?MODULE,QLen,Mem}} ->
+ {shutdown,{overloaded,QLen,Mem}} ->
ct:pal("Terminated with qlen = ~w, mem = ~w", [QLen,Mem]);
killed ->
ct:pal("Slow shutdown, handler process was killed!", [])
@@ -1087,7 +1193,7 @@ qlen_kill_new(Config) ->
ok
after
5000 ->
- Info = logger_disk_log_h:info(?MODULE),
+ Info = logger_olp:info(h_proc_name()),
ct:pal("Handler state = ~p", [Info]),
ct:fail("Handler not dead! It should not have survived this!")
end.
@@ -1105,7 +1211,7 @@ mem_kill_new(Config) ->
overload_kill_qlen=>50000,
overload_kill_mem_size=>Mem0+500,
overload_kill_restart_after=>RestartAfter}},
- ok = logger:set_handler_config(?MODULE, NewHConfig),
+ ok = logger:update_handler_config(?MODULE, NewHConfig),
MRef = erlang:monitor(process, Pid0),
NumOfReqs = 100,
Procs = 4,
@@ -1114,7 +1220,7 @@ mem_kill_new(Config) ->
receive
{'DOWN', MRef, _, _, Info} ->
case Info of
- {shutdown,{overloaded,?MODULE,QLen,Mem}} ->
+ {shutdown,{overloaded,QLen,Mem}} ->
ct:pal("Terminated with qlen = ~w, mem = ~w", [QLen,Mem]);
killed ->
ct:pal("Slow shutdown, handler process was killed!", [])
@@ -1124,7 +1230,7 @@ mem_kill_new(Config) ->
ok
after
5000 ->
- Info = logger_disk_log_h:info(?MODULE),
+ Info = logger_olp:info(h_proc_name()),
ct:pal("Handler state = ~p", [Info]),
ct:fail("Handler not dead! It should not have survived this!")
end.
@@ -1139,7 +1245,7 @@ restart_after(Config) ->
HConfig#{config=>DLHConfig#{overload_kill_enable=>true,
overload_kill_qlen=>10,
overload_kill_restart_after=>infinity}},
- ok = logger:set_handler_config(?MODULE, NewHConfig1),
+ ok = logger:update_handler_config(?MODULE, NewHConfig1),
MRef1 = erlang:monitor(process, whereis(h_proc_name())),
%% kill handler
send_burst({n,100}, {spawn,4,0}, {chars,79}, notice),
@@ -1150,7 +1256,7 @@ restart_after(Config) ->
ok
after
5000 ->
- Info1 = logger_std_h:info(?MODULE),
+ Info1 = logger_olp:info(h_proc_name()),
ct:pal("Handler state = ~p", [Info1]),
ct:fail("Handler not dead! It should not have survived this!")
end,
@@ -1161,7 +1267,7 @@ restart_after(Config) ->
HConfig#{config=>DLHConfig#{overload_kill_enable=>true,
overload_kill_qlen=>10,
overload_kill_restart_after=>RestartAfter}},
- ok = logger:set_handler_config(?MODULE, NewHConfig2),
+ ok = logger:update_handler_config(?MODULE, NewHConfig2),
Pid0 = whereis(h_proc_name()),
MRef2 = erlang:monitor(process, Pid0),
%% kill handler
@@ -1174,7 +1280,7 @@ restart_after(Config) ->
ok
after
5000 ->
- Info2 = logger_std_h:info(?MODULE),
+ Info2 = logger_olp:info(h_proc_name()),
ct:pal("Handler state = ~p", [Info2]),
ct:fail("Handler not dead! It should not have survived this!")
end,
@@ -1194,12 +1300,16 @@ handler_requests_under_load(Config) ->
drop_mode_qlen => 1000,
flush_qlen => 2000,
burst_limit_enable => false}},
- ok = logger:set_handler_config(?MODULE, NewHConfig),
- Pid = spawn_link(fun() -> send_requests(?MODULE, 1, [{filesync,[]},
- {info,[]},
- {reset,[]},
- {change_config,[]}])
- end),
+ ok = logger:update_handler_config(?MODULE, NewHConfig),
+ Pid = spawn_link(
+ fun() -> send_requests(1,[{logger_disk_log_h,filesync,[?MODULE],[]},
+ {logger_olp,info,[h_proc_name()],[]},
+ {logger_olp,reset,[h_proc_name()],[]},
+ {logger,update_handler_config,
+ [?MODULE, config,
+ #{overload_kill_enable => false}],
+ []}])
+ end),
Procs = 100,
Sent = Procs * send_burst({n,5000}, {spawn,Procs,10}, {chars,79}, notice),
Pid ! {self(),finish},
@@ -1211,29 +1321,22 @@ handler_requests_under_load(Config) ->
[E || E <- Res,
is_tuple(E) andalso (element(1,E) == error)]
end,
- Errors = [{Req,FindError(Res)} || {Req,Res} <- ReqResult],
- NoOfReqs = lists:foldl(fun({_,Res}, N) -> N + length(Res) end, 0, ReqResult),
+ Errors = [{Func,FindError(Res)} || {_,Func,_,Res} <- ReqResult],
+ NoOfReqs = lists:foldl(fun({_,_,_,Res}, N) -> N + length(Res) end,
+ 0, ReqResult),
ct:pal("~w requests made. Errors: ~n~p", [NoOfReqs,Errors]),
ok = file_delete(Log).
handler_requests_under_load(cleanup, _Config) ->
ok = stop_handler(?MODULE).
-send_requests(HName, TO, Reqs = [{Req,Res}|Rs]) ->
+send_requests(TO, Reqs = [{Mod,Func,Args,Res}|Rs]) ->
receive
{From,finish} ->
From ! {self(),Reqs}
after
TO ->
- Result =
- case Req of
- change_config ->
- logger:set_handler_config(HName, logger_disk_log_h,
- #{overload_kill_enable =>
- false});
- Func ->
- logger_disk_log_h:Func(HName)
- end,
- send_requests(HName, TO, Rs ++ [{Req,[Result|Res]}])
+ Result = apply(Mod,Func,Args),
+ send_requests(TO, Rs ++ [{Mod,Func,Args,[Result|Res]}])
end.
%%%-----------------------------------------------------------------
@@ -1351,15 +1454,6 @@ format(Msg,Tag) ->
erlang:display(Error),
exit(Error).
-remove(Handler, LogName) ->
- logger_disk_log_h:remove(Handler, LogName),
- HState = #{log_names := Logs} = logger_disk_log_h:info(),
- false = maps:is_key(LogName, HState),
- false = lists:member(LogName, Logs),
- false = logger_config:exist(?LOGGER_TABLE, LogName),
- {error,no_such_log} = disk_log:info(LogName),
- ok.
-
start_and_add(Name, Config, LogOpts) ->
HConfig = maps:get(config, Config, #{}),
HConfig1 = maps:merge(HConfig, LogOpts),
@@ -1486,7 +1580,9 @@ start_tracer(Trace,Expected) ->
ok.
tpl([{M,F,A}|Trace]) ->
- {ok,Match} = dbg:tpl(M,F,A,c),
+ tpl([{{M,F,A},c}|Trace]);
+tpl([{{M,F,A},MS}|Trace]) ->
+ {ok,Match} = dbg:tpl(M,F,A,MS),
case lists:keyfind(matched,1,Match) of
{_,_,1} ->
ok;
@@ -1499,10 +1595,10 @@ tpl([{M,F,A}|Trace]) ->
tpl([]) ->
ok.
-tracer({trace,_,call,{logger_disk_log_h,handle_cast,[Op|_]},Caller},
+tracer({trace,_,call,{logger_h_common,handle_cast,[Op|_]},Caller},
{Pid,[{Mod,Func,Op}|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]}) ->
+tracer({trace,_,call,{Mod=logger_disk_log_h,Func=disk_log_write,[_,_,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);
diff --git a/lib/kernel/test/logger_env_var_SUITE.erl b/lib/kernel/test/logger_env_var_SUITE.erl
index e8d1a313dc..9d2ad11be8 100644
--- a/lib/kernel/test/logger_env_var_SUITE.erl
+++ b/lib/kernel/test/logger_env_var_SUITE.erl
@@ -59,7 +59,8 @@ groups() ->
logger_undefined,
logger_many_handlers_default_first,
logger_many_handlers_default_last,
- logger_many_handlers_default_last_broken_filter
+ logger_many_handlers_default_last_broken_filter,
+ logger_proxy
]},
{bad,[],[bad_error_logger,
bad_level,
@@ -541,6 +542,19 @@ logger_many_handlers(Config, Env, LogErr, LogInfo, NumProgress) ->
ok.
+logger_proxy(Config) ->
+ %% assume current node runs with default settings
+ DefOpts = logger_olp:get_opts(logger_proxy),
+ {ok,_,Node} = setup(Config,
+ [{logger,[{proxy,#{sync_mode_qlen=>0,
+ drop_mode_qlen=>2}}]}]),
+ Expected = DefOpts#{sync_mode_qlen:=0,
+ drop_mode_qlen:=2},
+ Expected = rpc:call(Node,logger_olp,get_opts,[logger_proxy]),
+ Expected = rpc:call(Node,logger,get_proxy_config,[]),
+
+ ok.
+
sasl_compatible_false(Config) ->
Log = file(Config,?FUNCTION_NAME),
{ok,_,Node} = setup(Config,
diff --git a/lib/kernel/test/logger_olp_SUITE.erl b/lib/kernel/test/logger_olp_SUITE.erl
new file mode 100644
index 0000000000..ea3eec89f5
--- /dev/null
+++ b/lib/kernel/test/logger_olp_SUITE.erl
@@ -0,0 +1,90 @@
+%%
+%% %CopyrightBegin%
+%%
+%% Copyright Ericsson AB 2018. All Rights Reserved.
+%%
+%% Licensed under the Apache License, Version 2.0 (the "License");
+%% you may not use this file except in compliance with the License.
+%% You may obtain a copy of the License at
+%%
+%% http://www.apache.org/licenses/LICENSE-2.0
+%%
+%% Unless required by applicable law or agreed to in writing, software
+%% distributed under the License is distributed on an "AS IS" BASIS,
+%% WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+%% See the License for the specific language governing permissions and
+%% limitations under the License.
+%%
+%% %CopyrightEnd%
+%%
+-module(logger_olp_SUITE).
+
+-compile(export_all).
+
+-include_lib("kernel/src/logger_olp.hrl").
+
+suite() ->
+ [{timetrap,{seconds,30}}].
+
+init_per_suite(Config) ->
+ Config.
+
+end_per_suite(_Config) ->
+ ok.
+
+init_per_group(_Group, Config) ->
+ Config.
+
+end_per_group(_Group, _Config) ->
+ ok.
+
+init_per_testcase(_TestCase, Config) ->
+ Config.
+
+end_per_testcase(Case, Config) ->
+ try apply(?MODULE,Case,[cleanup,Config])
+ catch error:undef -> ok
+ end,
+ ok.
+
+groups() ->
+ [].
+
+all() ->
+ [idle_timer].
+
+%%%-----------------------------------------------------------------
+%%% Test cases
+idle_timer(_Config) ->
+ {ok,_Pid,Olp} = logger_olp:start_link(?MODULE,?MODULE,self(),#{}),
+ [logger_olp:load(Olp,{msg,N}) || N<-lists:seq(1,3)],
+ timer:sleep(?IDLE_DETECT_TIME*2),
+ [{load,{msg,1}},
+ {load,{msg,2}},
+ {load,{msg,3}},
+ {notify,idle}] = test_server:messages_get(),
+ logger_olp:cast(Olp,hello),
+ timer:sleep(?IDLE_DETECT_TIME*2),
+ [{cast,hello}] = test_server:messages_get(),
+ ok.
+idle_timer(cleanup,_Config) ->
+ unlink(whereis(?MODULE)),
+ logger_olp:stop(?MODULE),
+ ok.
+
+%%%-----------------------------------------------------------------
+%%% Olp callbacks
+init(P) ->
+ {ok,P}.
+
+handle_load(M,P) ->
+ P ! {load,M},
+ P.
+
+handle_cast(M,P) ->
+ P ! {cast,M},
+ {noreply,P}.
+
+notify(N,P) ->
+ P ! {notify,N},
+ P.
diff --git a/lib/kernel/test/logger_proxy_SUITE.erl b/lib/kernel/test/logger_proxy_SUITE.erl
new file mode 100644
index 0000000000..777531e4ed
--- /dev/null
+++ b/lib/kernel/test/logger_proxy_SUITE.erl
@@ -0,0 +1,274 @@
+%%
+%% %CopyrightBegin%
+%%
+%% Copyright Ericsson AB 2018. All Rights Reserved.
+%%
+%% Licensed under the Apache License, Version 2.0 (the "License");
+%% you may not use this file except in compliance with the License.
+%% You may obtain a copy of the License at
+%%
+%% http://www.apache.org/licenses/LICENSE-2.0
+%%
+%% Unless required by applicable law or agreed to in writing, software
+%% distributed under the License is distributed on an "AS IS" BASIS,
+%% WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+%% See the License for the specific language governing permissions and
+%% limitations under the License.
+%%
+%% %CopyrightEnd%
+%%
+-module(logger_proxy_SUITE).
+
+-compile(export_all).
+
+%% -include_lib("common_test/include/ct.hrl").
+%% -include_lib("kernel/include/logger.hrl").
+%% -include_lib("kernel/src/logger_internal.hrl").
+
+%% -define(str,"Log from "++atom_to_list(?FUNCTION_NAME)++
+%% ":"++integer_to_list(?LINE)).
+%% -define(map_rep,#{function=>?FUNCTION_NAME, line=>?LINE}).
+%% -define(keyval_rep,[{function,?FUNCTION_NAME}, {line,?LINE}]).
+
+%% -define(MY_LOC(N),#{mfa=>{?MODULE,?FUNCTION_NAME,?FUNCTION_ARITY},
+%% file=>?FILE, line=>?LINE-N}).
+
+%% -define(TRY(X), my_try(fun() -> X end)).
+
+
+-define(HNAME,list_to_atom(lists:concat([?MODULE,"_",?FUNCTION_NAME]))).
+-define(LOC,#{mfa=>{?MODULE,?FUNCTION_NAME,?FUNCTION_ARITY},line=>?LINE}).
+-define(ENSURE_TIME,5000).
+
+suite() ->
+ [{timetrap,{seconds,30}},
+ {ct_hooks,[logger_test_lib]}].
+
+init_per_suite(Config) ->
+ Config.
+
+end_per_suite(_Config) ->
+ ok.
+
+init_per_group(_Group, Config) ->
+ Config.
+
+end_per_group(_Group, _Config) ->
+ ok.
+
+init_per_testcase(_TestCase, Config) ->
+ Config.
+
+end_per_testcase(Case, Config) ->
+ try apply(?MODULE,Case,[cleanup,Config])
+ catch error:undef -> ok
+ end,
+ ok.
+
+groups() ->
+ [].
+
+all() ->
+ [basic,
+ emulator,
+ remote,
+ remote_emulator,
+ config,
+ restart_after,
+ terminate].
+
+%%%-----------------------------------------------------------------
+%%% Test cases
+basic(_Config) ->
+ ok = logger:add_handler(?HNAME,?MODULE,#{config=>self()}),
+ logger_proxy ! {log,notice,"Log from: ~p; ~p",[?FUNCTION_NAME,?LINE],L1=?LOC},
+ ok = ensure(L1),
+ logger_proxy ! {log,notice,[{test_case,?FUNCTION_NAME},{line,?LINE}],L2=?LOC},
+ ok = ensure(L2),
+ logger_proxy:log({remote,node(),{log,notice,
+ "Log from: ~p; ~p",
+ [?FUNCTION_NAME,?LINE],
+ L3=?LOC}}),
+ ok = ensure(L3),
+ logger_proxy:log({remote,node(),{log,notice,
+ [{test_case,?FUNCTION_NAME},
+ {line,?LINE}],
+ L4=?LOC}}),
+ ok = ensure(L4),
+ ok.
+basic(cleanup,_Config) ->
+ ok = logger:remove_handler(?HNAME).
+
+emulator(_Config) ->
+ ok = logger:add_handler(?HNAME,?MODULE,#{config=>self()}),
+ Pid = spawn(fun() -> erlang:error(some_reason) end),
+ ok = ensure(#{pid=>Pid}),
+ ok.
+emulator(cleanup,_Config) ->
+ ok = logger:remove_handler(?HNAME).
+
+remote(Config) ->
+ {ok,_,Node} = logger_test_lib:setup(Config,[{logger,[{proxy,#{}}]}]),
+ ok = logger:add_handler(?HNAME,?MODULE,#{config=>self()}),
+ L1 = ?LOC, spawn(Node,fun() -> logger:notice("Log from ~p; ~p",[?FUNCTION_NAME,?LINE],L1) end),
+ ok = ensure(L1),
+ L2 = ?LOC, spawn(Node,fun() -> logger:notice([{test_case,?FUNCTION_NAME},{line,?LINE}],L2) end),
+ ok = ensure(L2),
+ ok.
+remote(cleanup,_Config) ->
+ ok = logger:remove_handler(?HNAME).
+
+remote_emulator(Config) ->
+ {ok,_,Node} = logger_test_lib:setup(Config,[{logger,[{proxy,#{}}]}]),
+ ok = logger:add_handler(?HNAME,?MODULE,#{config=>self()}),
+ Pid = spawn(Node,fun() -> erlang:error(some_reason) end),
+ ok = ensure(#{pid=>Pid}),
+ ok.
+remote_emulator(cleanup,_Config) ->
+ ok = logger:remove_handler(?HNAME).
+
+config(_Config) ->
+ C1 = #{sync_mode_qlen:=SQ,
+ drop_mode_qlen:=DQ} = logger:get_proxy_config(),
+ C1 = logger_olp:get_opts(logger_proxy),
+
+ %% Update the existing config with these two values
+ SQ1 = SQ+1,
+ DQ1 = DQ+1,
+ ok = logger:update_proxy_config(#{sync_mode_qlen=>SQ1,
+ drop_mode_qlen=>DQ1}),
+ C2 = logger:get_proxy_config(), % reads from ets table
+ C2 = logger_olp:get_opts(logger_proxy), % ensure consistency with process opts
+ C2 = C1#{sync_mode_qlen:=SQ1,
+ drop_mode_qlen:=DQ1},
+
+ %% Update the existing again with only one value
+ SQ2 = SQ+2,
+ ok = logger:update_proxy_config(#{sync_mode_qlen=>SQ2}),
+ C3 = logger:get_proxy_config(),
+ C3 = logger_olp:get_opts(logger_proxy),
+ C3 = C2#{sync_mode_qlen:=SQ2},
+
+ %% Set the config, i.e. merge with defaults
+ ok = logger:set_proxy_config(#{sync_mode_qlen=>SQ1}),
+ C4 = logger:get_proxy_config(),
+ C4 = logger_olp:get_opts(logger_proxy),
+ C4 = C1#{sync_mode_qlen:=SQ1},
+
+ %% Reset to default
+ ok = logger:set_proxy_config(#{}),
+ C5 = logger:get_proxy_config(),
+ C5 = logger_olp:get_opts(logger_proxy),
+ C5 = logger_proxy:get_default_config(),
+
+ %% Errors
+ {error,{invalid_olp_config,_}} =
+ logger:set_proxy_config(#{faulty_key=>1}),
+ {error,{invalid_olp_config,_}} =
+ logger:set_proxy_config(#{sync_mode_qlen=>infinity}),
+ {error,{invalid_config,[]}} = logger:set_proxy_config([]),
+
+ {error,{invalid_olp_config,_}} =
+ logger:update_proxy_config(#{faulty_key=>1}),
+ {error,{invalid_olp_config,_}} =
+ logger:update_proxy_config(#{sync_mode_qlen=>infinity}),
+ {error,{invalid_config,[]}} = logger:update_proxy_config([]),
+
+ C5 = logger:get_proxy_config(),
+ C5 = logger_olp:get_opts(logger_proxy),
+
+ ok.
+config(cleanup,_Config) ->
+ _ = logger:set_logger_proxy(logger_proxy:get_default_config()),
+ ok.
+
+restart_after(_Config) ->
+ Restart = 3000,
+ ok = logger:update_proxy_config(#{overload_kill_enable => true,
+ overload_kill_qlen => 10,
+ overload_kill_restart_after => Restart}),
+ Proxy = whereis(logger_proxy),
+ Proxy = erlang:system_info(system_logger),
+ ProxyConfig = logger:get_proxy_config(),
+ ProxyConfig = logger_olp:get_opts(logger_proxy),
+
+ Ref = erlang:monitor(process,Proxy),
+ spawn(fun() ->
+ [logger_proxy ! {log,debug,
+ [{test_case,?FUNCTION_NAME},
+ {line,?LINE}],
+ ?LOC} || _ <- lists:seq(1,100)]
+ end),
+ receive
+ {'DOWN',Ref,_,_,_Reason} ->
+ undefined = erlang:system_info(system_logger),
+ timer:sleep(Restart),
+ poll_restarted(10)
+ after 5000 ->
+ ct:fail(proxy_not_terminated)
+ end,
+
+ Proxy1 = whereis(logger_proxy),
+ Proxy1 = erlang:system_info(system_logger),
+ ProxyConfig = logger:get_proxy_config(),
+ ProxyConfig = logger_olp:get_opts(logger_proxy),
+
+ ok.
+restart_after(cleanup,_Config) ->
+ _ = logger:set_logger_proxy(logger_proxy:get_default_config()),
+ ok.
+
+%% Test that system_logger flag is set to logger process if
+%% logger_proxy terminates for other reason than overloaded.
+terminate(_Config) ->
+ Logger = whereis(logger),
+ Proxy = whereis(logger_proxy),
+ Proxy = erlang:system_info(system_logger),
+ ProxyConfig = logger:get_proxy_config(),
+ ProxyConfig = logger_olp:get_opts(logger_proxy),
+
+ Ref = erlang:monitor(process,Proxy),
+ ok = logger_olp:stop(Proxy),
+ receive
+ {'DOWN',Ref,_,_,_Reason} ->
+ Logger = erlang:system_info(system_logger),
+ logger_proxy:restart(),
+ poll_restarted(10)
+ after 5000 ->
+ ct:fail(proxy_not_terminated)
+ end,
+
+ Proxy1 = whereis(logger_proxy),
+ Proxy1 = erlang:system_info(system_logger),
+ ProxyConfig = logger:get_proxy_config(),
+ ProxyConfig = logger_olp:get_opts(logger_proxy),
+
+ ok.
+
+%%%-----------------------------------------------------------------
+%%% Internal functions
+
+poll_restarted(0) ->
+ ct:fail(proxy_not_restarted);
+poll_restarted(N) ->
+ timer:sleep(1000),
+ case whereis(logger_proxy) of
+ undefined ->
+ poll_restarted(N-1);
+ _Pid ->
+ ok
+ end.
+
+%% Logger handler callback
+log(#{meta:=Meta},#{config:=Pid}) ->
+ Pid ! {logged,Meta}.
+
+%% Check that the log from the logger callback function log/2 is received
+ensure(Match) ->
+ receive {logged,Meta} ->
+ case maps:with(maps:keys(Match),Meta) of
+ Match -> ok;
+ _NoMatch -> {error,Match,Meta,test_server:messages_get()}
+ end
+ after ?ENSURE_TIME -> {error,Match,test_server:messages_get()}
+ end.
diff --git a/lib/kernel/test/logger_std_h_SUITE.erl b/lib/kernel/test/logger_std_h_SUITE.erl
index 3426567bbf..484d914ec3 100644
--- a/lib/kernel/test/logger_std_h_SUITE.erl
+++ b/lib/kernel/test/logger_std_h_SUITE.erl
@@ -25,10 +25,15 @@
-include_lib("kernel/include/logger.hrl").
-include_lib("kernel/src/logger_internal.hrl").
-include_lib("kernel/src/logger_h_common.hrl").
+-include_lib("kernel/src/logger_olp.hrl").
-include_lib("stdlib/include/ms_transform.hrl").
-include_lib("kernel/include/file.hrl").
--define(check_no_log, [] = test_server:messages_get()).
+-define(check_no_log,
+ begin
+ timer:sleep(?IDLE_DETECT_TIME*2),
+ [] = test_server:messages_get()
+ end).
-define(check(Expected),
receive
{log,Expected} ->
@@ -108,13 +113,13 @@ all() ->
add_remove_instance_file1,
add_remove_instance_file2,
default_formatter,
+ filter_config,
errors,
formatter_fail,
config_fail,
crash_std_h_to_file,
crash_std_h_to_disk_log,
bad_input,
- info_and_reset,
reconfig,
file_opts,
sync,
@@ -135,11 +140,12 @@ all() ->
mem_kill_new,
mem_kill_std,
restart_after,
- handler_requests_under_load
+ handler_requests_under_load,
+ recreate_deleted_log
].
add_remove_instance_tty(_Config) ->
- {error,{handler_not_added,{invalid_config,logger_std_h,{type,tty}}}} =
+ {error,{handler_not_added,{invalid_config,logger_std_h,#{type:=tty}}}} =
logger:add_handler(?MODULE,logger_std_h,
#{config => #{type => tty},
filter_default=>log,
@@ -204,6 +210,20 @@ default_formatter(_Config) ->
match = re:run(Msg,"=NOTICE REPORT====.*\n"++M1,[{capture,none}]),
ok.
+filter_config(_Config) ->
+ ok = logger:add_handler(?MODULE,logger_std_h,#{}),
+ {ok,#{config:=HConfig}=Config} = logger:get_handler_config(?MODULE),
+ HConfig = maps:without([olp],HConfig),
+
+ FakeFullHConfig = HConfig#{olp=>{regname,self(),erlang:make_ref()}},
+ #{config:=HConfig} =
+ logger_std_h:filter_config(Config#{config=>FakeFullHConfig}),
+ ok.
+
+filter_config(cleanup,_Config) ->
+ logger:remove_handler(?MODULE),
+ ok.
+
errors(Config) ->
Dir = ?config(priv_dir,Config),
Log = filename:join(Dir,?FUNCTION_NAME),
@@ -219,7 +239,7 @@ errors(Config) ->
{error,
{handler_not_added,
- {invalid_config,logger_std_h,{type,faulty_type}}}} =
+ {invalid_config,logger_std_h,#{type:=faulty_type}}}} =
logger:add_handler(?MODULE,logger_std_h,
#{config => #{type => faulty_type}}),
@@ -230,13 +250,13 @@ errors(Config) ->
_ ->
NoDir = lists:concat(["/",?MODULE,"_dir"]),
{error,
- {handler_not_added,{{open_failed,NoDir,eacces},_}}} =
+ {handler_not_added,{open_failed,NoDir,eacces}}} =
logger:add_handler(myh2,logger_std_h,
#{config=>#{type=>{file,NoDir}}})
end,
{error,
- {handler_not_added,{{open_failed,Log,_},_}}} =
+ {handler_not_added,{open_failed,Log,_}}} =
logger:add_handler(myh3,logger_std_h,
#{config=>#{type=>{file,Log,[bad_file_opt]}}}),
@@ -293,25 +313,27 @@ formatter_fail(cleanup,_Config) ->
logger:remove_handler(?MODULE).
config_fail(_Config) ->
- {error,{handler_not_added,{invalid_config,logger_std_h,{bad,bad}}}} =
+ {error,{handler_not_added,{invalid_config,logger_std_h,#{bad:=bad}}}} =
logger:add_handler(?MODULE,logger_std_h,
#{config => #{bad => bad},
filter_default=>log,
formatter=>{?MODULE,self()}}),
{error,{handler_not_added,{invalid_config,logger_std_h,
- {restart_type,bad}}}} =
+ #{restart_type:=bad}}}} =
logger:add_handler(?MODULE,logger_std_h,
#{config => #{restart_type => bad},
filter_default=>log,
formatter=>{?MODULE,self()}}),
- {error,{handler_not_added,{invalid_levels,{_,1,_}}}} =
+ {error,{handler_not_added,{invalid_olp_levels,#{drop_mode_qlen:=1}}}} =
logger:add_handler(?MODULE,logger_std_h,
#{config => #{drop_mode_qlen=>1}}),
- {error,{handler_not_added,{invalid_levels,{43,42,_}}}} =
+ {error,{handler_not_added,{invalid_olp_levels,#{sync_mode_qlen:=43,
+ drop_mode_qlen:=42}}}} =
logger:add_handler(?MODULE,logger_std_h,
#{config => #{sync_mode_qlen=>43,
drop_mode_qlen=>42}}),
- {error,{handler_not_added,{invalid_levels,{_,43,42}}}} =
+ {error,{handler_not_added,{invalid_olp_levels,#{drop_mode_qlen:=43,
+ flush_qlen:=42}}}} =
logger:add_handler(?MODULE,logger_std_h,
#{config => #{drop_mode_qlen=>43,
flush_qlen=>42}}),
@@ -319,18 +341,24 @@ config_fail(_Config) ->
ok = logger:add_handler(?MODULE,logger_std_h,
#{filter_default=>log,
formatter=>{?MODULE,self()}}),
- {error,{illegal_config_change,_,_}} =
+ {error,{illegal_config_change,logger_std_h,#{type:=_},#{type:=_}}} =
logger:set_handler_config(?MODULE,config,
#{type=>{file,"file"}}),
- {error,{illegal_config_change,_,_}} =
- logger:set_handler_config(?MODULE,id,bad),
- {error,{invalid_levels,_}} =
+
+ {error,{invalid_olp_levels,_}} =
logger:set_handler_config(?MODULE,config,
#{sync_mode_qlen=>100,
flush_qlen=>99}),
- {error,{invalid_config,logger_std_h,{filesync_rep_int,2000}}} =
+ {error,{invalid_config,logger_std_h,#{filesync_rep_int:=2000}}} =
logger:set_handler_config(?MODULE, config,
#{filesync_rep_int => 2000}),
+
+ %% Read-only fields may (accidentially) be included in the change,
+ %% but it won't take effect
+ {ok,C} = logger:get_handler_config(?MODULE),
+ ok = logger:set_handler_config(?MODULE,config,#{olp=>dummyvalue}),
+ {ok,C} = logger:get_handler_config(?MODULE),
+
ok.
config_fail(cleanup,_Config) ->
@@ -396,10 +424,13 @@ crash_std_h(Config,Func,Var,Type,Log) ->
%% logger would send the log event to the logger process here instead
%% of logging it itself.
log_on_remote_node(Node,Msg) ->
+ Pid = self(),
_ = spawn_link(Node,
fun() -> erlang:group_leader(whereis(user),self()),
- logger:notice(Msg)
+ logger:notice(Msg),
+ Pid ! done
end),
+ receive done -> ok end,
ok.
@@ -427,14 +458,7 @@ sync_and_read(Node,file,Log) ->
end.
bad_input(_Config) ->
- {error,{badarg,{filesync,["BadType"]}}} = logger_std_h:filesync("BadType"),
- {error,{badarg,{info,["BadType"]}}} = logger_std_h:info("BadType"),
- {error,{badarg,{reset,["BadType"]}}} = logger_std_h:reset("BadType").
-
-
-info_and_reset(_Config) ->
- #{id := ?STANDARD_HANDLER} = logger_std_h:info(?STANDARD_HANDLER),
- ok = logger_std_h:reset(?STANDARD_HANDLER).
+ {error,{badarg,{filesync,["BadType"]}}} = logger_std_h:filesync("BadType").
reconfig(Config) ->
Dir = ?config(priv_dir,Config),
@@ -444,9 +468,10 @@ reconfig(Config) ->
filter_default=>log,
filters=>?DEFAULT_HANDLER_FILTERS([?MODULE]),
formatter=>{?MODULE,self()}}),
- #{id := ?MODULE,
- type := standard_io,
- file_ctrl_pid := FileCtrlPid,
+ #{%id := ?MODULE,
+ cb_state:=#{handler_state := #{type := standard_io,
+ file_ctrl_pid := FileCtrlPid},
+ filesync_repeat_interval := no_repeat},
sync_mode_qlen := ?SYNC_MODE_QLEN,
drop_mode_qlen := ?DROP_MODE_QLEN,
flush_qlen := ?FLUSH_QLEN,
@@ -456,9 +481,25 @@ reconfig(Config) ->
overload_kill_enable := ?OVERLOAD_KILL_ENABLE,
overload_kill_qlen := ?OVERLOAD_KILL_QLEN,
overload_kill_mem_size := ?OVERLOAD_KILL_MEM_SIZE,
- overload_kill_restart_after := ?OVERLOAD_KILL_RESTART_AFTER,
- filesync_repeat_interval := ?FILESYNC_REPEAT_INTERVAL} =
- logger_std_h:info(?MODULE),
+ overload_kill_restart_after := ?OVERLOAD_KILL_RESTART_AFTER} =
+ logger_olp:info(h_proc_name()),
+
+ {ok,
+ #{config:=
+ #{type := standard_io,
+ sync_mode_qlen := ?SYNC_MODE_QLEN,
+ drop_mode_qlen := ?DROP_MODE_QLEN,
+ flush_qlen := ?FLUSH_QLEN,
+ burst_limit_enable := ?BURST_LIMIT_ENABLE,
+ burst_limit_max_count := ?BURST_LIMIT_MAX_COUNT,
+ burst_limit_window_time := ?BURST_LIMIT_WINDOW_TIME,
+ overload_kill_enable := ?OVERLOAD_KILL_ENABLE,
+ overload_kill_qlen := ?OVERLOAD_KILL_QLEN,
+ overload_kill_mem_size := ?OVERLOAD_KILL_MEM_SIZE,
+ overload_kill_restart_after := ?OVERLOAD_KILL_RESTART_AFTER,
+ filesync_repeat_interval := no_repeat} =
+ DefaultHConf}}
+ = logger:get_handler_config(?MODULE),
ok = logger:set_handler_config(?MODULE, config,
#{sync_mode_qlen => 1,
@@ -471,10 +512,11 @@ reconfig(Config) ->
overload_kill_qlen => 100000,
overload_kill_mem_size => 10000000,
overload_kill_restart_after => infinity,
- filesync_repeat_interval => no_repeat}),
- #{id := ?MODULE,
- type := standard_io,
- file_ctrl_pid := FileCtrlPid,
+ filesync_repeat_interval => 5000}),
+ #{%id := ?MODULE,
+ cb_state := #{handler_state := #{type := standard_io,
+ file_ctrl_pid := FileCtrlPid},
+ filesync_repeat_interval := no_repeat},
sync_mode_qlen := 1,
drop_mode_qlen := 2,
flush_qlen := 3,
@@ -484,8 +526,77 @@ reconfig(Config) ->
overload_kill_enable := true,
overload_kill_qlen := 100000,
overload_kill_mem_size := 10000000,
- overload_kill_restart_after := infinity,
- filesync_repeat_interval := no_repeat} = logger_std_h:info(?MODULE),
+ overload_kill_restart_after := infinity} = logger_olp:info(h_proc_name()),
+
+ {ok,#{config :=
+ #{type := standard_io,
+ sync_mode_qlen := 1,
+ drop_mode_qlen := 2,
+ flush_qlen := 3,
+ burst_limit_enable := false,
+ burst_limit_max_count := 10,
+ burst_limit_window_time := 10,
+ overload_kill_enable := true,
+ overload_kill_qlen := 100000,
+ overload_kill_mem_size := 10000000,
+ overload_kill_restart_after := infinity,
+ filesync_repeat_interval := no_repeat} = HConf}} =
+ logger:get_handler_config(?MODULE),
+
+ ok = logger:update_handler_config(?MODULE, config,
+ #{flush_qlen => ?FLUSH_QLEN}),
+ {ok,#{config:=C1}} = logger:get_handler_config(?MODULE),
+ ct:log("C1: ~p",[C1]),
+ C1 = HConf#{flush_qlen => ?FLUSH_QLEN},
+
+ ok = logger:set_handler_config(?MODULE, config, #{sync_mode_qlen => 1}),
+ {ok,#{config:=C2}} = logger:get_handler_config(?MODULE),
+ ct:log("C2: ~p",[C2]),
+ C2 = DefaultHConf#{sync_mode_qlen => 1},
+
+ ok = logger:set_handler_config(?MODULE, config, #{drop_mode_qlen => 100}),
+ {ok,#{config:=C3}} = logger:get_handler_config(?MODULE),
+ ct:log("C3: ~p",[C3]),
+ C3 = DefaultHConf#{drop_mode_qlen => 100},
+
+ ok = logger:update_handler_config(?MODULE, config, #{sync_mode_qlen => 1}),
+ {ok,#{config:=C4}} = logger:get_handler_config(?MODULE),
+ ct:log("C4: ~p",[C4]),
+ C4 = DefaultHConf#{sync_mode_qlen => 1,
+ drop_mode_qlen => 100},
+
+ ok = logger:remove_handler(?MODULE),
+
+ File = filename:join(Dir,lists:concat([?FUNCTION_NAME,".log"])),
+ ok = logger:add_handler(?MODULE,
+ logger_std_h,
+ #{config => #{type => {file,File}},
+ filter_default=>log,
+ filters=>?DEFAULT_HANDLER_FILTERS([?MODULE]),
+ formatter=>{?MODULE,self()}}),
+
+ {ok,#{config:=#{filesync_repeat_interval:=FSI}=FileHConfig}} =
+ logger:get_handler_config(?MODULE),
+ ok = logger:update_handler_config(?MODULE,config,
+ #{filesync_repeat_interval=>FSI+2000}),
+ {ok,#{config:=C5}} = logger:get_handler_config(?MODULE),
+ ct:log("C5: ~p",[C5]),
+ C5 = FileHConfig#{filesync_repeat_interval=>FSI+2000},
+
+ %% You are not allowed to actively set 'type' in runtime, since
+ %% this is a write once field.
+ {error, {illegal_config_change,logger_std_h,_,_}} =
+ logger:set_handler_config(?MODULE,config,#{type=>standard_io}),
+ {ok,#{config:=C6}} = logger:get_handler_config(?MODULE),
+ ct:log("C6: ~p",[C6]),
+ C6 = C5,
+
+ %% ... but if you don't specify 'type', then set_handler_config shall
+ %% NOT reset it to its default value
+ ok = logger:set_handler_config(?MODULE,config,#{sync_mode_qlen=>1}),
+ {ok,#{config:=C7}} = logger:get_handler_config(?MODULE),
+ ct:log("C7: ~p",[C7]),
+ C7 = FileHConfig#{sync_mode_qlen=>1},
ok.
reconfig(cleanup, _Config) ->
@@ -497,7 +608,7 @@ file_opts(Config) ->
Log = filename:join(Dir, lists:concat([?FUNCTION_NAME,".log"])),
BadFileOpts = [raw],
BadType = {file,Log,BadFileOpts},
- {error,{handler_not_added,{{open_failed,Log,enoent},_}}} =
+ {error,{handler_not_added,{open_failed,Log,enoent}}} =
logger:add_handler(?MODULE, logger_std_h,
#{config => #{type => BadType}}),
@@ -510,7 +621,9 @@ file_opts(Config) ->
filters=>?DEFAULT_HANDLER_FILTERS([?MODULE]),
formatter=>{?MODULE,self()}}),
- #{type := OkType} = logger_std_h:info(?MODULE),
+ #{cb_state := #{handler_state := #{type := OkType}}} =
+ logger_olp:info(h_proc_name()),
+ {ok,#{config := #{type := OkType}}} = logger:get_handler_config(?MODULE),
logger:notice(M1=?msg,?domain),
?check(M1),
B1 = ?bin(M1),
@@ -533,10 +646,8 @@ sync(Config) ->
%% check repeated filesync happens
start_tracer([{logger_std_h, write_to_dev, 5},
- {logger_std_h, sync_dev, 4},
{file, datasync, 1}],
[{logger_std_h, write_to_dev, <<"first\n">>},
- {logger_std_h, sync_dev},
{file,datasync}]),
logger:notice("first", ?domain),
@@ -545,10 +656,8 @@ sync(Config) ->
%% check that explicit filesync is only done once
start_tracer([{logger_std_h, write_to_dev, 5},
- {logger_std_h, sync_dev, 4},
{file, datasync, 1}],
[{logger_std_h, write_to_dev, <<"second\n">>},
- {logger_std_h, sync_dev},
{file,datasync},
{no_more,500}
]),
@@ -561,43 +670,39 @@ sync(Config) ->
%% check that if there's no repeated filesync active,
%% a filesync is still performed when handler goes idle
- logger:set_handler_config(?MODULE, config,
- #{filesync_repeat_interval => no_repeat}),
- no_repeat = maps:get(filesync_repeat_interval, logger_std_h:info(?MODULE)),
- %% The following timer is to make sure the time from last log
- %% ("second") to next ("third") is long enough, so the a flush is
- %% triggered by the idle timeout between "thrid" and "fourth".
- timer:sleep(?IDLE_DETECT_TIME_MSEC*2),
+ ok = logger:update_handler_config(?MODULE, 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},
- {logger_std_h, sync_dev, 4},
{file, datasync, 1}],
[{logger_std_h, write_to_dev, <<"third\n">>},
- {logger_std_h, sync_dev},
{file,datasync},
{logger_std_h, write_to_dev, <<"fourth\n">>},
- {logger_std_h, sync_dev},
{file,datasync}]),
logger:notice("third", ?domain),
%% wait for automatic filesync
- timer:sleep(?IDLE_DETECT_TIME_MSEC*2),
+ timer:sleep(?IDLE_DETECT_TIME*2),
logger:notice("fourth", ?domain),
%% wait for automatic filesync
- check_tracer(?IDLE_DETECT_TIME_MSEC*2),
+ check_tracer(?IDLE_DETECT_TIME*2),
%% switch repeated filesync on and verify that the looping works
SyncInt = 1000,
WaitT = 4500,
- OneSync = {logger_std_h,handle_cast,repeated_filesync},
- %% receive 1 initial repeated_filesync, then 1 per sec
- start_tracer([{logger_std_h,handle_cast,2}],
- [OneSync || _ <- lists:seq(1, 1 + trunc(WaitT/SyncInt))]),
-
- logger:set_handler_config(?MODULE, config,
- #{filesync_repeat_interval => SyncInt}),
- SyncInt = maps:get(filesync_repeat_interval, logger_std_h:info(?MODULE)),
+ OneSync = {logger_h_common,handle_cast,repeated_filesync},
+ %% receive 1 repeated_filesync per sec
+ start_tracer([{{logger_h_common,handle_cast,2},
+ [{[repeated_filesync,'_'],[],[]}]}],
+ [OneSync || _ <- lists:seq(1, trunc(WaitT/SyncInt))]),
+
+ ok = logger:update_handler_config(?MODULE, config,
+ #{filesync_repeat_interval => SyncInt}),
+ SyncInt = maps:get(filesync_repeat_interval,
+ maps:get(cb_state,logger_olp:info(h_proc_name()))),
timer:sleep(WaitT),
- logger:set_handler_config(?MODULE, config,
- #{filesync_repeat_interval => no_repeat}),
+ ok = logger:update_handler_config(?MODULE, config,
+ #{filesync_repeat_interval => no_repeat}),
check_tracer(100),
ok.
sync(cleanup, _Config) ->
@@ -652,11 +757,9 @@ sync_failure(Config) ->
rpc:call(Node, ?MODULE, set_result, [file_datasync,ok]),
SyncInt = 500,
- ok = rpc:call(Node, logger, set_handler_config,
+ ok = rpc:call(Node, logger, update_handler_config,
[?STANDARD_HANDLER, config,
#{filesync_repeat_interval => SyncInt}]),
- Info = rpc:call(Node, logger_std_h, info, [?STANDARD_HANDLER]),
- SyncInt = maps:get(filesync_repeat_interval, Info),
ok = log_on_remote_node(Node, "Logged1"),
?check_no_log,
@@ -718,7 +821,7 @@ op_switch_to_sync_file(Config) ->
drop_mode_qlen => NumOfReqs+1,
flush_qlen => 2*NumOfReqs,
burst_limit_enable => false}},
- ok = logger:set_handler_config(?MODULE, NewHConfig),
+ ok = logger:update_handler_config(?MODULE, NewHConfig),
%% TRecvPid = start_op_trace(),
send_burst({n,NumOfReqs}, seq, {chars,79}, notice),
Lines = count_lines(Log),
@@ -747,7 +850,7 @@ op_switch_to_sync_tty(Config) ->
drop_mode_qlen => NumOfReqs+1,
flush_qlen => 2*NumOfReqs,
burst_limit_enable => false}},
- ok = logger:set_handler_config(?MODULE, NewHConfig),
+ ok = logger:update_handler_config(?MODULE, NewHConfig),
send_burst({n,NumOfReqs}, seq, {chars,79}, notice),
ok.
op_switch_to_sync_tty(cleanup, _Config) ->
@@ -770,7 +873,7 @@ op_switch_to_drop_file(Config) ->
flush_qlen =>
Procs*NumOfReqs*Bursts,
burst_limit_enable => false}},
- ok = logger:set_handler_config(?MODULE, NewHConfig),
+ ok = logger:update_handler_config(?MODULE, NewHConfig),
%% It sometimes happens that the handler gets the
%% requests in a slow enough pace so that dropping
%% never occurs. Therefore, lets generate a number of
@@ -807,7 +910,7 @@ op_switch_to_drop_tty(Config) ->
flush_qlen =>
Procs*NumOfReqs+1,
burst_limit_enable => false}},
- ok = logger:set_handler_config(?MODULE, NewHConfig),
+ ok = logger:update_handler_config(?MODULE, NewHConfig),
send_burst({n,NumOfReqs}, {spawn,Procs,0}, {chars,79}, notice),
ok.
op_switch_to_drop_tty(cleanup, _Config) ->
@@ -832,7 +935,7 @@ op_switch_to_flush_file(Config) ->
drop_mode_qlen => 300,
flush_qlen => 300,
burst_limit_enable => false}},
- ok = logger:set_handler_config(?MODULE, NewHConfig),
+ ok = logger:update_handler_config(?MODULE, NewHConfig),
NumOfReqs = 1500,
Procs = 10,
Bursts = 10,
@@ -879,7 +982,7 @@ op_switch_to_flush_tty(Config) ->
drop_mode_qlen => 100,
flush_qlen => 100,
burst_limit_enable => false}},
- ok = logger:set_handler_config(?MODULE, NewHConfig),
+ ok = logger:update_handler_config(?MODULE, NewHConfig),
NumOfReqs = 1000,
Procs = 100,
send_burst({n,NumOfReqs}, {spawn,Procs,0}, {chars,79}, notice),
@@ -895,7 +998,7 @@ limit_burst_disabled(Config) ->
burst_limit_window_time => 2000,
drop_mode_qlen => 200,
flush_qlen => 300}},
- ok = logger:set_handler_config(?MODULE, NewHConfig),
+ ok = logger:update_handler_config(?MODULE, NewHConfig),
NumOfReqs = 100,
send_burst({n,NumOfReqs}, seq, {chars,79}, notice),
Logged = count_lines(Log),
@@ -915,7 +1018,7 @@ limit_burst_enabled_one(Config) ->
burst_limit_window_time => 2000,
drop_mode_qlen => 200,
flush_qlen => 300}},
- ok = logger:set_handler_config(?MODULE, NewHConfig),
+ ok = logger:update_handler_config(?MODULE, NewHConfig),
NumOfReqs = 100,
send_burst({n,NumOfReqs}, seq, {chars,79}, notice),
Logged = count_lines(Log),
@@ -936,7 +1039,7 @@ limit_burst_enabled_period(Config) ->
burst_limit_window_time => BurstTWin,
drop_mode_qlen => 20000,
flush_qlen => 20001}},
- ok = logger:set_handler_config(?MODULE, NewHConfig),
+ ok = logger:update_handler_config(?MODULE, NewHConfig),
Windows = 3,
Sent = send_burst({t,BurstTWin*Windows}, seq, {chars,79}, notice),
@@ -956,7 +1059,7 @@ kill_disabled(Config) ->
HConfig#{config=>StdHConfig#{overload_kill_enable=>false,
overload_kill_qlen=>10,
overload_kill_mem_size=>100}},
- ok = logger:set_handler_config(?MODULE, NewHConfig),
+ ok = logger:update_handler_config(?MODULE, NewHConfig),
NumOfReqs = 100,
send_burst({n,NumOfReqs}, seq, {chars,79}, notice),
Logged = count_lines(Log),
@@ -977,7 +1080,7 @@ qlen_kill_new(Config) ->
overload_kill_qlen=>10,
overload_kill_mem_size=>Mem0+50000,
overload_kill_restart_after=>RestartAfter}},
- ok = logger:set_handler_config(?MODULE, NewHConfig),
+ ok = logger:update_handler_config(?MODULE, NewHConfig),
MRef = erlang:monitor(process, Pid0),
NumOfReqs = 100,
Procs = 4,
@@ -986,7 +1089,7 @@ qlen_kill_new(Config) ->
receive
{'DOWN', MRef, _, _, Info} ->
case Info of
- {shutdown,{overloaded,?MODULE,QLen,Mem}} ->
+ {shutdown,{overloaded,QLen,Mem}} ->
ct:pal("Terminated with qlen = ~w, mem = ~w", [QLen,Mem]);
killed ->
ct:pal("Slow shutdown, handler process was killed!", [])
@@ -996,7 +1099,7 @@ qlen_kill_new(Config) ->
ok
after
5000 ->
- Info = logger_std_h:info(?MODULE),
+ Info = logger_olp:info(h_proc_name()),
ct:pal("Handler state = ~p", [Info]),
ct:fail("Handler not dead! It should not have survived this!")
end.
@@ -1011,7 +1114,7 @@ qlen_kill_std(_Config) ->
%% File = lists:concat([?MODULE,"_",?FUNCTION_NAME,".log"]),
%% Log = filename:join(Dir, File),
%% Node = start_std_h_on_new_node(Config, ?FUNCTION_NAME, Log),
- %% ok = rpc:call(Node, logger, set_handler_config,
+ %% ok = rpc:call(Node, logger, update_handler_config,
%% [?STANDARD_HANDLER, config,
%% #{overload_kill_enable=>true,
%% overload_kill_qlen=>10,
@@ -1028,7 +1131,7 @@ mem_kill_new(Config) ->
overload_kill_qlen=>50000,
overload_kill_mem_size=>Mem0+500,
overload_kill_restart_after=>RestartAfter}},
- ok = logger:set_handler_config(?MODULE, NewHConfig),
+ ok = logger:update_handler_config(?MODULE, NewHConfig),
MRef = erlang:monitor(process, Pid0),
NumOfReqs = 100,
Procs = 4,
@@ -1037,7 +1140,7 @@ mem_kill_new(Config) ->
receive
{'DOWN', MRef, _, _, Info} ->
case Info of
- {shutdown,{overloaded,?MODULE,QLen,Mem}} ->
+ {shutdown,{overloaded,QLen,Mem}} ->
ct:pal("Terminated with qlen = ~w, mem = ~w", [QLen,Mem]);
killed ->
ct:pal("Slow shutdown, handler process was killed!", [])
@@ -1047,7 +1150,7 @@ mem_kill_new(Config) ->
ok
after
5000 ->
- Info = logger_std_h:info(?MODULE),
+ Info = logger_olp:info(h_proc_name()),
ct:pal("Handler state = ~p", [Info]),
ct:fail("Handler not dead! It should not have survived this!")
end.
@@ -1067,7 +1170,7 @@ restart_after(Config) ->
HConfig#{config=>StdHConfig#{overload_kill_enable=>true,
overload_kill_qlen=>10,
overload_kill_restart_after=>infinity}},
- ok = logger:set_handler_config(?MODULE, NewHConfig1),
+ ok = logger:update_handler_config(?MODULE, NewHConfig1),
MRef1 = erlang:monitor(process, whereis(h_proc_name())),
%% kill handler
send_burst({n,100}, {spawn,4,0}, {chars,79}, notice),
@@ -1078,18 +1181,19 @@ restart_after(Config) ->
ok
after
5000 ->
- Info1 = logger_std_h:info(?MODULE),
+ Info1 = logger_olp:info(h_proc_name()),
ct:pal("Handler state = ~p", [Info1]),
ct:fail("Handler not dead! It should not have survived this!")
end,
-
+
{Log,_,_} = start_handler(?MODULE, ?FUNCTION_NAME, Config),
RestartAfter = ?OVERLOAD_KILL_RESTART_AFTER,
+
NewHConfig2 =
HConfig#{config=>StdHConfig#{overload_kill_enable=>true,
overload_kill_qlen=>10,
overload_kill_restart_after=>RestartAfter}},
- ok = logger:set_handler_config(?MODULE, NewHConfig2),
+ ok = logger:update_handler_config(?MODULE, NewHConfig2),
Pid0 = whereis(h_proc_name()),
MRef2 = erlang:monitor(process, Pid0),
%% kill handler
@@ -1102,7 +1206,7 @@ restart_after(Config) ->
ok
after
5000 ->
- Info2 = logger_std_h:info(?MODULE),
+ Info2 = logger_olp:info(h_proc_name()),
ct:pal("Handler state = ~p", [Info2]),
ct:fail("Handler not dead! It should not have survived this!")
end,
@@ -1123,12 +1227,16 @@ handler_requests_under_load(Config) ->
drop_mode_qlen => 1000,
flush_qlen => 2000,
burst_limit_enable => false}},
- ok = logger:set_handler_config(?MODULE, NewHConfig),
- Pid = spawn_link(fun() -> send_requests(?MODULE, 1, [{filesync,[]},
- {info,[]},
- {reset,[]},
- {change_config,[]}])
- end),
+ ok = logger:update_handler_config(?MODULE, NewHConfig),
+ Pid = spawn_link(
+ fun() -> send_requests(1,[{logger_std_h,filesync,[?MODULE],[]},
+ {logger_olp,info,[h_proc_name()],[]},
+ {logger_olp,reset,[h_proc_name()],[]},
+ {logger,update_handler_config,
+ [?MODULE, config,
+ #{overload_kill_enable => false}],
+ []}])
+ end),
Sent = send_burst({t,10000}, seq, {chars,79}, notice),
Pid ! {self(),finish},
ReqResult = receive {Pid,Result} -> Result end,
@@ -1139,36 +1247,45 @@ handler_requests_under_load(Config) ->
[E || E <- Res,
is_tuple(E) andalso (element(1,E) == error)]
end,
- Errors = [{Req,FindError(Res)} || {Req,Res} <- ReqResult],
- NoOfReqs = lists:foldl(fun({_,Res}, N) -> N + length(Res) end, 0, ReqResult),
+ Errors = [{Func,FindError(Res)} || {_,Func,_,Res} <- ReqResult],
+ NoOfReqs = lists:foldl(fun({_,_,_,Res}, N) -> N + length(Res) end,
+ 0, ReqResult),
ct:pal("~w requests made. Errors: ~n~p", [NoOfReqs,Errors]),
ok = file_delete(Log).
handler_requests_under_load(cleanup, _Config) ->
ok = stop_handler(?MODULE).
-send_requests(HName, TO, Reqs = [{Req,Res}|Rs]) ->
+recreate_deleted_log(Config) ->
+ {Log,_HConfig,_StdHConfig} =
+ start_handler(?MODULE, ?FUNCTION_NAME, Config),
+ logger:notice("first",?domain),
+ logger_std_h:filesync(?MODULE),
+ ok = file:rename(Log,Log++".old"),
+ logger:notice("second",?domain),
+ logger_std_h:filesync(?MODULE),
+ {ok,<<"first\n">>} = file:read_file(Log++".old"),
+ {ok,<<"second\n">>} = file:read_file(Log),
+ ok.
+recreate_deleted_log(cleanup, _Config) ->
+ ok = stop_handler(?MODULE).
+
+%%%-----------------------------------------------------------------
+%%%
+send_requests(TO, Reqs = [{Mod,Func,Args,Res}|Rs]) ->
receive
{From,finish} ->
From ! {self(),Reqs}
after
TO ->
- Result =
- case Req of
- change_config ->
- logger:set_handler_config(HName, config,
- #{overload_kill_enable =>
- false});
- Func ->
- logger_std_h:Func(HName)
- end,
- send_requests(HName, TO, Rs ++ [{Req,[Result|Res]}])
+ Result = apply(Mod,Func,Args),
+ send_requests(TO, Rs ++ [{Mod,Func,Args,[Result|Res]}])
end.
%%%-----------------------------------------------------------------
%%%
-start_handler(Name, TTY, Config) when TTY == standard_io;
- TTY == standard_error->
+start_handler(Name, TTY, _Config) when TTY == standard_io;
+ TTY == standard_error->
ok = logger:add_handler(Name,
logger_std_h,
#{config => #{type => TTY},
@@ -1422,7 +1539,7 @@ start_op_trace() ->
{ok,_} = dbg:p(self(), [c]),
MS1 = dbg:fun2ms(fun([_]) -> return_trace() end),
- {ok,_} = dbg:tp(logger_h_common, check_load, 1, MS1),
+ {ok,_} = dbg:tpl(logger_h_common, check_load, 1, MS1),
{ok,_} = dbg:tpl(logger_h_common, flush_log_requests, 2, []),
@@ -1496,7 +1613,10 @@ analyse(Msgs) ->
start_tracer(Trace,Expected) ->
Pid = self(),
- FileCtrlPid = maps:get(file_ctrl_pid, logger_std_h:info(?MODULE)),
+ FileCtrlPid = maps:get(file_ctrl_pid,
+ maps:get(handler_state,
+ maps:get(cb_state,
+ logger_olp:info(h_proc_name())))),
dbg:tracer(process,{fun tracer/2,{Pid,Expected}}),
dbg:p(whereis(h_proc_name()),[c]),
dbg:p(FileCtrlPid,[c]),
@@ -1504,7 +1624,9 @@ start_tracer(Trace,Expected) ->
ok.
tpl([{M,F,A}|Trace]) ->
- {ok,Match} = dbg:tpl(M,F,A,[]),
+ tpl([{{M,F,A},[]}|Trace]);
+tpl([{{M,F,A},MS}|Trace]) ->
+ {ok,Match} = dbg:tpl(M,F,A,MS),
case lists:keyfind(matched,1,Match) of
{_,_,1} ->
ok;
@@ -1517,7 +1639,7 @@ tpl([{M,F,A}|Trace]) ->
tpl([]) ->
ok.
-tracer({trace,_,call,{logger_std_h,handle_cast,[Op|_]}},
+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,_,_,_]}},
diff --git a/lib/kernel/test/logger_stress_SUITE.erl b/lib/kernel/test/logger_stress_SUITE.erl
new file mode 100644
index 0000000000..4072e8c86a
--- /dev/null
+++ b/lib/kernel/test/logger_stress_SUITE.erl
@@ -0,0 +1,456 @@
+%%
+%% %CopyrightBegin%
+%%
+%% Copyright Ericsson AB 2018. All Rights Reserved.
+%%
+%% Licensed under the Apache License, Version 2.0 (the "License");
+%% you may not use this file except in compliance with the License.
+%% You may obtain a copy of the License at
+%%
+%% http://www.apache.org/licenses/LICENSE-2.0
+%%
+%% Unless required by applicable law or agreed to in writing, software
+%% distributed under the License is distributed on an "AS IS" BASIS,
+%% WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+%% See the License for the specific language governing permissions and
+%% limitations under the License.
+%%
+%% %CopyrightEnd%
+%%
+-module(logger_stress_SUITE).
+
+-compile(export_all).
+
+-include_lib("common_test/include/ct_event.hrl").
+-include_lib("kernel/include/logger.hrl").
+-include_lib("kernel/src/logger_h_common.hrl").
+
+-ifdef(SAVE_STATS).
+ -define(COLLECT_STATS(_All_,_Procs_),
+ ct:pal("~p",[stats(_All_,_Procs_)])).
+-else.
+ -define(COLLECT_STATS(_All_,_Procs__), ok).
+-endif.
+
+-define(TEST_DURATION,120). % seconds
+
+suite() ->
+ [{timetrap,{minutes,3}},
+ {ct_hooks,[logger_test_lib]}].
+
+init_per_suite(Config) ->
+ Config.
+
+end_per_suite(_Config) ->
+ ok.
+
+init_per_group(_Group, Config) ->
+ Config.
+
+end_per_group(_Group, _Config) ->
+ ok.
+
+init_per_testcase(_TestCase, Config) ->
+ Config.
+
+end_per_testcase(Case, Config) ->
+ try apply(?MODULE,Case,[cleanup,Config])
+ catch error:undef -> ok
+ end,
+ ok.
+
+groups() ->
+ [].
+
+all() ->
+ [allow_events,
+ reject_events,
+ std_handler,
+ disk_log_handler,
+ emulator_events,
+ remote_events,
+ remote_to_disk_log,
+ remote_emulator_events,
+ remote_emulator_to_disk_log].
+
+%%%-----------------------------------------------------------------
+%%% Test cases
+%%%-----------------------------------------------------------------
+%% Time from log macro call to handler callback
+allow_events(Config) ->
+ {ok,_,Node} =
+ logger_test_lib:setup(Config,
+ [{logger,
+ [{handler,default,?MODULE,#{}}]},
+ {logger_level,notice}]),
+ N = 100000,
+ {T,_} = timer:tc(fun() -> rpc:call(Node,?MODULE,nlogs,[N]) end),
+ IOPS = N * 1000/T, % log events allowed per millisecond
+ ct_event:notify(#event{name = benchmark_data,
+ data = [{value,IOPS}]}),
+ {comment,io_lib:format("~.2f accepted events pr millisecond",
+ [IOPS])}.
+
+%% Time from log macro call to reject (log level)
+reject_events(Config) ->
+ {ok,_,Node} =
+ logger_test_lib:setup(Config,
+ [{logger,
+ [{handler,default,?MODULE,#{}}]},
+ {logger_level,error}]),
+ N = 1000000,
+ {T,_} = timer:tc(fun() -> rpc:call(Node,?MODULE,nlogs,[N]) end),
+ IOPS = N * 1000/T, % log events rejected per millisecond
+ ct_event:notify(#event{name = benchmark_data,
+ data = [{value,IOPS}]}),
+ {comment,io_lib:format("~.2f rejected events pr millisecond",
+ [IOPS])}.
+
+%% Cascading failure that produce gen_server and proc_lib reports -
+%% how many of the produced log events are actually written to a log
+%% with logger_std_h file handler.
+std_handler(Config) ->
+ {ok,_,Node} =
+ logger_test_lib:setup(Config,
+ [{logger,
+ [{handler,default,logger_std_h,
+ #{config=>#{type=>{file,"default.log"}}}}]}]),
+
+ cascade({Node,{logger_backend,log_allowed,2},[]},
+ {Node,{logger_std_h,write,4},[{default,logger_std_h_default}]},
+ fun otp_cascading/0).
+std_handler(cleanup,_Config) ->
+ _ = file:delete("default.log"),
+ ok.
+
+%% Cascading failure that produce gen_server and proc_lib reports -
+%% how many of the produced log events are actually written to a log
+%% with logger_disk_log_h wrap file handler.
+disk_log_handler(Config) ->
+ {ok,_,Node} =
+ logger_test_lib:setup(Config,
+ [{logger,
+ [{handler,default,logger_disk_log_h,#{}}]}]),
+ cascade({Node,{logger_backend,log_allowed,2},[]},
+ {Node,{logger_disk_log_h,write,4},
+ [{default,logger_disk_log_h_default}]},
+ fun otp_cascading/0).
+disk_log_handler(cleanup,_Config) ->
+ Files = filelib:wildcard("default.log.*"),
+ [_ = file:delete(F) || F <- Files],
+ ok.
+
+%% Cascading failure that produce log events from the emulator - how
+%% many of the produced log events pass through the proxy.
+emulator_events(Config) ->
+ {ok,_,Node} =
+ logger_test_lib:setup(Config,
+ [{logger,
+ [{handler,default,?MODULE,#{}}]}]),
+ cascade({Node,{?MODULE,producer,0},[]},
+ {Node,{?MODULE,log,2},[{proxy,logger_proxy}]},
+ fun em_cascading/0).
+
+%% Cascading failure that produce gen_server and proc_lib reports on
+%% remote node - how many of the produced log events pass through the
+%% proxy.
+remote_events(Config) ->
+ {ok,_,Node1} =
+ logger_test_lib:setup([{postfix,1}|Config],
+ [{logger,
+ [{handler,default,?MODULE,#{}}]}]),
+ {ok,_,Node2} =
+ logger_test_lib:setup([{postfix,2}|Config],[]),
+ cascade({Node2,{logger_backend,log_allowed,2},[{remote_proxy,logger_proxy}]},
+ {Node1,{?MODULE,log,2},[{local_proxy,logger_proxy}]},
+ fun otp_cascading/0).
+
+%% Cascading failure that produce gen_server and proc_lib reports on
+%% remote node - how many of the produced log events are actually
+%% written to a log with logger_disk_log_h wrap file handler.
+remote_to_disk_log(Config) ->
+ {ok,_,Node1} =
+ logger_test_lib:setup([{postfix,1}|Config],
+ [{logger,
+ [{handler,default,logger_disk_log_h,#{}}]}]),
+ {ok,_,Node2} =
+ logger_test_lib:setup([{postfix,2}|Config],[]),
+ cascade({Node2,{logger_backend,log_allowed,2},[{remote_proxy,logger_proxy}]},
+ {Node1,{logger_disk_log_h,write,4},
+ [{local_proxy,logger_proxy},
+ {local_default,logger_disk_log_h_default}]},
+ fun otp_cascading/0).
+remote_to_disk_log(cleanup,_Config) ->
+ Files = filelib:wildcard("default.log.*"),
+ [_ = file:delete(F) || F <- Files],
+ ok.
+
+%% Cascading failure that produce log events from the emulator on
+%% remote node - how many of the produced log events pass through the
+%% proxy.
+remote_emulator_events(Config) ->
+ {ok,_,Node1} =
+ logger_test_lib:setup([{postfix,1}|Config],
+ [{logger,
+ [{handler,default,?MODULE,#{}}]}]),
+ {ok,_,Node2} =
+ logger_test_lib:setup([{postfix,2}|Config],[]),
+ cascade({Node2,{?MODULE,producer,0},[{remote_proxy,logger_proxy}]},
+ {Node1,{?MODULE,log,2},[{local_proxy,logger_proxy}]},
+ fun em_cascading/0).
+
+%% Cascading failure that produce log events from the emulator on
+%% remote node - how many of the produced log events are actually
+%% written to a log with logger_disk_log_h wrap file handler.
+remote_emulator_to_disk_log(Config) ->
+ {ok,_,Node1} =
+ logger_test_lib:setup([{postfix,1}|Config],
+ [{logger,
+ [{handler,default,logger_disk_log_h,#{}}]}]),
+ {ok,_,Node2} =
+ logger_test_lib:setup([{postfix,2}|Config],[]),
+ cascade({Node2,{?MODULE,producer,0},[{remote_proxy,logger_proxy}]},
+ {Node1,{logger_disk_log_h,write,4},
+ [{local_proxy,logger_proxy},
+ {local_default,logger_disk_log_h_default}]},
+ fun em_cascading/0).
+remote_emulator_to_disk_log(cleanup,_Config) ->
+ Files = filelib:wildcard("default.log.*"),
+ [_ = file:delete(F) || F <- Files],
+ ok.
+
+%%%-----------------------------------------------------------------
+%%% Internal functions
+nlogs(N) ->
+ group_leader(whereis(user),self()),
+ Str = "\"#$%&'()*+,-./0123456789:;<=>?@ABCDEFGHIJKLMNOPQRSTUVWXYZ"
+ "[\\]^_`abcdefghijklmnopqr",
+ [?LOG_NOTICE(Str) || _ <- lists:seq(1,N)],
+ ok.
+
+%% cascade(ProducerInfo,ConsumerInfo,TestFun)
+cascade({PNode,PMFA,_PStatProcs},{CNode,CMFA,_CStatProcs},TestFun) ->
+ Tab = ets:new(counter,[set,public]),
+ ets:insert(Tab,{producer,0}),
+ ets:insert(Tab,{consumer,0}),
+ dbg:tracer(process,{fun tracer/2,{Tab,PNode,CNode}}),
+ dbg:n(PNode),
+ dbg:n(CNode),
+ dbg:cn(node()),
+ dbg:p(all,[call,arity]),
+ dbg:tpl(PMFA,[]),
+ dbg:tpl(CMFA,[]),
+
+ Pid = rpc:call(CNode,?MODULE,wrap_test,[PNode,TestFun]),
+ MRef = erlang:monitor(process,Pid),
+ TO = ?TEST_DURATION*1000,
+ receive {'DOWN',MRef,_,_,Reason} ->
+ ct:fail({remote_pid_down,Reason})
+ after TO ->
+ All = ets:lookup_element(Tab,producer,2),
+ Written = ets:lookup_element(Tab,consumer,2),
+ dbg:stop_clear(),
+ ?COLLECT_STATS(All,
+ [{PNode,P,Id} || {Id,P} <- _PStatProcs] ++
+ [{CNode,P,Id} || {Id,P} <- _CStatProcs]),
+ Ratio = Written/All * 100,
+ ct_event:notify(#event{name = benchmark_data,
+ data = [{value,Ratio}]}),
+ {comment,io_lib:format("~p % (~p written, ~p produced)",
+ [round(Ratio),Written,All])}
+ end.
+
+wrap_test(Fun) ->
+ wrap_test(node(),Fun).
+wrap_test(Node,Fun) ->
+ reset(),
+ group_leader(whereis(user),self()),
+ rpc:call(Node,?MODULE,do_fun,[Fun]).
+
+do_fun(Fun) ->
+ reset(),
+ Fun().
+
+reset() ->
+ reset([logger_std_h_default, logger_disk_log_h_default, logger_proxy]).
+reset([P|Ps]) ->
+ is_pid(whereis(P)) andalso logger_olp:reset(P),
+ reset(Ps);
+reset([]) ->
+ ok.
+
+
+tracer({trace,_,call,{?MODULE,producer,_}},{Tab,_PNode,_CNode}=S) ->
+ ets:update_counter(Tab,producer,1),
+ S;
+tracer({trace,Pid,call,{logger_backend,log_allowed,_}},{Tab,PNode,_CNode}=S) when node(Pid)=:=PNode ->
+ ets:update_counter(Tab,producer,1),
+ S;
+tracer({trace,_,call,{?MODULE,log,_}},{Tab,_PNode,_CNode}=S) ->
+ ets:update_counter(Tab,consumer,1),
+ S;
+tracer({trace,_,call,{_,write,_}},{Tab,_PNode,_CNode}=S) ->
+ ets:update_counter(Tab,consumer,1),
+ S;
+tracer(_,S) ->
+ S.
+
+
+%%%-----------------------------------------------------------------
+%%% Collect statistics
+-define(STAT_KEYS,
+ [burst_drops,
+ calls,
+ casts,
+ drops,
+ flushed,
+ flushes,
+ freq,
+ last_qlen,
+ max_qlen,
+ time,
+ writes]).
+-define(EVENT_KEYS,
+ [calls,casts,flushed]).
+
+stats(All,Procs) ->
+ NI = [{Id,rpc:call(N,logger_olp,info,[P])} || {N,P,Id}<-Procs],
+ [{all,All}|[stats(Id,I,All) || {Id,I} <- NI]].
+
+stats(Id,Info,All) ->
+ S = maps:with(?STAT_KEYS,Info),
+ AllOnProc = lists:sum(maps:values(maps:with(?EVENT_KEYS,S))),
+ if All>0 ->
+ Writes = maps:get(writes,S),
+ {_,ActiveTime} = maps:get(time,S),
+ Rate = round(100*Writes/All),
+ RateOnProc =
+ if AllOnProc>0 ->
+ round(100*Writes/AllOnProc);
+ true ->
+ 0
+ end,
+ AvFreq =
+ if ActiveTime>0 ->
+ round(Writes/ActiveTime);
+ true ->
+ 0
+ end,
+ {Id,
+ {stats,S},
+ {rate,Rate},
+ {rate_on_proc,RateOnProc},
+ {av_freq,AvFreq}};
+ true ->
+ {Id,none}
+ end.
+
+%%%-----------------------------------------------------------------
+%%% Spawn a lot of processes that crash repeatedly, causing a lot of
+%%% error reports from the emulator.
+em_cascading() ->
+ spawn(fun() -> super() end).
+
+super() ->
+ process_flag(trap_exit,true),
+ spawn_link(fun server/0),
+ [spawn_link(fun client/0) || _<-lists:seq(1,10000)],
+ super_loop().
+
+super_loop() ->
+ receive
+ {'EXIT',_,server} ->
+ spawn_link(fun server/0),
+ super_loop();
+ {'EXIT',_,_} ->
+ _L = lists:sum(lists:seq(1,10000)),
+ spawn_link(fun client/0),
+ super_loop()
+ end.
+
+client() ->
+ receive
+ after 1 ->
+ case whereis(server) of
+ Pid when is_pid(Pid) ->
+ ok;
+ undefined ->
+ producer(),
+ erlang:error(some_exception)
+ end
+ end,
+ client().
+
+server() ->
+ register(server,self()),
+ receive
+ after 3000 ->
+ exit(server)
+ end.
+
+
+%%%-----------------------------------------------------------------
+%%% Create a supervisor tree with processes that crash repeatedly,
+%%% causing a lot of supervisor reports and crashreports
+otp_cascading() ->
+ {ok,Pid} = supervisor:start_link({local,otp_super}, ?MODULE, [otp_super]),
+ unlink(Pid),
+ Pid.
+
+otp_server_sup() ->
+ supervisor:start_link({local,otp_server_sup},?MODULE,[otp_server_sup]).
+
+otp_client_sup(N) ->
+ supervisor:start_link({local,otp_client_sup},?MODULE,[otp_client_sup,N]).
+
+otp_server() ->
+ gen_server:start_link({local,otp_server},?MODULE,[otp_server],[]).
+
+otp_client() ->
+ gen_server:start_link(?MODULE,[otp_client],[]).
+
+init([otp_super]) ->
+ {ok, {{one_for_one, 200, 10},
+ [{client_sup,
+ {?MODULE, otp_client_sup, [10000]},
+ permanent, 1000, supervisor, [?MODULE]},
+ {server_sup,
+ {?MODULE, otp_server_sup, []},
+ permanent, 1000, supervisor, [?MODULE]}
+ ]}};
+init([otp_server_sup]) ->
+ {ok, {{one_for_one, 2, 10},
+ [{server,
+ {?MODULE, otp_server, []},
+ permanent, 1000, worker, [?MODULE]}
+ ]}};
+init([otp_client_sup,N]) ->
+ spawn(fun() ->
+ [supervisor:start_child(otp_client_sup,[])
+ || _ <- lists:seq(1,N)]
+ end),
+ {ok, {{simple_one_for_one, N*10, 1},
+ [{client,
+ {?MODULE, otp_client, []},
+ permanent, 1000, worker, [?MODULE]}
+ ]}};
+init([otp_server]) ->
+ {ok, server, 10000};
+init([otp_client]) ->
+ {ok, client,1}.
+
+handle_info(timeout, client) ->
+ true = is_pid(whereis(otp_server)),
+ {noreply,client,1};
+handle_info(timeout, server) ->
+ exit(self(), some_error).
+
+%%%-----------------------------------------------------------------
+%%% Logger callbacks
+log(_LogEvent,_Config) ->
+ ok.
+
+%%%-----------------------------------------------------------------
+%%% Function to trace on for counting produced emulator messages
+producer() ->
+ ok.
diff --git a/lib/kernel/test/logger_test_lib.erl b/lib/kernel/test/logger_test_lib.erl
index 81eb9ce5eb..be4bc427fb 100644
--- a/lib/kernel/test/logger_test_lib.erl
+++ b/lib/kernel/test/logger_test_lib.erl
@@ -28,11 +28,17 @@
post_end_per_testcase/5, post_end_per_suite/3]).
setup(Config,Vars) ->
+ Postfix = case proplists:get_value(postfix, Config) of
+ undefined -> "";
+ P -> ["_",P]
+ end,
FuncStr = lists:concat([proplists:get_value(suite, Config), "_",
- proplists:get_value(tc, Config)]),
+ proplists:get_value(tc, Config)|
+ Postfix]),
ConfigFileName = filename:join(proplists:get_value(priv_dir, Config), FuncStr),
file:write_file(ConfigFileName ++ ".config", io_lib:format("[{kernel, ~p}].",[Vars])),
- case test_server:start_node(proplists:get_value(tc, Config), slave,
+ Sname = lists:concat([proplists:get_value(tc,Config)|Postfix]),
+ case test_server:start_node(Sname, slave,
[{args, ["-pa ",filename:dirname(code:which(?MODULE)),
" -boot start_sasl -kernel start_timer true "
"-config ",ConfigFileName]}]) of
diff --git a/lib/kernel/test/prim_file_SUITE.erl b/lib/kernel/test/prim_file_SUITE.erl
index a02b5f87d1..2f465a15bc 100644
--- a/lib/kernel/test/prim_file_SUITE.erl
+++ b/lib/kernel/test/prim_file_SUITE.erl
@@ -1300,7 +1300,8 @@ e_delete(Config) when is_list(Config) ->
case os:type() of
{win32, _} ->
%% Remove a character device.
- {error, eacces} = ?PRIM_FILE:delete("nul");
+ expect({error, eacces}, {error, einval},
+ ?PRIM_FILE:delete("nul"));
_ ->
?PRIM_FILE:write_file_info(
Base, #file_info {mode=0}),
diff --git a/lib/kernel/test/sendfile_SUITE.erl b/lib/kernel/test/sendfile_SUITE.erl
index 0c0b1cbcb6..ad060aa05c 100644
--- a/lib/kernel/test/sendfile_SUITE.erl
+++ b/lib/kernel/test/sendfile_SUITE.erl
@@ -341,7 +341,21 @@ t_sendfile_closeduring(Config) ->
-1
end,
- ok = sendfile_send({127,0,0,1}, Send, 0).
+ ok = sendfile_send({127,0,0,1}, Send, 0, [{active,false}]),
+ [] = flush(),
+ ok = sendfile_send({127,0,0,1}, Send, 0, [{active,true}]),
+ [] = flush(),
+ ok.
+
+flush() ->
+ lists:reverse(flush([])).
+
+flush(Acc) ->
+ receive M ->
+ flush([M | Acc])
+ after 0 ->
+ Acc
+ end.
t_sendfile_crashduring(Config) ->
Filename = proplists:get_value(big_file, Config),
@@ -409,12 +423,16 @@ sendfile_send(Send) ->
sendfile_send(Host, Send) ->
sendfile_send(Host, Send, []).
sendfile_send(Host, Send, Orig) ->
+ sendfile_send(Host, Send, Orig, [{active,false}]).
+
+sendfile_send(Host, Send, Orig, SockOpts) ->
+
SFServer = spawn_link(?MODULE, sendfile_server, [self(), Orig]),
receive
{server, Port} ->
- {ok, Sock} = gen_tcp:connect(Host, Port,
- [binary,{packet,0},
- {active,false}]),
+ Opts = [binary,{packet,0}|SockOpts],
+ io:format("connect with opts = ~p\n", [Opts]),
+ {ok, Sock} = gen_tcp:connect(Host, Port, Opts),
Data = case proplists:get_value(arity,erlang:fun_info(Send)) of
1 ->
Send(Sock);
diff --git a/lib/kernel/test/seq_trace_SUITE.erl b/lib/kernel/test/seq_trace_SUITE.erl
index cf4bf11328..663f910751 100644
--- a/lib/kernel/test/seq_trace_SUITE.erl
+++ b/lib/kernel/test/seq_trace_SUITE.erl
@@ -19,13 +19,17 @@
%%
-module(seq_trace_SUITE).
+%% label_capability_mismatch needs to run a part of the test on an OTP 20 node.
+-compile(r20).
+
-export([all/0, suite/0,groups/0,init_per_suite/1, end_per_suite/1,
init_per_group/2,end_per_group/2,
init_per_testcase/2,end_per_testcase/2]).
-export([token_set_get/1, tracer_set_get/1, print/1,
send/1, distributed_send/1, recv/1, distributed_recv/1,
trace_exit/1, distributed_exit/1, call/1, port/1,
- match_set_seq_token/1, gc_seq_token/1, label_capability_mismatch/1]).
+ match_set_seq_token/1, gc_seq_token/1, label_capability_mismatch/1,
+ send_literal/1]).
%% internal exports
-export([simple_tracer/2, one_time_receiver/0, one_time_receiver/1,
@@ -44,7 +48,7 @@ suite() ->
{timetrap,{minutes,1}}].
all() ->
- [token_set_get, tracer_set_get, print, send,
+ [token_set_get, tracer_set_get, print, send, send_literal,
distributed_send, recv, distributed_recv, trace_exit,
distributed_exit, call, port, match_set_seq_token,
gc_seq_token, label_capability_mismatch].
@@ -158,23 +162,51 @@ do_print(TsType) ->
{0,{print,_,_,[],print3}, Ts1}] = stop_tracer(2),
check_ts(TsType, Ts0),
check_ts(TsType, Ts1).
-
+
send(Config) when is_list(Config) ->
lists:foreach(fun do_send/1, ?TIMESTAMP_MODES).
do_send(TsType) ->
+ do_send(TsType, send).
+
+do_send(TsType, Msg) ->
seq_trace:reset_trace(),
start_tracer(),
Receiver = spawn(?MODULE,one_time_receiver,[]),
Label = make_ref(),
seq_trace:set_token(label,Label),
set_token_flags([send, TsType]),
- Receiver ! send,
+ Receiver ! Msg,
Self = self(),
seq_trace:reset_trace(),
- [{Label,{send,_,Self,Receiver,send}, Ts}] = stop_tracer(1),
+ [{Label,{send,_,Self,Receiver,Msg}, Ts}] = stop_tracer(1),
check_ts(TsType, Ts).
+%% This testcase tests that we do not segfault when we have a
+%% literal as the message and the message is copied onto the
+%% heap during a GC.
+send_literal(Config) when is_list(Config) ->
+ lists:foreach(fun do_send_literal/1,
+ [atom, make_ref(), ets:new(hej,[]), 1 bsl 64,
+ "gurka", {tuple,test,with,#{}}, #{}]).
+
+do_send_literal(Msg) ->
+ N = 10000,
+ seq_trace:reset_trace(),
+ start_tracer(),
+ Label = make_ref(),
+ seq_trace:set_token(label,Label),
+ set_token_flags([send, 'receive', no_timestamp]),
+ Receiver = spawn_link(fun() -> receive ok -> ok end end),
+ [Receiver ! Msg || _ <- lists:seq(1, N)],
+ erlang:garbage_collect(Receiver),
+ [Receiver ! Msg || _ <- lists:seq(1, N)],
+ erlang:garbage_collect(Receiver),
+ Self = self(),
+ seq_trace:reset_trace(),
+ [{Label,{send,_,Self,Receiver,Msg}, Ts} | _] = stop_tracer(N),
+ check_ts(no_timestamp, Ts).
+
distributed_send(Config) when is_list(Config) ->
lists:foreach(fun do_distributed_send/1, ?TIMESTAMP_MODES).
@@ -329,7 +361,7 @@ do_incompatible_labels(Rel) ->
Mdir = filename:dirname(Dir),
true = rpc:call(Node,code,add_patha,[Mdir]),
seq_trace:reset_trace(),
- rpc:call(Node,?MODULE,start_tracer,[]),
+ true = is_pid(rpc:call(Node,?MODULE,start_tracer,[])),
Receiver = spawn(Node,?MODULE,one_time_receiver,[]),
%% This node does not support arbitrary labels, so it must fail with a
@@ -356,7 +388,7 @@ do_compatible_labels(Rel) ->
Mdir = filename:dirname(Dir),
true = rpc:call(Node,code,add_patha,[Mdir]),
seq_trace:reset_trace(),
- rpc:call(Node,?MODULE,start_tracer,[]),
+ true = is_pid(rpc:call(Node,?MODULE,start_tracer,[])),
Receiver = spawn(Node,?MODULE,one_time_receiver,[]),
%% This node does not support arbitrary labels, but small integers should
generated by cgit v1.2.3 (git 2.25.1) at 2024-08-28 11:06:02 +0000