diff options
author | Siri Hansen <[email protected]> | 2018-10-19 11:41:53 +0200 |
---|---|---|
committer | GitHub <[email protected]> | 2018-10-19 11:41:53 +0200 |
commit | 05bcb5c45860e6cbb9480f8b5de9ff0ce614b548 (patch) | |
tree | c8c8d2172fddc4b2b4b79a8cc558891ada1e89e5 /lib/kernel | |
parent | 0522af5e12281908870db3370370e7baaf56a169 (diff) | |
parent | 6fae4fbd3650366730d35988ee588c32848dbecc (diff) | |
download | otp-05bcb5c45860e6cbb9480f8b5de9ff0ce614b548.tar.gz otp-05bcb5c45860e6cbb9480f8b5de9ff0ce614b548.tar.bz2 otp-05bcb5c45860e6cbb9480f8b5de9ff0ce614b548.zip |
Merge pull request #1975 from sirihansen/siri/logger/config-set-or-update
Forward set/update indicator to handler callback changing_config
OTP-15364
Diffstat (limited to 'lib/kernel')
-rw-r--r-- | lib/kernel/doc/src/logger.xml | 92 | ||||
-rw-r--r-- | lib/kernel/doc/src/logger_chapter.xml | 30 | ||||
-rw-r--r-- | lib/kernel/doc/src/logger_disk_log_h.xml | 10 | ||||
-rw-r--r-- | lib/kernel/doc/src/logger_std_h.xml | 4 | ||||
-rw-r--r-- | lib/kernel/src/logger.erl | 35 | ||||
-rw-r--r-- | lib/kernel/src/logger_disk_log_h.erl | 81 | ||||
-rw-r--r-- | lib/kernel/src/logger_h_common.erl | 5 | ||||
-rw-r--r-- | lib/kernel/src/logger_server.erl | 146 | ||||
-rw-r--r-- | lib/kernel/src/logger_std_h.erl | 67 | ||||
-rw-r--r-- | lib/kernel/test/logger_SUITE.erl | 12 | ||||
-rw-r--r-- | lib/kernel/test/logger_disk_log_h_SUITE.erl | 179 | ||||
-rw-r--r-- | lib/kernel/test/logger_std_h_SUITE.erl | 175 |
12 files changed, 651 insertions, 185 deletions
diff --git a/lib/kernel/doc/src/logger.xml b/lib/kernel/doc/src/logger.xml index 464c65ba76..2bcf137299 100644 --- a/lib/kernel/doc/src/logger.xml +++ b/lib/kernel/doc/src/logger.xml @@ -748,6 +748,14 @@ start(_, []) -> exists, its associated value will be changed to the given value. If it does not exist, it will be added.</p> + <p>If the value is incomplete, which for example can be the + case for the <c>config</c> key, it is up to the handler + implementation how the unspecified parts are set. For all + handlers in the Kernel application, unspecified data for + the <c>config</c> key is set to default values. To update + only specified data, and keep the existing configuration for + the rest, use <seealso marker="#update_handler_config-3"> + <c>update_handler_config/3</c></seealso>.</p> <p>See the definition of the <seealso marker="#type-handler_config"> <c>handler_config()</c></seealso> type for more @@ -933,6 +941,42 @@ logger:set_handler_config(HandlerId, maps:merge(Old, Config)). </func> <func> + <name name="update_handler_config" arity="3" clause_i="1"/> + <name name="update_handler_config" arity="3" clause_i="2"/> + <name name="update_handler_config" arity="3" clause_i="3"/> + <name name="update_handler_config" arity="3" clause_i="4"/> + <name name="update_handler_config" arity="3" clause_i="5"/> + <fsummary>Add or update configuration data for the specified + handler.</fsummary> + <type variable="HandlerId"/> + <type variable="Level" name_i="1"/> + <type variable="FilterDefault" name_i="2"/> + <type variable="Filters" name_i="3"/> + <type variable="Formatter" name_i="4"/> + <type variable="Config" name_i="5"/> + <type variable="Return"/> + <desc> + <p>Add or update configuration data for the specified + handler. If the given <c><anno>Key</anno></c> already + exists, its associated value will be changed + to the given value. If it does not exist, it will + be added.</p> + <p>If the value is incomplete, which for example can be the + case for the <c>config</c> key, it is up to the handler + implementation how the unspecified parts are set. For all + handlers in the Kernel application, unspecified data for + the <c>config</c> key is not changed. To reset unspecified + data to default values, + use <seealso marker="#set_handler_config-3"> + <c>set_handler_config/3</c></seealso>.</p> + <p>See the definition of + the <seealso marker="#type-handler_config"> + <c>handler_config()</c></seealso> type for more + information about the different parameters.</p> + </desc> + </func> + + <func> <name name="update_primary_config" arity="1"/> <fsummary>Update primary configuration data for Logger.</fsummary> <desc> @@ -1041,10 +1085,11 @@ logger:set_process_metadata(maps:merge(logger:get_process_metadata(), Meta)). </func> <func> - <name>HModule:changing_config(Config1, Config2) -> {ok, Config3} | {error, Reason}</name> + <name>HModule:changing_config(SetOrUpdate, OldConfig, NewConfig) -> {ok, Config} | {error, Reason}</name> <fsummary>The configuration for this handler is about to change.</fsummary> <type> - <v>Config1 = Config2 = Config3 = + <v>SetOrUpdate = set | update</v> + <v>OldConfig = NewConfig = Config = <seealso marker="#type-handler_config">handler_config()</seealso></v> <v>Reason = term()</v> </type> @@ -1053,18 +1098,51 @@ logger:set_process_metadata(maps:merge(logger:get_process_metadata(), Meta)). <p>The function is called on a temporary process when the configuration for a handler is about to change. The purpose is to verify and act on the new configuration.</p> - <p><c>Config1</c> is the existing configuration - and <c>Config2</c> is the new configuration.</p> + <p><c>OldConfig</c> is the existing configuration + and <c>NewConfig</c> is the new configuration.</p> <p>The handler identity is associated with the <c>id</c> key - in <c>Config1</c>.</p> + in <c>OldConfig</c>.</p> + <p><c>SetOrUpdate</c> has the value <c>set</c> if the + configuration change originates from a call to + <seealso marker="#set_handler_config-2"> + <c>set_handler_config/2,3</c></seealso>, and <c>update</c> + if it originates from <seealso marker="#update_handler_config-2"> + <c>update_handler_config/2,3</c></seealso>. The handler can + use this parameteter to decide how to update the value of + the <c>config</c> field, that is, the handler specific + configuration data. Typically, if <c>SetOrUpdate</c> + equals <c>set</c>, values that are not specified must be + given their default values. If <c>SetOrUpdate</c> + equals <c>update</c>, the values found in <c>OldConfig</c> + must be used instead.</p> <p>If everything succeeds, the callback function must return a - possibly adjusted configuration in <c>{ok,Config3}</c>.</p> + possibly adjusted configuration in <c>{ok,Config}</c>.</p> <p>If the configuration is faulty, the callback function must return <c>{error,Reason}</c>.</p> </desc> </func> <func> + <name>HModule:filter_config(Config) -> FilteredConfig</name> + <fsummary>Remove internal data from configuration.</fsummary> + <type> + <v>Config = FilteredConfig = + <seealso marker="#type-handler_config">handler_config()</seealso></v> + </type> + <desc> + <p>This callback function is optional.</p> + <p>The function is called when one of the Logger API functions + for fetching the handler configuration is called, for + example + <seealso marker="#get_handler_config-1"> + <c>logger:get_handler_config/1</c></seealso>.</p> + <p>It allows the handler to remove internal data fields from + its configuration data before it is returned to the + caller.</p> + </desc> + </func> + + <func> <name>HModule:log(LogEvent, Config) -> void()</name> <fsummary>Log the given log event.</fsummary> <type> @@ -1136,7 +1214,7 @@ logger:set_process_metadata(maps:merge(logger:get_process_metadata(), Meta)). <item><seealso marker="logger#set_handler_config-2"> <c>logger:set_handler_config/2,3</c></seealso></item> <item><seealso marker="logger#update_handler_config-2"> - <c>logger:updata_handler_config/2</c></seealso></item> + <c>logger:updata_handler_config/2,3</c></seealso></item> <item><seealso marker="logger#update_formatter_config-2"> <c>logger:update_formatter_config/2</c></seealso></item> </list> diff --git a/lib/kernel/doc/src/logger_chapter.xml b/lib/kernel/doc/src/logger_chapter.xml index 4a81cfa34a..1870d2ab79 100644 --- a/lib/kernel/doc/src/logger_chapter.xml +++ b/lib/kernel/doc/src/logger_chapter.xml @@ -384,8 +384,8 @@ logger:debug(#{got => connection_request, id => Id, state => State}, <p>In addition to the mandatory callback function <c>log/2</c>, a handler module can export the optional callback - functions <c>adding_handler/1</c>, <c>changing_config/2</c> - and <c>removing_handler/1</c>. See + functions <c>adding_handler/1</c>, <c>changing_config/3</c>, + <c>filter_config/1</c>, and <c>removing_handler/1</c>. See section <seealso marker="logger#handler_callback_functions">Handler Callback Functions</seealso> in the logger(3) manual page for more information about these function.</p> @@ -555,7 +555,7 @@ logger:debug(#{got => connection_request, id => Id, state => State}, <item><seealso marker="logger#set_handler_config-2"> <c>set_handler_config/2,3</c></seealso></item> <item><seealso marker="logger#update_handler_config-2"> - <c>update_handler_config/2</c></seealso></item> + <c>update_handler_config/2,3</c></seealso></item> <item><seealso marker="logger#add_handler_filter-3"> <c>add_handler_filter/3</c></seealso></item> <item><seealso marker="logger#remove_handler_filter-2"> @@ -704,9 +704,13 @@ logger:debug(#{got => connection_request, id => Id, state => State}, <item> <p>If <c>HandlerId</c> is <c>default</c>, then this entry modifies the default handler, equivalent to calling</p> - <pre><seealso marker="logger#set_handler_config-2"> - logger:set_handler_config(default, Module, HandlerConfig) - </seealso></pre> + <pre><seealso marker="logger#remove_handler-1"> + logger:remove_handler(default) + </seealso></pre> + <p>followed by</p> + <pre><seealso marker="logger#add_handler-3"> + logger:add_handler(default, Module, HandlerConfig) + </seealso></pre> <p>For all other values of <c>HandlerId</c>, this entry adds a new handler, equivalent to calling</p> <pre><seealso marker="logger:add_handler/3"> @@ -1024,7 +1028,8 @@ ok</pre> <list> <item><c>adding_handler(Config)</c></item> <item><c>removing_handler(Config)</c></item> - <item><c>changing_config(OldConfig, NewConfig)</c></item> + <item><c>changing_config(SetOrUpdate, OldConfig, NewConfig)</c></item> + <item><c>filter_config(Config)</c></item> </list> <p>When a handler is added, by for example a call to <seealso marker="logger#add_handler-3"> @@ -1043,11 +1048,18 @@ ok</pre> <p>When <seealso marker="logger#set_handler_config-2"> <c>logger:set_handler_config/2,3</c></seealso> or <seealso marker="logger#update_handler_config/2"> - <c>logger:update_handler_config/2</c></seealso> is called, + <c>logger:update_handler_config/2,3</c></seealso> is called, Logger - calls <c>HModule:changing_config(OldConfig, NewConfig)</c>. If + calls <c>HModule:changing_config(SetOrUpdate, OldConfig, NewConfig)</c>. If this function returns <c>{ok,NewConfig1}</c>, Logger writes <c>NewConfig1</c> to the configuration database.</p> + <p>When <seealso marker="logger#get_config-0"> + <c>logger:get_config/0</c></seealso> or + <seealso marker="logger#get_handler_config-0"> + <c>logger:get_handler_config/0,1</c></seealso> is called, + Logger calls <c>HModule:filter_config(Config)</c>. This function + must return the handler configuration where internal data is + removed.</p> <p>A simple handler that prints to the terminal can be implemented as follows:</p> diff --git a/lib/kernel/doc/src/logger_disk_log_h.xml b/lib/kernel/doc/src/logger_disk_log_h.xml index dfe2ab3275..d9b941a0a9 100644 --- a/lib/kernel/doc/src/logger_disk_log_h.xml +++ b/lib/kernel/doc/src/logger_disk_log_h.xml @@ -66,6 +66,10 @@ corresponds to the <c>name</c> property in the <seealso marker="disk_log#open-1"><c>dlog_option()</c></seealso> datatype.</p> + <p>The value is set when the handler is added, and it can not + be changed in runtime.</p> + <p>Defaults to the same name as the handler identity, in the + current directory.</p> </item> <tag><c>type</c></tag> <item> @@ -73,6 +77,8 @@ corresponds to the <c>type</c> property in the <seealso marker="disk_log#open-1"><c>dlog_option()</c></seealso> datatype.</p> + <p>The value is set when the handler is added, and it can not + be changed in runtime.</p> <p>Defaults to <c>wrap</c>.</p> </item> <tag><c>max_no_files</c></tag> @@ -82,6 +88,8 @@ corresponds to the <c>MaxNoFiles</c> element in the <c>size</c> property in the <seealso marker="disk_log#open-1"><c>dlog_option()</c></seealso> datatype.</p> + <p>The value is set when the handler is added, and it can not + be changed in runtime.</p> <p>Defaults to <c>10</c>.</p> <p>The setting has no effect on a halt log.</p> </item> @@ -93,6 +101,8 @@ corresponds to the <c>MaxNoBytes</c> element in the <c>size</c> property in the <seealso marker="disk_log#open-1"><c>dlog_option()</c></seealso> datatype.</p> + <p>The value is set when the handler is added, and it can not + be changed in runtime.</p> <p>Defaults to <c>1048576</c> bytes for a wrap log, and <c>infinity</c> for a halt log.</p> </item> diff --git a/lib/kernel/doc/src/logger_std_h.xml b/lib/kernel/doc/src/logger_std_h.xml index fcd8189bae..e156f5719b 100644 --- a/lib/kernel/doc/src/logger_std_h.xml +++ b/lib/kernel/doc/src/logger_std_h.xml @@ -74,7 +74,9 @@ circular logging. Use the disk_log handler, <seealso marker="logger_disk_log_h"><c>logger_disk_log_h</c></seealso>, for this.</p> - <p> Defaults to <c>standard_io</c>.</p> + <p>The value is set when the handler is added, and it can not + be changed in runtime.</p> + <p>Defaults to <c>standard_io</c>.</p> </item> <tag><c>filesync_repeat_interval</c></tag> <item> diff --git a/lib/kernel/src/logger.erl b/lib/kernel/src/logger.erl index 752dd8d493..6762998d4f 100644 --- a/lib/kernel/src/logger.erl +++ b/lib/kernel/src/logger.erl @@ -43,7 +43,8 @@ get_module_level/0, get_module_level/1, set_primary_config/1, set_primary_config/2, set_handler_config/2, set_handler_config/3, - update_primary_config/1, update_handler_config/2, + update_primary_config/1, + update_handler_config/2, update_handler_config/3, update_formatter_config/2, update_formatter_config/3, get_primary_config/0, get_handler_config/1, get_handler_config/0, get_handler_ids/0, get_config/0, @@ -423,6 +424,29 @@ set_handler_config(HandlerId,Config) -> update_primary_config(Config) -> logger_server:update_config(primary,Config). +-spec update_handler_config(HandlerId,level,Level) -> Return when + HandlerId :: handler_id(), + Level :: level() | all | none, + Return :: ok | {error,term()}; + (HandlerId,filter_default,FilterDefault) -> Return when + HandlerId :: handler_id(), + FilterDefault :: log | stop, + Return :: ok | {error,term()}; + (HandlerId,filters,Filters) -> Return when + HandlerId :: handler_id(), + Filters :: [{filter_id(),filter()}], + Return :: ok | {error,term()}; + (HandlerId,formatter,Formatter) -> Return when + HandlerId :: handler_id(), + Formatter :: {module(), formatter_config()}, + Return :: ok | {error,term()}; + (HandlerId,config,Config) -> Return when + HandlerId :: handler_id(), + Config :: term(), + Return :: ok | {error,term()}. +update_handler_config(HandlerId,Key,Value) -> + logger_server:update_config(HandlerId,Key,Value). + -spec update_handler_config(HandlerId,Config) -> ok | {error,term()} when HandlerId :: handler_id(), Config :: handler_config(). @@ -439,7 +463,14 @@ get_primary_config() -> HandlerId :: handler_id(), Config :: handler_config(). get_handler_config(HandlerId) -> - logger_config:get(?LOGGER_TABLE,HandlerId). + case logger_config:get(?LOGGER_TABLE,HandlerId) of + {ok,#{module:=Module}=Config} -> + {ok,try Module:filter_config(Config) + catch _:_ -> Config + end}; + Error -> + Error + end. -spec get_handler_config() -> [Config] when Config :: handler_config(). diff --git a/lib/kernel/src/logger_disk_log_h.erl b/lib/kernel/src/logger_disk_log_h.erl index a8f141f135..2a81458ec8 100644 --- a/lib/kernel/src/logger_disk_log_h.erl +++ b/lib/kernel/src/logger_disk_log_h.erl @@ -33,7 +33,8 @@ terminate/2, code_change/3]). %% logger callbacks --export([log/2, adding_handler/1, removing_handler/1, changing_config/2]). +-export([log/2, adding_handler/1, removing_handler/1, changing_config/3, + filter_config/1]). %% handler internal -export([log_handler_info/4]). @@ -114,9 +115,8 @@ reset(Name) -> %%% Handler being added adding_handler(#{id:=Name}=Config) -> case check_config(adding, Config) of - {ok, Config1} -> + {ok, #{config:=HConfig}=Config1} -> %% create initial handler state by merging defaults with config - HConfig = maps:get(config, Config1, #{}), HState = maps:merge(get_init_state(), HConfig), case logger_h_common:overload_levels_ok(HState) of true -> @@ -133,32 +133,40 @@ adding_handler(#{id:=Name}=Config) -> %%%----------------------------------------------------------------- %%% Updating handler config -changing_config(OldConfig = #{id:=Name, config:=OldHConfig}, - NewConfig = #{id:=Name, config:=NewHConfig}) -> - #{type:=Type, file:=File, max_no_files:=MaxFs, - max_no_bytes:=MaxBytes} = OldHConfig, - case NewHConfig of - #{type:=Type, file:=File, max_no_files:=MaxFs, - max_no_bytes:=MaxBytes} -> - changing_config1(OldConfig, NewConfig); - _ -> - {error,{illegal_config_change,OldConfig,NewConfig}} - end; -changing_config(OldConfig, NewConfig) -> - {error,{illegal_config_change,OldConfig,NewConfig}}. +changing_config(SetOrUpdate,OldConfig=#{config:=OldHConfig},NewConfig) -> + WriteOnce = maps:with([type,file,max_no_files,max_no_bytes],OldHConfig), + ReadOnly = maps:with([handler_pid,mode_tab],OldHConfig), + NewHConfig0 = maps:get(config, NewConfig, #{}), + Default = + case SetOrUpdate of + set -> + %% Do not reset write-once fields to defaults + maps:merge(get_default_config(),WriteOnce); + update -> + OldHConfig + end, -changing_config1(OldConfig=#{config:=OldHConfig}, NewConfig) -> + %% Allow (accidentially) included read-only fields - just overwrite them + NewHConfig = maps:merge(maps:merge(Default,NewHConfig0),ReadOnly), + + %% But fail if write-once fields are changed + case maps:with([type,file,max_no_files,max_no_bytes],NewHConfig) of + WriteOnce -> + changing_config1(maps:get(handler_pid,OldHConfig), + OldConfig, + NewConfig#{config=>NewHConfig}); + Other -> + {Old,New} = logger_server:diff_maps(WriteOnce,Other), + {error,{illegal_config_change,#{config=>Old},#{config=>New}}} + end. + +changing_config1(HPid, OldConfig, NewConfig) -> case check_config(changing, NewConfig) of - {ok,NewConfig1 = #{config:=NewHConfig}} -> - #{handler_pid:=HPid, - mode_tab:=ModeTab} = OldHConfig, - NewHConfig1 = NewHConfig#{handler_pid=>HPid, - mode_tab=>ModeTab}, - NewConfig2 = NewConfig1#{config=>NewHConfig1}, - try gen_server:call(HPid, {change_config,OldConfig,NewConfig2}, + Result = {ok,NewConfig1} -> + try gen_server:call(HPid, {change_config,OldConfig,NewConfig1}, ?DEFAULT_CALL_TIMEOUT) of - ok -> {ok,NewConfig2}; - HError -> HError + ok -> Result; + Error -> Error catch _:{timeout,_} -> {error,handler_busy} end; @@ -168,10 +176,12 @@ changing_config1(OldConfig=#{config:=OldHConfig}, NewConfig) -> check_config(adding, #{id:=Name}=Config) -> %% merge handler specific config data - HConfig = merge_default_logopts(Name, maps:get(config, Config, #{})), - case check_h_config(maps:to_list(HConfig)) of + HConfig1 = maps:get(config, Config, #{}), + HConfig2 = maps:merge(get_default_config(), HConfig1), + HConfig3 = merge_default_logopts(Name, HConfig2), + case check_h_config(maps:to_list(HConfig3)) of ok -> - {ok,Config#{config=>HConfig}}; + {ok,Config#{config=>HConfig3}}; Error -> Error end; @@ -238,6 +248,11 @@ log(LogEvent, Config = #{id := Name, Bin = logger_h_common:log_to_binary(LogEvent, Config), logger_h_common:call_cast_or_drop(Name, HPid, ModeTab, Bin). +%%%----------------------------------------------------------------- +%%% Remove internal fields from configuration +filter_config(#{config:=HConfig}=Config) -> + Config#{config=>maps:without([handler_pid,mode_tab],HConfig)}. + %%%=================================================================== %%% gen_server callbacks %%%=================================================================== @@ -438,7 +453,7 @@ code_change(_OldVsn, State, _Extra) -> %%%----------------------------------------------------------------- %%% -get_init_state() -> +get_default_config() -> #{sync_mode_qlen => ?SYNC_MODE_QLEN, drop_mode_qlen => ?DROP_MODE_QLEN, flush_qlen => ?FLUSH_QLEN, @@ -449,10 +464,12 @@ get_init_state() -> overload_kill_qlen => ?OVERLOAD_KILL_QLEN, overload_kill_mem_size => ?OVERLOAD_KILL_MEM_SIZE, overload_kill_restart_after => ?OVERLOAD_KILL_RESTART_AFTER, - dl_sync_int => ?CONTROLLER_SYNC_INTERVAL, - filesync_ok_qlen => ?FILESYNC_OK_QLEN, filesync_repeat_interval => ?FILESYNC_REPEAT_INTERVAL}. +get_init_state() -> + #{dl_sync_int => ?CONTROLLER_SYNC_INTERVAL, + filesync_ok_qlen => ?FILESYNC_OK_QLEN}. + %%%----------------------------------------------------------------- %%% Add a disk_log handler to the logger. %%% This starts a dedicated handler process which should always diff --git a/lib/kernel/src/logger_h_common.erl b/lib/kernel/src/logger_h_common.erl index 38ac7d8ffc..94c640cb92 100644 --- a/lib/kernel/src/logger_h_common.erl +++ b/lib/kernel/src/logger_h_common.erl @@ -306,8 +306,11 @@ stop_or_restart(Name, {shutdown,Reason={overloaded,_Name,_QLen,_Mem}}, exit(HandlerPid, kill) end, case ConfigResult of - {ok,#{module:=HMod}=HConfig} when is_integer(RestartAfter) -> + {ok,#{module:=HMod}=HConfig0} when is_integer(RestartAfter) -> _ = logger:remove_handler(Name), + HConfig = try HMod:filter_config(HConfig0) + catch _:_ -> HConfig0 + end, _ = timer:apply_after(RestartAfter, logger, add_handler, [Name,HMod,HConfig]); {ok,_} -> diff --git a/lib/kernel/src/logger_server.erl b/lib/kernel/src/logger_server.erl index a1d40f1123..b7735dbcf7 100644 --- a/lib/kernel/src/logger_server.erl +++ b/lib/kernel/src/logger_server.erl @@ -27,9 +27,13 @@ add_filter/2, remove_filter/2, set_module_level/2, unset_module_level/0, unset_module_level/1, cache_module_level/1, - set_config/2, set_config/3, update_config/2, + set_config/2, set_config/3, + update_config/2, update_config/3, update_formatter_config/2]). +%% Helper +-export([diff_maps/2]). + %% gen_server callbacks -export([init/1, handle_call/3, handle_cast/2, handle_info/2, terminate/2]). @@ -105,12 +109,25 @@ cache_module_level(Module) -> gen_server:cast(?SERVER,{cache_module_level,Module}). set_config(Owner,Key,Value) -> - update_config(Owner,#{Key=>Value}). + case sanity_check(Owner,Key,Value) of + ok -> + call({change_config,set,Owner,Key,Value}); + Error -> + Error + end. set_config(Owner,Config) -> case sanity_check(Owner,Config) of ok -> - call({set_config,Owner,Config}); + call({change_config,set,Owner,Config}); + Error -> + Error + end. + +update_config(Owner,Key,Value) -> + case sanity_check(Owner,Key,Value) of + ok -> + call({change_config,update,Owner,Key,Value}); Error -> Error end. @@ -118,7 +135,7 @@ set_config(Owner,Config) -> update_config(Owner, Config) -> case sanity_check(Owner,Config) of ok -> - call({update_config,Owner,Config}); + call({change_config,update,Owner,Config}); Error -> Error end. @@ -204,46 +221,72 @@ handle_call({add_filter,Id,Filter}, _From,#state{tid=Tid}=State) -> handle_call({remove_filter,Id,FilterId}, _From, #state{tid=Tid}=State) -> Reply = do_remove_filter(Tid,Id,FilterId), {reply,Reply,State}; -handle_call({update_config,primary,NewConfig}, _From, #state{tid=Tid}=State) -> +handle_call({change_config,SetOrUpd,primary,Config0}, _From, + #state{tid=Tid}=State) -> + {ok,#{handlers:=Handlers}=OldConfig} = logger_config:get(Tid,primary), + Default = + case SetOrUpd of + set -> default_config(primary); + update -> OldConfig + end, + Config = maps:merge(Default,Config0), + Reply = logger_config:set(Tid,primary,Config#{handlers=>Handlers}), + {reply,Reply,State}; +handle_call({change_config,_SetOrUpd,primary,Key,Value}, _From, + #state{tid=Tid}=State) -> {ok,OldConfig} = logger_config:get(Tid,primary), - Config = maps:merge(OldConfig,NewConfig), - {reply,logger_config:set(Tid,primary,Config),State}; -handle_call({update_config,HandlerId,NewConfig}, From, #state{tid=Tid}=State) -> + Reply = logger_config:set(Tid,primary,OldConfig#{Key=>Value}), + {reply,Reply,State}; +handle_call({change_config,SetOrUpd,HandlerId,Config0}, From, + #state{tid=Tid}=State) -> case logger_config:get(Tid,HandlerId) of {ok,#{module:=Module}=OldConfig} -> - Config = maps:merge(OldConfig,NewConfig), - call_h_async( - fun() -> - call_h(Module,changing_config,[OldConfig,Config], - {ok,Config}) - end, - fun({ok,Config1}) -> - logger_config:set(Tid,HandlerId,Config1); - (Error) -> - Error - end,From,State); - Error -> - {reply,Error,State} + Default = + case SetOrUpd of + set -> default_config(HandlerId,Module); + update -> OldConfig + end, + Config = maps:merge(Default,Config0), + case check_config_change(OldConfig,Config) of + ok -> + call_h_async( + fun() -> + call_h(Module,changing_config, + [SetOrUpd,OldConfig,Config], + {ok,Config}) + end, + fun({ok,Config1}) -> + logger_config:set(Tid,HandlerId,Config1); + (Error) -> + Error + end,From,State); + Error -> + {reply,Error,State} + end; + _ -> + {reply,{error,{not_found,HandlerId}},State} end; -handle_call({set_config,primary,Config0}, _From, #state{tid=Tid}=State) -> - Config = maps:merge(default_config(primary),Config0), - {ok,#{handlers:=Handlers}} = logger_config:get(Tid,primary), - Reply = logger_config:set(Tid,primary,Config#{handlers=>Handlers}), - {reply,Reply,State}; -handle_call({set_config,HandlerId,Config0}, From, #state{tid=Tid}=State) -> +handle_call({change_config,SetOrUpd,HandlerId,Key,Value}, From, + #state{tid=Tid}=State) -> case logger_config:get(Tid,HandlerId) of {ok,#{module:=Module}=OldConfig} -> - Config = maps:merge(default_config(HandlerId,Module),Config0), - call_h_async( - fun() -> - call_h(Module,changing_config,[OldConfig,Config], - {ok,Config}) - end, - fun({ok,Config1}) -> - logger_config:set(Tid,HandlerId,Config1); - (Error) -> - Error - end,From,State); + Config = OldConfig#{Key=>Value}, + case check_config_change(OldConfig,Config) of + ok -> + call_h_async( + fun() -> + call_h(Module,changing_config, + [SetOrUpd,OldConfig,Config], + {ok,Config}) + end, + fun({ok,Config1}) -> + logger_config:set(Tid,HandlerId,Config1); + (Error) -> + Error + end,From,State); + Error -> + {reply,Error,State} + end; _ -> {reply,{error,{not_found,HandlerId}},State} end; @@ -320,7 +363,7 @@ call(Request) -> true when Action == add_handler; Action == remove_handler; Action == add_filter; Action == remove_filter; - Action == update_config; Action == set_config -> + Action == change_config -> {error,{attempting_syncronous_call_to_self,Request}}; _ -> gen_server:call(?SERVER,Request,?DEFAULT_LOGGER_CALL_TIMEOUT) @@ -458,6 +501,15 @@ check_formatter({Mod,Config}) -> check_formatter(Formatter) -> throw({invalid_formatter,Formatter}). +%% When changing configuration for a handler, the id and module fields +%% can not be changed. +check_config_change(#{id:=Id,module:=Module},#{id:=Id,module:=Module}) -> + ok; +check_config_change(OldConfig,NewConfig) -> + {Old,New} = logger_server:diff_maps(maps:with([id,module],OldConfig), + maps:with([id,module],NewConfig)), + {error,{illegal_config_change,Old,New}}. + call_h(Module, Function, Args, DefRet) -> %% Not calling code:ensure_loaded + erlang:function_exported here, %% since in some rare terminal cases, the code_server might not @@ -466,6 +518,11 @@ call_h(Module, Function, Args, DefRet) -> catch C:R:S -> case {C,R,S} of + {error,undef,[{Module,Function=changing_config,Args,_}|_]} + when length(Args)=:=3 -> + %% Backwards compatible call, if changing_config/3 + %% did not exist. + call_h(Module, Function, tl(Args), DefRet); {error,undef,[{Module,Function,Args,_}|_]} -> DefRet; _ -> @@ -525,3 +582,14 @@ call_h_reply(Unexpected,State) -> {process,?SERVER}, {message,Unexpected}]), {noreply,State}. + +%% Return two maps containing only the fields that differ. +diff_maps(M1,M2) -> + diffs(lists:sort(maps:to_list(M1)),lists:sort(maps:to_list(M2)),#{},#{}). + +diffs([H|T1],[H|T2],D1,D2) -> + diffs(T1,T2,D1,D2); +diffs([{K,V1}|T1],[{K,V2}|T2],D1,D2) -> + diffs(T1,T2,D1#{K=>V1},D2#{K=>V2}); +diffs([],[],D1,D2) -> + {D1,D2}. diff --git a/lib/kernel/src/logger_std_h.erl b/lib/kernel/src/logger_std_h.erl index 66fa6b6ab6..42e0f5caf4 100644 --- a/lib/kernel/src/logger_std_h.erl +++ b/lib/kernel/src/logger_std_h.erl @@ -35,7 +35,8 @@ terminate/2, code_change/3]). %% logger callbacks --export([log/2, adding_handler/1, removing_handler/1, changing_config/2]). +-export([log/2, adding_handler/1, removing_handler/1, changing_config/3, + filter_config/1]). %% handler internal -export([log_handler_info/4]). @@ -116,9 +117,8 @@ reset(Name) -> %%% Handler being added adding_handler(#{id:=Name}=Config) -> case check_config(adding, Config) of - {ok, Config1} -> + {ok, #{config:=HConfig}=Config1} -> %% create initial handler state by merging defaults with config - HConfig = maps:get(config, Config1, #{}), HState = maps:merge(get_init_state(), HConfig), case logger_h_common:overload_levels_ok(HState) of true -> @@ -135,22 +135,31 @@ adding_handler(#{id:=Name}=Config) -> %%%----------------------------------------------------------------- %%% Updating handler config -changing_config(OldConfig=#{id:=Name, config:=OldHConfig}, - NewConfig=#{id:=Name}) -> - #{type:=Type, handler_pid:=HPid, mode_tab:=ModeTab} = OldHConfig, - NewHConfig = maps:get(config, NewConfig, #{}), - case maps:get(type, NewHConfig, Type) of - Type -> - NewHConfig1 = NewHConfig#{type=>Type, - handler_pid=>HPid, - mode_tab=>ModeTab}, - changing_config1(HPid, OldConfig, - NewConfig#{config=>NewHConfig1}); - _ -> - {error,{illegal_config_change,OldConfig,NewConfig}} - end; -changing_config(OldConfig, NewConfig) -> - {error,{illegal_config_change,OldConfig,NewConfig}}. +changing_config(SetOrUpdate,OldConfig=#{config:=OldHConfig},NewConfig) -> + WriteOnce = maps:with([type],OldHConfig), + ReadOnly = maps:with([handler_pid,mode_tab],OldHConfig), + NewHConfig0 = maps:get(config, NewConfig, #{}), + Default = + case SetOrUpdate of + set -> + %% Do not reset write-once fields to defaults + maps:merge(get_default_config(),WriteOnce); + update -> + OldHConfig + end, + + %% Allow (accidentially) included read-only fields - just overwrite them + NewHConfig = maps:merge(maps:merge(Default, NewHConfig0),ReadOnly), + + %% But fail if write-once fields are changed + case maps:with([type],NewHConfig) of + WriteOnce -> + changing_config1(maps:get(handler_pid,OldHConfig), + OldConfig, + NewConfig#{config=>NewHConfig}); + Other -> + {error,{illegal_config_change,#{config=>WriteOnce},#{config=>Other}}} + end. changing_config1(HPid, OldConfig, NewConfig) -> case check_config(changing, NewConfig) of @@ -169,8 +178,7 @@ changing_config1(HPid, OldConfig, NewConfig) -> check_config(adding, Config) -> %% Merge in defaults on handler level HConfig0 = maps:get(config, Config, #{}), - HConfig = maps:merge(#{type => standard_io}, - HConfig0), + HConfig = maps:merge(get_default_config(),HConfig0), case check_h_config(maps:to_list(HConfig)) of ok -> {ok,Config#{config=>HConfig}}; @@ -223,6 +231,11 @@ log(LogEvent, Config = #{id := Name, Bin = logger_h_common:log_to_binary(LogEvent, Config), logger_h_common:call_cast_or_drop(Name, HPid, ModeTab, Bin). +%%%----------------------------------------------------------------- +%%% Remove internal fields from configuration +filter_config(#{config:=HConfig}=Config) -> + Config#{config=>maps:without([handler_pid,mode_tab],HConfig)}. + %%%=================================================================== %%% gen_server callbacks %%%=================================================================== @@ -428,8 +441,9 @@ code_change(_OldVsn, State, _Extra) -> %%%----------------------------------------------------------------- %%% -get_init_state() -> - #{sync_mode_qlen => ?SYNC_MODE_QLEN, +get_default_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, @@ -439,10 +453,12 @@ get_init_state() -> overload_kill_qlen => ?OVERLOAD_KILL_QLEN, overload_kill_mem_size => ?OVERLOAD_KILL_MEM_SIZE, overload_kill_restart_after => ?OVERLOAD_KILL_RESTART_AFTER, - file_ctrl_sync_int => ?CONTROLLER_SYNC_INTERVAL, - filesync_ok_qlen => ?FILESYNC_OK_QLEN, filesync_repeat_interval => ?FILESYNC_REPEAT_INTERVAL}. +get_init_state() -> + #{file_ctrl_sync_int => ?CONTROLLER_SYNC_INTERVAL, + filesync_ok_qlen => ?FILESYNC_OK_QLEN}. + %%%----------------------------------------------------------------- %%% Add a standard handler to the logger. %%% This starts a dedicated handler process which should always @@ -825,4 +841,3 @@ sync_dev(Fd, DevName, PrevSyncResult, HandlerName) -> logger_h_common:error_notify({HandlerName,filesync,DevName,Error}), Error end. - diff --git a/lib/kernel/test/logger_SUITE.erl b/lib/kernel/test/logger_SUITE.erl index b7ccba8e70..d831d0d108 100644 --- a/lib/kernel/test/logger_SUITE.erl +++ b/lib/kernel/test/logger_SUITE.erl @@ -246,6 +246,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), diff --git a/lib/kernel/test/logger_disk_log_h_SUITE.erl b/lib/kernel/test/logger_disk_log_h_SUITE.erl index a815db14e9..905c2c52c5 100644 --- a/lib/kernel/test/logger_disk_log_h_SUITE.erl +++ b/lib/kernel/test/logger_disk_log_h_SUITE.erl @@ -92,6 +92,7 @@ all() -> disk_log_opts, default_formatter, logging, + filter_config, errors, formatter_fail, config_fail, @@ -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([handler_pid,mode_tab],HConfig), + + FakeFullHConfig = HConfig#{handler_pid=>self(),mode_tab=>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, + #{config:=#{type:=wrap}}, + #{config:=#{type:=halt}}}} = + logger:update_handler_config(Name1, + config, + #{type=>halt, + file=>LogFile1}), + + {error,{illegal_config_change, + #{config:=#{file:=LogFile1}}, + #{config:=#{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, + #{handler_pid=>self(), + mode_tab=>erlang:make_ref()}), + {ok,C} = logger:get_handler_config(Name1), + ok = logger:remove_handler(Name1), {error,{not_found,Name1}} = logger:remove_handler(Name1), @@ -403,21 +434,21 @@ config_fail(_Config) -> 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}), + logger:update_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), + logger:update_handler_config(?MODULE,id,bad), %% 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}), + 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}), + logger:update_handler_config(?MODULE, config, + HConfig#{filesync_rep_int => 2000}), ok. config_fail(cleanup,_Config) -> logger:remove_handler(?MODULE). @@ -459,10 +490,26 @@ reconfig(Config) -> log_opts := #{type := ?DISK_LOG_TYPE, max_no_files := ?DISK_LOG_MAX_NO_FILES, max_no_bytes := ?DISK_LOG_MAX_NO_BYTES, - file := _DiskLogFile}} = + file := DiskLogFile}} = logger_disk_log_h:info(?MODULE), + {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), - {ok,#{config := HConfig0}} = logger:get_handler_config(?MODULE), HConfig1 = HConfig0#{sync_mode_qlen => 1, drop_mode_qlen => 2, flush_qlen => 3, @@ -488,6 +535,29 @@ reconfig(Config) -> overload_kill_restart_after := infinity, filesync_repeat_interval := no_repeat} = logger_disk_log_h:info(?MODULE), + {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), @@ -507,6 +577,43 @@ reconfig(Config) -> max_no_bytes := 1024, file := File}} = logger_disk_log_h:info(?MODULE), + {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) -> @@ -536,7 +643,7 @@ sync(Config) -> %% 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)), @@ -569,13 +676,13 @@ sync(Config) -> [OneSync || _ <- lists:seq(1, 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)), 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) -> @@ -797,7 +904,7 @@ sync_failure(Config) -> LogOpts = maps:get(log_opts, 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]), @@ -872,7 +979,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 +1004,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 +1050,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 +1092,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 +1112,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 +1133,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 +1153,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 +1175,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, @@ -1105,7 +1212,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, @@ -1139,7 +1246,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), @@ -1161,7 +1268,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 @@ -1194,7 +1301,7 @@ handler_requests_under_load(Config) -> drop_mode_qlen => 1000, flush_qlen => 2000, burst_limit_enable => false}}, - ok = logger:set_handler_config(?MODULE, NewHConfig), + ok = logger:update_handler_config(?MODULE, NewHConfig), Pid = spawn_link(fun() -> send_requests(?MODULE, 1, [{filesync,[]}, {info,[]}, {reset,[]}, @@ -1227,9 +1334,9 @@ send_requests(HName, TO, Reqs = [{Req,Res}|Rs]) -> Result = case Req of change_config -> - logger:set_handler_config(HName, logger_disk_log_h, - #{overload_kill_enable => - false}); + logger:update_handler_config(HName, logger_disk_log_h, + #{overload_kill_enable => + false}); Func -> logger_disk_log_h:Func(HName) end, diff --git a/lib/kernel/test/logger_std_h_SUITE.erl b/lib/kernel/test/logger_std_h_SUITE.erl index 3426567bbf..b6a09f4980 100644 --- a/lib/kernel/test/logger_std_h_SUITE.erl +++ b/lib/kernel/test/logger_std_h_SUITE.erl @@ -108,6 +108,7 @@ all() -> add_remove_instance_file1, add_remove_instance_file2, default_formatter, + filter_config, errors, formatter_fail, config_fail, @@ -204,6 +205,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([handler_pid,mode_tab],HConfig), + + FakeFullHConfig = HConfig#{handler_pid=>self(),mode_tab=>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), @@ -319,11 +334,10 @@ 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,#{config:=#{type:=_}},#{config:=#{type:=_}}}} = logger:set_handler_config(?MODULE,config, #{type=>{file,"file"}}), - {error,{illegal_config_change,_,_}} = - logger:set_handler_config(?MODULE,id,bad), + {error,{invalid_levels,_}} = logger:set_handler_config(?MODULE,config, #{sync_mode_qlen=>100, @@ -331,6 +345,15 @@ config_fail(_Config) -> {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, + #{handler_pid=>self(), + mode_tab=>erlang:make_ref()}), + {ok,C} = logger:get_handler_config(?MODULE), + ok. config_fail(cleanup,_Config) -> @@ -457,9 +480,26 @@ 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} = + filesync_repeat_interval := ?FILESYNC_REPEAT_INTERVAL} = DefaultInfo = logger_std_h:info(?MODULE), + {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 := ?FILESYNC_REPEAT_INTERVAL} = + DefaultHConf}} + = logger:get_handler_config(?MODULE), + ok = logger:set_handler_config(?MODULE, config, #{sync_mode_qlen => 1, drop_mode_qlen => 2, @@ -485,7 +525,77 @@ reconfig(Config) -> overload_kill_qlen := 100000, overload_kill_mem_size := 10000000, overload_kill_restart_after := infinity, - filesync_repeat_interval := no_repeat} = logger_std_h:info(?MODULE), + filesync_repeat_interval := no_repeat} = Info = logger_std_h:info(?MODULE), + + {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: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) -> @@ -561,8 +671,8 @@ 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}), + ok = logger:update_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 @@ -592,12 +702,12 @@ sync(Config) -> 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}), + ok = logger:update_handler_config(?MODULE, config, + #{filesync_repeat_interval => SyncInt}), SyncInt = maps:get(filesync_repeat_interval, logger_std_h:info(?MODULE)), 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,7 +762,7 @@ 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]), @@ -718,7 +828,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 +857,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 +880,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 +917,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 +942,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 +989,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 +1005,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 +1025,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 +1046,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 +1066,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 +1087,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, @@ -1011,7 +1121,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 +1138,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, @@ -1067,7 +1177,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), @@ -1082,14 +1192,15 @@ restart_after(Config) -> 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 @@ -1123,7 +1234,7 @@ handler_requests_under_load(Config) -> drop_mode_qlen => 1000, flush_qlen => 2000, burst_limit_enable => false}}, - ok = logger:set_handler_config(?MODULE, NewHConfig), + ok = logger:update_handler_config(?MODULE, NewHConfig), Pid = spawn_link(fun() -> send_requests(?MODULE, 1, [{filesync,[]}, {info,[]}, {reset,[]}, @@ -1155,9 +1266,9 @@ send_requests(HName, TO, Reqs = [{Req,Res}|Rs]) -> Result = case Req of change_config -> - logger:set_handler_config(HName, config, - #{overload_kill_enable => - false}); + logger:update_handler_config(HName, config, + #{overload_kill_enable => + false}); Func -> logger_std_h:Func(HName) end, |