File 2121-logger-Print-kernel-progress-if-level-is-d... of Package erlang

Overview Repositories Revisions Requests Users Attributes Meta

File 2121-logger-Print-kernel-progress-if-level-is-debug.patch of Package erlang (Revision a95c38533dd94a5c195230b3b146d029)

Currently displaying revision a95c38533dd94a5c195230b3b146d029 , Show latest

From fb64e0cf579f6c62633f9c13ede884dba820981e Mon Sep 17 00:00:00 2001
From: Lukas Larsson <lukas@erlang.org>
Date: Tue, 26 Sep 2023 16:12:00 +0200
Subject: [PATCH] logger: Print kernel progress if level is debug

When debugging the start of kernel it is nice to be
able to see the log messages of the different kernel
services. So we change so that simple handler will
print progress report messages if the log level is
debug or higher.
---
 lib/kernel/src/logger_simple_h.erl        | 61 +++++++++++++----------
 lib/kernel/test/logger_simple_h_SUITE.erl | 28 +++++++++++
 2 files changed, 63 insertions(+), 26 deletions(-)

diff --git a/lib/kernel/src/logger_simple_h.erl b/lib/kernel/src/logger_simple_h.erl
index d35c533b6d..d7064be036 100644
--- a/lib/kernel/src/logger_simple_h.erl
+++ b/lib/kernel/src/logger_simple_h.erl
@@ -56,31 +56,40 @@ removing_handler(#{id:=simple}) ->
             end
     end.
 
-log(#{meta:=#{error_logger:=#{tag:=info_report,type:=Type}}},_Config)
-  when Type=/=std_info ->
-    %% Skip info reports that are not 'std_info' (ref simple logger in
-    %% error_logger)
-    ok;
-log(#{msg:=_,meta:=#{time:=_}=M}=Log,_Config) ->
-    _ = case whereis(?MODULE) of
-            undefined ->
-                %% Is the node on the way down? Real emergency?
-                %% Log directly from client just to get it out
-                case maps:get(internal_log_event, M, false) of
-                    false ->
-                        do_log(simple,
-                          #{level=>error,
-                            msg=>{report,{error,simple_handler_process_dead}},
-                            meta=>#{time=>logger:timestamp()}});
-                    true ->
-                        ok
-                end,
-                do_log(simple,Log);
-            _ ->
-                ?MODULE ! {log,Log}
-        end,
-    ok;
-log(_,_) ->
+log(#{meta:=#{error_logger:=#{tag:=info_report,type:=Type}}} = Log,_Meta)
+  when Type =/= std_info ->
+    case logger:allow(debug, ?MODULE) of
+        false ->
+            %% Skip info reports that are not 'std_info' (ref simple logger in
+            %% error_logger)
+            ok;
+        true ->
+            %% If log level is debug or all we emit even these reports
+            do_log(Log)
+    end;
+log(Log,_Config) ->
+    _ = do_log(Log),
+    ok.
+
+do_log(#{msg:=_,meta:=#{time:=_}=M}=Log) ->
+    case whereis(?MODULE) of
+        undefined ->
+            %% Is the node on the way down? Real emergency?
+            %% Log directly from client just to get it out
+            case maps:get(internal_log_event, M, false) of
+                false ->
+                    do_log(simple,
+                           #{level=>error,
+                             msg=>{report,{error,simple_handler_process_dead}},
+                             meta=>#{time=>logger:timestamp()}});
+                true ->
+                    ok
+            end,
+            do_log(simple,Log);
+        _ ->
+            ?MODULE ! {log,Log}
+    end;
+do_log(_) ->
     %% Unexpected log.
     %% We don't want to crash the simple logger, so ignore this.
     ok.
@@ -90,7 +99,7 @@ log(_,_) ->
 init(Starter) ->
     register(?MODULE,self()),
     Starter ! {self(),started},
-    loop(rich, #{buffer_size=>10,dropped=>0,buffer=>[]}).
+    loop(rich, #{buffer_size=>20,dropped=>0,buffer=>[]}).
 
 loop(Mode, Buffer) ->
     receive
diff --git a/lib/kernel/test/logger_simple_h_SUITE.erl b/lib/kernel/test/logger_simple_h_SUITE.erl
index 3e0227d5c5..63f16c6126 100644
--- a/lib/kernel/test/logger_simple_h_SUITE.erl
+++ b/lib/kernel/test/logger_simple_h_SUITE.erl
@@ -22,6 +22,7 @@
 -compile(export_all).
 
 -include_lib("common_test/include/ct.hrl").
+-include_lib("stdlib/include/assert.hrl").
 -include_lib("kernel/include/logger.hrl").
 -include_lib("kernel/src/logger_internal.hrl").
 
@@ -80,6 +81,7 @@ groups() ->
 
 all() -> 
     [start_stop,
+     start_debug,
      start_crash,
      replace_default,
      replace_file,
@@ -102,6 +104,32 @@ start_stop(_Config) ->
 start_stop(cleanup,_Config) ->
     logger:remove_handler(simple).
 
+%% Test that the simple logger works when debug level is used
+start_debug(_Config) ->
+
+    Output = os:cmd(ct:get_progname() ++ " -s init stop"),
+    LogOutput = re:replace(unicode:characters_to_binary(Output),"\r\n","\n",[global]),
+    ct:log("~ts",[LogOutput]),
+    nomatch = re:run(LogOutput,"^=PROGRESS REPORT====",[global,multiline]),
+
+    InfoOutput = os:cmd(ct:get_progname() ++ " -kernel logger_level info -s init stop"),
+    InfoLogOutput = re:replace(unicode:characters_to_binary(InfoOutput),"\r\n","\n",[global]),
+    ct:log("~ts",[InfoLogOutput]),
+    {match,InfoNumReports} = re:run(InfoLogOutput,"^=PROGRESS REPORT====",[global,multiline]),
+
+    %% Test that more progress reports are logged for info than default
+    ?assert(0 < length(InfoNumReports)),
+
+    DebugOutput = os:cmd(ct:get_progname() ++ " -kernel logger_level debug -s init stop"),
+    DebugLogOutput = re:replace(unicode:characters_to_binary(DebugOutput),"\r\n","\n",[global]),
+    ct:log("~ts",[DebugLogOutput]),
+    {match,DebugNumReports} = re:run(DebugLogOutput,"^=PROGRESS REPORT====",[global,multiline]),
+
+    %% Test that more progress reports are logged for debug than info
+    ?assert(length(InfoNumReports) < length(DebugNumReports)),
+
+    ok.
+
 %% Test that the simple logger works during startup crash
 start_crash(_Config) ->
 
-- 
2.35.3

Places

File 2121-logger-Print-kernel-progress-if-level-is-debug.patch of Package erlang (Revision a95c38533dd94a5c195230b3b146d029)

Places