aboutsummaryrefslogtreecommitdiffstats
path: root/lib/kernel
diff options
context:
space:
mode:
authorPeter Andersson <[email protected]>2018-06-04 14:55:08 +0200
committerSiri Hansen <[email protected]>2018-06-08 14:40:54 +0200
commite5bbcfd47088162a1c349eeb5aa3c37d8263d274 (patch)
treed9e3f2ecbd325faf87e7a80b17c112b0460f35e1 /lib/kernel
parent0a235e6b1f008ade99b18438e671b93ff82cc268 (diff)
downloadotp-e5bbcfd47088162a1c349eeb5aa3c37d8263d274.tar.gz
otp-e5bbcfd47088162a1c349eeb5aa3c37d8263d274.tar.bz2
otp-e5bbcfd47088162a1c349eeb5aa3c37d8263d274.zip
[logger] Change registered name of built-in handlers and use TID for mode table
Diffstat (limited to 'lib/kernel')
-rw-r--r--lib/kernel/src/logger_disk_log_h.erl121
-rw-r--r--lib/kernel/src/logger_h_common.erl32
-rw-r--r--lib/kernel/src/logger_h_common.hrl25
-rw-r--r--lib/kernel/src/logger_std_h.erl122
-rw-r--r--lib/kernel/test/logger_disk_log_h_SUITE.erl54
-rw-r--r--lib/kernel/test/logger_std_h_SUITE.erl48
6 files changed, 232 insertions, 170 deletions
diff --git a/lib/kernel/src/logger_disk_log_h.erl b/lib/kernel/src/logger_disk_log_h.erl
index 00643b6a84..ba90fefcd3 100644
--- a/lib/kernel/src/logger_disk_log_h.erl
+++ b/lib/kernel/src/logger_disk_log_h.erl
@@ -63,7 +63,8 @@ start_link(Name, Config, HandlerState) ->
sync(Name) when is_atom(Name) ->
try
- gen_server:call(Name, disk_log_sync, ?DEFAULT_CALL_TIMEOUT)
+ gen_server:call(?name_to_reg_name(?MODULE,Name),
+ disk_log_sync, ?DEFAULT_CALL_TIMEOUT)
catch
_:{timeout,_} -> {error,handler_busy}
end;
@@ -79,7 +80,8 @@ sync(Name) ->
info(Name) when is_atom(Name) ->
try
- gen_server:call(Name, info, ?DEFAULT_CALL_TIMEOUT)
+ gen_server:call(?name_to_reg_name(?MODULE,Name),
+ info, ?DEFAULT_CALL_TIMEOUT)
catch
_:{timeout,_} -> {error,handler_busy}
end;
@@ -94,7 +96,8 @@ info(Name) ->
reset(Name) when is_atom(Name) ->
try
- gen_server:call(Name, reset, ?DEFAULT_CALL_TIMEOUT)
+ gen_server:call(?name_to_reg_name(?MODULE,Name),
+ reset, ?DEFAULT_CALL_TIMEOUT)
catch
_:{timeout,_} -> {error,handler_busy}
end;
@@ -117,10 +120,10 @@ adding_handler(#{id:=Name}=Config) ->
case logger_h_common:overload_levels_ok(HState) of
true ->
case start(Name, Config1, HState) of
- ok ->
+ {ok,Config2} ->
%% Make sure wait_for_buffer is not stored, so we
%% won't hang and wait for buffer on a restart
- {ok, maps:remove(wait_for_buffer,Config1)};
+ {ok, maps:remove(wait_for_buffer,Config2)};
Error ->
Error
end;
@@ -136,13 +139,18 @@ adding_handler(#{id:=Name}=Config) ->
%%%-----------------------------------------------------------------
%%% Updating handler config
-changing_config(OldConfig=#{id:=Name, disk_log_opts:=DLOpts},
+changing_config(OldConfig=#{id:=Name, disk_log_opts:=DLOpts, ?MODULE:=HConfig},
NewConfig=#{id:=Name, disk_log_opts:=DLOpts}) ->
case check_config(changing, NewConfig) of
- Result = {ok,NewConfig1} ->
- try gen_server:call(Name, {change_config,OldConfig,NewConfig1},
+ {ok,NewConfig1 = #{?MODULE:=NewHConfig}} ->
+ #{handler_pid:=HPid,
+ mode_tab:=ModeTab} = HConfig,
+ NewHConfig1 = NewHConfig#{handler_pid=>HPid,
+ mode_tab=>ModeTab},
+ NewConfig2 = NewConfig1#{?MODULE=>NewHConfig1},
+ try gen_server:call(HPid, {change_config,OldConfig,NewConfig2},
?DEFAULT_CALL_TIMEOUT) of
- ok -> Result;
+ ok -> {ok,NewConfig2};
HError -> HError
catch
_:{timeout,_} -> {error,handler_busy}
@@ -225,12 +233,12 @@ removing_handler(#{id:=Name}) ->
%%%-----------------------------------------------------------------
%%% Get buffer when swapping from simple handler
-swap_buffer(Name,Buffer) ->
- case whereis(Name) of
+swap_buffer(Name, Buffer) ->
+ case whereis(?name_to_reg_name(?MODULE,Name)) of
undefined ->
ok;
- _ ->
- Name ! {buffer,Buffer}
+ Pid ->
+ Pid ! {buffer,Buffer}
end.
%%%-----------------------------------------------------------------
@@ -239,21 +247,22 @@ swap_buffer(Name,Buffer) ->
LogEvent :: logger:log_event(),
Config :: logger:config().
-log(LogEvent,Config=#{id:=Name}) ->
+log(LogEvent, Config = #{id := Name,
+ ?MODULE := #{handler_pid := HPid,
+ mode_tab := ModeTab}}) ->
%% if the handler has crashed, we must drop this request
%% and hope the handler restarts so we can try again
- true = is_pid(whereis(Name)),
- Bin = logger_h_common:log_to_binary(LogEvent,Config),
- logger_h_common:call_cast_or_drop(Name, Bin).
-
+ true = is_process_alive(HPid),
+ Bin = logger_h_common:log_to_binary(LogEvent, Config),
+ logger_h_common:call_cast_or_drop(Name, HPid, ModeTab, Bin).
%%%===================================================================
%%% gen_server callbacks
%%%===================================================================
-init([Name, Config = #{disk_log_opts := LogOpts},
+init([Name, Config = #{?MODULE := HConfig, disk_log_opts := LogOpts},
State = #{dl_sync_int := DLSyncInt}]) ->
- register(Name, self()),
+ register(?name_to_reg_name(?MODULE,Name), self()),
process_flag(trap_exit, true),
process_flag(message_queue_data, off_heap),
@@ -262,25 +271,36 @@ init([Name, Config = #{disk_log_opts := LogOpts},
case open_disk_log(Name, LogOpts) of
ok ->
- catch ets:new(Name, [public, named_table]),
- ?set_mode(Name, async),
- proc_lib:init_ack({ok,self()}),
- T0 = ?timestamp(),
- State1 =
- ?merge_with_stats(State#{id => Name,
- mode => async,
- dl_sync => DLSyncInt,
- log_opts => LogOpts,
- last_qlen => 0,
- last_log_ts => T0,
- burst_win_ts => T0,
- burst_msg_count => 0,
- last_op => sync,
- prev_log_result => ok,
- prev_sync_result => ok,
- prev_disk_log_info => undefined}),
- gen_server:cast(self(), repeated_disk_log_sync),
- enter_loop(Config, State1);
+ try ets:new(Name, [public]) of
+ ModeTab ->
+ ?set_mode(ModeTab, async),
+ T0 = ?timestamp(),
+ State1 =
+ ?merge_with_stats(State#{
+ id => Name,
+ mode_tab => ModeTab,
+ mode => async,
+ dl_sync => DLSyncInt,
+ log_opts => LogOpts,
+ last_qlen => 0,
+ last_log_ts => T0,
+ burst_win_ts => T0,
+ burst_msg_count => 0,
+ last_op => sync,
+ prev_log_result => ok,
+ prev_sync_result => ok,
+ prev_disk_log_info => undefined}),
+ Config1 =
+ Config#{?MODULE => HConfig#{handler_pid => self(),
+ mode_tab => ModeTab}},
+ proc_lib:init_ack({ok,self(),Config1}),
+ gen_server:cast(self(), repeated_disk_log_sync),
+ enter_loop(Config1, State1)
+ catch
+ _:Error ->
+ logger_h_common:error_notify({open_disk_log,Name,Error}),
+ proc_lib:init_ack(Error)
+ end;
Error ->
logger_h_common:error_notify({open_disk_log,Name,Error}),
proc_lib:init_ack(Error)
@@ -477,8 +497,8 @@ start(Name, Config, HandlerState) ->
type => worker,
modules => [?MODULE]},
case supervisor:start_child(logger_sup, LoggerDLH) of
- {ok,_} ->
- ok;
+ {ok,_Pid,Config1} ->
+ {ok,Config1};
Error ->
Error
end.
@@ -486,16 +506,16 @@ start(Name, Config, HandlerState) ->
%%%-----------------------------------------------------------------
%%% Stop and remove the handler.
stop(Name) ->
- case whereis(Name) of
+ case whereis(?name_to_reg_name(?MODULE,Name)) of
undefined ->
ok;
- _ ->
+ Pid ->
%% We don't want to do supervisor:terminate_child here
%% since we need to distinguish this explicit stop from a
%% system termination in order to avoid circular attempts
%% at removing the handler (implying deadlocks and
%% timeouts).
- _ = gen_server:call(Name,stop),
+ _ = gen_server:call(Pid, stop),
_ = supervisor:delete_child(logger_sup, Name),
ok
end.
@@ -530,7 +550,7 @@ do_log(Bin, CallOrCast, State = #{id:=Name, mode := _Mode0}) ->
%% this function is called by do_log/3 after an overload check
%% has been performed, where QLen > FlushQLen
-flush(Name, _QLen0, T1, State=#{last_log_ts := _T0}) ->
+flush(_Name, _QLen0, T1, State=#{last_log_ts := _T0, mode_tab := ModeTab}) ->
%% flush messages in the mailbox (a limited number in
%% order to not cause long delays)
_NewFlushed = logger_h_common:flush_log_requests(?FLUSH_MAX_N),
@@ -539,20 +559,21 @@ flush(Name, _QLen0, T1, State=#{last_log_ts := _T0}) ->
%% handler will be scheduled out often and the mailbox could
%% grow very large, so we'd better check the queue again here
{_,_QLen1} = process_info(self(), message_queue_len),
- ?observe(Name,{max_qlen,_QLen1}),
+ ?observe(_Name,{max_qlen,_QLen1}),
%% Add 1 for the current log request
- ?observe(Name,{flushed,_NewFlushed+1}),
+ ?observe(_Name,{flushed,_NewFlushed+1}),
State1 = ?update_max_time(?diff_time(T1,_T0),State),
{dropped,?update_other(flushed,FLUSHED,_NewFlushed,
- State1#{mode => ?set_mode(Name,async),
+ State1#{mode => ?set_mode(ModeTab,async),
last_qlen => 0,
last_log_ts => T1})}.
%% this function is called to write to disk_log
write(Name, Mode, T1, Bin, _CallOrCast,
- State = #{dl_sync := DLSync,
+ State = #{mode_tab := ModeTab,
+ dl_sync := DLSync,
dl_sync_int := DLSyncInt,
last_qlen := LastQLen,
last_log_ts := T0}) ->
@@ -589,7 +610,7 @@ write(Name, Mode, T1, Bin, _CallOrCast,
{Mode1,BurstMsgCount1,State2} =
if (LastQLen1 < ?FILESYNC_OK_QLEN) andalso
(Time > ?IDLE_DETECT_TIME_USEC) ->
- {?change_mode(Name,Mode,async), 0, disk_log_sync(Name,State1)};
+ {?change_mode(ModeTab,Mode,async), 0, disk_log_sync(Name,State1)};
true ->
{Mode, BurstMsgCount,State1}
end,
diff --git a/lib/kernel/src/logger_h_common.erl b/lib/kernel/src/logger_h_common.erl
index 336398cd4a..73a5b27ea1 100644
--- a/lib/kernel/src/logger_h_common.erl
+++ b/lib/kernel/src/logger_h_common.erl
@@ -24,7 +24,7 @@
-export([log_to_binary/2,
check_common_config/1,
- call_cast_or_drop/2,
+ call_cast_or_drop/4,
check_load/1,
limit_burst/1,
kill_if_choked/4,
@@ -84,6 +84,10 @@ try_format(Log,Formatter,FormatterConfig) ->
%%%-----------------------------------------------------------------
%%% Check that the configuration term is valid
+check_common_config({mode_tab,_Tid}) ->
+ valid;
+check_common_config({handler_pid,Pid}) when is_pid(Pid) ->
+ valid;
check_common_config({toggle_sync_qlen,N}) when is_integer(N) ->
valid;
check_common_config({drop_new_reqs_qlen,N}) when is_integer(N) ->
@@ -116,16 +120,16 @@ check_common_config(_) ->
%%%-----------------------------------------------------------------
%%% Overload Protection
-call_cast_or_drop(Name, Bin) ->
+call_cast_or_drop(_Name, HandlerPid, ModeTab, Bin) ->
%% If the handler process is getting overloaded, the log request
%% will be synchronous instead of asynchronous (slows down the
%% logging tempo of a process doing lots of logging. If the
%% handler is choked, drop mode is set and no request will be sent.
- try ?get_mode(Name) of
+ try ?get_mode(ModeTab) of
async ->
- gen_server:cast(Name, {log,Bin});
+ gen_server:cast(HandlerPid, {log,Bin});
sync ->
- try gen_server:call(Name, {log,Bin}, ?DEFAULT_CALL_TIMEOUT) of
+ try gen_server:call(HandlerPid, {log,Bin}, ?DEFAULT_CALL_TIMEOUT) of
%% if return value from call == dropped, the
%% message has been flushed by handler and should
%% therefore not be counted as dropped in stats
@@ -133,28 +137,28 @@ call_cast_or_drop(Name, Bin) ->
dropped -> ok
catch
_:{timeout,_} ->
- ?observe(Name,{dropped,1})
+ ?observe(_Name,{dropped,1})
end;
drop ->
- ?observe(Name,{dropped,1})
+ ?observe(_Name,{dropped,1})
catch
%% if the ETS table doesn't exist (maybe because of a
%% handler restart), we can only drop the request
- _:_ -> ?observe(Name,{dropped,1})
+ _:_ -> ?observe(_Name,{dropped,1})
end,
ok.
handler_exit(_Name, Reason) ->
exit(Reason).
-check_load(State = #{id:=Name, mode := Mode,
+check_load(State = #{id:=_Name, mode_tab := ModeTab, mode := Mode,
toggle_sync_qlen := ToggleSyncQLen,
drop_new_reqs_qlen := DropNewQLen,
flush_reqs_qlen := FlushQLen}) ->
{_,Mem} = process_info(self(), memory),
- ?observe(Name,{max_mem,Mem}),
+ ?observe(_Name,{max_mem,Mem}),
{_,QLen} = process_info(self(), message_queue_len),
- ?observe(Name,{max_qlen,QLen}),
+ ?observe(_Name,{max_qlen,QLen}),
%% When the handler process gets scheduled in, it's impossible
%% to predict the QLen. We could jump "up" arbitrarily from say
%% async to sync, async to drop, sync to flush, etc. However, when
@@ -171,11 +175,11 @@ check_load(State = #{id:=Name, mode := Mode,
%% be dropped on the client side (never sent get to
%% the handler).
IncDrops = if Mode == drop -> 0; true -> 1 end,
- {?change_mode(Name, Mode, drop), IncDrops,0};
+ {?change_mode(ModeTab, Mode, drop), IncDrops,0};
QLen >= ToggleSyncQLen ->
- {?change_mode(Name, Mode, sync), 0,0};
+ {?change_mode(ModeTab, Mode, sync), 0,0};
true ->
- {?change_mode(Name, Mode, async), 0,0}
+ {?change_mode(ModeTab, Mode, async), 0,0}
end,
State1 = ?update_other(drops,DROPS,_NewDrops,State),
{Mode1, QLen, Mem,
diff --git a/lib/kernel/src/logger_h_common.hrl b/lib/kernel/src/logger_h_common.hrl
index ed365ce6eb..e4d3431468 100644
--- a/lib/kernel/src/logger_h_common.hrl
+++ b/lib/kernel/src/logger_h_common.hrl
@@ -77,29 +77,30 @@
-define(DISK_LOG_MAX_NO_BYTES, 1048576).
%%%-----------------------------------------------------------------
+%%% Utility macros
+
+-define(name_to_reg_name(MODULE,Name),
+ list_to_atom(lists:concat([MODULE,"_",Name]))).
+
+%%%-----------------------------------------------------------------
%%% Overload protection macros
-define(timestamp(), erlang:monotonic_time(microsecond)).
--define(get_mode(HandlerName),
- case ets:lookup(HandlerName, mode) of
- [{mode,sync}] ->
- case whereis(HandlerName)==self() of
- true -> async;
- _ -> sync
- end;
+-define(get_mode(Tid),
+ case ets:lookup(Tid, mode) of
[{mode,M}] -> M;
_ -> async
end).
--define(set_mode(HandlerName, M),
- begin ets:insert(HandlerName, {mode,M}), M end).
+-define(set_mode(Tid, M),
+ begin ets:insert(Tid, {mode,M}), M end).
--define(change_mode(HandlerName, M0, M1),
+-define(change_mode(Tid, M0, M1),
if M0 == M1 ->
M0;
true ->
- ets:insert(HandlerName, {mode,M1}),
+ ets:insert(Tid, {mode,M1}),
M1
end).
@@ -124,7 +125,7 @@
%%% slow down execution and therefore should not be include in code
%%% to be officially released.
--define(TEST_HOOKS, true).
+%%-define(TEST_HOOKS, true).
-ifdef(TEST_HOOKS).
-define(TEST_HOOKS_TAB, logger_h_test_hooks).
diff --git a/lib/kernel/src/logger_std_h.erl b/lib/kernel/src/logger_std_h.erl
index 323f4f02e7..5ec9eced12 100644
--- a/lib/kernel/src/logger_std_h.erl
+++ b/lib/kernel/src/logger_std_h.erl
@@ -64,7 +64,8 @@ start_link(Name, Config, HandlerState) ->
sync(Name) when is_atom(Name) ->
try
- gen_server:call(Name, filesync, ?DEFAULT_CALL_TIMEOUT)
+ gen_server:call(?name_to_reg_name(?MODULE,Name),
+ filesync, ?DEFAULT_CALL_TIMEOUT)
catch
_:{timeout,_} -> {error,handler_busy}
end;
@@ -80,7 +81,8 @@ sync(Name) ->
info(Name) when is_atom(Name) ->
try
- gen_server:call(Name, info, ?DEFAULT_CALL_TIMEOUT)
+ gen_server:call(?name_to_reg_name(?MODULE,Name),
+ info, ?DEFAULT_CALL_TIMEOUT)
catch
_:{timeout,_} -> {error,handler_busy}
end;
@@ -95,7 +97,8 @@ info(Name) ->
reset(Name) when is_atom(Name) ->
try
- gen_server:call(Name, reset, ?DEFAULT_CALL_TIMEOUT)
+ gen_server:call(?name_to_reg_name(?MODULE,Name),
+ reset, ?DEFAULT_CALL_TIMEOUT)
catch
_:{timeout,_} -> {error,handler_busy}
end;
@@ -118,10 +121,10 @@ adding_handler(#{id:=Name}=Config) ->
case logger_h_common:overload_levels_ok(HState) of
true ->
case start(Name, Config1, HState) of
- ok ->
+ {ok,Config2} ->
%% Make sure wait_for_buffer is not stored, so we
%% won't hang and wait for buffer on a restart
- {ok, maps:remove(wait_for_buffer,Config1)};
+ {ok, maps:remove(wait_for_buffer,Config2)};
Error ->
Error
end;
@@ -137,13 +140,16 @@ adding_handler(#{id:=Name}=Config) ->
%%%-----------------------------------------------------------------
%%% Updating handler config
-changing_config(OldConfig=#{id:=Name, ?MODULE:=#{type:=Type}},
+changing_config(OldConfig=#{id:=Name, ?MODULE:=HConfig},
NewConfig=#{id:=Name}) ->
+ #{type:=Type, handler_pid:=HPid, mode_tab:=ModeTab} = HConfig,
MyConfig = maps:get(?MODULE, NewConfig, #{}),
case maps:get(type, MyConfig, Type) of
Type ->
- MyConfig1 = MyConfig#{type=>Type},
- changing_config1(Name, OldConfig,
+ MyConfig1 = MyConfig#{type=>Type,
+ handler_pid=>HPid,
+ mode_tab=>ModeTab},
+ changing_config1(HPid, OldConfig,
NewConfig#{?MODULE=>MyConfig1});
_ ->
{error,{illegal_config_change,OldConfig,NewConfig}}
@@ -151,10 +157,10 @@ changing_config(OldConfig=#{id:=Name, ?MODULE:=#{type:=Type}},
changing_config(OldConfig, NewConfig) ->
{error,{illegal_config_change,OldConfig,NewConfig}}.
-changing_config1(Name, OldConfig, NewConfig) ->
+changing_config1(HPid, OldConfig, NewConfig) ->
case check_config(changing, NewConfig) of
Result = {ok,NewConfig1} ->
- try gen_server:call(Name, {change_config,OldConfig,NewConfig1},
+ try gen_server:call(HPid, {change_config,OldConfig,NewConfig1},
?DEFAULT_CALL_TIMEOUT) of
ok -> Result;
HError -> HError
@@ -209,12 +215,12 @@ removing_handler(#{id:=Name}) ->
%%%-----------------------------------------------------------------
%%% Get buffer when swapping from simple handler
-swap_buffer(Name,Buffer) ->
- case whereis(Name) of
+swap_buffer(Name, Buffer) ->
+ case whereis(?name_to_reg_name(?MODULE,Name)) of
undefined ->
ok;
- _ ->
- Name ! {buffer,Buffer}
+ Pid ->
+ Pid ! {buffer,Buffer}
end.
%%%-----------------------------------------------------------------
@@ -223,20 +229,22 @@ swap_buffer(Name,Buffer) ->
LogEvent :: logger:log_event(),
Config :: logger:config().
-log(LogEvent,Config=#{id:=Name}) ->
+log(LogEvent, Config = #{id := Name,
+ ?MODULE := #{handler_pid := HPid,
+ mode_tab := ModeTab}}) ->
%% if the handler has crashed, we must drop this request
%% and hope the handler restarts so we can try again
- true = is_pid(whereis(Name)),
- Bin = logger_h_common:log_to_binary(LogEvent,Config),
- logger_h_common:call_cast_or_drop(Name, Bin).
+ true = is_process_alive(HPid),
+ Bin = logger_h_common:log_to_binary(LogEvent, Config),
+ logger_h_common:call_cast_or_drop(Name, HPid, ModeTab, Bin).
%%%===================================================================
%%% gen_server callbacks
%%%===================================================================
-init([Name, Config,
- State0 = #{type := Type, file_ctrl_sync_int := FileCtrlSyncInt}]) ->
- register(Name, self()),
+init([Name, Config = #{?MODULE := HConfig},
+ State0 = #{type := Type, file_ctrl_sync_int := FileCtrlSyncInt}]) ->
+ register(?name_to_reg_name(?MODULE,Name), self()),
process_flag(trap_exit, true),
process_flag(message_queue_data, off_heap),
@@ -245,21 +253,32 @@ init([Name, Config,
case do_init(Name, Type) of
{ok,InitState} ->
- catch ets:new(Name, [public, named_table]),
- ?set_mode(Name, async),
- State = maps:merge(State0, InitState),
- T0 = ?timestamp(),
- State1 =
- ?merge_with_stats(State#{mode => async,
- file_ctrl_sync => FileCtrlSyncInt,
- last_qlen => 0,
- last_log_ts => T0,
- last_op => sync,
- burst_win_ts => T0,
- burst_msg_count => 0}),
- proc_lib:init_ack({ok,self()}),
- gen_server:cast(self(), repeated_filesync),
- enter_loop(Config, State1);
+ try ets:new(Name, [public]) of
+ ModeTab ->
+ ?set_mode(ModeTab, async),
+ State = maps:merge(State0, InitState),
+ T0 = ?timestamp(),
+ State1 =
+ ?merge_with_stats(State#{
+ mode_tab => ModeTab,
+ mode => async,
+ file_ctrl_sync => FileCtrlSyncInt,
+ last_qlen => 0,
+ last_log_ts => T0,
+ last_op => sync,
+ burst_win_ts => T0,
+ burst_msg_count => 0}),
+ Config1 =
+ Config#{?MODULE => HConfig#{handler_pid => self(),
+ mode_tab => ModeTab}},
+ proc_lib:init_ack({ok,self(),Config1}),
+ gen_server:cast(self(), repeated_filesync),
+ enter_loop(Config1, State1)
+ catch
+ _:Error ->
+ logger_h_common:error_notify({init_handler,Name,Error}),
+ proc_lib:init_ack(Error)
+ end;
Error ->
logger_h_common:error_notify({init_handler,Name,Error}),
proc_lib:init_ack(Error)
@@ -466,8 +485,8 @@ start(Name, Config, HandlerState) ->
type => worker,
modules => [?MODULE]},
case supervisor:start_child(logger_sup, LoggerStdH) of
- {ok,_Pid} ->
- ok;
+ {ok,_Pid,Config1} ->
+ {ok,Config1};
Error ->
Error
end.
@@ -475,16 +494,16 @@ start(Name, Config, HandlerState) ->
%%%-----------------------------------------------------------------
%%% Stop and remove the handler.
stop(Name) ->
- case whereis(Name) of
+ case whereis(?name_to_reg_name(?MODULE,Name)) of
undefined ->
ok;
- _ ->
+ Pid ->
%% We don't want to do supervisor:terminate_child here
%% since we need to distinguish this explicit stop from a
%% system termination in order to avoid circular attempts
%% at removing the handler (implying deadlocks and
%% timeouts).
- _ = gen_server:call(Name,stop),
+ _ = gen_server:call(Pid, stop),
_ = supervisor:delete_child(logger_sup, Name),
ok
end.
@@ -519,7 +538,7 @@ do_log(Bin, CallOrCast, State = #{id:=Name}) ->
%% this clause is called by do_log/3 after an overload check
%% has been performed, where QLen > FlushQLen
-flush(Name, _QLen0, T1, State=#{last_log_ts := _T0}) ->
+flush(_Name, _QLen0, T1, State=#{last_log_ts := _T0, mode_tab := ModeTab}) ->
%% flush messages in the mailbox (a limited number in
%% order to not cause long delays)
_NewFlushed = logger_h_common:flush_log_requests(?FLUSH_MAX_N),
@@ -528,20 +547,21 @@ flush(Name, _QLen0, T1, State=#{last_log_ts := _T0}) ->
%% handler will be scheduled out often and the mailbox could
%% grow very large, so we'd better check the queue again here
{_,_QLen1} = process_info(self(), message_queue_len),
- ?observe(Name,{max_qlen,_QLen1}),
+ ?observe(_Name,{max_qlen,_QLen1}),
%% Add 1 for the current log request
- ?observe(Name,{flushed,_NewFlushed+1}),
+ ?observe(_Name,{flushed,_NewFlushed+1}),
State1 = ?update_max_time(?diff_time(T1,_T0),State),
{dropped,?update_other(flushed,FLUSHED,_NewFlushed,
- State1#{mode => ?set_mode(Name,async),
+ State1#{mode => ?set_mode(ModeTab,async),
last_qlen => 0,
last_log_ts => T1})}.
%% this clause is called to write to file
-write(Name, Mode, T1, Bin, _CallOrCast,
- State = #{file_ctrl_pid := FileCtrlPid,
+write(_Name, Mode, T1, Bin, _CallOrCast,
+ State = #{mode_tab := ModeTab,
+ file_ctrl_pid := FileCtrlPid,
file_ctrl_sync := FileCtrlSync,
last_qlen := LastQLen,
last_log_ts := T0,
@@ -555,15 +575,15 @@ write(Name, Mode, T1, Bin, _CallOrCast,
%% file writes so it can keep up with incoming messages
{Result,LastQLen1} =
if DoWrite, FileCtrlSync == 0 ->
- ?observe(Name,{_CallOrCast,1}),
+ ?observe(_Name,{_CallOrCast,1}),
file_write_sync(FileCtrlPid, Bin, false),
{ok,element(2, process_info(self(), message_queue_len))};
DoWrite ->
- ?observe(Name,{_CallOrCast,1}),
+ ?observe(_Name,{_CallOrCast,1}),
file_write_async(FileCtrlPid, Bin),
{ok,LastQLen};
not DoWrite ->
- ?observe(Name,{flushed,1}),
+ ?observe(_Name,{flushed,1}),
{dropped,LastQLen}
end,
@@ -585,7 +605,7 @@ write(Name, Mode, T1, Bin, _CallOrCast,
_File ->
file_ctrl_filesync_async(FileCtrlPid)
end,
- {?change_mode(Name, Mode, async),0};
+ {?change_mode(ModeTab, Mode, async),0};
true ->
{Mode,BurstMsgCount}
end,
diff --git a/lib/kernel/test/logger_disk_log_h_SUITE.erl b/lib/kernel/test/logger_disk_log_h_SUITE.erl
index 2b5bbe6aed..e1b1f16414 100644
--- a/lib/kernel/test/logger_disk_log_h_SUITE.erl
+++ b/lib/kernel/test/logger_disk_log_h_SUITE.erl
@@ -107,10 +107,10 @@ start_stop_handler(_Config) ->
ok = logger:add_handler(?MODULE, logger_disk_log_h, #{}),
{error,{already_exist,?MODULE}} =
logger:add_handler(?MODULE, logger_disk_log_h, #{}),
- true = is_pid(whereis(?MODULE)),
+ true = is_pid(whereis(h_proc_name())),
ok = logger:remove_handler(?MODULE),
timer:sleep(500),
- undefined = whereis(?MODULE).
+ undefined = whereis(h_proc_name()).
start_stop_handler(cleanup, _Config) ->
logger:remove_handler(?MODULE).
@@ -326,7 +326,7 @@ formatter_fail(Config) ->
filters=>?DEFAULT_HANDLER_FILTERS([?MODULE])},
%% no formatter!
logger:add_handler(Name, logger_disk_log_h, HConfig),
- Pid = whereis(Name),
+ Pid = whereis(h_proc_name(Name)),
true = is_pid(Pid),
#{handlers:=HC1} = logger:i(),
H = [Id || {Id,_,_} <- HC1],
@@ -357,7 +357,7 @@ formatter_fail(Config) ->
5000),
%% Check that handler is still alive and was never dead
- Pid = whereis(Name),
+ Pid = whereis(h_proc_name(Name)),
#{handlers:=HC2} = logger:i(),
H = [Id || {Id,_,_} <- HC2],
ok.
@@ -598,7 +598,7 @@ disk_log_wrap(Config) ->
Pid
end,
{ok,_} = dbg:tracer(process, {TraceFun, Tester}),
- {ok,_} = dbg:p(whereis(?MODULE), [c]),
+ {ok,_} = dbg:p(whereis(h_proc_name()), [c]),
{ok,_} = dbg:tp(logger_disk_log_h, handle_info, 2, []),
Text = [34 + rand:uniform(126-34) || _ <- lists:seq(1,MaxBytes)],
@@ -652,7 +652,7 @@ disk_log_full(Config) ->
Pid
end,
{ok,_} = dbg:tracer(process, {TraceFun, Tester}),
- {ok,_} = dbg:p(whereis(?MODULE), [c]),
+ {ok,_} = dbg:p(whereis(h_proc_name()), [c]),
{ok,_} = dbg:tp(logger_disk_log_h, handle_info, 2, []),
NoOfChars = 5,
@@ -701,10 +701,10 @@ disk_log_events(Config) ->
Pid
end,
{ok,_} = dbg:tracer(process, {TraceFun, Tester}),
- {ok,_} = dbg:p(whereis(?MODULE), [c]),
+ {ok,_} = dbg:p(whereis(h_proc_name()), [c]),
{ok,_} = dbg:tp(logger_disk_log_h, handle_info, 2, []),
- [whereis(?MODULE) ! E || E <- Events],
+ [whereis(h_proc_name()) ! E || E <- Events],
%% wait for trace messages
timer:sleep(2000),
dbg:stop_clear(),
@@ -889,7 +889,7 @@ op_switch_to_drop(Config) ->
[send_burst({n,NumOfReqs}, {spawn,Procs,0}, {chars,79}, info) ||
_ <- lists:seq(1, Bursts)],
Logged = count_lines(Log),
- ok= stop_handler(?MODULE),
+ ok = stop_handler(?MODULE),
_ = file:delete(Log),
ct:pal("Number of messages dropped = ~w (~w)",
[Procs*NumOfReqs*Bursts-Logged,Procs*NumOfReqs*Bursts]),
@@ -1033,14 +1033,14 @@ kill_disabled(Config) ->
Logged = count_lines(Log),
ct:pal("Number of messages logged = ~w", [Logged]),
ok = file:delete(Log),
- true = is_pid(whereis(?MODULE)),
+ true = is_pid(whereis(h_proc_name())),
ok.
kill_disabled(cleanup, _Config) ->
ok = stop_handler(?MODULE).
qlen_kill_new(Config) ->
{_Log,HConfig,DLHConfig} = start_handler(?MODULE, ?FUNCTION_NAME, Config),
- Pid0 = whereis(?MODULE),
+ Pid0 = whereis(h_proc_name()),
{_,Mem0} = process_info(Pid0, memory),
RestartAfter = ?HANDLER_RESTART_AFTER,
NewHConfig =
@@ -1064,7 +1064,7 @@ qlen_kill_new(Config) ->
ct:pal("Slow shutdown, handler process was killed!", [])
end,
timer:sleep(RestartAfter + 2000),
- true = is_pid(whereis(?MODULE)),
+ true = is_pid(whereis(h_proc_name())),
ok
after
5000 ->
@@ -1077,7 +1077,7 @@ qlen_kill_new(cleanup, _Config) ->
mem_kill_new(Config) ->
{_Log,HConfig,DLHConfig} = start_handler(?MODULE, ?FUNCTION_NAME, Config),
- Pid0 = whereis(?MODULE),
+ Pid0 = whereis(h_proc_name()),
{_,Mem0} = process_info(Pid0, memory),
RestartAfter = ?HANDLER_RESTART_AFTER,
NewHConfig =
@@ -1101,7 +1101,7 @@ mem_kill_new(Config) ->
ct:pal("Slow shutdown, handler process was killed!", [])
end,
timer:sleep(RestartAfter + 2000),
- true = is_pid(whereis(?MODULE)),
+ true = is_pid(whereis(h_proc_name())),
ok
after
5000 ->
@@ -1119,13 +1119,13 @@ restart_after(Config) ->
handler_overloaded_qlen=>10,
handler_restart_after=>never}},
ok = logger:set_handler_config(?MODULE, NewHConfig1),
- MRef1 = erlang:monitor(process, whereis(?MODULE)),
+ MRef1 = erlang:monitor(process, whereis(h_proc_name())),
%% kill handler
send_burst({n,100}, {spawn,2,0}, {chars,79}, info),
receive
{'DOWN', MRef1, _, _, _Info1} ->
timer:sleep(?HANDLER_RESTART_AFTER + 1000),
- undefined = whereis(?MODULE),
+ undefined = whereis(h_proc_name()),
ok
after
5000 ->
@@ -1139,14 +1139,14 @@ restart_after(Config) ->
handler_overloaded_qlen=>10,
handler_restart_after=>RestartAfter}},
ok = logger:set_handler_config(?MODULE, NewHConfig2),
- Pid0 = whereis(?MODULE),
+ Pid0 = whereis(h_proc_name()),
MRef2 = erlang:monitor(process, Pid0),
%% kill handler
send_burst({n,100}, {spawn,2,0}, {chars,79}, info),
receive
{'DOWN', MRef2, _, _, _Info2} ->
timer:sleep(RestartAfter + 2000),
- Pid1 = whereis(?MODULE),
+ Pid1 = whereis(h_proc_name()),
true = is_pid(Pid1),
false = (Pid1 == Pid0),
ok
@@ -1225,14 +1225,15 @@ start_handler(Name, FuncName, Config) ->
max_no_bytes => 100000000},
filter_default=>log,
filters=>?DEFAULT_HANDLER_FILTERS([Name]),
- formatter=>{?MODULE,op}}),
+ formatter=>{?MODULE,op},
+ level => info}),
{ok,{_,HConfig = #{logger_disk_log_h := DLHConfig}}} =
logger:get_handler_config(Name),
{lists:concat([File,".1"]),HConfig,DLHConfig}.
stop_handler(Name) ->
- ok = logger:remove_handler(Name),
- ct:pal("Handler ~p stopped!", [Name]).
+ ct:pal("Stopping handler ~p!", [Name]),
+ logger:remove_handler(Name).
send_burst(NorT, Type, {chars,Sz}, Class) ->
Text = [34 + rand:uniform(126-34) || _ <- lists:seq(1,Sz)],
@@ -1331,7 +1332,7 @@ start_and_add(Name, Config, LogOpts) ->
[Name,Config#{disk_log_opts=>LogOpts}]),
ok = logger:add_handler(Name, logger_disk_log_h,
Config#{disk_log_opts=>LogOpts}),
- Pid = whereis(Name),
+ Pid = whereis(h_proc_name(Name)),
true = is_pid(Pid),
Name = proplists:get_value(name, disk_log:info(Name)),
ok.
@@ -1339,7 +1340,7 @@ start_and_add(Name, Config, LogOpts) ->
remove_and_stop(Handler) ->
ok = logger:remove_handler(Handler),
timer:sleep(500),
- undefined = whereis(Handler),
+ undefined = whereis(h_proc_name(Handler)),
ok.
try_read_file(FileName, Expected, Time) ->
@@ -1442,7 +1443,7 @@ repeat_until_ok(Fun, C, Stop, FirstReason) ->
start_tracer(Trace,Expected) ->
Pid = self(),
dbg:tracer(process,{fun tracer/2,{Pid,Expected}}),
- dbg:p(whereis(?MODULE),[c]),
+ dbg:p(h_proc_name(),[c]),
tpl(Trace),
ok.
@@ -1498,3 +1499,8 @@ escape([H|T]) ->
[H|escape(T)];
escape([]) ->
[].
+
+h_proc_name() ->
+ h_proc_name(?MODULE).
+h_proc_name(Name) ->
+ list_to_atom(lists:concat([logger_disk_log_h,"_",Name])).
diff --git a/lib/kernel/test/logger_std_h_SUITE.erl b/lib/kernel/test/logger_std_h_SUITE.erl
index c6391e55fc..fa90be0fc8 100644
--- a/lib/kernel/test/logger_std_h_SUITE.erl
+++ b/lib/kernel/test/logger_std_h_SUITE.erl
@@ -170,7 +170,7 @@ add_remove_instance_file(Log, Type) ->
filter_default=>stop,
filters=>?DEFAULT_HANDLER_FILTERS([?MODULE]),
formatter=>{?MODULE,self()}}),
- Pid = whereis(?MODULE),
+ Pid = whereis(h_proc_name()),
true = is_pid(Pid),
logger:info(M1=?msg,?domain),
?check(M1),
@@ -178,7 +178,7 @@ add_remove_instance_file(Log, Type) ->
try_read_file(Log, {ok,B1}, ?FILESYNC_REP_INT),
ok = logger:remove_handler(?MODULE),
timer:sleep(500),
- undefined = whereis(?MODULE),
+ undefined = whereis(h_proc_name()),
logger:info(?msg,?domain),
?check_no_log,
try_read_file(Log, {ok,B1}, ?FILESYNC_REP_INT),
@@ -240,7 +240,7 @@ formatter_fail(Config) ->
#{logger_std_h => #{type => {file,Log}},
filter_default=>stop,
filters=>?DEFAULT_HANDLER_FILTERS([?MODULE])}),
- Pid = whereis(?MODULE),
+ Pid = whereis(h_proc_name()),
true = is_pid(Pid),
#{handlers:=HC1} = logger:i(),
H = [Id || {Id,_,_} <- HC1],
@@ -271,7 +271,7 @@ formatter_fail(Config) ->
5000),
%% Check that handler is still alive and was never dead
- Pid = whereis(?MODULE),
+ Pid = whereis(h_proc_name()),
#{handlers:=HC2} = logger:i(),
H = [Id || {Id,_,_} <- HC2],
@@ -354,7 +354,12 @@ crash_std_h(Config,Func,Var,Type,Log) ->
ct:pal("Starting ~p with ~tp", [Name,Args]),
%% Start a node which prints kernel logs to the destination specified by Type
{ok,Node} = test_server:start_node(Name, peer, [{args, Args}]),
- Pid = rpc:call(Node,erlang,whereis,[?STANDARD_HANDLER]),
+ HProcName =
+ case Type of
+ file -> ?name_to_reg_name(logger_std_h,?STANDARD_HANDLER);
+ disk_log -> ?name_to_reg_name(logger_disk_log_h,?STANDARD_HANDLER)
+ end,
+ Pid = rpc:call(Node,erlang,whereis,[HProcName]),
ok = rpc:call(Node,logger,set_handler_config,[?STANDARD_HANDLER,formatter,
{?MODULE,self()}]),
ok = log_on_remote_node(Node,"dummy1"),
@@ -367,7 +372,7 @@ crash_std_h(Config,Func,Var,Type,Log) ->
%% Wait a bit, then check that it is gone
timer:sleep(2000),
- undefined = rpc:call(Node,erlang,whereis,[?STANDARD_HANDLER]),
+ undefined = rpc:call(Node,erlang,whereis,[HProcName]),
%% Check that file is not empty
{ok,Bin2} = sync_and_read(Node,Type,Log),
@@ -940,14 +945,14 @@ kill_disabled(Config) ->
Logged = count_lines(Log),
ct:pal("Number of messages logged = ~w", [Logged]),
ok = file:delete(Log),
- true = is_pid(whereis(?MODULE)),
+ true = is_pid(whereis(h_proc_name())),
ok.
kill_disabled(cleanup, _Config) ->
ok = stop_handler(?MODULE).
qlen_kill_new(Config) ->
{_Log,HConfig,StdHConfig} = start_handler(?MODULE, ?FUNCTION_NAME, Config),
- Pid0 = whereis(?MODULE),
+ Pid0 = whereis(h_proc_name()),
{_,Mem0} = process_info(Pid0, memory),
RestartAfter = ?HANDLER_RESTART_AFTER,
NewHConfig =
@@ -970,7 +975,7 @@ qlen_kill_new(Config) ->
ct:pal("Slow shutdown, handler process was killed!", [])
end,
timer:sleep(RestartAfter + 2000),
- true = is_pid(whereis(?MODULE)),
+ true = is_pid(whereis(h_proc_name())),
ok
after
5000 ->
@@ -998,7 +1003,7 @@ qlen_kill_std(_Config) ->
mem_kill_new(Config) ->
{_Log,HConfig,StdHConfig} = start_handler(?MODULE, ?FUNCTION_NAME, Config),
- Pid0 = whereis(?MODULE),
+ Pid0 = whereis(h_proc_name()),
{_,Mem0} = process_info(Pid0, memory),
RestartAfter = ?HANDLER_RESTART_AFTER,
NewHConfig =
@@ -1021,7 +1026,7 @@ mem_kill_new(Config) ->
ct:pal("Slow shutdown, handler process was killed!", [])
end,
timer:sleep(RestartAfter * 3),
- true = is_pid(whereis(?MODULE)),
+ true = is_pid(whereis(h_proc_name())),
ok
after
5000 ->
@@ -1044,13 +1049,13 @@ restart_after(Config) ->
handler_overloaded_qlen=>10,
handler_restart_after=>never}},
ok = logger:set_handler_config(?MODULE, NewHConfig1),
- MRef1 = erlang:monitor(process, whereis(?MODULE)),
+ MRef1 = erlang:monitor(process, whereis(h_proc_name())),
%% kill handler
send_burst({n,100}, {spawn,2,0}, {chars,79}, info),
receive
{'DOWN', MRef1, _, _, _Info1} ->
timer:sleep(?HANDLER_RESTART_AFTER + 1000),
- undefined = whereis(?MODULE),
+ undefined = whereis(h_proc_name()),
ok
after
5000 ->
@@ -1064,14 +1069,14 @@ restart_after(Config) ->
handler_overloaded_qlen=>10,
handler_restart_after=>RestartAfter}},
ok = logger:set_handler_config(?MODULE, NewHConfig2),
- Pid0 = whereis(?MODULE),
+ Pid0 = whereis(h_proc_name()),
MRef2 = erlang:monitor(process, Pid0),
%% kill handler
send_burst({n,100}, {spawn,2,0}, {chars,79}, info),
receive
{'DOWN', MRef2, _, _, _Info2} ->
timer:sleep(RestartAfter + 2000),
- Pid1 = whereis(?MODULE),
+ Pid1 = whereis(h_proc_name()),
true = is_pid(Pid1),
false = (Pid1 == Pid0),
ok
@@ -1286,7 +1291,7 @@ add_remove_instance_nofile(Type) ->
filter_default=>stop,
filters=>?DEFAULT_HANDLER_FILTERS([?MODULE]),
formatter=>{?MODULE,self()}}),
- Pid = whereis(?MODULE),
+ Pid = whereis(h_proc_name()),
true = is_pid(Pid),
group_leader(group_leader(),Pid), % to get printouts in test log
logger:info(M1=?msg,?domain),
@@ -1295,7 +1300,7 @@ add_remove_instance_nofile(Type) ->
ok = logger_std_h:sync(?MODULE),
ok = logger:remove_handler(?MODULE),
timer:sleep(500),
- undefined = whereis(?MODULE),
+ undefined = whereis(h_proc_name()),
logger:info(?msg,?domain),
?check_no_log,
ok.
@@ -1379,7 +1384,7 @@ start_op_trace() ->
TRecvPid = spawn_link(fun() -> trace_receiver(5000) end),
{ok,_} = dbg:tracer(process, {TraceFun, TRecvPid}),
- {ok,_} = dbg:p(whereis(?MODULE), [c]),
+ {ok,_} = dbg:p(whereis(h_proc_name()), [c]),
{ok,_} = dbg:p(self(), [c]),
MS1 = dbg:fun2ms(fun([_]) -> return_trace() end),
@@ -1459,7 +1464,7 @@ start_tracer(Trace,Expected) ->
Pid = self(),
FileCtrlPid = maps:get(file_ctrl_pid, logger_std_h:info(?MODULE)),
dbg:tracer(process,{fun tracer/2,{Pid,Expected}}),
- dbg:p(whereis(?MODULE),[c]),
+ dbg:p(whereis(h_proc_name()),[c]),
dbg:p(FileCtrlPid,[c]),
tpl(Trace),
ok.
@@ -1525,3 +1530,8 @@ escape([H|T]) ->
[H|escape(T)];
escape([]) ->
[].
+
+h_proc_name() ->
+ h_proc_name(?MODULE).
+h_proc_name(Name) ->
+ ?name_to_reg_name(logger_std_h,Name).