File 3501-Add-support-for-primary-metadata-to-the-lo... of Package erlang

Overview Repositories Revisions Requests Users Attributes Meta

File 3501-Add-support-for-primary-metadata-to-the-logger.patch of Package erlang (Revision 048167bcaa30c6163f4d1505a6baf337)

Currently displaying revision 048167bcaa30c6163f4d1505a6baf337 , Show latest

From 576b69ac6e55ad29a83b6b0bb1ce17040492625f Mon Sep 17 00:00:00 2001
From: =?UTF-8?q?=C5=81ukasz=20Niemier?= <lukasz@niemier.pl>
Date: Thu, 14 Nov 2019 14:46:27 +0100
Subject: [PATCH] Add support for primary metadata to the logger

This adds new `kernel` configuration option `logger_metadata`
that will contain default metadata.

Resolves #4105
---
 lib/kernel/doc/src/kernel_app.xml     |  6 ++++
 lib/kernel/doc/src/logger.xml         | 29 +++++++++++-----
 lib/kernel/doc/src/logger_chapter.xml | 29 +++++++++++++++-
 lib/kernel/src/logger.erl             | 48 ++++++++++++++++++++-------
 lib/kernel/src/logger_backend.erl     | 24 +++++++-------
 lib/kernel/src/logger_config.erl      |  3 ++
 lib/kernel/src/logger_server.erl      |  3 ++
 lib/kernel/test/logger_SUITE.erl      | 16 ++++++++-
 8 files changed, 124 insertions(+), 34 deletions(-)

diff --git a/lib/kernel/doc/src/kernel_app.xml b/lib/kernel/doc/src/kernel_app.xml
index eb95b9b733..c17b327f32 100644
--- a/lib/kernel/doc/src/kernel_app.xml
+++ b/lib/kernel/doc/src/kernel_app.xml
@@ -200,6 +200,12 @@
 <c>logger:set_primary_config(level, Level)</c></seemfa>.
 	Defaults to <c>notice</c>.
 </item>
+ <tag><marker id="logger_metadata"/><c>logger_metadata = Metadata</c></tag>
+ <item>
+	Specifies primary metadata for log events.
+	<c>Metadata = map()</c>
+	Defaults to <c>#{}</c>.
+ </item>
 <tag><marker id="logger_sasl_compatible"/>
 	<c>logger_sasl_compatible = true | false</c></tag>
 <item>
diff --git a/lib/kernel/doc/src/logger.xml b/lib/kernel/doc/src/logger.xml
index 801a2c1193..2f76dbd567 100644
--- a/lib/kernel/doc/src/logger.xml
+++ b/lib/kernel/doc/src/logger.xml
@@ -199,17 +199,28 @@ logger:error("error happened because: ~p", [Reason]). % Without macro
 	 <item><c>file => ?FILE</c></item>
 	 <item><c>line => ?LINE</c></item>
 	</list>
-	You can add custom metadata, either by specifying a map as
-	 the last parameter to any of the log macros or the API
-	 functions, or by setting process metadata
-	 with <seemfa marker="#set_process_metadata/1">
+	You can add custom metadata, either by:
+ <list>
+ <item>specifying a map as the last parameter to any of the
+ log macros or the logger API functions.</item>
+ <item>setting process metadata with <seemfa marker="#set_process_metadata/1">
 	 <c>set_process_metadata/1</c></seemfa>
-	 or <seemfa marker="#update_process_metadata/1">
-	 <c>update_process_metadata/1</c></seemfa>.
+	 or <seemfa marker="#update_process_metadata/1">
+	 <c>update_process_metadata/1</c></seemfa>.</item>
+ <item>setting primary metadata with <seemfa marker="#set_primary_config/1">
+ <c>set_primary_config/1</c></seemfa> or through the kernel
+ configuration parameter <seeapp marker="kernel_app#logger_metadata">
+ logger_metadata</seeapp></item>
+ </list>
+ <note>
+ When adding custom metadata, make sure not to use any of the keys
+ mentioned above as that may cause a lot of confusion about the log
+ events.
+ </note>
 	Logger merges all the metadata maps before forwarding the
 	 log event to the handlers. If the same keys occur, values
-	 from the log call overwrite process metadata, which in turn
-	 overwrite values set by Logger.
+	 from the log call overwrite process metadata, which overwrites
+ the primary metadata, which in turn overwrite values set by Logger.
 	The following custom metadata keys have special meaning:
 	<taglist>
 	 <tag><c>domain</c></tag>
@@ -816,10 +827,12 @@ start(_, []) ->
 <name name="set_primary_config" arity="2" clause_i="1" since="OTP 21.0"/>
 <name name="set_primary_config" arity="2" clause_i="2" since="OTP 21.0"/>
 <name name="set_primary_config" arity="2" clause_i="3" since="OTP 21.0"/>
+ <name name="set_primary_config" arity="2" clause_i="4" since="OTP 24.0"/>
 <fsummary>Add or update primary configuration data for Logger.</fsummary>
 <type variable="Level" name_i="1"/>
 <type variable="FilterDefault" name_i="2"/>
 <type variable="Filters" name_i="3"/>
+ <type variable="Meta" name_i="4"/>
 <desc>
 Add or update primary configuration data for Logger. If the
 given <c><anno>Key</anno></c> already exists, its associated
diff --git a/lib/kernel/doc/src/logger_chapter.xml b/lib/kernel/doc/src/logger_chapter.xml
index b082607751..e2782ad652 100644
--- a/lib/kernel/doc/src/logger_chapter.xml
+++ b/lib/kernel/doc/src/logger_chapter.xml
@@ -237,8 +237,21 @@ logger:debug(#{got => connection_request, id => Id, state => State},
 <title>Metadata</title>
 Metadata contains additional data associated with a log
 	message. Logger inserts some metadata fields by default, and
-	the client can add custom metadata in two different ways:
+	the client can add custom metadata in three different ways:
 <taglist>
+ <tag>Set primary metadata</tag>
+ <item>
+ Primary metadata applies is the base metadata given to
+ all log events. At startup it can be set using
+ the kernel configuration parameter
+ <seeapp marker="kernel_app#logger_metadata">logger_metadata</seeapp>.
+ At run-time it can be set and updated using
+ <seemfa marker="logger#set_primary_config/1">
+ <c>logger:set_primary_config/1</c></seemfa> and
+ <seemfa marker="logger#update_primary_config/1">
+ <c>logger:update_primary_config/1</c></seemfa> respectively.
+ 
+ </item>
 	<tag>Set process metadata</tag>
 	<item>
 	 Process metadata is set and updated
@@ -544,6 +557,13 @@ logger:debug(#{got => connection_request, id => Id, state => State},
 	 for more information about how this option is used.
 	 Defaults to <c>log</c>.
 	</item>
+ <tag><c>metadata = </c><seetype marker="logger#metadata"><c>metadata()</c></seetype></tag>
+	<item>
+	 The primary metadata to be used for all log calls.
+ See section <seeguide marker="#metadata">Metadata</seeguide>
+	 for more information about how this option is used.
+	 Defaults to <c>#{}</c>.
+	</item>
 </taglist>
 </section>
 
@@ -762,6 +782,13 @@ logger:debug(#{got => connection_request, id => Id, state => State},
 	 Examples</seeguide> for examples using the <c>logger</c>
 	 parameter for system configuration.
 </item>
+ <tag><marker id="logger_metadata"/>
+	<c>logger_metadata = map()</c></tag>
+ <item>
+	Specifies the primary metadata. See
+	 the <seeapp marker="kernel_app#logger_metadata"><c>kernel(6)</c></seeapp>
+	 manual page for more information about this parameter.
+ </item>
 <tag><marker id="logger_level"/>
 	<c>logger_level = Level</c></tag>
 <item>
diff --git a/lib/kernel/src/logger.erl b/lib/kernel/src/logger.erl
index 167637b8b4..29fac2427d 100644
--- a/lib/kernel/src/logger.erl
+++ b/lib/kernel/src/logger.erl
@@ -108,6 +108,7 @@
 -type filter_arg() :: term().
 -type filter_return() :: stop | ignore | log_event().
 -type primary_config() :: #{level => level() | all | none,
+ metadata => metadata(),
 filter_default => log | stop,
 filters => [{filter_id(),filter()}]}.
 -type handler_config() :: #{id => handler_id(),
@@ -403,7 +404,9 @@ remove_handler(HandlerId) ->
 (filter_default,FilterDefault) -> ok | {error,term()} when
 FilterDefault :: log | stop;
 (filters,Filters) -> ok | {error,term()} when
- Filters :: [{filter_id(),filter()}].
+ Filters :: [{filter_id(),filter()}];
+ (metadata,Meta) -> ok | {error,term()} when
+ Meta :: metadata().
 set_primary_config(Key,Value) ->
 logger_server:set_config(primary,Key,Value).
 
@@ -799,6 +802,7 @@ internal_init_logger() ->
 Env = get_logger_env(kernel),
 check_logger_config(kernel,Env),
 ok = logger:set_primary_config(level, get_logger_level()),
+ ok = logger:set_primary_config(metadata, get_primary_metadata()),
 ok = logger:set_primary_config(filter_default,
 get_primary_filter_default(Env)),
 
@@ -955,6 +959,14 @@ get_logger_level() ->
 throw({logger_level, Level})
 end.
 
+get_primary_metadata() ->
+ case application:get_env(kernel,logger_default_metadata,#{}) of
+ Meta when is_map(Meta) ->
+ Meta;
+ Meta ->
+ throw({logger_metadata, Meta})
+ end.
+
 get_primary_filter_default(Env) ->
 case lists:keyfind(filters,1,Env) of
 {filters,Default,_} ->
@@ -1067,40 +1079,52 @@ log_allowed(Location,Level,{Fun,FunArgs},Meta) when is_function(Fun,1) ->
 [{Fun,FunArgs},{C,R}]},
 Meta)
 end;
-log_allowed(Location,Level,Msg,Meta0) when is_map(Meta0) ->
+log_allowed(Location,Level,Msg,LogCallMeta) when is_map(LogCallMeta) ->
+
+ Tid = tid(),
+
+ {ok,PrimaryConfig} = logger_config:get(Tid,primary),
+
 %% Metadata priorities are:
- %% Location (added in API macros) - will be overwritten by process
- %% metadata (set by set_process_metadata/1), which in turn will be
+ %% Location (added in API macros) - will be overwritten by
+ %% Default Metadata (added by logger:primary_config/1) - will be overwritten by
+ %% process metadata (set by set_process_metadata/1), which in turn will be
 %% overwritten by the metadata given as argument in the log call
 %% (function or macro).
+
 Meta = add_default_metadata(
- maps:merge(Location,maps:merge(proc_meta(),Meta0))),
+ maps:merge(
+ Location,
+ maps:merge(
+ maps:get(metadata,PrimaryConfig),
+ maps:merge(proc_meta(),LogCallMeta)))),
+
 case node(maps:get(gl,Meta)) of
 Node when Node=/=node() ->
 log_remote(Node,Level,Msg,Meta);
 _ ->
 ok
 end,
- do_log_allowed(Level,Msg,Meta,tid()).
+ do_log_allowed(Level,Msg,Meta,Tid,PrimaryConfig).
 
-do_log_allowed(Level,{Format,Args}=Msg,Meta,Tid)
+do_log_allowed(Level,{Format,Args}=Msg,Meta,Tid,Config)
 when ?IS_LEVEL(Level),
 ?IS_FORMAT(Format),
 is_list(Args),
 is_map(Meta) ->
- logger_backend:log_allowed(#{level=>Level,msg=>Msg,meta=>Meta},Tid);
-do_log_allowed(Level,Report,Meta,Tid)
+ logger_backend:log_allowed(#{level=>Level,msg=>Msg,meta=>Meta},Tid,Config);
+do_log_allowed(Level,Report,Meta,Tid,Config)
 when ?IS_LEVEL(Level),
 ?IS_REPORT(Report),
 is_map(Meta) ->
 logger_backend:log_allowed(#{level=>Level,msg=>{report,Report},meta=>Meta},
- Tid);
-do_log_allowed(Level,String,Meta,Tid)
+ Tid,Config);
+do_log_allowed(Level,String,Meta,Tid,Config)
 when ?IS_LEVEL(Level),
 ?IS_STRING(String),
 is_map(Meta) ->
 logger_backend:log_allowed(#{level=>Level,msg=>{string,String},meta=>Meta},
- Tid).
+ Tid,Config).
 tid() ->
 ets:whereis(?LOGGER_TABLE).
 
diff --git a/lib/kernel/src/logger_backend.erl b/lib/kernel/src/logger_backend.erl
index 7003d2268e..682d0452bd 100644
--- a/lib/kernel/src/logger_backend.erl
+++ b/lib/kernel/src/logger_backend.erl
@@ -19,7 +19,7 @@
 %%
 -module(logger_backend).
 
--export([log_allowed/2]).
+-export([log_allowed/3]).
 
 -include("logger_internal.hrl").
 
@@ -27,28 +27,28 @@
 
 %%%-----------------------------------------------------------------
 %%% The default logger backend
-log_allowed(Log, Tid) ->
- {ok,Config} = logger_config:get(Tid,primary),
- Filters = maps:get(filters,Config,[]),
- case apply_filters(primary,Log,Filters,Config) of
+log_allowed(Log, Tid, PrimaryConfig) ->
+ Filters = maps:get(filters,PrimaryConfig,[]),
+ case apply_filters(primary,Log,Filters,PrimaryConfig) of
 stop ->
 ok;
 Log1 ->
- Handlers = maps:get(handlers,Config,[]),
+ Handlers = maps:get(handlers,PrimaryConfig,[]),
 call_handlers(Log1,Handlers,Tid)
 end,
 ok.
 
 call_handlers(#{level:=Level}=Log,[Id|Handlers],Tid) ->
+ %% Get the config for handle Id
 case logger_config:get(Tid,Id,Level) of
- {ok,#{module:=Module}=Config} ->
- Filters = maps:get(filters,Config,[]),
- case apply_filters(Id,Log,Filters,Config) of
+ {ok,#{module:=Module}=HandlerConfig} ->
+ Filters = maps:get(filters,HandlerConfig,[]),
+ case apply_filters(Id,Log,Filters,HandlerConfig) of
 stop ->
 ok;
 Log1 ->
- Config1 = maps:without(?OWN_KEYS,Config),
- try Module:log(Log1,Config1)
+ HandlerConfig1 = maps:without(?OWN_KEYS,HandlerConfig),
+ try Module:log(Log1,HandlerConfig1)
 catch C:R:S ->
 case logger:remove_handler(Id) of
 ok ->
@@ -60,7 +60,7 @@ call_handlers(#{level:=Level}=Log,[Id|Handlers],Tid) ->
 [{logger,removed_failing_handler},
 {handler,{Id,Module}},
 {log_event,Log1},
- {config,Config1},
+ {config,HandlerConfig1},
 {reason,{C,R,filter_stacktrace(S)}}]);
 {error,{not_found,_}} ->
 %% Probably already removed by other client
diff --git a/lib/kernel/src/logger_config.erl b/lib/kernel/src/logger_config.erl
index 9e94fdc6a1..4bf11aa38c 100644
--- a/lib/kernel/src/logger_config.erl
+++ b/lib/kernel/src/logger_config.erl
@@ -122,9 +122,12 @@ set(Tid,proxy,Config) ->
 ok;
 set(Tid,What,Config) ->
 LevelInt = level_to_int(maps:get(level,Config)),
+ %% Put either primary or handler level in pt cache
 ok = persistent_term:put({?MODULE,table_key(What)}, LevelInt),
 case What of
 primary ->
+ %% If we change primary level, then we need to flush
+ %% the module level cache.
 [persistent_term:put(Key,?PRIMARY_TO_CACHE(LevelInt))
 || {{?MODULE,Module} = Key,Level} <- persistent_term:get(),
 ?IS_MODULE(Module), ?IS_CACHED(Level)],
diff --git a/lib/kernel/src/logger_server.erl b/lib/kernel/src/logger_server.erl
index 6bdac471ec..942c0aac5a 100644
--- a/lib/kernel/src/logger_server.erl
+++ b/lib/kernel/src/logger_server.erl
@@ -415,6 +415,7 @@ do_remove_filter(Tid,Id,FilterId) ->
 
 default_config(primary) ->
 #{level=>notice,
+ metadata=>#{},
 filters=>[],
 filter_default=>log};
 default_config(Id) ->
@@ -461,6 +462,8 @@ check_config(Owner,[{filter_default,FD}|Config]) ->
 check_config(handler,[{formatter,Formatter}|Config]) ->
 check_formatter(Formatter),
 check_config(handler,Config);
+check_config(primary,[{metadata,Meta}|Config]) when is_map(Meta) ->
+ check_config(primary,Config);
 check_config(primary,[C|_]) ->
 throw({invalid_primary_config,C});
 check_config(handler,[{_,_}|Config]) ->
diff --git a/lib/kernel/test/logger_SUITE.erl b/lib/kernel/test/logger_SUITE.erl
index 8513cf2936..6165962cf9 100644
--- a/lib/kernel/test/logger_SUITE.erl
+++ b/lib/kernel/test/logger_SUITE.erl
@@ -274,7 +274,7 @@ change_config(_Config) ->
 ok = logger:set_primary_config(#{filter_default=>stop}),
 #{level:=notice,filters:=[],filter_default:=stop}=PC1 =
 logger:get_primary_config(),
- 3 = maps:size(PC1),
+ 4 = maps:size(PC1),
 %% Check that internal 'handlers' field has not been changed
 MS = [{{{?HANDLER_KEY,'$1'},'_'},[],['$1']}],
 HIds1 = lists:sort(ets:select(?LOGGER_TABLE,MS)), % dirty, internal data
@@ -918,6 +918,20 @@ process_metadata(_Config) ->
 logger:notice(S3=?str,#{custom=>func}),
 check_logged(notice,S3,#{time=>Time,line=>0,custom=>func}),
 
+ %% Test that primary metadata is overwritten by process metadata
+ ok = logger:update_primary_config(
+ #{metadata=>#{time=>Time,custom=>global,global=>added,line=>1}}),
+ logger:notice(S4=?str),
+ check_logged(notice,S4,#{time=>Time,line=>0,custom=>proc,global=>added}),
+
+ %% Test that primary metadata is overwritten by func metadata
+ %% and that primary overwrites location metadata.
+ ok = logger:unset_process_metadata(),
+ logger:notice(S5=?str,#{custom=>func}),
+ check_logged(notice,S5,#{time=>Time,line=>1,custom=>func,global=>added}),
+ ok = logger:set_process_metadata(ProcMeta),
+ ok = logger:update_primary_config(#{metadata=>#{}}),
+
 ProcMeta = logger:get_process_metadata(),
 ok = logger:update_process_metadata(#{custom=>changed,custom2=>added}),
 Expected = ProcMeta#{custom:=changed,custom2=>added},
-- 
2.26.2

Places

File 3501-Add-support-for-primary-metadata-to-the-logger.patch of Package erlang (Revision 048167bcaa30c6163f4d1505a6baf337)

Places