kernel(logger): Add logger filtering on process level

This adds possibility to filter logger messages on process basis. This feature is mostly useful for disabling logging in some processes or to increase logging verbosity during debugging.
erlang · Sep 11, 2019 · 853e61a · 853e61a
1 parent 5e2444b
commit 853e61a
Show file tree

Hide file tree

Showing 6 changed files with 124 additions and 9 deletions.
diff --git a/lib/kernel/doc/src/logger.xml b/lib/kernel/doc/src/logger.xml
@@ -688,6 +688,17 @@ start(_, []) ->
       </desc>
     </func>
 
+    <func>
+      <name name="get_process_level" arity="0" since="OTP 23.0"/>
+        <fsummary>Retrieve level set with set_process_level/1.</fsummary>
+        <p>Retrieve data set
+          with <seealso marker="#set_process_level-1">
+	    <c>set_process_level/1</c></seealso> or
+	  <seealso marker="#unset_process_level-0">
+	    <c>unset_process_level/0</c></seealso>.</p>
+      </desc>
+    </func>
+
     <func>
       <name name="i" arity="0" since="OTP 21.3"/>
       <name name="i" arity="1" since="OTP 21.3"/>
@@ -887,6 +898,36 @@ start(_, []) ->
       </desc>
     </func>
 
+    <func>
+      <name name="set_process_level" arity="1" since="OTP 23.0"/>
+      <fsummary>Set the log level for current process.</fsummary>
+      <desc>
+        <p>Set the log level for current process.</p>
+        <p>The log level for a process overrides the primary and module
+	  log level of Logger for log events originating from current
+	  process. Notice, however, that it does not override the
+	  level configuration for any handler.</p>
+	<p>For example: Assume that the primary log level for Logger
+	  is <c>info</c>, and there is one handler, <c>h1</c>, with
+	  level <c>info</c> and one handler, <c>h2</c>, with
+	  level <c>debug</c>.</p>
+	<p>With this configuration, no debug messages will be logged,
+	  since they are all stopped by the primary log level.</p>
+	<p>If the level for current process is now set
+	  to <c>debug</c>, then debug events from this module will be
+	  logged by the handler <c>h2</c>, but not by
+	  handler <c>h1</c>.</p>
+	<p>Debug events from other processes are still not logged.</p>
+        <p>To change the primary log level for Logger, use
+          <seealso marker="#set_primary_config/2">
+	    <c>set_primary_config(level, Level)</c></seealso>.</p>
+        <p>To change the log level for a handler, use
+          <seealso marker="#set_handler_config/3">
+	    <c>set_handler_config(HandlerId, level, Level)</c>
+	  </seealso>.</p>
+      </desc>
+    </func>
+
     <func>
       <name name="set_process_metadata" arity="1" since="OTP 21.0"/>
       <fsummary>Set metadata to use when logging from current process.</fsummary>
@@ -948,6 +989,18 @@ start(_, []) ->
       </desc>
     </func>
 
+    <func>
+      <name name="unset_process_level" arity="0" since="OTP 23.0"/>
+      <fsummary>Delete data set with set_process_level/1.</fsummary>
+      <desc>
+        <p>Delete data set
+          with <seealso marker="#set_process_level-1">
+	    <c>set_process_level/1</c></seealso> or
+	  <seealso marker="#get_process_level-1">
+	    <c>get_process_level/1</c></seealso>.</p>
+      </desc>
+    </func>
+
     <func>
       <name name="update_formatter_config" arity="2" since="OTP 21.0"/>
       <fsummary>Update the formatter configuration for the specified handler.</fsummary>

diff --git a/lib/kernel/src/logger.erl b/lib/kernel/src/logger.erl
@@ -41,6 +41,8 @@
          unset_module_level/1, unset_module_level/0,
          set_application_level/2, unset_application_level/1,
          get_module_level/0, get_module_level/1,
+         get_process_level/0, set_process_level/1,
+         unset_process_level/0,
          set_primary_config/1, set_primary_config/2,
          set_handler_config/2, set_handler_config/3,
          set_proxy_config/1,
@@ -257,7 +259,8 @@ log(Level, FunOrFormat, Args, Metadata) ->
       Level :: level(),
       Module :: module().
 allow(Level,Module) when ?IS_LEVEL(Level), is_atom(Module) ->
-    logger_config:allow(?LOGGER_TABLE,Level,Module).
+    ProcessLevel = get_process_level(),
+    logger_config:allow(?LOGGER_TABLE,Level,Module,ProcessLevel).
 
 
 -spec macro_log(Location,Level,StringOrReport)  -> ok when
@@ -560,6 +563,22 @@ unset_module_level(Modules) ->
 unset_module_level() ->
     logger_server:unset_module_level().
 
+-spec get_process_level() -> level() | all | none | undefined.
+get_process_level() ->
+    get(?LOGGER_PROCESS_LEVEL).
+
+-spec set_process_level(Level) -> ok | {error, term()} when
+      Level :: level() | all | none.
+set_process_level(Level) when ?IS_LEVEL_ALL(Level) ->
+    put(?LOGGER_PROCESS_LEVEL, Level);
+
+set_process_level(Level) ->
+    {error,{invalid_level,Level}}.
+
+-spec unset_process_level() -> ok.
+unset_process_level() ->
+    erase(?LOGGER_PROCESS_LEVEL).
+
 -spec set_application_level(Application,Level) -> ok | {error, not_loaded} when
       Application :: atom(),
       Level :: level() | all | none.
@@ -1027,14 +1046,16 @@ get_logger_env(App) ->
 %%%-----------------------------------------------------------------
 %%% Internal
 do_log(Level,Msg,#{mfa:={Module,_,_}}=Meta) ->
-    case logger_config:allow(?LOGGER_TABLE,Level,Module) of
+    ProcessLevel = get_process_level(),
+    case logger_config:allow(?LOGGER_TABLE,Level,Module,ProcessLevel) of
         true ->
             log_allowed(#{},Level,Msg,Meta);
         false ->
             ok
     end;
 do_log(Level,Msg,Meta) ->
-    case logger_config:allow(?LOGGER_TABLE,Level) of
+    ProcessLevel = get_process_level(),
+    case logger_config:allow(?LOGGER_TABLE,Level,?NOT_MODULE,ProcessLevel) of
         true ->
             log_allowed(#{},Level,Msg,Meta);
         false ->

diff --git a/lib/kernel/src/logger_config.erl b/lib/kernel/src/logger_config.erl
@@ -21,7 +21,7 @@
 
 -export([new/1,delete/2,
          exist/2,
-         allow/2,allow/3,
+         allow/4,
          get/2, get/3,
          create/3, set/3,
          set_module_level/3,unset_module_level/2,
@@ -39,8 +39,21 @@ new(Name) ->
 delete(Tid,Id) ->
     ets:delete(Tid,table_key(Id)).
 
-allow(Tid,Level,Module) ->
+allow(Tid,Level,Module,ProcessLevel) when is_atom(Level) ->
     LevelInt = level_to_int(Level),
+    allow(Tid,LevelInt,Module,ProcessLevel);
+allow(Tid,LevelInt,Module,undefined) when is_integer(LevelInt) ->
+    allow(Tid,LevelInt,Module);
+allow(Tid,LevelInt,Module,ProcessLevel) when is_integer(LevelInt) ->
+    ProcessLevelInt = level_to_int(ProcessLevel),
+
+    case LevelInt =< ProcessLevelInt of
+        true -> true;
+        _ -> allow(Tid,LevelInt,Module)
+    end.
+
+allow(Tid,LevelInt,?NOT_MODULE) -> allow(Tid,LevelInt);
+allow(Tid,LevelInt,Module) ->
     case ets:lookup(Tid,Module) of
         [{Module,{ModLevel,cached}}] when is_integer(ModLevel),
                                           LevelInt =< ModLevel ->
@@ -50,14 +63,14 @@ allow(Tid,Level,Module) ->
             true;
         [] ->
             logger_server:cache_module_level(Module),
-            allow(Tid,Level);
+            allow(Tid,LevelInt);
         _ ->
             false
     end.
 
-allow(Tid,Level) ->
+allow(Tid,LevelInt) ->
     GlobalLevelInt = ets:lookup_element(Tid,?PRIMARY_KEY,2),
-    level_to_int(Level) =< GlobalLevelInt.
+    LevelInt =< GlobalLevelInt.
 
 exist(Tid,What) ->
     ets:member(Tid,table_key(What)).

diff --git a/lib/kernel/src/logger_internal.hrl b/lib/kernel/src/logger_internal.hrl
@@ -23,6 +23,7 @@
 -define(PRIMARY_KEY,'$primary_config$').
 -define(HANDLER_KEY,'$handler_config$').
 -define(LOGGER_META_KEY,'$logger_metadata$').
+-define(LOGGER_PROCESS_LEVEL,'$logger_level$').
 -define(STANDARD_HANDLER, default).
 -define(DEFAULT_HANDLER_FILTERS,?DEFAULT_HANDLER_FILTERS([otp])).
 -define(DEFAULT_HANDLER_FILTERS(Domain),
@@ -107,3 +108,5 @@
 
 -define(IS_STRING(String),
         (is_list(String) orelse is_binary(String))).
+
+-define(NOT_MODULE, {}).
diff --git a/lib/kernel/test/logger_SUITE.erl b/lib/kernel/test/logger_SUITE.erl
@@ -87,6 +87,7 @@ all() ->
      log_all_levels_api,
      macros,
      set_level,
+     set_process_level,
      set_module_level,
      set_application_level,
      cache_module_level,
@@ -397,6 +398,30 @@ set_level(cleanup,_Config) ->
     logger:set_primary_config(level,notice),
     ok.
 
+set_process_level(_Config) ->
+    ok = logger:add_handler(h1,?MODULE,#{level=>notice,filter_default=>log}),
+    {error,{invalid_level,bad}} = logger:set_process_level(bad),
+    ok = logger:set_process_level(warning),
+    warning = logger:get_process_level(),
+    logger:notice(?map_rep),
+    ok = check_no_log(),
+    logger:warning(M1=?map_rep,?MY_LOC(0)),
+    ok = check_logged(warning,M1,?MY_LOC(1)),
+    _ = spawn(fun ->
+        logger:notice(M2=?map_rep,?MY_LOC(0)),
+        ok = check_logger(notice,M2,?MY_LOC(1))
+    end),
+    ok = logger:unset_porcess_level(),
+    undefined = logger:get_process_level(),
+    logger:notice(M2=?map_rep,?MY_LOC(0)),
+    ok = check_logged(notice,M2,?MY_LOC(1)),
+    ok.
+
+set_level(cleanup,_Config) ->
+    logger:remove_handler(h1),
+    logger:unset_process_level(),
+    ok.
+
 set_module_level(_Config) ->
     [] = logger:get_module_level([?MODULE,other]),
     [] = logger:get_module_level(?MODULE),

diff --git a/lib/kernel/test/logger_disk_log_h_SUITE.erl b/lib/kernel/test/logger_disk_log_h_SUITE.erl
@@ -86,7 +86,7 @@ end_per_testcase(Case, Config) ->
 groups() ->
     [].
 
-all() -> 
+all() ->
     [start_stop_handler,
      create_log,
      open_existing_log,