-
Notifications
You must be signed in to change notification settings - Fork 3.9k
Commit
This commit does not belong to any branch on this repository, and may belong to a fork outside of the repository.
Switch from Lager to the new Erlang Logger API for logging
The configuration remains the same for the end-user. The only exception
is the log root directory: it is now set through the `log_root`
application env. variable in `rabbit`. People using the Cuttlefish-based
configuration file are not affected by this exception.
The main change is how the logging facility is configured. It now
happens in `rabbit_prelaunch_logging`. The `rabbit_lager` module is
removed.
The supported outputs remain the same: the console, text files, the
`amq.rabbitmq.log` exchange and syslog.
The message text format slightly changed: the timestamp is more precise
(now to the microsecond) and the level can be abbreviated to always be
4-character long to align all messages and improve readability. Here is
an example:
2021-03-03 10:22:30.377392+01:00 [dbug] <0.229.0> == Prelaunch DONE ==
2021-03-03 10:22:30.377860+01:00 [info] <0.229.0>
2021-03-03 10:22:30.377860+01:00 [info] <0.229.0> Starting RabbitMQ 3.8.10+115.g071f3fb on Erlang 23.2.5
2021-03-03 10:22:30.377860+01:00 [info] <0.229.0> Licensed under the MPL 2.0. Website: https://rabbitmq.com
The example above also shows that multiline messages are supported and
each line is prepended with the same prefix (the timestamp, the level
and the Erlang process PID).
JSON is also supported as a message format and now for any outputs.
Indeed, it is possible to use it with e.g. syslog or the exchange. Here
is an example of a JSON-formatted message sent to syslog:
Mar 3 11:23:06 localhost rabbitmq-server[27908] <0.229.0> - {"time":"2021-03-03T11:23:06.998466+01:00","level":"notice","msg":"Logging: configured log handlers are now ACTIVE","meta":{"domain":"rabbitmq.prelaunch","file":"src/rabbit_prelaunch_logging.erl","gl":"<0.228.0>","line":311,"mfa":["rabbit_prelaunch_logging","configure_logger",1],"pid":"<0.229.0>"}}
For quick testing, the values accepted by the `$RABBITMQ_LOGS`
environment variables were extended:
* `-` still means stdout
* `-stderr` means stderr
* `syslog:` means syslog on localhost
* `exchange:` means logging to `amq.rabbitmq.log`
`$RABBITMQ_LOG` was also extended. It now accepts a `+json` modifier (in
addition to the existing `+color` one). With that modifier, messages are
formatted as JSON intead of plain text.
The `rabbitmqctl rotate_logs` command is deprecated. The reason is
Logger does not expose a function to force log rotation. However, it
will detect when a file was rotated by an external tool.
From a developer point of view, the old `rabbit_log*` API remains
supported, though it is now deprecated. It is implemented as regular
modules: there is no `parse_transform` involved anymore.
In the code, it is recommended to use the new Logger macros. For
instance, `?LOG_INFO(Format, Args)`. If possible, messages should be
augmented with some metadata. For instance (note the map after the
message):
?LOG_NOTICE("Logging: switching to configured handler(s); following "
"messages may not be visible in this log output",
#{domain => ?RMQLOG_DOMAIN_PRELAUNCH}),
Domains in Erlang Logger parlance are the way to categorize messages.
Some predefined domains, matching previous categories, are currently
defined in `rabbit_common/include/logging.hrl` or headers in the
relevant plugins for plugin-specific categories.
At this point, very few messages have been converted from the old
`rabbit_log*` API to the new macros. It can be done gradually when
working on a particular module or logging.
The Erlang builtin console/file handler, `logger_std_h`, has been forked
because it lacks date-based file rotation. The configuration of
date-based rotation is identical to Lager. Once the dust has settled for
this feature, the goal is to submit it upstream for inclusion in Erlang.
The forked module is calld `rabbit_logger_std_h` and is based
`logger_std_h` in Erlang 23.0.- Loading branch information
Showing
108 changed files
with
5,351 additions
and
2,841 deletions.
There are no files selected for viewing
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
| Original file line number | Diff line number | Diff line change |
|---|---|---|
|
|
@@ -5,6 +5,7 @@ | |
| *.coverdata | ||
| /ebin/ | ||
| /.erlang.mk/ | ||
| /logs/ | ||
| /rabbitmq_prelaunch.d | ||
| /xrefr | ||
|
|
||
|
|
||
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
127 changes: 127 additions & 0 deletions
127
deps/rabbit/apps/rabbitmq_prelaunch/src/rabbit_logger_json_fmt.erl
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
| Original file line number | Diff line number | Diff line change |
|---|---|---|
| @@ -0,0 +1,127 @@ | ||
| %% This Source Code Form is subject to the terms of the Mozilla Public | ||
| %% License, v. 2.0. If a copy of the MPL was not distributed with this | ||
| %% file, You can obtain one at https://mozilla.org/MPL/2.0/. | ||
| %% | ||
| %% Copyright (c) 2021 VMware, Inc. or its affiliates. All rights reserved. | ||
| %% | ||
|
|
||
| -module(rabbit_logger_json_fmt). | ||
|
|
||
| -export([format/2]). | ||
|
|
||
| format( | ||
| #{msg := Msg, | ||
| level := Level, | ||
| meta := #{time := Timestamp} = Meta}, | ||
| Config) -> | ||
| FormattedTimestamp = unicode:characters_to_binary( | ||
| format_time(Timestamp, Config)), | ||
| FormattedMsg = unicode:characters_to_binary( | ||
| format_msg(Msg, Meta, Config)), | ||
| FormattedMeta = format_meta(Meta, Config), | ||
| Json = jsx:encode( | ||
| [{time, FormattedTimestamp}, | ||
| {level, Level}, | ||
| {msg, FormattedMsg}, | ||
| {meta, FormattedMeta}]), | ||
| [Json, $\n]. | ||
|
|
||
| format_time(Timestamp, _) -> | ||
| Options = [{unit, microsecond}], | ||
| calendar:system_time_to_rfc3339(Timestamp, Options). | ||
|
|
||
| format_msg({string, Chardata}, Meta, Config) -> | ||
| format_msg({"~ts", [Chardata]}, Meta, Config); | ||
| format_msg({report, Report}, Meta, Config) -> | ||
| FormattedReport = format_report(Report, Meta, Config), | ||
| format_msg(FormattedReport, Meta, Config); | ||
| format_msg({Format, Args}, _, _) -> | ||
| io_lib:format(Format, Args). | ||
|
|
||
| format_report( | ||
| #{label := {application_controller, _}} = Report, Meta, Config) -> | ||
| format_application_progress(Report, Meta, Config); | ||
| format_report( | ||
| #{label := {supervisor, progress}} = Report, Meta, Config) -> | ||
| format_supervisor_progress(Report, Meta, Config); | ||
| format_report( | ||
| Report, #{report_cb := Cb} = Meta, Config) -> | ||
| try | ||
| case erlang:fun_info(Cb, arity) of | ||
| {arity, 1} -> Cb(Report); | ||
| {arity, 2} -> {"~ts", [Cb(Report, #{})]} | ||
| end | ||
| catch | ||
| _:_:_ -> | ||
| format_report(Report, maps:remove(report_cb, Meta), Config) | ||
| end; | ||
| format_report(Report, _, _) -> | ||
| logger:format_report(Report). | ||
|
|
||
| format_application_progress(#{label := {_, progress}, | ||
| report := InternalReport}, _, _) -> | ||
| Application = proplists:get_value(application, InternalReport), | ||
| StartedAt = proplists:get_value(started_at, InternalReport), | ||
| {"Application ~w started on ~0p", | ||
| [Application, StartedAt]}; | ||
| format_application_progress(#{label := {_, exit}, | ||
| report := InternalReport}, _, _) -> | ||
| Application = proplists:get_value(application, InternalReport), | ||
| Exited = proplists:get_value(exited, InternalReport), | ||
| {"Application ~w exited with reason: ~0p", | ||
| [Application, Exited]}. | ||
|
|
||
| format_supervisor_progress(#{report := InternalReport}, _, _) -> | ||
| Supervisor = proplists:get_value(supervisor, InternalReport), | ||
| Started = proplists:get_value(started, InternalReport), | ||
| Id = proplists:get_value(id, Started), | ||
| Pid = proplists:get_value(pid, Started), | ||
| Mfa = proplists:get_value(mfargs, Started), | ||
| {"Supervisor ~w: child ~w started (~w): ~0p", | ||
| [Supervisor, Id, Pid, Mfa]}. | ||
|
|
||
| format_meta(Meta, _) -> | ||
| maps:fold( | ||
| fun | ||
| (time, _, Acc) -> | ||
| Acc; | ||
| (domain = Key, Components, Acc) -> | ||
| Term = unicode:characters_to_binary( | ||
| string:join( | ||
| [atom_to_list(Cmp) || Cmp <- Components], | ||
| ".")), | ||
| Acc#{Key => Term}; | ||
| (Key, Value, Acc) -> | ||
| case convert_to_types_accepted_by_jsx(Value) of | ||
| false -> Acc; | ||
| Term -> Acc#{Key => Term} | ||
| end | ||
| end, #{}, Meta). | ||
|
|
||
| convert_to_types_accepted_by_jsx(Term) when is_map(Term) -> | ||
| maps:map( | ||
| fun(_, Value) -> convert_to_types_accepted_by_jsx(Value) end, | ||
| Term); | ||
| convert_to_types_accepted_by_jsx(Term) when is_list(Term) -> | ||
| case io_lib:deep_char_list(Term) of | ||
| true -> | ||
| unicode:characters_to_binary(Term); | ||
| false -> | ||
| [convert_to_types_accepted_by_jsx(E) || E <- Term] | ||
| end; | ||
| convert_to_types_accepted_by_jsx(Term) when is_tuple(Term) -> | ||
| convert_to_types_accepted_by_jsx(erlang:tuple_to_list(Term)); | ||
| convert_to_types_accepted_by_jsx(Term) when is_function(Term) -> | ||
| String = erlang:fun_to_list(Term), | ||
| unicode:characters_to_binary(String); | ||
| convert_to_types_accepted_by_jsx(Term) when is_pid(Term) -> | ||
| String = erlang:pid_to_list(Term), | ||
| unicode:characters_to_binary(String); | ||
| convert_to_types_accepted_by_jsx(Term) when is_port(Term) -> | ||
| String = erlang:port_to_list(Term), | ||
| unicode:characters_to_binary(String); | ||
| convert_to_types_accepted_by_jsx(Term) when is_reference(Term) -> | ||
| String = erlang:ref_to_list(Term), | ||
| unicode:characters_to_binary(String); | ||
| convert_to_types_accepted_by_jsx(Term) -> | ||
| Term. |
Oops, something went wrong.