Sign Up
Log In
Log In
or
Sign Up
Places
All Projects
Status Monitor
Collapse sidebar
home:Ledest:erlang
erlang
2054-logger-Fix-simple-logger-to-work-when-init...
Overview
Repositories
Revisions
Requests
Users
Attributes
Meta
File 2054-logger-Fix-simple-logger-to-work-when-init-process-i.patch of Package erlang
From 44a998b6ef8913de1152f33e137a9e58111889b8 Mon Sep 17 00:00:00 2001 From: Lukas Larsson <lukas@erlang.org> Date: Mon, 2 May 2022 22:24:50 +0200 Subject: [PATCH 4/4] logger: Fix simple logger to work when init process is busy When wanting to log during system shutdown, the init process is not always available to load new modules. So we need to make sure that the simple logger can handle the fact that it cannot load the correct formatting modules. --- erts/preloaded/src/init.erl | 1 + lib/kernel/src/logger_simple_h.erl | 63 ++++++++++++++++------- lib/kernel/test/logger_simple_h_SUITE.erl | 16 ++++++ 3 files changed, 62 insertions(+), 18 deletions(-) diff --git a/erts/preloaded/src/init.erl b/erts/preloaded/src/init.erl index 29a6766455..d175ce9a88 100644 --- a/erts/preloaded/src/init.erl +++ b/erts/preloaded/src/init.erl @@ -833,6 +833,7 @@ del(_Item, []) -> []. terminate(Pid,Kernel,Reason) -> case kernel_pid(Pid,Kernel) of {ok,Name} -> + %% If you change this time, also change the time in logger_simple_h.erl sleep(500), %% Flush error printouts! % erlang:display({"Kernel pid terminated",Name,Reason}), crash("Kernel pid terminated", [Name, Reason]); diff --git a/lib/kernel/src/logger_simple_h.erl b/lib/kernel/src/logger_simple_h.erl index db0dce97a7..72b0236183 100644 --- a/lib/kernel/src/logger_simple_h.erl +++ b/lib/kernel/src/logger_simple_h.erl @@ -68,14 +68,14 @@ log(#{msg:=_,meta:=#{time:=_}=M}=Log,_Config) -> %% Log directly from client just to get it out case maps:get(internal_log_event, M, false) of false -> - do_log( + do_log(simple, #{level=>error, msg=>{report,{error,simple_handler_process_dead}}, meta=>#{time=>logger:timestamp()}}); true -> ok end, - do_log(Log); + do_log(simple,Log); _ -> ?MODULE ! {log,Log} end, @@ -90,9 +90,9 @@ log(_,_) -> init(Starter) -> register(?MODULE,self()), Starter ! {self(),started}, - loop(#{buffer_size=>10,dropped=>0,buffer=>[]}). + loop(rich, #{buffer_size=>10,dropped=>0,buffer=>[]}). -loop(Buffer) -> +loop(Mode, Buffer) -> receive stop -> %% We replay the logger messages if there is @@ -109,11 +109,11 @@ loop(Buffer) -> unlink(whereis(logger)), ok; {log,#{msg:=_,meta:=#{time:=_}}=Log} -> - do_log(Log), - loop(update_buffer(Buffer,Log)); + NewMode = do_log(Mode, Log), + loop(NewMode, update_buffer(Buffer,Log)); _ -> %% Unexpected message - flush it! - loop(Buffer) + loop(Mode, Buffer) end. update_buffer(#{buffer_size:=0,dropped:=D}=Buffer,_Log) -> @@ -139,16 +139,42 @@ drop_msg(N) -> %%%----------------------------------------------------------------- %%% Internal -do_log(Log) -> - try - Str = logger_formatter:format(Log, - #{ legacy_header => true, single_line => false - ,depth => unlimited, time_offset => "" - }), - erlang:display_string(stdout, lists:flatten(unicode:characters_to_list(Str))) - catch _E:_R:_ST -> - % erlang:display({_E,_R,_ST}), - display_log(Log) +%% If the init process is busy (for instance doing a shutdown) +%% we can get blocked while trying to load code. So we spawn a process +%% for each log message that can potentially block. If the logging cannot +%% be done within 300ms, we instead log the raw log message to stdout +%% and switch mode to always log using the raw format. +do_log(simple, Log) -> + display_log(Log), simple; +do_log(rich = Mode, Log) -> + + {Pid, Ref} = + spawn_monitor( + fun() -> + Str = logger_formatter:format( + Log, + #{ legacy_header => true, single_line => false, + depth => unlimited, time_offset => "" + }), + erlang:display_string(stdout, lists:flatten(unicode:characters_to_list(Str))) + end), + receive + {'DOWN', Ref, _, _, normal} -> + Mode; + {'DOWN', Ref, _, _, _Else} -> + display_log(Log), + Mode + after 300 -> + %% init:terminate/3 sleeps for 500 ms before exiting, + %% so we wait for 300 ms for the log to happen + exit(Pid, kill), + receive + {'DOWN', Ref, _, _, normal} -> + Mode; + {'DOWN', Ref, _, _, _Else} -> + display_log(Log), + simple + end end. display_log(#{msg:={report,Report}, @@ -164,7 +190,8 @@ display_date(Timestamp) when is_integer(Timestamp) -> Sec = Timestamp div 1000000, {{Y,Mo,D},{H,Mi,S}} = erlang:universaltime_to_localtime( erlang:posixtime_to_universaltime(Sec)), - erlang:display_string(stdout, + erlang:display_string( + stdout, integer_to_list(Y) ++ "-" ++ pad(Mo,2) ++ "-" ++ pad(D,2) ++ " " ++ diff --git a/lib/kernel/test/logger_simple_h_SUITE.erl b/lib/kernel/test/logger_simple_h_SUITE.erl index 8ac52e54c7..9bc910a04b 100644 --- a/lib/kernel/test/logger_simple_h_SUITE.erl +++ b/lib/kernel/test/logger_simple_h_SUITE.erl @@ -80,6 +80,7 @@ groups() -> all() -> [start_stop, + start_crash, replace_default, replace_file, replace_disk_log @@ -101,6 +102,21 @@ start_stop(_Config) -> start_stop(cleanup,_Config) -> logger:remove_handler(simple). +%% Test that the simple logger works during startup crash +start_crash(_Config) -> + + Output = os:cmd(ct:get_progname() ++ " -user baduser"), + ErrorOutput = re:replace(unicode:characters_to_binary(Output),"\r\n","\n",[global]), + ct:log("~ts",[ErrorOutput]), + {match,[_]} = re:run(ErrorOutput,"^(=SUPERVISOR REPORT====| supervisor_report *\n)",[global]), + {match,[_, _]} = re:run(ErrorOutput," crash_report *\n",[global]), + {match,[_]} = re:run(ErrorOutput," std_info *\n",[global]), + {match,[[CD]]} = re:run(ErrorOutput,"\nCrash dump is being written to: (.*)\\.\\.\\.done", + [{capture, all_but_first, binary}, global]), + ok = file:delete(CD), + ok. + + %% This testcase just tests that it does not crash, the default handler prints %% to stdout which we cannot read from in a detached slave. replace_default(Config) -> -- 2.35.3
Locations
Projects
Search
Status Monitor
Help
OpenBuildService.org
Documentation
API Documentation
Code of Conduct
Contact
Support
@OBShq
Terms
openSUSE Build Service is sponsored by
The Open Build Service is an
openSUSE project
.
Sign Up
Log In
Places
Places
All Projects
Status Monitor
