diff options
Diffstat (limited to 'lib')
| -rw-r--r-- | lib/kernel/src/Makefile | 4 | ||||
| -rw-r--r-- | lib/kernel/src/logger_h_common.erl | 2 | ||||
| -rw-r--r-- | lib/kernel/src/logger_h_common.hrl | 191 | ||||
| -rw-r--r-- | lib/kernel/src/logger_olp.erl | 5 | ||||
| -rw-r--r-- | lib/kernel/src/logger_olp.hrl | 180 | ||||
| -rw-r--r-- | lib/kernel/src/logger_std_h.erl | 2 | ||||
| -rw-r--r-- | lib/kernel/test/logger_disk_log_h_SUITE.erl | 1 | ||||
| -rw-r--r-- | lib/kernel/test/logger_olp_SUITE.erl | 2 | ||||
| -rw-r--r-- | lib/kernel/test/logger_std_h_SUITE.erl | 12 |
9 files changed, 219 insertions, 180 deletions
diff --git a/lib/kernel/src/Makefile b/lib/kernel/src/Makefile index c3fee02334..3d1506ea08 100644 --- a/lib/kernel/src/Makefile +++ b/lib/kernel/src/Makefile @@ -153,7 +153,7 @@ INTERNAL_HRL_FILES= application_master.hrl disk_log.hrl \ inet_dns.hrl inet_res.hrl \ inet_boot.hrl inet_config.hrl inet_int.hrl \ inet_dns_record_adts.hrl \ - logger_internal.hrl logger_h_common.hrl + logger_internal.hrl logger_olp.hrl logger_h_common.hrl ERL_FILES= $(MODULES:%=%.erl) @@ -281,7 +281,7 @@ $(EBIN)/logger_config.beam: logger_internal.hrl ../include/logger.hrl $(EBIN)/logger_disk_log_h.beam: logger_h_common.hrl logger_internal.hrl ../include/logger.hrl ../include/file.hrl $(EBIN)/logger_filters.beam: logger_internal.hrl ../include/logger.hrl $(EBIN)/logger_formatter.beam: logger_internal.hrl ../include/logger.hrl -$(EBIN)/logger_olp.beam: logger_h_common.hrl logger_internal.hrl +$(EBIN)/logger_olp.beam: logger_olp.hrl logger_internal.hrl $(EBIN)/logger_proxy.beam: logger_internal.hrl $(EBIN)/logger_server.beam: logger_internal.hrl ../include/logger.hrl $(EBIN)/logger_simple_h.beam: logger_internal.hrl ../include/logger.hrl diff --git a/lib/kernel/src/logger_h_common.erl b/lib/kernel/src/logger_h_common.erl index 6f55c5997d..51fe8f3157 100644 --- a/lib/kernel/src/logger_h_common.erl +++ b/lib/kernel/src/logger_h_common.erl @@ -223,6 +223,8 @@ start(OlpOpts0, #{id := Name, module:=Module, config:=HConfig} = Config0) -> init(#{id := Name, module := Module, config := HConfig}) -> process_flag(trap_exit, true), + ?init_test_hooks(), + case Module:init(Name, HConfig) of {ok,HState} -> %% Storing common config in state to avoid copying diff --git a/lib/kernel/src/logger_h_common.hrl b/lib/kernel/src/logger_h_common.hrl index f2d642f6f0..004a61d9d9 100644 --- a/lib/kernel/src/logger_h_common.hrl +++ b/lib/kernel/src/logger_h_common.hrl @@ -1,50 +1,22 @@ - -%%%----------------------------------------------------------------- -%%% Overload protection configuration - -%%! *** NOTE *** -%%! It's important that: -%%! SYNC_MODE_QLEN =< DROP_MODE_QLEN =< FLUSH_QLEN -%%! and that DROP_MODE_QLEN >= 2. -%%! Otherwise the handler could end up in drop mode with no new -%%! log requests to process. This would cause all future requests -%%! to be dropped (no switch to async mode would ever take place). - -%% This specifies the message_queue_len value where the log -%% requests switch from asynchronous casts to synchronous calls. --define(SYNC_MODE_QLEN, 10). -%% Above this message_queue_len, log requests will be dropped, -%% i.e. no log requests get sent to the handler process. --define(DROP_MODE_QLEN, 200). -%% Above this message_queue_len, the handler process will flush -%% its mailbox and only leave this number of messages in it. --define(FLUSH_QLEN, 1000). - -%% Never flush more than this number of messages in one go, -%% or the handler will be unresponsive for seconds (keep this -%% number as large as possible or the mailbox could grow large). --define(FLUSH_MAX_N, 5000). - -%% BURST_LIMIT_MAX_COUNT is the max number of log requests allowed -%% to be written within a BURST_LIMIT_WINDOW_TIME time frame. --define(BURST_LIMIT_ENABLE, true). --define(BURST_LIMIT_MAX_COUNT, 500). --define(BURST_LIMIT_WINDOW_TIME, 1000). - -%% This enables/disables the feature to automatically get the -%% handler terminated if it gets too loaded (and can't keep up). --define(OVERLOAD_KILL_ENABLE, false). -%% If the message_queue_len goes above this size even after -%% flushing has been performed, the handler is terminated. --define(OVERLOAD_KILL_QLEN, 20000). -%% If the memory usage exceeds this level --define(OVERLOAD_KILL_MEM_SIZE, 3000000). - -%% This is the default time that the handler will wait before -%% restarting and accepting new requests. The value 'infinity' -%% disables restarts. --define(OVERLOAD_KILL_RESTART_AFTER, 5000). -%%-define(OVERLOAD_KILL_RESTART_AFTER, infinity). +%% +%% %CopyrightBegin% +%% +%% Copyright Ericsson AB 1997-2015. 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% +%% %% The handler sends asynchronous write requests to the process %% controlling the i/o device, but every once in this interval @@ -65,10 +37,6 @@ -define(FILESYNC_REPEAT_INTERVAL, 5000). %%-define(FILESYNC_REPEAT_INTERVAL, no_repeat). -%% This is the time in milliseconds after last load message received -%% that we notify the callback about being idle. --define(IDLE_DETECT_TIME, 100). - %% Default disk log option values -define(DISK_LOG_TYPE, wrap). -define(DISK_LOG_MAX_NO_FILES, 10). @@ -81,43 +49,6 @@ list_to_atom(lists:concat([MODULE,"_",Name]))). %%%----------------------------------------------------------------- -%%% Overload protection macros - --define(timestamp(), erlang:monotonic_time(microsecond)). - --define(get_mode(Tid), - case ets:lookup(Tid, mode) of - [{mode,M}] -> M; - _ -> async - end). - --define(set_mode(Tid, M), - begin ets:insert(Tid, {mode,M}), M end). - --define(change_mode(Tid, M0, M1), - if M0 == M1 -> - M0; - true -> - ets:insert(Tid, {mode,M1}), - M1 - end). - --define(min(X1, X2), - if X2 == undefined -> X1; - X2 < X1 -> X2; - true -> X1 - end). - --define(max(X1, X2), - if - X2 == undefined -> X1; - X2 > X1 -> X2; - true -> X1 - end). - --define(diff_time(OS_T1, OS_T0), OS_T1-OS_T0). - -%%%----------------------------------------------------------------- %%% The test hook macros make it possible to observe and manipulate %%% internal handler functionality. When enabled, these macros will %%% slow down execution and therefore should not be include in code @@ -181,7 +112,6 @@ [{_,ERROR}] -> ERROR catch _:_ -> disk_log:sync(LOG) end). - -define(DEFAULT_CALL_TIMEOUT, 5000). -else. % DEFAULTS! -define(TEST_HOOKS_TAB, undefined). @@ -194,87 +124,4 @@ -define(file_datasync(DEVICE), file:datasync(DEVICE)). -define(disk_log_write(LOG, MODE, DATA), disk_log_write(LOG, MODE, DATA)). -define(disk_log_sync(LOG), disk_log:sync(LOG)). - -define(DEFAULT_CALL_TIMEOUT, 10000). --endif. - -%%%----------------------------------------------------------------- -%%% These macros enable statistics counters in the state of the -%%% handler which is useful for analysing the overload protection -%%% behaviour. These counters should not be included in code to be -%%% officially released (as some counters will grow very large -%%% over time). - -%% -define(SAVE_STATS, true). --ifdef(SAVE_STATS). - -define(merge_with_stats(STATE), - begin - TIME = ?timestamp(), - STATE#{start => TIME, time => {TIME,0}, - flushes => 0, flushed => 0, drops => 0, - burst_drops => 0, casts => 0, calls => 0, - writes => 0, max_qlen => 0, max_time => 0, - freq => {TIME,0,0}} end). - - -define(update_max_qlen(QLEN, STATE), - begin #{max_qlen := QLEN0} = STATE, - STATE#{max_qlen => ?max(QLEN0,QLEN)} end). - - -define(update_calls_or_casts(CALL_OR_CAST, INC, STATE), - case CALL_OR_CAST of - cast -> - #{casts := CASTS0} = STATE, - STATE#{casts => CASTS0+INC}; - call -> - #{calls := CALLS0} = STATE, - STATE#{calls => CALLS0+INC} - end). - - -define(update_max_time(TIME, STATE), - begin #{max_time := TIME0} = STATE, - STATE#{max_time => ?max(TIME0,TIME)} end). - - -define(update_other(OTHER, VAR, INCVAL, STATE), - begin #{OTHER := VAR} = STATE, - STATE#{OTHER => VAR+INCVAL} end). - - -define(update_freq(TIME,STATE), - begin - case STATE of - #{freq := {START, 49, _}} -> - STATE#{freq => {TIME, 0, trunc(1000000*50/(?diff_time(TIME,START)))}}; - #{freq := {START, N, FREQ}} -> - STATE#{freq => {START, N+1, FREQ}} - end end). - - -define(update_time(TIME,STATE), - begin #{start := START} = STATE, - STATE#{time => {TIME,trunc((?diff_time(TIME,START))/1000000)}} end). - --else. % DEFAULT! - -define(merge_with_stats(STATE), STATE). - -define(update_max_qlen(_QLEN, STATE), STATE). - -define(update_calls_or_casts(_CALL_OR_CAST, _INC, STATE), STATE). - -define(update_max_time(_TIME, STATE), STATE). - -define(update_other(_OTHER, _VAR, _INCVAL, STATE), STATE). - -define(update_freq(_TIME, STATE), STATE). - -define(update_time(_TIME, STATE), STATE). --endif. - -%%%----------------------------------------------------------------- -%%% These macros enable callbacks that make it possible to analyse -%%% the overload protection behaviour from outside the handler -%%% process (including dropped requests on the client side). -%%% An external callback module (?OBSERVER_MOD) is required which -%%% is not part of the kernel application. For this reason, these -%%% callbacks should not be included in code to be officially released. - -%%-define(OBSERVER_MOD, logger_test). --ifdef(OBSERVER_MOD). - -define(start_observation(NAME), ?OBSERVER:start_observation(NAME)). - -define(observe(NAME,EVENT), ?OBSERVER:observe(NAME,EVENT)). - --else. % DEFAULT! - -define(start_observation(_NAME), ok). - -define(observe(_NAME,_EVENT), ok). -endif. -%%! <--- diff --git a/lib/kernel/src/logger_olp.erl b/lib/kernel/src/logger_olp.erl index 0f9314b4a3..009280a9c9 100644 --- a/lib/kernel/src/logger_olp.erl +++ b/lib/kernel/src/logger_olp.erl @@ -20,7 +20,7 @@ -module(logger_olp). -behaviour(gen_server). --include("logger_h_common.hrl"). +-include("logger_olp.hrl"). -include("logger_internal.hrl"). %% API @@ -172,7 +172,6 @@ init([Name,Module,Args,Options]) -> register(Name, self()), process_flag(message_queue_data, off_heap), - ?init_test_hooks(), ?start_observation(Name), try ets:new(Name, [public]) of @@ -324,7 +323,7 @@ call({_Name, Pid, _ModeRef},Msg) -> call(Pid, Msg); call(Server, Msg) -> try - gen_server:call(Server, Msg, ?DEFAULT_CALL_TIMEOUT) + gen_server:call(Server, Msg) catch _:{timeout,_} -> {error,busy} end. diff --git a/lib/kernel/src/logger_olp.hrl b/lib/kernel/src/logger_olp.hrl new file mode 100644 index 0000000000..9b4f5ebf27 --- /dev/null +++ b/lib/kernel/src/logger_olp.hrl @@ -0,0 +1,180 @@ +%% +%% %CopyrightBegin% +%% +%% Copyright Ericsson AB 1997-2015. 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% +%% + +%%%----------------------------------------------------------------- +%%% Overload protection configuration + +%%! *** NOTE *** +%%! It's important that: +%%! SYNC_MODE_QLEN =< DROP_MODE_QLEN =< FLUSH_QLEN +%%! and that DROP_MODE_QLEN >= 2. +%%! Otherwise the process could end up in drop mode with no new +%%! log requests to process. This would cause all future requests +%%! to be dropped (no switch to async mode would ever take place). + +%% This specifies the message_queue_len value where the log +%% requests switch from asynchronous casts to synchronous calls. +-define(SYNC_MODE_QLEN, 10). +%% Above this message_queue_len, log requests will be dropped, +%% i.e. no log requests get sent to the process. +-define(DROP_MODE_QLEN, 200). +%% Above this message_queue_len, the process will flush its mailbox +%% and only leave this number of messages in it. +-define(FLUSH_QLEN, 1000). + +%% Never flush more than this number of messages in one go, or the +%% process will be unresponsive for seconds (keep this number as large +%% as possible or the mailbox could grow large). +-define(FLUSH_MAX_N, 5000). + +%% BURST_LIMIT_MAX_COUNT is the max number of log requests allowed +%% to be written within a BURST_LIMIT_WINDOW_TIME time frame. +-define(BURST_LIMIT_ENABLE, true). +-define(BURST_LIMIT_MAX_COUNT, 500). +-define(BURST_LIMIT_WINDOW_TIME, 1000). + +%% This enables/disables the feature to automatically terminate the +%% process if it gets too loaded (and can't keep up). +-define(OVERLOAD_KILL_ENABLE, false). +%% If the message_queue_len goes above this size even after +%% flushing has been performed, the process is terminated. +-define(OVERLOAD_KILL_QLEN, 20000). +%% If the memory usage exceeds this level, the process is terminated. +-define(OVERLOAD_KILL_MEM_SIZE, 3000000). + +%% This is the default time to wait before restarting and accepting +%% new requests. The value 'infinity' disables restarts. +-define(OVERLOAD_KILL_RESTART_AFTER, 5000). + +%% This is the time in milliseconds after last load message received +%% that we notify the callback about being idle. +-define(IDLE_DETECT_TIME, 100). + +%%%----------------------------------------------------------------- +%%% Overload protection macros + +-define(timestamp(), erlang:monotonic_time(microsecond)). + +-define(get_mode(Tid), + case ets:lookup(Tid, mode) of + [{mode,M}] -> M; + _ -> async + end). + +-define(set_mode(Tid, M), + begin ets:insert(Tid, {mode,M}), M end). + +-define(change_mode(Tid, M0, M1), + if M0 == M1 -> + M0; + true -> + ets:insert(Tid, {mode,M1}), + M1 + end). + +-define(max(X1, X2), + if + X2 == undefined -> X1; + X2 > X1 -> X2; + true -> X1 + end). + +-define(diff_time(OS_T1, OS_T0), OS_T1-OS_T0). + +%%%----------------------------------------------------------------- +%%% These macros enable statistics counters in the state of the +%%% process, which is useful for analysing the overload protection +%%% behaviour. These counters should not be included in code to be +%%% officially released (as some counters will grow very large over +%%% time). + +%% -define(SAVE_STATS, true). +-ifdef(SAVE_STATS). + -define(merge_with_stats(STATE), + begin + TIME = ?timestamp(), + STATE#{start => TIME, time => {TIME,0}, + flushes => 0, flushed => 0, drops => 0, + burst_drops => 0, casts => 0, calls => 0, + writes => 0, max_qlen => 0, max_time => 0, + freq => {TIME,0,0}} end). + + -define(update_max_qlen(QLEN, STATE), + begin #{max_qlen := QLEN0} = STATE, + STATE#{max_qlen => ?max(QLEN0,QLEN)} end). + + -define(update_calls_or_casts(CALL_OR_CAST, INC, STATE), + case CALL_OR_CAST of + cast -> + #{casts := CASTS0} = STATE, + STATE#{casts => CASTS0+INC}; + call -> + #{calls := CALLS0} = STATE, + STATE#{calls => CALLS0+INC} + end). + + -define(update_max_time(TIME, STATE), + begin #{max_time := TIME0} = STATE, + STATE#{max_time => ?max(TIME0,TIME)} end). + + -define(update_other(OTHER, VAR, INCVAL, STATE), + begin #{OTHER := VAR} = STATE, + STATE#{OTHER => VAR+INCVAL} end). + + -define(update_freq(TIME,STATE), + begin + case STATE of + #{freq := {START, 49, _}} -> + STATE#{freq => {TIME, 0, trunc(1000000*50/(?diff_time(TIME,START)))}}; + #{freq := {START, N, FREQ}} -> + STATE#{freq => {START, N+1, FREQ}} + end end). + + -define(update_time(TIME,STATE), + begin #{start := START} = STATE, + STATE#{time => {TIME,trunc((?diff_time(TIME,START))/1000000)}} end). + +-else. % DEFAULT! + -define(merge_with_stats(STATE), STATE). + -define(update_max_qlen(_QLEN, STATE), STATE). + -define(update_calls_or_casts(_CALL_OR_CAST, _INC, STATE), STATE). + -define(update_max_time(_TIME, STATE), STATE). + -define(update_other(_OTHER, _VAR, _INCVAL, STATE), STATE). + -define(update_freq(_TIME, STATE), STATE). + -define(update_time(_TIME, STATE), STATE). +-endif. + +%%%----------------------------------------------------------------- +%%% These macros enable callbacks that make it possible to analyse the +%%% overload protection behaviour from outside the process (including +%%% dropped requests on the client side). An external callback module +%%% (?OBSERVER_MOD) is required which is not part of the kernel +%%% application. For this reason, these callbacks should not be +%%% included in code to be officially released. + +%%-define(OBSERVER_MOD, logger_test). +-ifdef(OBSERVER_MOD). + -define(start_observation(NAME), ?OBSERVER:start_observation(NAME)). + -define(observe(NAME,EVENT), ?OBSERVER:observe(NAME,EVENT)). + +-else. % DEFAULT! + -define(start_observation(_NAME), ok). + -define(observe(_NAME,_EVENT), ok). +-endif. diff --git a/lib/kernel/src/logger_std_h.erl b/lib/kernel/src/logger_std_h.erl index 63d1dbaba2..8c957578c8 100644 --- a/lib/kernel/src/logger_std_h.erl +++ b/lib/kernel/src/logger_std_h.erl @@ -36,6 +36,8 @@ -export([log/2, adding_handler/1, removing_handler/1, changing_config/3, filter_config/1]). +-define(DEFAULT_CALL_TIMEOUT, 5000). + %%%=================================================================== %%% API %%%=================================================================== diff --git a/lib/kernel/test/logger_disk_log_h_SUITE.erl b/lib/kernel/test/logger_disk_log_h_SUITE.erl index 2b7b48bec0..ad342b5ef0 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"). diff --git a/lib/kernel/test/logger_olp_SUITE.erl b/lib/kernel/test/logger_olp_SUITE.erl index 8d08996755..8ba66e5a03 100644 --- a/lib/kernel/test/logger_olp_SUITE.erl +++ b/lib/kernel/test/logger_olp_SUITE.erl @@ -21,7 +21,7 @@ -compile(export_all). --include_lib("kernel/src/logger_h_common.hrl"). +-include_lib("kernel/src/logger_olp.hrl"). suite() -> [{timetrap,{seconds,30}}]. diff --git a/lib/kernel/test/logger_std_h_SUITE.erl b/lib/kernel/test/logger_std_h_SUITE.erl index b6ff87d058..25dcc20496 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} -> @@ -420,10 +425,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. |