diff options
-rw-r--r-- | erts/emulator/beam/utils.c | 2 | ||||
-rw-r--r-- | erts/preloaded/ebin/erl_prim_loader.beam | bin | 53300 -> 52636 bytes | |||
-rw-r--r-- | erts/preloaded/ebin/init.beam | bin | 50364 -> 50304 bytes | |||
-rw-r--r-- | erts/preloaded/ebin/prim_file.beam | bin | 28072 -> 28084 bytes | |||
-rw-r--r-- | erts/preloaded/src/erl_prim_loader.erl | 7 | ||||
-rw-r--r-- | erts/preloaded/src/init.erl | 7 | ||||
-rw-r--r-- | erts/preloaded/src/prim_file.erl | 7 | ||||
-rw-r--r-- | lib/kernel/doc/src/logger.xml | 24 | ||||
-rw-r--r-- | lib/kernel/src/code_server.erl | 10 | ||||
-rw-r--r-- | lib/kernel/src/logger.erl | 10 | ||||
-rw-r--r-- | lib/kernel/src/logger_h_common.erl | 2 | ||||
-rw-r--r-- | lib/kernel/src/logger_simple_h.erl | 4 | ||||
-rw-r--r-- | lib/kernel/test/logger_SUITE.erl | 4 | ||||
-rw-r--r-- | lib/kernel/test/logger_formatter_SUITE.erl | 2 |
14 files changed, 57 insertions, 22 deletions
diff --git a/erts/emulator/beam/utils.c b/erts/emulator/beam/utils.c index 36a492f00d..36cfe0548e 100644 --- a/erts/emulator/beam/utils.c +++ b/erts/emulator/beam/utils.c @@ -1946,7 +1946,7 @@ do_allocate_logger_message(Eterm gleader, ErtsMonotonicTime *ts, Eterm *pid, else sz += MAP4_SZ /* metadata map w gl w pid*/; - *ts = ERTS_MONOTONIC_TO_USEC(erts_get_monotonic_time(NULL) + erts_get_time_offset()); + *ts = ERTS_MONOTONIC_TO_USEC(erts_os_system_time()); erts_bld_sint64(NULL, &sz, *ts); *bp = new_message_buffer(sz); diff --git a/erts/preloaded/ebin/erl_prim_loader.beam b/erts/preloaded/ebin/erl_prim_loader.beam Binary files differindex bbee904837..661bcd8413 100644 --- a/erts/preloaded/ebin/erl_prim_loader.beam +++ b/erts/preloaded/ebin/erl_prim_loader.beam diff --git a/erts/preloaded/ebin/init.beam b/erts/preloaded/ebin/init.beam Binary files differindex 3392674e3c..1d89174b25 100644 --- a/erts/preloaded/ebin/init.beam +++ b/erts/preloaded/ebin/init.beam diff --git a/erts/preloaded/ebin/prim_file.beam b/erts/preloaded/ebin/prim_file.beam Binary files differindex b9f4791ba9..0efd954e50 100644 --- a/erts/preloaded/ebin/prim_file.beam +++ b/erts/preloaded/ebin/prim_file.beam diff --git a/erts/preloaded/src/erl_prim_loader.erl b/erts/preloaded/src/erl_prim_loader.erl index fefdd34292..1605c20f2c 100644 --- a/erts/preloaded/src/erl_prim_loader.erl +++ b/erts/preloaded/src/erl_prim_loader.erl @@ -297,12 +297,13 @@ check_file_result(Func, Target, {error,Reason}) -> "Target: " ++ TargetStr ++ ". " ++ "Function: " ++ atom_to_list(Func) ++ ". " ++ Process end, - %% this is equal to calling error_logger:error_report/1 which - %% we don't want to do from code_server during system boot + %% This is equal to calling logger:error/2 which + %% we don't want to do from code_server during system boot. + %% We don't want to call logger:timestamp() either. logger ! {log,error,#{label=>{?MODULE,file_error},report=>Report}, #{pid=>self(), gl=>group_leader(), - time=>erlang:system_time(microsecond), + time=>os:system_time(microsecond), error_logger=>#{tag=>error_report, type=>std_error}}}, error diff --git a/erts/preloaded/src/init.erl b/erts/preloaded/src/init.erl index 54cbd96710..5ea67347ec 100644 --- a/erts/preloaded/src/init.erl +++ b/erts/preloaded/src/init.erl @@ -477,13 +477,16 @@ do_handle_msg(Msg,State) -> {From, {ensure_loaded, _}} -> From ! {init, not_allowed}; X -> + %% This is equal to calling logger:info/3 which we don't + %% want to do from the init process, at least not during + %% system boot. We don't want to call logger:timestamp() + %% either. case whereis(user) of undefined -> - Time = erlang:system_time(microsecond), catch logger ! {log, info, "init got unexpected: ~p", [X], #{pid=>self(), gl=>self(), - time=>Time, + time=>os:system_time(microsecond), error_logger=>#{tag=>info_msg}}}; User -> User ! X, diff --git a/erts/preloaded/src/prim_file.erl b/erts/preloaded/src/prim_file.erl index 0994e2a9f4..1aa5d85c64 100644 --- a/erts/preloaded/src/prim_file.erl +++ b/erts/preloaded/src/prim_file.erl @@ -572,12 +572,13 @@ list_dir_convert([RawName | Rest], SkipInvalid, Result) -> {error, ignore} -> list_dir_convert(Rest, SkipInvalid, Result); {error, warning} -> - %% this is equal to calling error_logger:warning_msg/2 which - %% we don't want to do from code_server during system boot + %% This is equal to calling logger:warning/3 which + %% we don't want to do from code_server during system boot. + %% We don't want to call logger:timestamp() either. logger ! {log,warning,"Non-unicode filename ~p ignored\n", [RawName], #{pid=>self(), gl=>group_leader(), - time=>erlang:system_time(microsecond), + time=>os:system_time(microsecond), error_logger=>#{tag=>warning_msg}}}, list_dir_convert(Rest, SkipInvalid, Result); {error, _} -> diff --git a/lib/kernel/doc/src/logger.xml b/lib/kernel/doc/src/logger.xml index df2d081d76..e6448e144e 100644 --- a/lib/kernel/doc/src/logger.xml +++ b/lib/kernel/doc/src/logger.xml @@ -190,7 +190,7 @@ logger:error("error happened because: ~p", [Reason]). % Without macro <list> <item><c>pid => self()</c></item> <item><c>gl => group_leader()</c></item> - <item><c>time => erlang:system_time(microsecond)</c></item> + <item><c>time => logger:timestamp()</c></item> </list> <p>When a log macro is used, Logger also inserts location information:</p> @@ -288,8 +288,8 @@ logger:error("error happened because: ~p", [Reason]). % Without macro <name name="timestamp"/> <desc> <p>A timestamp produced - with <seealso marker="erts:erlang#system_time-1"> - <c>erlang:system_time(microsecond)</c></seealso>.</p> + with <seealso marker="#timestamp-0"> + <c>logger:timestamp()</c></seealso>.</p> </desc> </datatype> </datatypes> @@ -1117,6 +1117,24 @@ logger:set_proxy_config(maps:merge(Old, Config)). a key-value list before formatting as such.</p> </desc> </func> + + <func> + <name name="timestamp" arity="0" since="OTP @OTP-15625@"/> + <fsummary>Return a timestamp to insert in meta data for a log + event.</fsummary> + <desc> + <p>Return a timestamp that can be inserted as the <c>time</c> + field in the meta data for a log event. It is produced with + <seealso marker="kernel:os#system_time-1"> + <c>os:system_time(microsecond)</c></seealso>.</p> + <p>Notice that Logger automatically inserts a timestamp in the + meta data unless it already exists. This function is + exported for the rare case when the timestamp must be taken + at a different point in time than when the log event is + issued.</p> + </desc> + </func> + </funcs> <section> diff --git a/lib/kernel/src/code_server.erl b/lib/kernel/src/code_server.erl index 1b4a67ecb7..68e1205301 100644 --- a/lib/kernel/src/code_server.erl +++ b/lib/kernel/src/code_server.erl @@ -1434,19 +1434,25 @@ all_loaded(Db) -> -spec error_msg(io:format(), [term()]) -> 'ok'. error_msg(Format, Args) -> + %% This is equal to calling logger:error/3 which we don't want to + %% do from code_server. We don't want to call logger:timestamp() + %% either. logger ! {log,error,Format,Args, #{pid=>self(), gl=>group_leader(), - time=>erlang:system_time(microsecond), + time=>os:system_time(microsecond), error_logger=>#{tag=>error}}}, ok. -spec info_msg(io:format(), [term()]) -> 'ok'. info_msg(Format, Args) -> + %% This is equal to calling logger:info/3 which we don't want to + %% do from code_server. We don't want to call logger:timestamp() + %% either. logger ! {log,info,Format,Args, #{pid=>self(), gl=>group_leader(), - time=>erlang:system_time(microsecond), + time=>os:system_time(microsecond), error_logger=>#{tag=>info_msg}}}, ok. diff --git a/lib/kernel/src/logger.erl b/lib/kernel/src/logger.erl index 7d36640f52..38bd2f481c 100644 --- a/lib/kernel/src/logger.erl +++ b/lib/kernel/src/logger.erl @@ -61,6 +61,7 @@ -export([set_process_metadata/1, update_process_metadata/1, unset_process_metadata/0, get_process_metadata/0]). -export([i/0, i/1]). +-export([timestamp/0]). %% Basic report formatting -export([format_report/1, format_otp_report/1]). @@ -154,7 +155,8 @@ filter_return/0, config_handler/0, formatter_config/0, - olp_config/0]). + olp_config/0, + timestamp/0]). %%%----------------------------------------------------------------- %%% API @@ -354,6 +356,10 @@ internal_log(Level,Term) when is_atom(Level) -> erlang:display_string("Logger - "++ atom_to_list(Level) ++ ": "), erlang:display(Term). +-spec timestamp() -> timestamp(). +timestamp() -> + os:system_time(microsecond). + %%%----------------------------------------------------------------- %%% Configuration -spec add_primary_filter(FilterId,Filter) -> ok | {error,term()} when @@ -1129,7 +1135,7 @@ proc_meta() -> default(pid) -> self(); default(gl) -> group_leader(); -default(time) -> erlang:system_time(microsecond). +default(time) -> timestamp(). %% Remove everything upto and including this module from the stacktrace filter_stacktrace(Module,[{Module,_,_,_}|_]) -> diff --git a/lib/kernel/src/logger_h_common.erl b/lib/kernel/src/logger_h_common.erl index e69f6de38d..4b5e0a7dd0 100644 --- a/lib/kernel/src/logger_h_common.erl +++ b/lib/kernel/src/logger_h_common.erl @@ -351,7 +351,7 @@ log_handler_info(Name, Format, Args, #{module:=Module, {ok,Conf} -> Conf; _ -> #{formatter=>{?DEFAULT_FORMATTER,?DEFAULT_FORMAT_CONFIG}} end, - Meta = #{time=>erlang:system_time(microsecond)}, + Meta = #{time=>logger:timestamp()}, Bin = log_to_binary(#{level => notice, msg => {Format,Args}, meta => Meta}, Config), diff --git a/lib/kernel/src/logger_simple_h.erl b/lib/kernel/src/logger_simple_h.erl index fe181722f3..a0d51dba25 100644 --- a/lib/kernel/src/logger_simple_h.erl +++ b/lib/kernel/src/logger_simple_h.erl @@ -69,7 +69,7 @@ log(#{msg:=_,meta:=#{time:=_}}=Log,_Config) -> do_log( #{level=>error, msg=>{report,{error,simple_handler_process_dead}}, - meta=>#{time=>erlang:system_time(microsecond)}}), + meta=>#{time=>logger:timestamp()}}), do_log(Log); _ -> ?MODULE ! {log,Log} @@ -129,7 +129,7 @@ drop_msg(0) -> drop_msg(N) -> [#{level=>info, msg=>{"Simple handler buffer full, dropped ~w messages",[N]}, - meta=>#{time=>erlang:system_time(microsecond)}}]. + meta=>#{time=>logger:timestamp()}}]. %%%----------------------------------------------------------------- %%% Internal diff --git a/lib/kernel/test/logger_SUITE.erl b/lib/kernel/test/logger_SUITE.erl index 2dad651f9c..70bb775db8 100644 --- a/lib/kernel/test/logger_SUITE.erl +++ b/lib/kernel/test/logger_SUITE.erl @@ -899,14 +899,14 @@ process_metadata(_Config) -> undefined = logger:get_process_metadata(), {error,badarg} = ?TRY(logger:set_process_metadata(bad)), ok = logger:add_handler(h1,?MODULE,#{level=>notice,filter_default=>log}), - Time = erlang:system_time(microsecond), + Time = logger:timestamp(), ProcMeta = #{time=>Time,line=>0,custom=>proc}, ok = logger:set_process_metadata(ProcMeta), S1 = ?str, ?LOG_NOTICE(S1,#{custom=>macro}), check_logged(notice,S1,#{time=>Time,line=>0,custom=>macro}), - Time2 = erlang:system_time(microsecond), + Time2 = logger:timestamp(), S2 = ?str, ?LOG_NOTICE(S2,#{time=>Time2,line=>1,custom=>macro}), check_logged(notice,S2,#{time=>Time2,line=>1,custom=>macro}), diff --git a/lib/kernel/test/logger_formatter_SUITE.erl b/lib/kernel/test/logger_formatter_SUITE.erl index 8c13f0f908..83e3e6c40a 100644 --- a/lib/kernel/test/logger_formatter_SUITE.erl +++ b/lib/kernel/test/logger_formatter_SUITE.erl @@ -867,7 +867,7 @@ my_try(Fun) -> try Fun() catch C:R:S -> {C,R,hd(S)} end. timestamp() -> - erlang:system_time(microsecond). + logger:timestamp(). %% necessary? add_time(#{time:=_}=Meta) -> |