File 3501-Add-support-for-primary-metadata-to-the-logger.patch of Package erlang
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>.</p>
<p>Defaults to <c>notice</c>.</p>
</item>
+ <tag><marker id="logger_metadata"/><c>logger_metadata = Metadata</c></tag>
+ <item>
+ <p>Specifies primary metadata for log events.</p>
+ <p><c>Metadata = map()</c></p>
+ <p>Defaults to <c>#{}</c>.</p>
+ </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>
- <p>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">
+ <p>You can add custom metadata, either by:</p>
+ <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>.</p>
+ 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>
+ <p>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.</p>
+ </note>
<p>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.</p>
+ from the log call overwrite process metadata, which overwrites
+ the primary metadata, which in turn overwrite values set by Logger.</p>
<p>The following custom metadata keys have special meaning:</p>
<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>
<p>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>
<p>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:</p>
+ the client can add custom metadata in three different ways:</p>
<taglist>
+ <tag>Set primary metadata</tag>
+ <item>
+ <p>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.
+ </p>
+ </item>
<tag>Set process metadata</tag>
<item>
<p>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.</p>
<p>Defaults to <c>log</c>.</p>
</item>
+ <tag><c>metadata = </c><seetype marker="logger#metadata"><c>metadata()</c></seetype></tag>
+ <item>
+ <p>The primary metadata to be used for all log calls.</p>
+ <p>See section <seeguide marker="#metadata">Metadata</seeguide>
+ for more information about how this option is used.</p>
+ <p>Defaults to <c>#{}</c>.</p>
+ </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.</p>
</item>
+ <tag><marker id="logger_metadata"/>
+ <c>logger_metadata = map()</c></tag>
+ <item>
+ <p>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.</p>
+ </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
