diff options
Diffstat (limited to 'src')
| -rw-r--r-- | src/rabbit.app.src | 4 | ||||
| -rw-r--r-- | src/rabbit.erl | 237 | ||||
| -rw-r--r-- | src/rabbit_control_main.erl | 7 | ||||
| -rw-r--r-- | src/rabbit_error_logger.erl | 14 | ||||
| -rw-r--r-- | src/rabbit_error_logger_file_h.erl | 177 | ||||
| -rw-r--r-- | src/rabbit_file.erl | 1 | ||||
| -rw-r--r-- | src/rabbit_lager.erl | 266 | ||||
| -rw-r--r-- | src/rabbit_log.erl | 165 | ||||
| -rw-r--r-- | src/rabbit_sasl_report_file_h.erl | 100 |
9 files changed, 476 insertions, 495 deletions
diff --git a/src/rabbit.app.src b/src/rabbit.app.src index 4ee0191138..f347b24585 100644 --- a/src/rabbit.app.src +++ b/src/rabbit.app.src @@ -9,7 +9,9 @@ rabbit_router, rabbit_sup, rabbit_direct_client_sup]}, - {applications, [kernel, stdlib, sasl, mnesia, rabbit_common, ranch, os_mon, xmerl]}, + %% FIXME: Remove goldrush, once rabbit_plugins.erl knows how to ignore + %% indirect dependencies of rabbit. + {applications, [kernel, stdlib, sasl, mnesia, goldrush, lager, rabbit_common, ranch, os_mon, xmerl]}, %% we also depend on crypto, public_key and ssl but they shouldn't be %% in here as we don't actually want to start it {mod, {rabbit, []}}, diff --git a/src/rabbit.erl b/src/rabbit.erl index e4cf7bcbbd..8f415eb582 100644 --- a/src/rabbit.erl +++ b/src/rabbit.erl @@ -20,11 +20,17 @@ -export([start/0, boot/0, stop/0, stop_and_halt/0, await_startup/0, status/0, is_running/0, - is_running/1, environment/0, rotate_logs/1, force_event_refresh/1, + is_running/1, environment/0, rotate_logs/0, force_event_refresh/1, start_fhc/0]). -export([start/2, stop/1]). -export([start_apps/1, stop_apps/1]). --export([log_location/1, config_files/0]). %% for testing and mgmt-agent +-export([log_locations/0, config_files/0]). %% for testing and mgmt-agent + +-ifdef(TEST). + +-export([start_logger/0]). + +-endif. %%--------------------------------------------------------------------------- %% Boot steps. @@ -200,9 +206,8 @@ -ifdef(use_specs). --type(file_suffix() :: binary()). %% this really should be an abstract type --type(log_location() :: 'tty' | 'undefined' | file:filename()). +-type(log_location() :: string()). -type(param() :: atom()). -type(app_name() :: atom()). @@ -220,10 +225,10 @@ -spec(is_running/0 :: () -> boolean()). -spec(is_running/1 :: (node()) -> boolean()). -spec(environment/0 :: () -> [{param(), term()}]). --spec(rotate_logs/1 :: (file_suffix()) -> rabbit_types:ok_or_error(any())). +-spec(rotate_logs/0 :: () -> rabbit_types:ok_or_error(any())). -spec(force_event_refresh/1 :: (reference()) -> 'ok'). --spec(log_location/1 :: ('sasl' | 'kernel') -> log_location()). +-spec(log_locations/0 :: () -> [log_location()]). -spec(start/2 :: ('normal',[]) -> {'error', @@ -258,7 +263,7 @@ start() -> %% restarting the app. ok = ensure_application_loaded(), HipeResult = rabbit_hipe:maybe_hipe_compile(), - ok = ensure_working_log_handlers(), + ok = start_logger(), rabbit_hipe:log_hipe_result(HipeResult), rabbit_node_monitor:prepare_cluster_status_files(), rabbit_mnesia:check_cluster_consistency(), @@ -269,7 +274,7 @@ boot() -> start_it(fun() -> ok = ensure_application_loaded(), HipeResult = rabbit_hipe:maybe_hipe_compile(), - ok = ensure_working_log_handlers(), + ok = start_logger(), rabbit_hipe:log_hipe_result(HipeResult), rabbit_node_monitor:prepare_cluster_status_files(), ok = rabbit_upgrade:maybe_upgrade_mnesia(), @@ -300,10 +305,8 @@ start_it(StartFun) -> false -> StartFun() end catch - throw:{could_not_start, _App, _Reason} = Err -> - boot_error(Err, not_available); - _:Reason -> - boot_error(Reason, erlang:get_stacktrace()) + Class:Reason -> + boot_error(Class, Reason) after unlink(Marker), Marker ! stop, @@ -442,22 +445,34 @@ environment(App) -> lists:keysort(1, [P || P = {K, _} <- application:get_all_env(App), not lists:member(K, Ignore)]). -rotate_logs(BinarySuffix) -> - Suffix = binary_to_list(BinarySuffix), - rabbit_log:info("Rotating logs with suffix '~s'~n", [Suffix]), - log_rotation_result(rotate_logs(log_location(kernel), - Suffix, - rabbit_error_logger_file_h), - rotate_logs(log_location(sasl), - Suffix, - rabbit_sasl_report_file_h)). + +rotate_logs() -> + rabbit_lager:fold_sinks( + fun + (_, [], Acc) -> + Acc; + (SinkName, FileNames, Acc) -> + lager:log(SinkName, info, self(), + "Log file rotation forced", []), + %% FIXME: We use an internal message, understood by + %% lager_file_backend. We should use a proper API, when + %% it's added to Lager. + %% + %% FIXME: This message is asynchronous, therefore this + %% entire call is asynchronous: at the end of this + %% function, we can't guaranty the rotation is completed. + [SinkName ! {rotate, FileName} || FileName <- FileNames], + lager:log(SinkName, info, self(), + "Log file re-opened after forced rotation", []), + Acc + end, ok). %%-------------------------------------------------------------------- start(normal, []) -> case erts_version_check() of ok -> - rabbit_log:info("Starting RabbitMQ ~s on Erlang ~s~n~s~n~s~n", + rabbit_log:info("~n Starting RabbitMQ ~s on Erlang ~s~n ~s~n ~s~n", [rabbit_misc:version(), rabbit_misc:otp_release(), ?COPYRIGHT_MESSAGE, ?INFORMATION_MESSAGE]), {ok, SupPid} = rabbit_sup:start_link(), @@ -481,10 +496,9 @@ stop(_State) -> ok. -ifdef(use_specs). --spec(boot_error/2 :: (term(), not_available | [tuple()]) -> no_return()). +-spec(boot_error/2 :: (atom(), term()) -> no_return()). -endif. -boot_error({could_not_start, rabbit, {{timeout_waiting_for_tables, _}, _}}, - _Stacktrace) -> +boot_error(_, {could_not_start, rabbit, {{timeout_waiting_for_tables, _}, _}}) -> AllNodes = rabbit_mnesia:cluster_nodes(all), Suffix = "~nBACKGROUND~n==========~n~n" "This cluster node was shut down while other nodes were still running.~n" @@ -503,26 +517,25 @@ boot_error({could_not_start, rabbit, {{timeout_waiting_for_tables, _}, _}}, end, log_boot_error_and_exit( timeout_waiting_for_tables, - Err ++ rabbit_nodes:diagnostics(Nodes) ++ "~n~n", []); -boot_error(Reason, Stacktrace) -> - Fmt = "Error description:~n ~p~n~n" - "Log files (may contain more information):~n ~s~n ~s~n~n", - Args = [Reason, log_location(kernel), log_location(sasl)], - boot_error(Reason, Fmt, Args, Stacktrace). - --ifdef(use_specs). --spec(boot_error/4 :: (term(), string(), [any()], not_available | [tuple()]) - -> no_return()). --endif. -boot_error(Reason, Fmt, Args, not_available) -> - log_boot_error_and_exit(Reason, Fmt, Args); -boot_error(Reason, Fmt, Args, Stacktrace) -> - log_boot_error_and_exit(Reason, Fmt ++ "Stack trace:~n ~p~n~n", - Args ++ [Stacktrace]). + "~n" ++ Err ++ rabbit_nodes:diagnostics(Nodes), []); +boot_error(Class, {error, {cannot_log_to_file, _, _}} = Reason) -> + log_boot_error_and_exit( + Reason, + "~nError description:~s", + [lager:pr_stacktrace(erlang:get_stacktrace(), {Class, Reason})]); +boot_error(Class, Reason) -> + LogLocations = log_locations(), + log_boot_error_and_exit( + Reason, + "~nError description:~s" + "~nLog file(s) (may contain more information):~n" ++ + lists:flatten([" ~s~n" || _ <- lists:seq(1, length(LogLocations))]), + [lager:pr_stacktrace(erlang:get_stacktrace(), {Class, Reason})] ++ + LogLocations). log_boot_error_and_exit(Reason, Format, Args) -> - io:format("~n~nBOOT FAILED~n===========~n~n" ++ Format, Args), - rabbit_log:info(Format, Args), + rabbit_log:error(Format, Args), + io:format("~nBOOT FAILED~n===========~n" ++ Format ++ "~n", Args), timer:sleep(1000), exit(Reason). @@ -566,75 +579,12 @@ insert_default_data() -> %%--------------------------------------------------------------------------- %% logging -ensure_working_log_handlers() -> - Handlers = gen_event:which_handlers(error_logger), - ok = ensure_working_log_handler(error_logger_tty_h, - rabbit_error_logger_file_h, - error_logger_tty_h, - log_location(kernel), - Handlers), - - ok = ensure_working_log_handler(sasl_report_tty_h, - rabbit_sasl_report_file_h, - sasl_report_tty_h, - log_location(sasl), - Handlers), +start_logger() -> + rabbit_lager:start_logger(), ok. -ensure_working_log_handler(OldHandler, NewHandler, TTYHandler, - LogLocation, Handlers) -> - case LogLocation of - undefined -> ok; - tty -> case lists:member(TTYHandler, Handlers) of - true -> ok; - false -> - throw({error, {cannot_log_to_tty, - TTYHandler, not_installed}}) - end; - _ -> case lists:member(NewHandler, Handlers) of - true -> ok; - false -> case rotate_logs(LogLocation, "", - OldHandler, NewHandler) of - ok -> ok; - {error, Reason} -> - throw({error, {cannot_log_to_file, - LogLocation, Reason}}) - end - end - end. - -log_location(Type) -> - case application:get_env(rabbit, case Type of - kernel -> error_logger; - sasl -> sasl_error_logger - end) of - {ok, {file, File}} -> File; - {ok, false} -> undefined; - {ok, tty} -> tty; - {ok, silent} -> undefined; - {ok, Bad} -> throw({error, {cannot_log_to_file, Bad}}); - _ -> undefined - end. - -rotate_logs(File, Suffix, Handler) -> - rotate_logs(File, Suffix, Handler, Handler). - -rotate_logs(undefined, _Suffix, _OldHandler, _NewHandler) -> ok; -rotate_logs(tty, _Suffix, _OldHandler, _NewHandler) -> ok; -rotate_logs(File, Suffix, OldHandler, NewHandler) -> - gen_event:swap_handler(error_logger, - {OldHandler, swap}, - {NewHandler, {File, Suffix}}). - -log_rotation_result({error, MainLogError}, {error, SaslLogError}) -> - {error, {{cannot_rotate_main_logs, MainLogError}, - {cannot_rotate_sasl_logs, SaslLogError}}}; -log_rotation_result({error, MainLogError}, ok) -> - {error, {cannot_rotate_main_logs, MainLogError}}; -log_rotation_result(ok, {error, SaslLogError}) -> - {error, {cannot_rotate_sasl_logs, SaslLogError}}; -log_rotation_result(ok, ok) -> - ok. +log_locations() -> + rabbit_lager:log_locations(). force_event_refresh(Ref) -> rabbit_direct:force_event_refresh(Ref), @@ -646,15 +596,13 @@ force_event_refresh(Ref) -> %% misc log_broker_started(Plugins) -> - rabbit_log:with_local_io( - fun() -> - PluginList = iolist_to_binary([rabbit_misc:format(" * ~s~n", [P]) - || P <- Plugins]), - rabbit_log:info( - "Server startup complete; ~b plugins started.~n~s", - [length(Plugins), PluginList]), - io:format(" completed with ~p plugins.~n", [length(Plugins)]) - end). + PluginList = iolist_to_binary([rabbit_misc:format(" * ~s~n", [P]) + || P <- Plugins]), + Message = string:strip(rabbit_misc:format( + "Server startup complete; ~b plugins started.~n~s", + [length(Plugins), PluginList]), right, $\n), + rabbit_log:info(Message), + io:format(" completed with ~p plugins.~n", [length(Plugins)]). erts_version_check() -> ERTSVer = erlang:system_info(version), @@ -679,30 +627,44 @@ erts_version_check() -> print_banner() -> {ok, Product} = application:get_key(id), {ok, Version} = application:get_key(vsn), - io:format("~n ~s ~s. ~s" - "~n ## ## ~s" - "~n ## ##" - "~n ########## Logs: ~s" - "~n ###### ## ~s" - "~n ##########" - "~n Starting broker...", - [Product, Version, ?COPYRIGHT_MESSAGE, ?INFORMATION_MESSAGE, - log_location(kernel), log_location(sasl)]). + {LogFmt, LogLocations} = case log_locations() of + [_ | Tail] = LL -> + LF = lists:flatten(["~n ~s" + || _ <- lists:seq(1, length(Tail))]), + {LF, LL}; + [] -> + {"", ["(none)"]} + end, + io:format("~n ## ##" + "~n ## ## ~s ~s. ~s" + "~n ########## ~s" + "~n ###### ##" + "~n ########## Logs: ~s" ++ + LogFmt ++ + "~n~n Starting broker...", + [Product, Version, ?COPYRIGHT_MESSAGE, ?INFORMATION_MESSAGE] ++ + LogLocations). log_banner() -> + {FirstLog, OtherLogs} = case log_locations() of + [Head | Tail] -> + {Head, [{"", F} || F <- Tail]}; + [] -> + {"(none)", []} + end, Settings = [{"node", node()}, {"home dir", home_dir()}, {"config file(s)", config_files()}, {"cookie hash", rabbit_nodes:cookie_hash()}, - {"log", log_location(kernel)}, - {"sasl log", log_location(sasl)}, - {"database dir", rabbit_mnesia:dir()}], + {"log(s)", FirstLog}] ++ + OtherLogs ++ + [{"database dir", rabbit_mnesia:dir()}], DescrLen = 1 + lists:max([length(K) || {K, _V} <- Settings]), Format = fun (K, V) -> rabbit_misc:format( - "~-" ++ integer_to_list(DescrLen) ++ "s: ~s~n", [K, V]) + " ~-" ++ integer_to_list(DescrLen) ++ "s: ~s~n", [K, V]) end, - Banner = iolist_to_binary( + Banner = string:strip(lists:flatten( [case S of {"config file(s)" = K, []} -> Format(K, "(none)"); @@ -710,8 +672,8 @@ log_banner() -> [Format(K, V0) | [Format("", V) || V <- Vs]]; {K, V} -> Format(K, V) - end || S <- Settings]), - rabbit_log:info("~s", [Banner]). + end || S <- Settings]), right, $\n), + rabbit_log:info("~n~s", [Banner]). warn_if_kernel_config_dubious() -> case erlang:system_info(kernel_poll) of @@ -875,9 +837,8 @@ ensure_working_fhc() -> {ok, true} -> "ON"; {ok, false} -> "OFF" end, - rabbit_log:info( - "FHC read buffering: ~s~n" - "FHC write buffering: ~s~n", [ReadBuf, WriteBuf]), + rabbit_log:info("FHC read buffering: ~s~n", [ReadBuf]), + rabbit_log:info("FHC write buffering: ~s~n", [WriteBuf]), Filename = filename:join(code:lib_dir(kernel, ebin), "kernel.app"), {ok, Fd} = file_handle_cache:open(Filename, [raw, binary, read], []), {ok, _} = file_handle_cache:read(Fd, 1), diff --git a/src/rabbit_control_main.erl b/src/rabbit_control_main.erl index c6e39b17f5..b30ea7c636 100644 --- a/src/rabbit_control_main.erl +++ b/src/rabbit_control_main.erl @@ -375,11 +375,8 @@ action(environment, Node, _App, _Opts, Inform) -> display_call_result(Node, {rabbit, environment, []}); action(rotate_logs, Node, [], _Opts, Inform) -> - Inform("Reopening logs for node ~p", [Node]), - call(Node, {rabbit, rotate_logs, [""]}); -action(rotate_logs, Node, Args = [Suffix], _Opts, Inform) -> - Inform("Rotating logs to files with suffix \"~s\"", [Suffix]), - call(Node, {rabbit, rotate_logs, Args}); + Inform("Rotating logs for node ~p", [Node]), + call(Node, {rabbit, rotate_logs, []}); action(close_connection, Node, [PidStr, Explanation], _Opts, Inform) -> Inform("Closing connection \"~s\"", [PidStr]), diff --git a/src/rabbit_error_logger.erl b/src/rabbit_error_logger.erl index bbaf9577f9..e8b7ce5669 100644 --- a/src/rabbit_error_logger.erl +++ b/src/rabbit_error_logger.erl @@ -27,7 +27,6 @@ -export([init/1, terminate/2, code_change/3, handle_call/2, handle_event/2, handle_info/2]). --import(rabbit_error_logger_file_h, [safe_handle_event/3]). %%---------------------------------------------------------------------------- @@ -110,3 +109,16 @@ publish1(RoutingKey, Format, Data, LogExch) -> timestamp = Timestamp}, list_to_binary(io_lib:format(Format, Args))), ok. + + +safe_handle_event(HandleEvent, Event, State) -> + try + HandleEvent(Event, State) + catch + _:Error -> + io:format( + "Error in log handler~n====================~n" + "Event: ~P~nError: ~P~nStack trace: ~p~n~n", + [Event, 30, Error, 30, erlang:get_stacktrace()]), + {ok, State} + end. diff --git a/src/rabbit_error_logger_file_h.erl b/src/rabbit_error_logger_file_h.erl deleted file mode 100644 index 9268c10a35..0000000000 --- a/src/rabbit_error_logger_file_h.erl +++ /dev/null @@ -1,177 +0,0 @@ -%% The contents of this file are subject to the Mozilla Public License -%% Version 1.1 (the "License"); you may not use this file except in -%% compliance with the License. You may obtain a copy of the License -%% at http://www.mozilla.org/MPL/ -%% -%% Software distributed under the License is distributed on an "AS IS" -%% basis, WITHOUT WARRANTY OF ANY KIND, either express or implied. See -%% the License for the specific language governing rights and -%% limitations under the License. -%% -%% The Original Code is RabbitMQ. -%% -%% The Initial Developer of the Original Code is GoPivotal, Inc. -%% Copyright (c) 2007-2016 Pivotal Software, Inc. All rights reserved. -%% - --module(rabbit_error_logger_file_h). --include("rabbit.hrl"). - --behaviour(gen_event). - --export([init/1, handle_event/2, handle_call/2, handle_info/2, terminate/2, - code_change/3]). - --export([safe_handle_event/3]). - -%% extracted from error_logger_file_h. Since 18.1 the state of the -%% error logger module changed. See: -%% https://github.com/erlang/otp/commit/003091a1fcc749a182505ef5675c763f71eacbb0#diff-d9a19ba08f5d2b60fadfc3aa1566b324R108 -%% github issue: -%% https://github.com/rabbitmq/rabbitmq-server/issues/324 --record(st, {fd, - filename, - prev_handler, - depth = unlimited}). - -%% extracted from error_logger_file_h. See comment above. -get_depth() -> - case application:get_env(kernel, error_logger_format_depth) of - {ok, Depth} when is_integer(Depth) -> - erlang:max(10, Depth); - undefined -> - unlimited - end. - --define(ERTS_NEW_LOGGER_STATE, "7.1"). - -%% rabbit_error_logger_file_h is a wrapper around the error_logger_file_h -%% module because the original's init/1 does not match properly -%% with the result of closing the old handler when swapping handlers. -%% The first init/1 additionally allows for simple log rotation -%% when the suffix is not the empty string. -%% The original init/2 also opened the file in 'write' mode, thus -%% overwriting old logs. To remedy this, init/2 from -%% lib/stdlib/src/error_logger_file_h.erl from R14B3 was copied as -%% init_file/2 and changed so that it opens the file in 'append' mode. - -%% Used only when swapping handlers in log rotation, pre OTP 18.1 -init({{File, Suffix}, []}) -> - rotate_logs(File, Suffix), - init(File); -%% Used only when swapping handlers in log rotation, since OTP 18.1 -init({{File, Suffix}, ok}) -> - rotate_logs(File, Suffix), - init(File); -%% Used only when swapping handlers and the original handler -%% failed to terminate or was never installed -init({{File, _}, error}) -> - init(File); -%% Used only when swapping handlers without performing -%% log rotation -init({File, []}) -> - init(File); -%% Used only when taking over from the tty handler -init({{File, []}, _}) -> - init(File); -init({File, {error_logger, Buf}}) -> - rabbit_file:ensure_parent_dirs_exist(File), - init_file(File, {error_logger, Buf}); -init(File) -> - rabbit_file:ensure_parent_dirs_exist(File), - init_file(File, []). - -init_file(File, {error_logger, Buf}) -> - case init_file(File, error_logger) of - {ok, State} -> - [handle_event(Event, State) || - {_, Event} <- lists:reverse(Buf)], - {ok, State}; - Error -> - Error - end; -init_file(File, PrevHandler) -> - process_flag(trap_exit, true), - case file:open(File, [append]) of - {ok, Fd} -> - FoundVer = erlang:system_info(version), - State = - case rabbit_misc:version_compare( - ?ERTS_NEW_LOGGER_STATE, FoundVer, lte) of - true -> - #st{fd = Fd, - filename = File, - prev_handler = PrevHandler, - depth = get_depth()}; - _ -> - {Fd, File, PrevHandler} - end, - {ok, State}; - Error -> Error - end. - -handle_event(Event, State) -> - safe_handle_event(fun handle_event0/2, Event, State). - -safe_handle_event(HandleEvent, Event, State) -> - try - HandleEvent(Event, State) - catch - _:Error -> - io:format( - "Error in log handler~n====================~n" - "Event: ~P~nError: ~P~nStack trace: ~p~n~n", - [Event, 30, Error, 30, erlang:get_stacktrace()]), - {ok, State} - end. - -%% filter out "application: foo; exited: stopped; type: temporary" -handle_event0({info_report, _, {_, std_info, _}}, State) -> - {ok, State}; -%% When a node restarts quickly it is possible the rest of the cluster -%% will not have had the chance to remove its queues from -%% Mnesia. That's why rabbit_amqqueue:recover/0 invokes -%% on_node_down(node()). But before we get there we can receive lots -%% of messages intended for the old version of the node. The emulator -%% logs an event for every one of those messages; in extremis this can -%% bring the server to its knees just logging "Discarding..." -%% again and again. So just log the first one, then go silent. -handle_event0(Event = {error, _, {emulator, _, ["Discarding message" ++ _]}}, - State) -> - case get(discarding_message_seen) of - true -> {ok, State}; - undefined -> put(discarding_message_seen, true), - error_logger_file_h:handle_event(t(Event), State) - end; -%% Clear this state if we log anything else (but not a progress report). -handle_event0(Event = {info_msg, _, _}, State) -> - erase(discarding_message_seen), - error_logger_file_h:handle_event(t(Event), State); -handle_event0(Event, State) -> - error_logger_file_h:handle_event(t(Event), State). - -handle_info(Info, State) -> - error_logger_file_h:handle_info(Info, State). - -handle_call(Call, State) -> - error_logger_file_h:handle_call(Call, State). - -terminate(Reason, State) -> - error_logger_file_h:terminate(Reason, State). - -code_change(OldVsn, State, Extra) -> - error_logger_file_h:code_change(OldVsn, State, Extra). - -%%---------------------------------------------------------------------- - -t(Term) -> truncate:log_event(Term, ?LOG_TRUNC). - -rotate_logs(File, Suffix) -> - case rabbit_file:append_file(File, Suffix) of - ok -> file:delete(File), - ok; - {error, Error} -> - rabbit_log:error("Failed to append contents of " - "log file '~s' to '~s':~n~p~n", - [File, [File, Suffix], Error]) - end. diff --git a/src/rabbit_file.erl b/src/rabbit_file.erl index 6c4f0e5ccd..3dd0421485 100644 --- a/src/rabbit_file.erl +++ b/src/rabbit_file.erl @@ -23,6 +23,7 @@ -export([append_file/2, ensure_parent_dirs_exist/1]). -export([rename/2, delete/1, recursive_delete/1, recursive_copy/2]). -export([lock_file/1]). +-export([read_file_info/1]). -import(file_handle_cache, [with_handle/1, with_handle/2]). diff --git a/src/rabbit_lager.erl b/src/rabbit_lager.erl new file mode 100644 index 0000000000..6ae9c10a5e --- /dev/null +++ b/src/rabbit_lager.erl @@ -0,0 +1,266 @@ +%% The contents of this file are subject to the Mozilla Public License +%% Version 1.1 (the "License"); you may not use this file except in +%% compliance with the License. You may obtain a copy of the License +%% at http://www.mozilla.org/MPL/ +%% +%% Software distributed under the License is distributed on an "AS IS" +%% basis, WITHOUT WARRANTY OF ANY KIND, either express or implied. See +%% the License for the specific language governing rights and +%% limitations under the License. +%% +%% The Original Code is RabbitMQ. +%% +%% The Initial Developer of the Original Code is GoPivotal, Inc. +%% Copyright (c) 2007-2015 Pivotal Software, Inc. All rights reserved. +%% + +-module(rabbit_lager). + +-include("rabbit_log.hrl"). + +%% API +-export([start_logger/0, log_locations/0, fold_sinks/2]). + +start_logger() -> + application:stop(lager), + ensure_lager_configured(), + lager:start(), + fold_sinks( + fun + (_, [], Acc) -> + Acc; + (SinkName, _, Acc) -> + lager:log(SinkName, info, self(), + "Log file opened with Lager", []), + Acc + end, ok), + ensure_log_working(). + +log_locations() -> + ensure_lager_configured(), + DefaultHandlers = application:get_env(lager, handlers, []), + Sinks = application:get_env(lager, extra_sinks, []), + ExtraHandlers = [proplists:get_value(handlers, Props, []) + || {_, Props} <- Sinks], + lists:sort(log_locations1([DefaultHandlers | ExtraHandlers], [])). + +log_locations1([Handlers | Rest], Locations) -> + Locations1 = log_locations2(Handlers, Locations), + log_locations1(Rest, Locations1); +log_locations1([], Locations) -> + Locations. + +log_locations2([{lager_file_backend, Settings} | Rest], Locations) -> + FileName = lager_file_name1(Settings), + Locations1 = case lists:member(FileName, Locations) of + false -> [FileName | Locations]; + true -> Locations + end, + log_locations2(Rest, Locations1); +log_locations2([{lager_console_backend, _} | Rest], Locations) -> + Locations1 = case lists:member("<stdout>", Locations) of + false -> ["<stdout>" | Locations]; + true -> Locations + end, + log_locations2(Rest, Locations1); +log_locations2([_ | Rest], Locations) -> + log_locations2(Rest, Locations); +log_locations2([], Locations) -> + Locations. + +fold_sinks(Fun, Acc) -> + Handlers = lager_config:global_get(handlers), + Sinks = dict:to_list(lists:foldl( + fun + ({{lager_file_backend, F}, _, S}, Dict) -> + dict:append(S, F, Dict); + ({_, _, S}, Dict) -> + case dict:is_key(S, Dict) of + true -> dict:store(S, [], Dict); + false -> Dict + end + end, + dict:new(), Handlers)), + fold_sinks(Sinks, Fun, Acc). + +fold_sinks([{SinkName, FileNames} | Rest], Fun, Acc) -> + Acc1 = Fun(SinkName, FileNames, Acc), + fold_sinks(Rest, Fun, Acc1); +fold_sinks([], _, Acc) -> + Acc. + +ensure_log_working() -> + {ok, Handlers} = application:get_env(lager, handlers), + [ ensure_lager_handler_file_exist(Handler) + || Handler <- Handlers ], + Sinks = application:get_env(lager, extra_sinks, []), + ensure_extra_sinks_working(Sinks, list_expected_sinks()). + +ensure_extra_sinks_working(Sinks, [SinkName | Rest]) -> + case proplists:get_value(SinkName, Sinks) of + undefined -> throw({error, {cannot_log_to_file, unknown, + rabbit_log_lager_event_sink_undefined}}); + Sink -> + SinkHandlers = proplists:get_value(handlers, Sink, []), + [ ensure_lager_handler_file_exist(Handler) + || Handler <- SinkHandlers ] + end, + ensure_extra_sinks_working(Sinks, Rest); +ensure_extra_sinks_working(_Sinks, []) -> + ok. + +ensure_lager_handler_file_exist(Handler) -> + case lager_file_name(Handler) of + false -> ok; + FileName -> ensure_logfile_exist(FileName) + end. + +lager_file_name({lager_file_backend, Settings}) -> + lager_file_name1(Settings); +lager_file_name(_) -> + false. + +lager_file_name1(Settings) when is_list(Settings) -> + {file, FileName} = proplists:lookup(file, Settings), + lager_util:expand_path(FileName); +lager_file_name1({FileName, _}) -> lager_util:expand_path(FileName); +lager_file_name1({FileName, _, _, _, _}) -> lager_util:expand_path(FileName); +lager_file_name1(_) -> + throw({error, {cannot_log_to_file, unknown, + lager_file_backend_config_invalid}}). + + +ensure_logfile_exist(FileName) -> + LogFile = lager_util:expand_path(FileName), + case rabbit_file:read_file_info(LogFile) of + {ok,_} -> ok; + {error, Err} -> throw({error, {cannot_log_to_file, LogFile, Err}}) + end. + +lager_handlers(Silent) when Silent == silent; Silent == false -> + []; +lager_handlers(tty) -> + [{lager_console_backend, info}]; +lager_handlers(FileName) when is_list(FileName) -> + LogFile = lager_util:expand_path(FileName), + case rabbit_file:ensure_dir(LogFile) of + ok -> ok; + {error, Reason} -> + throw({error, {cannot_log_to_file, LogFile, + {cannot_create_parent_dirs, LogFile, Reason}}}) + end, + [{lager_file_backend, [{file, FileName}, + {level, info}, + {formatter_config, + [date, " ", time, " ", color, "[", severity, "] ", + {pid, ""}, + " ", message, "\n"]}, + {date, ""}, + {size, 0}]}]. + + +ensure_lager_configured() -> + case lager_configured() of + false -> configure_lager(); + true -> ok + end. + +%% Lager should have handlers and sinks +lager_configured() -> + Sinks = lager:list_all_sinks(), + ExpectedSinks = list_expected_sinks(), + application:get_env(lager, handlers) =/= undefined + andalso + lists:all(fun(S) -> lists:member(S, Sinks) end, ExpectedSinks). + +configure_lager() -> + application:load(lager), + %% Turn off reformatting for error_logger messages + case application:get_env(lager, error_logger_format_raw) of + undefined -> application:set_env(lager, error_logger_format_raw, true); + _ -> ok + end, + case application:get_env(lager, log_root) of + undefined -> + application:set_env(lager, log_root, + application:get_env(rabbit, lager_log_root, + undefined)); + _ -> ok + end, + + %% Configure the default sink/handlers. + Handlers0 = application:get_env(lager, handlers, undefined), + DefaultHandlers = lager_handlers(application:get_env(rabbit, + lager_handler, + tty)), + Handlers = case os:getenv("RABBITMQ_LOGS_source") of + %% There are no default handlers in rabbitmq.config, create a + %% configuration from $RABBITMQ_LOGS. + false when Handlers0 =:= undefined -> DefaultHandlers; + %% There are default handlers configure in rabbitmq.config, but + %% the user explicitely sets $RABBITMQ_LOGS; create new handlers + %% based on that, instead of using rabbitmq.config. + "environment" -> DefaultHandlers; + %% Use the default handlers configured in rabbitmq.com. + _ -> Handlers0 + end, + application:set_env(lager, handlers, Handlers), + + %% Setup extra sink/handlers. If they are not configured, redirect + %% messages to the default sink. To know the list of expected extra + %% sinks, we look at the 'lager_extra_sinks' compilation option. + Sinks0 = application:get_env(lager, extra_sinks, []), + Sinks1 = configure_extra_sinks(Sinks0, list_expected_sinks()), + %% TODO Waiting for basho/lager#303 + %% Sinks2 = lists:keystore(error_logger_lager_event, 1, Sinks1, + %% {error_logger_lager_event, + %% [{handlers, Handlers}]}), + application:set_env(lager, extra_sinks, Sinks1), + + case application:get_env(lager, error_logger_hwm) of + undefined -> + application:set_env(lager, error_logger_hwm, 100); + {ok, Val} when is_integer(Val) andalso Val =< 100 -> + application:set_env(lager, error_logger_hwm, 100); + {ok, _Val} -> + ok + end, + ok. + +configure_extra_sinks(Sinks, [SinkName | Rest]) -> + Sink0 = proplists:get_value(SinkName, Sinks, []), + Sink1 = case proplists:is_defined(handlers, Sink0) of + false -> lists:keystore(handlers, 1, Sink0, + {handlers, + [{lager_forwarder_backend, + lager_util:make_internal_sink_name(lager) + }]}); + true -> Sink0 + end, + Sinks1 = lists:keystore(SinkName, 1, Sinks, {SinkName, Sink1}), + configure_extra_sinks(Sinks1, Rest); +configure_extra_sinks(Sinks, []) -> + Sinks. + +list_expected_sinks() -> + case application:get_env(rabbit, lager_extra_sinks) of + {ok, List} -> + List; + undefined -> + CompileOptions = proplists:get_value(options, + ?MODULE:module_info(compile), + []), + AutoList = [lager_util:make_internal_sink_name(M) + || M <- proplists:get_value(lager_extra_sinks, + CompileOptions, [])], + List = case lists:member(?LAGER_SINK, AutoList) of + true -> AutoList; + false -> [?LAGER_SINK | AutoList] + end, + %% Store the list in the application environment. If this + %% module is later cover-compiled, the compile option will + %% be lost, so we will be able to retrieve the list from the + %% application environment. + application:set_env(rabbit, lager_extra_sinks, List), + List + end. diff --git a/src/rabbit_log.erl b/src/rabbit_log.erl index c6081fad0d..5eedd925fe 100644 --- a/src/rabbit_log.erl +++ b/src/rabbit_log.erl @@ -16,32 +16,54 @@ -module(rabbit_log). --export([log/3, log/4, debug/1, debug/2, info/1, info/2, warning/1, - warning/2, error/1, error/2]). --export([with_local_io/1]). - +-export([log/3, log/4]). +-export([debug/1, debug/2, debug/3, + info/1, info/2, info/3, + notice/1, notice/2, notice/3, + warning/1, warning/2, warning/3, + error/1, error/2, error/3, + critical/1, critical/2, critical/3, + alert/1, alert/2, alert/3, + emergency/1, emergency/2, emergency/3, + none/1, none/2, none/3]). + +-include("rabbit_log.hrl"). %%---------------------------------------------------------------------------- -ifdef(use_specs). --export_type([level/0]). - -type(category() :: atom()). --type(level() :: 'debug' | 'info' | 'warning' | 'error'). - --spec(log/3 :: (category(), level(), string()) -> 'ok'). --spec(log/4 :: (category(), level(), string(), [any()]) -> 'ok'). - --spec(debug/1 :: (string()) -> 'ok'). --spec(debug/2 :: (string(), [any()]) -> 'ok'). --spec(info/1 :: (string()) -> 'ok'). --spec(info/2 :: (string(), [any()]) -> 'ok'). --spec(warning/1 :: (string()) -> 'ok'). --spec(warning/2 :: (string(), [any()]) -> 'ok'). --spec(error/1 :: (string()) -> 'ok'). --spec(error/2 :: (string(), [any()]) -> 'ok'). --spec(with_local_io/1 :: (fun (() -> A)) -> A). +-spec(log/3 :: (category(), lager:log_level(), string()) -> 'ok'). +-spec(log/4 :: (category(), lager:log_level(), string(), [any()]) -> 'ok'). + +-spec(debug/1 :: (string()) -> 'ok'). +-spec(debug/2 :: (string(), [any()]) -> 'ok'). +-spec(debug/3 :: (pid() | [tuple()], string(), [any()]) -> 'ok'). +-spec(info/1 :: (string()) -> 'ok'). +-spec(info/2 :: (string(), [any()]) -> 'ok'). +-spec(info/3 :: (pid() | [tuple()], string(), [any()]) -> 'ok'). +-spec(notice/1 :: (string()) -> 'ok'). +-spec(notice/2 :: (string(), [any()]) -> 'ok'). +-spec(notice/3 :: (pid() | [tuple()], string(), [any()]) -> 'ok'). +-spec(warning/1 :: (string()) -> 'ok'). +-spec(warning/2 :: (string(), [any()]) -> 'ok'). +-spec(warning/3 :: (pid() | [tuple()], string(), [any()]) -> 'ok'). +-spec(error/1 :: (string()) -> 'ok'). +-spec(error/2 :: (string(), [any()]) -> 'ok'). +-spec(error/3 :: (pid() | [tuple()], string(), [any()]) -> 'ok'). +-spec(critical/1 :: (string()) -> 'ok'). +-spec(critical/2 :: (string(), [any()]) -> 'ok'). +-spec(critical/3 :: (pid() | [tuple()], string(), [any()]) -> 'ok'). +-spec(alert/1 :: (string()) -> 'ok'). +-spec(alert/2 :: (string(), [any()]) -> 'ok'). +-spec(alert/3 :: (pid() | [tuple()], string(), [any()]) -> 'ok'). +-spec(emergency/1 :: (string()) -> 'ok'). +-spec(emergency/2 :: (string(), [any()]) -> 'ok'). +-spec(emergency/3 :: (pid() | [tuple()], string(), [any()]) -> 'ok'). +-spec(none/1 :: (string()) -> 'ok'). +-spec(none/2 :: (string(), [any()]) -> 'ok'). +-spec(none/3 :: (pid() | [tuple()], string(), [any()]) -> 'ok'). -endif. @@ -50,56 +72,53 @@ log(Category, Level, Fmt) -> log(Category, Level, Fmt, []). log(Category, Level, Fmt, Args) when is_list(Args) -> - case level(Level) =< catlevel(Category) of - false -> ok; - true -> F = case Level of - debug -> fun error_logger:info_msg/2; - info -> fun error_logger:info_msg/2; - warning -> fun error_logger:warning_msg/2; - error -> fun error_logger:error_msg/2 - end, - with_local_io(fun () -> F(Fmt, Args) end) - end. - -debug(Fmt) -> log(default, debug, Fmt). -debug(Fmt, Args) -> log(default, debug, Fmt, Args). -info(Fmt) -> log(default, info, Fmt). -info(Fmt, Args) -> log(default, info, Fmt, Args). -warning(Fmt) -> log(default, warning, Fmt). -warning(Fmt, Args) -> log(default, warning, Fmt, Args). -error(Fmt) -> log(default, error, Fmt). -error(Fmt, Args) -> log(default, error, Fmt, Args). - -catlevel(Category) -> - %% We can get here as part of rabbitmqctl when it is impersonating - %% a node; in which case the env will not be defined. - CatLevelList = case application:get_env(rabbit, log_levels) of - {ok, L} -> L; - undefined -> [] - end, - level(proplists:get_value(Category, CatLevelList, info)). - -%%-------------------------------------------------------------------- - -level(debug) -> 4; -level(info) -> 3; -level(warning) -> 2; -level(warn) -> 2; -level(error) -> 1; -level(none) -> 0. - -%% Execute Fun using the IO system of the local node (i.e. the node on -%% which the code is executing). Since this is invoked for every log -%% message, we try to avoid unnecessarily churning group_leader/1. -with_local_io(Fun) -> - GL = group_leader(), - Node = node(), - case node(GL) of - Node -> Fun(); - _ -> group_leader(whereis(user), self()), - try - Fun() - after - group_leader(GL, self()) - end - end. + Sink = case Category of + default -> ?LAGER_SINK; + _ -> lager_util:make_internal_sink_name(Category) + end, + lager:log(Sink, Level, self(), Fmt, Args). + +debug(Format) -> debug(Format, []). +debug(Format, Args) -> debug(self(), Format, Args). +debug(Metadata, Format, Args) -> + lager:log(?LAGER_SINK, debug, Metadata, Format, Args). + +info(Format) -> info(Format, []). +info(Format, Args) -> info(self(), Format, Args). +info(Metadata, Format, Args) -> + lager:log(?LAGER_SINK, info, Metadata, Format, Args). + +notice(Format) -> notice(Format, []). +notice(Format, Args) -> notice(self(), Format, Args). +notice(Metadata, Format, Args) -> + lager:log(?LAGER_SINK, notice, Metadata, Format, Args). + +warning(Format) -> warning(Format, []). +warning(Format, Args) -> warning(self(), Format, Args). +warning(Metadata, Format, Args) -> + lager:log(?LAGER_SINK, warning, Metadata, Format, Args). + +error(Format) -> ?MODULE:error(Format, []). +error(Format, Args) -> ?MODULE:error(self(), Format, Args). +error(Metadata, Format, Args) -> + lager:log(?LAGER_SINK, error, Metadata, Format, Args). + +critical(Format) -> critical(Format, []). +critical(Format, Args) -> critical(self(), Format, Args). +critical(Metadata, Format, Args) -> + lager:log(?LAGER_SINK, critical, Metadata, Format, Args). + +alert(Format) -> alert(Format, []). +alert(Format, Args) -> alert(self(), Format, Args). +alert(Metadata, Format, Args) -> + lager:log(?LAGER_SINK, alert, Metadata, Format, Args). + +emergency(Format) -> emergency(Format, []). +emergency(Format, Args) -> emergency(self(), Format, Args). +emergency(Metadata, Format, Args) -> + lager:log(?LAGER_SINK, emergency, Metadata, Format, Args). + +none(Format) -> none(Format, []). +none(Format, Args) -> none(self(), Format, Args). +none(Metadata, Format, Args) -> + lager:log(?LAGER_SINK, none, Metadata, Format, Args). diff --git a/src/rabbit_sasl_report_file_h.erl b/src/rabbit_sasl_report_file_h.erl deleted file mode 100644 index 9ba24ab325..0000000000 --- a/src/rabbit_sasl_report_file_h.erl +++ /dev/null @@ -1,100 +0,0 @@ -%% The contents of this file are subject to the Mozilla Public License -%% Version 1.1 (the "License"); you may not use this file except in -%% compliance with the License. You may obtain a copy of the License -%% at http://www.mozilla.org/MPL/ -%% -%% Software distributed under the License is distributed on an "AS IS" -%% basis, WITHOUT WARRANTY OF ANY KIND, either express or implied. See -%% the License for the specific language governing rights and -%% limitations under the License. -%% -%% The Original Code is RabbitMQ. -%% -%% The Initial Developer of the Original Code is GoPivotal, Inc. -%% Copyright (c) 2007-2016 Pivotal Software, Inc. All rights reserved. -%% - --module(rabbit_sasl_report_file_h). --include("rabbit.hrl"). - --behaviour(gen_event). - --export([init/1, handle_event/2, handle_call/2, handle_info/2, terminate/2, - code_change/3]). - --import(rabbit_error_logger_file_h, [safe_handle_event/3]). - -%% rabbit_sasl_report_file_h is a wrapper around the sasl_report_file_h -%% module because the original's init/1 does not match properly -%% with the result of closing the old handler when swapping handlers. -%% The first init/1 additionally allows for simple log rotation -%% when the suffix is not the empty string. -%% The original init/1 also opened the file in 'write' mode, thus -%% overwriting old logs. To remedy this, init/1 from -%% lib/sasl/src/sasl_report_file_h.erl from R14B3 was copied as -%% init_file/1 and changed so that it opens the file in 'append' mode. - -%% Used only when swapping handlers and performing -%% log rotation -init({{File, Suffix}, []}) -> - case rabbit_file:append_file(File, Suffix) of - ok -> file:delete(File), - ok; - {error, Error} -> - rabbit_log:error("Failed to append contents of " - "sasl log file '~s' to '~s':~n~p~n", - [File, [File, Suffix], Error]) - end, - init(File); -%% Used only when swapping handlers and the original handler -%% failed to terminate or was never installed -init({{File, _}, error}) -> - init(File); -%% Used only when swapping handlers without -%% doing any log rotation -init({File, []}) -> - init(File); -init({File, _Type} = FileInfo) -> - rabbit_file:ensure_parent_dirs_exist(File), - init_file(FileInfo); -init(File) -> - rabbit_file:ensure_parent_dirs_exist(File), - init_file({File, sasl_error_logger_type()}). - -init_file({File, Type}) -> - process_flag(trap_exit, true), - case file:open(File, [append]) of - {ok,Fd} -> {ok, {Fd, File, Type}}; - Error -> Error - end. - -handle_event(Event, State) -> - safe_handle_event(fun handle_event0/2, Event, State). - -handle_event0(Event, State) -> - sasl_report_file_h:handle_event( - truncate:log_event(Event, ?LOG_TRUNC), State). - -handle_info(Info, State) -> - sasl_report_file_h:handle_info(Info, State). - -handle_call(Call, State) -> - sasl_report_file_h:handle_call(Call, State). - -terminate(Reason, State) -> - sasl_report_file_h:terminate(Reason, State). - -code_change(_OldVsn, State, _Extra) -> - %% There is no sasl_report_file_h:code_change/3 - {ok, State}. - -%%---------------------------------------------------------------------- - -sasl_error_logger_type() -> - case application:get_env(sasl, errlog_type) of - {ok, error} -> error; - {ok, progress} -> progress; - {ok, all} -> all; - {ok, Bad} -> throw({error, {wrong_errlog_type, Bad}}); - _ -> all - end. |