aboutsummaryrefslogtreecommitdiffstats
path: root/lib/kernel
diff options
context:
space:
mode:
Diffstat (limited to 'lib/kernel')
-rw-r--r--lib/kernel/src/logger_disk_log_h.erl89
-rw-r--r--lib/kernel/src/logger_h_common.erl71
-rw-r--r--lib/kernel/src/logger_std_h.erl102
-rw-r--r--lib/kernel/test/logger_disk_log_h_SUITE.erl43
-rw-r--r--lib/kernel/test/logger_std_h_SUITE.erl47
5 files changed, 239 insertions, 113 deletions
diff --git a/lib/kernel/src/logger_disk_log_h.erl b/lib/kernel/src/logger_disk_log_h.erl
index d339957ac8..c3d2204630 100644
--- a/lib/kernel/src/logger_disk_log_h.erl
+++ b/lib/kernel/src/logger_disk_log_h.erl
@@ -37,6 +37,9 @@
adding_handler/1, removing_handler/1,
changing_config/2, swap_buffer/2]).
+%% handler internal
+-export([log_handler_info/4]).
+
%%%===================================================================
%%% API
%%%===================================================================
@@ -250,7 +253,7 @@ swap_buffer(Name, Buffer) ->
log(LogEvent, Config = #{id := Name,
config := #{handler_pid := HPid,
mode_tab := ModeTab}}) ->
- %% if the handler has crashed, we must drop this request
+ %% if the handler has crashed, we must drop this event
%% and hope the handler restarts so we can try again
true = is_process_alive(HPid),
Bin = logger_h_common:log_to_binary(LogEvent, Config),
@@ -295,6 +298,16 @@ init([Name, Config = #{config := HConfig, disk_log_opts := LogOpts},
mode_tab => ModeTab}},
proc_lib:init_ack({ok,self(),Config1}),
gen_server:cast(self(), repeated_disk_log_sync),
+ case logger_h_common:unset_restart_flag(Name, ?MODULE) of
+ true ->
+ %% inform about restart
+ gen_server:cast(self(), {log_handler_info,
+ "Handler ~p restarted",
+ [Name]});
+ false ->
+ %% initial start
+ ok
+ end,
enter_loop(Config1, State1)
catch
_:Error ->
@@ -315,15 +328,13 @@ enter_loop(#{wait_for_buffer:=true}=Config,State) ->
Bin = logger_h_common:log_to_binary(Log,Config),
{_,S1} = do_log(Bin,cast,S),
S1
- end,
- State,
- Buffer)
+ end, State, Buffer)
end,
gen_server:enter_loop(?MODULE,[],State1);
enter_loop(_Config,State) ->
gen_server:enter_loop(?MODULE,[],State).
-%% This is the synchronous log request.
+%% This is the synchronous log event.
handle_call({log, Bin}, _From, State) ->
{Result,State1} = do_log(Bin, call, State),
%% Result == ok | dropped
@@ -377,15 +388,19 @@ handle_call(stop, _From, State) ->
{stop, {shutdown,stopped}, ok, State}.
-%% This is the asynchronous log request.
+%% This is the asynchronous log event.
handle_cast({log, Bin}, State) ->
{_,State1} = do_log(Bin, cast, State),
{noreply, State1};
+handle_cast({log_handler_info, Format, Args}, State = #{id:=Name}) ->
+ log_handler_info(Name, Format, Args, State),
+ {noreply, State};
+
%% If FILESYNC_REPEAT_INTERVAL is set to a millisec value, this
%% clause gets called repeatedly by the handler. In order to
%% guarantee that a filesync *always* happens after the last log
-%% request, the repeat operation must be active!
+%% event, the repeat operation must be active!
handle_cast(repeated_disk_log_sync,
State = #{id := Name,
filesync_repeat_interval := FSyncInt,
@@ -526,21 +541,31 @@ stop(Name) ->
if C == 0 -> Interval;
true -> C-1 end).
-%% check for overload between every request (and set Mode to async,
+%% check for overload between every event (and set Mode to async,
%% sync or drop accordingly), but never flush the whole mailbox
-%% before LogWindowSize requests have been handled
-do_log(Bin, CallOrCast, State = #{id:=Name, mode := _Mode0}) ->
+%% before LogWindowSize events have been handled
+do_log(Bin, CallOrCast, State = #{id:=Name, mode := Mode0}) ->
T1 = ?timestamp(),
%% check if the handler is getting overloaded, or if it's
%% recovering from overload (the check must be done for each
- %% request to react quickly to large bursts of requests and
+ %% event to react quickly to large bursts of events and
%% to ensure that the handler can never end up in drop mode
%% with an empty mailbox, which would stop operation)
{Mode1,QLen,Mem,State1} = logger_h_common:check_load(State),
+ if (Mode1 == drop) andalso (Mode0 =/= drop) ->
+ log_handler_info(Name, "Handler ~p switched to drop mode",
+ [Name], State);
+ (Mode0 == drop) andalso ((Mode1 == async) orelse (Mode1 == sync)) ->
+ log_handler_info(Name, "Handler ~p switched to ~w mode",
+ [Name,Mode1], State);
+ true ->
+ ok
+ end,
+
%% kill the handler if it can't keep up with the load
- logger_h_common:kill_if_choked(Name, QLen, Mem, State),
+ logger_h_common:kill_if_choked(Name, QLen, Mem, ?MODULE, State),
if Mode1 == flush ->
flush(Name, QLen, T1, State1);
@@ -550,22 +575,26 @@ 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, mode_tab := ModeTab}) ->
+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),
+ NewFlushed = logger_h_common:flush_log_events(?FLUSH_MAX_N),
+
+ %% write info in log about flushed messages
+ log_handler_info(Name, "Handler ~p flushed ~w log events",
+ [Name,NewFlushed], State),
%% because of the receive loop when flushing messages, the
%% 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}),
+ %% Add 1 for the current log event
+ ?observe(Name,{flushed,NewFlushed+1}),
State1 = ?update_max_time(?diff_time(T1,_T0),State),
- {dropped,?update_other(flushed,FLUSHED,_NewFlushed,
+ {dropped,?update_other(flushed,FLUSHED,NewFlushed,
State1#{mode => ?set_mode(ModeTab,async),
last_qlen => 0,
last_log_ts => T1})}.
@@ -578,10 +607,10 @@ write(Name, Mode, T1, Bin, _CallOrCast,
last_qlen := LastQLen,
last_log_ts := T0}) ->
%% check if we need to limit the number of writes
- %% during a burst of log requests
+ %% during a burst of log events
{DoWrite,BurstWinT,BurstMsgCount} = logger_h_common:limit_burst(State),
- %% only send a synhrounous request to the disk_log process
+ %% only send a synhrounous event to the disk_log process
%% every DLSyncInt time, to give the handler time between
%% writes so it can keep up with incoming messages
{Status,LastQLen1,State1} =
@@ -599,13 +628,13 @@ write(Name, Mode, T1, Bin, _CallOrCast,
{dropped, LastQLen, State}
end,
- %% Check if the time since the previous log request is long enough -
+ %% Check if the time since the previous log event is long enough -
%% and the queue length small enough - to assume the mailbox has
%% been emptied, and if so, do filesync operation and reset mode to
%% async. Note that this is the best we can do to detect an idle
%% handler without setting a timer after each log call/cast. If the
- %% time between two consecutive log requests is fast and no new
- %% request comes in after the last one, idle state won't be detected!
+ %% time between two consecutive log events is fast and no new
+ %% event comes in after the last one, idle state won't be detected!
Time = ?diff_time(T1,T0),
{Mode1,BurstMsgCount1,State2} =
if (LastQLen1 < ?FILESYNC_OK_QLEN) andalso
@@ -628,6 +657,20 @@ write(Name, Mode, T1, Bin, _CallOrCast,
{Status,State4}.
+log_handler_info(Name, Format, Args, State) ->
+ Config =
+ case logger:get_handler_config(Name) of
+ {ok,Conf} -> Conf;
+ _ -> #{formatter=>{?DEFAULT_FORMATTER,?DEFAULT_FORMAT_CONFIG}}
+ end,
+ Meta = #{time=>erlang:system_time(microsecond)},
+ Bin = logger_h_common:log_to_binary(#{level => notice,
+ msg => {Format,Args},
+ meta => Meta}, Config),
+ _ = disk_log_write(Name, Bin, State),
+ ok.
+
+
open_disk_log(Name, LogOpts) ->
#{file := File,
max_no_bytes := MaxNoBytes,
diff --git a/lib/kernel/src/logger_h_common.erl b/lib/kernel/src/logger_h_common.erl
index 2a935328aa..d2fcc7e115 100644
--- a/lib/kernel/src/logger_h_common.erl
+++ b/lib/kernel/src/logger_h_common.erl
@@ -27,10 +27,12 @@
call_cast_or_drop/4,
check_load/1,
limit_burst/1,
- kill_if_choked/4,
- flush_log_requests/0,
- flush_log_requests/1,
+ kill_if_choked/5,
+ flush_log_events/0,
+ flush_log_events/1,
handler_exit/2,
+ set_restart_flag/2,
+ unset_restart_flag/2,
cancel_timer/1,
stop_or_restart/3,
overload_levels_ok/1,
@@ -52,7 +54,8 @@ log_to_binary(Log,Config) ->
do_log_to_binary(Log,Config).
do_log_to_binary(Log,Config) ->
- {Formatter,FormatterConfig} = maps:get(formatter,Config),
+ {Formatter,FormatterConfig} =
+ maps:get(formatter,Config,{?DEFAULT_FORMATTER,?DEFAULT_FORMAT_CONFIG}),
String = try_format(Log,Formatter,FormatterConfig),
try unicode:characters_to_binary(String)
catch _:_ ->
@@ -121,10 +124,10 @@ check_common_config(_) ->
%%%-----------------------------------------------------------------
%%% Overload Protection
call_cast_or_drop(_Name, HandlerPid, ModeTab, Bin) ->
- %% If the handler process is getting overloaded, the log request
+ %% If the handler process is getting overloaded, the log event
%% 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.
+ %% handler is choked, drop mode is set and no event will be sent.
try ?get_mode(ModeTab) of
async ->
gen_server:cast(HandlerPid, {log,Bin});
@@ -143,7 +146,7 @@ call_cast_or_drop(_Name, HandlerPid, ModeTab, Bin) ->
?observe(_Name,{dropped,1})
catch
%% if the ETS table doesn't exist (maybe because of a
- %% handler restart), we can only drop the request
+ %% handler restart), we can only drop the event
_:_ -> ?observe(_Name,{dropped,1})
end,
ok.
@@ -151,6 +154,24 @@ call_cast_or_drop(_Name, HandlerPid, ModeTab, Bin) ->
handler_exit(_Name, Reason) ->
exit(Reason).
+set_restart_flag(Name, Module) ->
+ Flag = list_to_atom(lists:concat([Module,"_",Name,"_restarting"])),
+ spawn(fun() ->
+ register(Flag, self()),
+ timer:sleep(infinity)
+ end),
+ ok.
+
+unset_restart_flag(Name, Module) ->
+ Flag = list_to_atom(lists:concat([Module,"_",Name,"_restarting"])),
+ case whereis(Flag) of
+ undefined ->
+ false;
+ Pid ->
+ exit(Pid, kill),
+ true
+ end.
+
check_load(State = #{id:=_Name, mode_tab := ModeTab, mode := Mode,
toggle_sync_qlen := ToggleSyncQLen,
drop_new_reqs_qlen := DropNewQLen,
@@ -162,7 +183,7 @@ check_load(State = #{id:=_Name, mode_tab := ModeTab, mode := Mode,
%% 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
- %% the handler process manages the log requests (without flushing),
+ %% the handler process manages the log events (without flushing),
%% one after the other, we will move "down" from drop to sync and
%% from sync to async. This way we don't risk getting stuck in
%% drop or sync mode with an empty mailbox.
@@ -171,7 +192,7 @@ check_load(State = #{id:=_Name, mode_tab := ModeTab, mode := Mode,
QLen >= FlushQLen ->
{flush, 0,1};
QLen >= DropNewQLen ->
- %% Note that drop mode will force log requests to
+ %% Note that drop mode will force log events to
%% be dropped on the client side (never sent get to
%% the handler).
IncDrops = if Mode == drop -> 0; true -> 1 end,
@@ -208,38 +229,42 @@ limit_burst(#{burst_win_ts := BurstWinT0,
{true,BurstWinT0,BurstMsgCount+1}
end.
-kill_if_choked(Name, QLen, Mem,
- #{enable_kill_overloaded := KillIfOL,
- handler_overloaded_qlen := HOLQLen,
- handler_overloaded_mem := HOLMem}) ->
+kill_if_choked(Name, QLen, Mem, HandlerMod,
+ State = #{enable_kill_overloaded := KillIfOL,
+ handler_overloaded_qlen := HOLQLen,
+ handler_overloaded_mem := HOLMem}) ->
if KillIfOL andalso
- ((QLen > HOLQLen) orelse (Mem > HOLMem)) ->
+ ((QLen > HOLQLen) orelse (Mem > HOLMem)) ->
+ HandlerMod:log_handler_info(Name,
+ "Handler ~p overloaded and stopping",
+ [Name], State),
+ set_restart_flag(Name, HandlerMod),
handler_exit(Name, {shutdown,{overloaded,Name,QLen,Mem}});
true ->
ok
end.
-flush_log_requests() ->
- flush_log_requests(-1).
+flush_log_events() ->
+ flush_log_events(-1).
-flush_log_requests(Limit) ->
+flush_log_events(Limit) ->
process_flag(priority, high),
- Flushed = flush_log_requests(0, Limit),
+ Flushed = flush_log_events(0, Limit),
process_flag(priority, normal),
Flushed.
-flush_log_requests(Limit, Limit) ->
+flush_log_events(Limit, Limit) ->
Limit;
-flush_log_requests(N, Limit) ->
- %% flush log requests but leave other requests, such as
+flush_log_events(N, Limit) ->
+ %% flush log events but leave other events, such as
%% file/disk_log_sync, info and change_config, so that these
%% have a chance to be processed even under heavy load
receive
{'$gen_cast',{log,_}} ->
- flush_log_requests(N+1, Limit);
+ flush_log_events(N+1, Limit);
{'$gen_call',{Pid,MRef},{log,_}} ->
Pid ! {MRef, dropped},
- flush_log_requests(N+1, Limit)
+ flush_log_events(N+1, Limit)
after
0 -> N
end.
diff --git a/lib/kernel/src/logger_std_h.erl b/lib/kernel/src/logger_std_h.erl
index bebd5300b4..77b054a9b7 100644
--- a/lib/kernel/src/logger_std_h.erl
+++ b/lib/kernel/src/logger_std_h.erl
@@ -38,6 +38,9 @@
-export([log/2, adding_handler/1, removing_handler/1,
changing_config/2, swap_buffer/2]).
+%% handler internal
+-export([log_handler_info/4]).
+
%%%===================================================================
%%% API
%%%===================================================================
@@ -232,7 +235,7 @@ swap_buffer(Name, Buffer) ->
log(LogEvent, Config = #{id := Name,
config := #{handler_pid := HPid,
mode_tab := ModeTab}}) ->
- %% if the handler has crashed, we must drop this request
+ %% if the handler has crashed, we must drop this event
%% and hope the handler restarts so we can try again
true = is_process_alive(HPid),
Bin = logger_h_common:log_to_binary(LogEvent, Config),
@@ -284,17 +287,20 @@ init([Name, Config = #{config := HConfig},
proc_lib:init_ack(Error)
end.
-do_init(Name, Std) when Std=:=standard_io; Std=:=standard_error ->
- case open_log_file(Name, Std) of
- {ok,FileCtrlPid} ->
- {ok,#{id=>Name,type=>Std,file_ctrl_pid=>FileCtrlPid}};
- Error ->
- Error
- end;
-do_init(Name, FileInfo) when is_tuple(FileInfo) ->
- case open_log_file(Name, FileInfo) of
+do_init(Name, Type) ->
+ case open_log_file(Name, Type) of
{ok,FileCtrlPid} ->
- {ok,#{id=>Name,type=>FileInfo,file_ctrl_pid=>FileCtrlPid}};
+ case logger_h_common:unset_restart_flag(Name, ?MODULE) of
+ true ->
+ %% inform about restart
+ gen_server:cast(self(), {log_handler_info,
+ "Handler ~p restarted",
+ [Name]});
+ false ->
+ %% initial start
+ ok
+ end,
+ {ok,#{id=>Name,type=>Type,file_ctrl_pid=>FileCtrlPid}};
Error ->
Error
end.
@@ -316,7 +322,7 @@ enter_loop(#{wait_for_buffer:=true}=Config,State) ->
enter_loop(_Config,State) ->
gen_server:enter_loop(?MODULE,[],State).
-%% This is the synchronous log request.
+%% This is the synchronous log event.
handle_call({log, Bin}, _From, State) ->
{Result,State1} = do_log(Bin, call, State),
%% Result == ok | dropped
@@ -371,15 +377,19 @@ handle_call(reset, _From, State) ->
handle_call(stop, _From, State) ->
{stop, {shutdown,stopped}, ok, State}.
-%% This is the asynchronous log request.
+%% This is the asynchronous log event.
handle_cast({log, Bin}, State) ->
{_,State1} = do_log(Bin, cast, State),
{noreply, State1};
+handle_cast({log_handler_info, Format, Args}, State = #{id:=Name}) ->
+ log_handler_info(Name, Format, Args, State),
+ {noreply, State};
+
%% If FILESYNC_REPEAT_INTERVAL is set to a millisec value, this
%% clause gets called repeatedly by the handler. In order to
%% guarantee that a filesync *always* happens after the last log
-%% request, the repeat operation must be active!
+%% event, the repeat operation must be active!
handle_cast(repeated_filesync,
State = #{type := Type,
file_ctrl_pid := FileCtrlPid,
@@ -514,21 +524,31 @@ stop(Name) ->
if C == 0 -> Interval;
true -> C-1 end).
-%% check for overload between every request (and set Mode to async,
+%% check for overload between every event (and set Mode to async,
%% sync or drop accordingly), but never flush the whole mailbox
-%% before LogWindowSize requests have been handled
-do_log(Bin, CallOrCast, State = #{id:=Name}) ->
+%% before LogWindowSize events have been handled
+do_log(Bin, CallOrCast, State = #{id:=Name, mode:=Mode0}) ->
T1 = ?timestamp(),
%% check if the handler is getting overloaded, or if it's
%% recovering from overload (the check must be done for each
- %% request to react quickly to large bursts of requests and
+ %% event to react quickly to large bursts of events and
%% to ensure that the handler can never end up in drop mode
%% with an empty mailbox, which would stop operation)
{Mode1,QLen,Mem,State1} = logger_h_common:check_load(State),
+ if (Mode1 == drop) andalso (Mode0 =/= drop) ->
+ log_handler_info(Name, "Handler ~p switched to drop mode",
+ [Name], State);
+ (Mode0 == drop) andalso ((Mode1 == async) orelse (Mode1 == sync)) ->
+ log_handler_info(Name, "Handler ~p switched to ~w mode",
+ [Name,Mode1], State);
+ true ->
+ ok
+ end,
+
%% kill the handler if it can't keep up with the load
- logger_h_common:kill_if_choked(Name, QLen, Mem, State),
+ logger_h_common:kill_if_choked(Name, QLen, Mem, ?MODULE, State),
if Mode1 == flush ->
flush(Name, QLen, T1, State1);
@@ -538,22 +558,26 @@ 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, mode_tab := ModeTab}) ->
+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),
+ NewFlushed = logger_h_common:flush_log_events(?FLUSH_MAX_N),
+
+ %% write info in log about flushed messages
+ log_handler_info(Name, "Handler ~p flushed ~w log events",
+ [Name,NewFlushed], State),
%% because of the receive loop when flushing messages, the
%% 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}),
+ %% Add 1 for the current log event
+ ?observe(Name,{flushed,NewFlushed+1}),
State1 = ?update_max_time(?diff_time(T1,_T0),State),
- {dropped,?update_other(flushed,FLUSHED,_NewFlushed,
+ {dropped,?update_other(flushed,FLUSHED,NewFlushed,
State1#{mode => ?set_mode(ModeTab,async),
last_qlen => 0,
last_log_ts => T1})}.
@@ -567,10 +591,10 @@ write(_Name, Mode, T1, Bin, _CallOrCast,
last_log_ts := T0,
file_ctrl_sync_int := FileCtrlSyncInt}) ->
%% check if we need to limit the number of writes
- %% during a burst of log requests
+ %% during a burst of log events
{DoWrite,BurstWinT,BurstMsgCount} = logger_h_common:limit_burst(State),
- %% only send a synhrounous request to the file controller process
+ %% only send a synhrounous event to the file controller process
%% every FileCtrlSyncInt time, to give the handler time between
%% file writes so it can keep up with incoming messages
{Result,LastQLen1} =
@@ -587,13 +611,13 @@ write(_Name, Mode, T1, Bin, _CallOrCast,
{dropped,LastQLen}
end,
- %% Check if the time since the previous log request is long enough -
+ %% Check if the time since the previous log event is long enough -
%% and the queue length small enough - to assume the mailbox has
%% been emptied, and if so, do filesync operation and reset mode to
%% async. Note that this is the best we can do to detect an idle
%% handler without setting a timer after each log call/cast. If the
- %% time between two consecutive log requests is fast and no new
- %% request comes in after the last one, idle state won't be detected!
+ %% time between two consecutive log events is fast and no new
+ %% event comes in after the last one, idle state won't be detected!
Time = ?diff_time(T1,T0),
{Mode1,BurstMsgCount1} =
if (LastQLen1 < ?FILESYNC_OK_QLEN) andalso
@@ -654,6 +678,20 @@ close_log_file(Fd) ->
_ = file:datasync(Fd),
_ = file:close(Fd).
+
+log_handler_info(Name, Format, Args, #{file_ctrl_pid := FileCtrlPid}) ->
+ Config =
+ case logger:get_handler_config(Name) of
+ {ok,Conf} -> Conf;
+ _ -> #{formatter=>{?DEFAULT_FORMATTER,?DEFAULT_FORMAT_CONFIG}}
+ end,
+ Meta = #{time=>erlang:system_time(microsecond)},
+ Bin = logger_h_common:log_to_binary(#{level => notice,
+ msg => {Format,Args},
+ meta => Meta}, Config),
+ _ = file_write_async(FileCtrlPid, Bin),
+ ok.
+
%%%-----------------------------------------------------------------
%%% File control process
@@ -726,7 +764,7 @@ file_ctrl_init(HandlerName, StdDev, Starter) ->
file_ctrl_loop(Fd, Type, DevName, Synced,
PrevWriteResult, PrevSyncResult, HandlerName) ->
receive
- %% asynchronous request
+ %% asynchronous event
{log,Bin} ->
Result = if Type == file ->
write_to_dev(Fd, Bin, DevName,
@@ -737,7 +775,7 @@ file_ctrl_loop(Fd, Type, DevName, Synced,
file_ctrl_loop(Fd, Type, DevName, false,
Result, PrevSyncResult, HandlerName);
- %% synchronous request
+ %% synchronous event
{{log,From,Bin,FileSync},MRef} ->
if Type == file ->
%% check that file hasn't been deleted
diff --git a/lib/kernel/test/logger_disk_log_h_SUITE.erl b/lib/kernel/test/logger_disk_log_h_SUITE.erl
index 8fefbd1426..2b3551c3f7 100644
--- a/lib/kernel/test/logger_disk_log_h_SUITE.erl
+++ b/lib/kernel/test/logger_disk_log_h_SUITE.erl
@@ -856,7 +856,7 @@ op_switch_to_sync(Config) ->
ok = logger:set_handler_config(?MODULE, NewHConfig),
send_burst({n,NumOfReqs}, seq, {chars,79}, info),
Lines = count_lines(Log),
- ok = file:delete(Log),
+ ok = file_delete(Log),
NumOfReqs = Lines,
ok.
op_switch_to_sync(cleanup, _Config) ->
@@ -887,7 +887,7 @@ op_switch_to_drop(Config) ->
_ <- lists:seq(1, Bursts)],
Logged = count_lines(Log),
ok = stop_handler(?MODULE),
- _ = file:delete(Log),
+ _ = file_delete(Log),
ct:pal("Number of messages dropped = ~w (~w)",
[Procs*NumOfReqs*Bursts-Logged,Procs*NumOfReqs*Bursts]),
true = (Logged < (Procs*NumOfReqs*Bursts)),
@@ -939,7 +939,7 @@ op_switch_to_flush(Config) ->
_ <- lists:seq(1,Bursts)],
Logged = count_lines(Log),
ok= stop_handler(?MODULE),
- _ = file:delete(Log),
+ _ = file_delete(Log),
ct:pal("Number of messages flushed/dropped = ~w (~w)",
[NumOfReqs*Procs*Bursts-Logged,NumOfReqs*Procs*Bursts]),
true = (Logged < (NumOfReqs*Procs*Bursts)),
@@ -971,7 +971,7 @@ limit_burst_disabled(Config) ->
send_burst({n,NumOfReqs}, seq, {chars,79}, info),
Logged = count_lines(Log),
ct:pal("Number of messages logged = ~w", [Logged]),
- ok = file:delete(Log),
+ ok = file_delete(Log),
NumOfReqs = Logged.
limit_burst_disabled(cleanup, _Config) ->
ok = stop_handler(?MODULE).
@@ -990,7 +990,7 @@ limit_burst_enabled_one(Config) ->
send_burst({n,NumOfReqs}, seq, {chars,79}, info),
Logged = count_lines(Log),
ct:pal("Number of messages logged = ~w", [Logged]),
- ok = file:delete(Log),
+ ok = file_delete(Log),
ReqLimit = Logged.
limit_burst_enabled_one(cleanup, _Config) ->
ok = stop_handler(?MODULE).
@@ -1012,7 +1012,7 @@ limit_burst_enabled_period(Config) ->
Logged = count_lines(Log),
ct:pal("Number of messages sent = ~w~nNumber of messages logged = ~w",
[Sent,Logged]),
- ok = file:delete(Log),
+ ok = file_delete(Log),
true = (Logged > (ReqLimit*Windows)) andalso
(Logged < (ReqLimit*(Windows+2))).
limit_burst_enabled_period(cleanup, _Config) ->
@@ -1029,7 +1029,7 @@ kill_disabled(Config) ->
send_burst({n,NumOfReqs}, seq, {chars,79}, info),
Logged = count_lines(Log),
ct:pal("Number of messages logged = ~w", [Logged]),
- ok = file:delete(Log),
+ ok = file_delete(Log),
true = is_pid(whereis(h_proc_name())),
ok.
kill_disabled(cleanup, _Config) ->
@@ -1187,7 +1187,7 @@ handler_requests_under_load(Config) ->
Errors = [{Req,FindError(Res)} || {Req,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).
+ ok = file_delete(Log).
handler_requests_under_load(cleanup, _Config) ->
ok = stop_handler(?MODULE).
@@ -1301,9 +1301,11 @@ format(#{msg:={report,#{label:={gen_server,terminate}}}},op) ->
"";
format(#{msg:={report,#{label:={proc_lib,crash}}}},op) ->
"";
-format(#{msg:={F,A}},Pid) when is_list(F), is_list(A) ->
+format(#{msg:={F,A}},OpOrPid) when is_list(F), is_list(A) ->
String = lists:flatten(io_lib:format(F,A)),
- Pid ! {log,String},
+ if is_pid(OpOrPid) -> OpOrPid ! {log,String};
+ true -> ok
+ end,
String++"\n";
format(#{msg:={string,String0}},Pid) ->
String = unicode:characters_to_list(String0),
@@ -1402,17 +1404,21 @@ wait_until_written(File, Sz) ->
end.
count_lines1(File) ->
- Counter = fun Cnt(Dev,LC) ->
- case file:read_line(Dev) of
- eof -> LC;
- _ -> Cnt(Dev,LC+1)
- end
- end,
{_,Dev} = file:open(File, [read]),
- Lines = Counter(Dev, 0),
+ Lines = count_lines2(Dev, 0),
file:close(Dev),
Lines.
+count_lines2(Dev, LC) ->
+ case file:read_line(Dev) of
+ {ok,"Handler logger_disk_log_h_SUITE " ++_} ->
+ %% Not counting handler info
+ count_lines2(Dev,LC);
+ {ok,_} ->
+ count_lines2(Dev,LC+1);
+ eof -> LC
+ end.
+
repeat_until_ok(Fun, N) ->
repeat_until_ok(Fun, 0, N, undefined).
@@ -1500,3 +1506,6 @@ h_proc_name() ->
h_proc_name(?MODULE).
h_proc_name(Name) ->
list_to_atom(lists:concat([logger_disk_log_h,"_",Name])).
+
+file_delete(Log) ->
+ file:delete(Log).
diff --git a/lib/kernel/test/logger_std_h_SUITE.erl b/lib/kernel/test/logger_std_h_SUITE.erl
index fd1840b9ff..a67b55eee1 100644
--- a/lib/kernel/test/logger_std_h_SUITE.erl
+++ b/lib/kernel/test/logger_std_h_SUITE.erl
@@ -707,7 +707,7 @@ op_switch_to_sync_file(Config) ->
%% TRecvPid = start_op_trace(),
send_burst({n,NumOfReqs}, seq, {chars,79}, info),
Lines = count_lines(Log),
- ok = file:delete(Log),
+ ok = file_delete(Log),
%% true = analyse_trace(TRecvPid,
%% fun(Events) -> find_mode(async,Events) end),
%% true = analyse_trace(TRecvPid,
@@ -764,7 +764,7 @@ op_switch_to_drop_file(Config) ->
_ <- lists:seq(1, Bursts)],
Logged = count_lines(Log),
ok = stop_handler(?MODULE),
- _ = file:delete(Log),
+ _ = file_delete(Log),
ct:pal("Number of messages dropped = ~w (~w)",
[Procs*NumOfReqs*Bursts-Logged,Procs*NumOfReqs*Bursts]),
true = (Logged < (Procs*NumOfReqs*Bursts)),
@@ -799,7 +799,7 @@ op_switch_to_drop_tty(cleanup, _Config) ->
ok = stop_handler(?MODULE).
op_switch_to_flush_file() ->
- [{timetrap,{minutes,3}}].
+ [{timetrap,{minutes,5}}].
op_switch_to_flush_file(Config) ->
Test =
fun() ->
@@ -832,7 +832,7 @@ op_switch_to_flush_file(Config) ->
_ <- lists:seq(1,Bursts)],
Logged = count_lines(Log),
ok = stop_handler(?MODULE),
- _ = file:delete(Log),
+ _ = file_delete(Log),
ct:pal("Number of messages flushed/dropped = ~w (~w)",
[NumOfReqs*Procs*Bursts-Logged,NumOfReqs*Procs*Bursts]),
true = (Logged < (NumOfReqs*Procs*Bursts)),
@@ -850,6 +850,8 @@ op_switch_to_flush_file(Config) ->
op_switch_to_flush_file(cleanup, _Config) ->
_ = stop_handler(?MODULE).
+op_switch_to_flush_tty() ->
+ [{timetrap,{minutes,5}}].
op_switch_to_flush_tty(Config) ->
{HConfig,StdHConfig} = start_handler(?MODULE, standard_io, Config),
@@ -883,7 +885,7 @@ limit_burst_disabled(Config) ->
send_burst({n,NumOfReqs}, seq, {chars,79}, info),
Logged = count_lines(Log),
ct:pal("Number of messages logged = ~w", [Logged]),
- ok = file:delete(Log),
+ ok = file_delete(Log),
NumOfReqs = Logged.
limit_burst_disabled(cleanup, _Config) ->
ok = stop_handler(?MODULE).
@@ -902,7 +904,7 @@ limit_burst_enabled_one(Config) ->
send_burst({n,NumOfReqs}, seq, {chars,79}, info),
Logged = count_lines(Log),
ct:pal("Number of messages logged = ~w", [Logged]),
- ok = file:delete(Log),
+ ok = file_delete(Log),
ReqLimit = Logged.
limit_burst_enabled_one(cleanup, _Config) ->
ok = stop_handler(?MODULE).
@@ -924,7 +926,7 @@ limit_burst_enabled_period(Config) ->
Logged = count_lines(Log),
ct:pal("Number of messages sent = ~w~nNumber of messages logged = ~w",
[Sent,Logged]),
- ok = file:delete(Log),
+ ok = file_delete(Log),
true = (Logged > (ReqLimit*Windows)) andalso
(Logged < (ReqLimit*(Windows+2))).
limit_burst_enabled_period(cleanup, _Config) ->
@@ -941,7 +943,7 @@ kill_disabled(Config) ->
send_burst({n,NumOfReqs}, seq, {chars,79}, info),
Logged = count_lines(Log),
ct:pal("Number of messages logged = ~w", [Logged]),
- ok = file:delete(Log),
+ ok = file_delete(Log),
true = is_pid(whereis(h_proc_name())),
ok.
kill_disabled(cleanup, _Config) ->
@@ -1117,7 +1119,7 @@ handler_requests_under_load(Config) ->
Errors = [{Req,FindError(Res)} || {Req,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).
+ ok = file_delete(Log).
handler_requests_under_load(cleanup, _Config) ->
ok = stop_handler(?MODULE).
@@ -1192,17 +1194,21 @@ wait_until_written(File, Sz) ->
end.
count_lines1(File) ->
- Counter = fun Cnt(Dev,LC) ->
- case file:read_line(Dev) of
- eof -> LC;
- _ -> Cnt(Dev,LC+1)
- end
- end,
{_,Dev} = file:open(File, [read]),
- Lines = Counter(Dev, 0),
+ Lines = count_lines2(Dev, 0),
file:close(Dev),
Lines.
+count_lines2(Dev, LC) ->
+ case file:read_line(Dev) of
+ {ok,"Handler logger_std_h_SUITE " ++_} ->
+ %% Not counting handler info
+ count_lines2(Dev,LC);
+ {ok,_} ->
+ count_lines2(Dev,LC+1);
+ eof -> LC
+ end.
+
send_burst(NorT, Type, {chars,Sz}, Class) ->
Text = [34 + rand:uniform(126-34) || _ <- lists:seq(1,Sz)],
case NorT of
@@ -1271,9 +1277,11 @@ format(#{msg:={report,#{label:={gen_server,terminate}}}},op) ->
"";
format(#{msg:={report,#{label:={proc_lib,crash}}}},op) ->
"";
-format(#{msg:={F,A}},Pid) when is_list(F), is_list(A) ->
+format(#{msg:={F,A}},OpOrPid) when is_list(F), is_list(A) ->
String = lists:flatten(io_lib:format(F,A)),
- Pid ! {log,String},
+ if is_pid(OpOrPid) -> OpOrPid ! {log,String};
+ true -> ok
+ end,
String++"\n";
format(#{msg:={string,String0}},Pid) ->
String = unicode:characters_to_list(String0),
@@ -1530,3 +1538,6 @@ h_proc_name() ->
h_proc_name(?MODULE).
h_proc_name(Name) ->
?name_to_reg_name(logger_std_h,Name).
+
+file_delete(Log) ->
+ file:delete(Log).
generated by cgit v1.2.3 (git 2.25.1) at 2024-11-17 02:36:12 +0000