From 0c6255e368ffb6000d403568c0ed0f6d125d25b0 Mon Sep 17 00:00:00 2001 From: Daniil Fedotov Date: Fri, 18 Aug 2017 11:14:56 +0100 Subject: [PATCH 1/4] Refactor log configuration to be consistent with log doc guide --- Makefile | 1 - priv/schema/rabbit.schema | 124 ++++---- scripts/rabbitmq-server | 4 +- src/rabbit_lager.erl | 337 +++++++++++++++++----- test/unit_inbroker_non_parallel_SUITE.erl | 26 +- 5 files changed, 362 insertions(+), 130 deletions(-) diff --git a/Makefile b/Makefile index 9aeaf80c723f..5ca29092d3d9 100644 --- a/Makefile +++ b/Makefile @@ -47,7 +47,6 @@ define PROJECT_ENV {auth_backends, [rabbit_auth_backend_internal]}, {delegate_count, 16}, {trace_vhosts, []}, - {log_levels, [{connection, info}]}, {ssl_cert_login_from, distinguished_name}, {ssl_handshake_timeout, 5000}, {ssl_allow_poodle_attack, false}, diff --git a/priv/schema/rabbit.schema b/priv/schema/rabbit.schema index 70351f116c15..cd6d7a678106 100644 --- a/priv/schema/rabbit.schema +++ b/priv/schema/rabbit.schema @@ -990,80 +990,98 @@ end}. {datatype, string}, {validators, ["dir_writable"]}]}. -{mapping, "log.console", "lager.handlers", [ +{mapping, "log.console", "rabbit.log.console.enabled", [ {datatype, {enum, [true, false]}} ]}. +{mapping, "log.console.level", "rabbit.log.console.level", [ + {datatype, {enum, [debug, info, notice, warning, error, critical, alert, emergency, none]}} +]}. -{mapping, "log.syslog", "lager.handlers", [ +{mapping, "log.syslog", "rabbit.log.syslog.enabled", [ {datatype, {enum, [true, false]}} ]}. -{mapping, "log.file", "lager.handlers", [ - {datatype, [{enum, [false]}, string]} +{mapping, "log.syslog.level", "rabbit.log.syslog.level", [ + {datatype, {enum, [debug, info, notice, warning, error, critical, alert, emergency, none]}} +]}. +{mapping, "log.syslog.identity", "rabbit.log.syslog.identity", [ + {datatype, string} +]}. +{mapping, "log.syslog.facility", "rabbit.log.syslog.facility", [ + {datatype, atom} ]}. -{mapping, "log.file.level", "lager.handlers", [ - {datatype, {enum, [debug, info, warning, error]}} +{mapping, "log.file", "rabbit.log.file.file", [ + {datatype, [{enum, [false]}, string]} ]}. -{mapping, "log.$handler.level", "lager.handlers", [ - {datatype, {enum, [debug, info, warning, error]}} +{mapping, "log.file.level", "rabbit.log.file.level", [ + {datatype, + {enum, ['=debug', debug, + info, '!=info', + notice, '<=notice', + ' - ConsoleHandler = case cuttlefish:conf_get("log.console", Conf, false) of - true -> - ConsoleLevel = cuttlefish:conf_get("log.console.level", Conf, info), - [{lager_console_backend, ConsoleLevel}]; - false -> [] - end, - FileHandler = case cuttlefish:conf_get("log.file", Conf, undefined) of - false -> []; - File -> - FileLevel = cuttlefish:conf_get("log.file.level", Conf, info), - RotationDate = cuttlefish:conf_get("log.file.rotation.date", Conf, ""), - RotationSize = cuttlefish:conf_get("log.file.rotation.size", Conf, 0), - RotationCount = cuttlefish:conf_get("log.file.rotation.count", Conf, 10), - [{lager_file_backend, [{file, File}, - {level, FileLevel}, - {date, RotationDate}, - {size, RotationSize}, - {formatter_config, - [date, " ", time, " ", color, - "[", severity, "] ", - {pid, ""}, - " ", message, "\n"]}, - {count, RotationCount}]}] - end, - SyslogHandler = case cuttlefish:conf_get("log.syslog", Conf, false) of - false -> []; - true -> - SyslogLevel = cuttlefish:conf_get("log.syslog.level", Conf, info), - Identity = cuttlefish:conf_get("log.syslog.identity", Conf), - Facility = cuttlefish:conf_get("log.syslog.facility", Conf), - [{lager_syslog_backend, [Identity, Facility, SyslogLevel]}] - end, - case ConsoleHandler ++ FileHandler ++ SyslogHandler of - [] -> undefined; - Other -> Other - end -end}. +{mapping, "log.mirroring.level", "rabbit.log.categories.mirroring.level", [ + {datatype, {enum, [debug, info, notice, warning, error, critical, alert, emergency, none]}} +]}. +{mapping, "log.mirroring.file", "rabbit.log.categories.mirroring.file", [ + {datatype, string} +]}. + +{mapping, "log.queue.level", "rabbit.log.categories.queue.level", [ + {datatype, {enum, [debug, info, notice, warning, error, critical, alert, emergency, none]}} +]}. +{mapping, "log.queue.file", "rabbit.log.categories.queue.file", [ + {datatype, string} +]}. +{mapping, "log.federation.level", "rabbit.log.categories.federation.level", [ + {datatype, {enum, [debug, info, notice, warning, error, critical, alert, emergency, none]}} +]}. +{mapping, "log.federation.file", "rabbit.log.categories.federation.file", [ + {datatype, string} +]}. + +{mapping, "log.upgrade.level", "rabbit.log.categories.upgrade.level", [ + {datatype, {enum, [debug, info, notice, warning, error, critical, alert, emergency, none]}} +]}. +{mapping, "log.upgrade.file", "rabbit.log.categories.upgrade.file", [ + {datatype, string} +]}. + +{mapping, "log.default.level", "rabbit.log.categories.default.level", [ + {datatype, {enum, [debug, info, notice, warning, error, critical, alert, emergency, none]}} +]}. % =============================== % Validators diff --git a/scripts/rabbitmq-server b/scripts/rabbitmq-server index 4edec5b47026..27948ea6b7c5 100755 --- a/scripts/rabbitmq-server +++ b/scripts/rabbitmq-server @@ -221,8 +221,8 @@ start_rabbitmq_server() { -sasl errlog_type error \ -sasl sasl_error_logger "$SASL_ERROR_LOGGER" \ -rabbit lager_log_root "\"$RABBITMQ_LOG_BASE\"" \ - -rabbit lager_handler "$RABBIT_LAGER_HANDLER" \ - -rabbit lager_handler_upgrade "$RABBITMQ_LAGER_HANDLER_UPGRADE" \ + -rabbit lager_default_file "$RABBIT_LAGER_HANDLER" \ + -rabbit lager_upgrade_file "$RABBITMQ_LAGER_HANDLER_UPGRADE" \ -rabbit enabled_plugins_file "\"$RABBITMQ_ENABLED_PLUGINS_FILE\"" \ -rabbit plugins_dir "\"$RABBITMQ_PLUGINS_DIR\"" \ -rabbit plugins_expand_dir "\"$RABBITMQ_PLUGINS_EXPAND_DIR\"" \ diff --git a/src/rabbit_lager.erl b/src/rabbit_lager.erl index cb27eda788de..36f2b159bc47 100644 --- a/src/rabbit_lager.erl +++ b/src/rabbit_lager.erl @@ -137,28 +137,6 @@ ensure_logfile_exist(FileName) -> {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(); @@ -193,36 +171,62 @@ configure_lager() -> end; _ -> ok end, + %% Set rabbit.log config variable based on environment. + prepare_rabbit_log_config(), + %% At this point we should have rabbit.log application variable + %% configured to generate RabbitMQ log handlers. + GeneratedHandlers = generate_lager_handlers(), - %% 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 + %% If there are lager handlers configured, + %% both lager and generate RabbitMQ handlers are used. + %% This is because it's hard to decide clear preference rules. + %% RabbitMQ handlers can be set to [] to use only lager handlers. + Handlers = case application:get_env(lager, handlers, undefined) of + undefined -> GeneratedHandlers; + LagerHandlers -> + %% Remove handlers generated in previous starts + FormerRabbitHandlers = application:get_env(lager, rabbit_handlers, []), + GeneratedHandlers ++ remove_rabbit_handlers(LagerHandlers, + FormerRabbitHandlers) end, + application:set_env(lager, handlers, Handlers), + application:set_env(lager, rabbit_handlers, GeneratedHandlers), %% 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, - [error_logger | 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), + LogConfig = application:get_env(rabbit, log, []), + LogLevels = application:get_env(rabbit, log_levels, []), + Categories = proplists:get_value(categories, LogConfig, []), + CategoriesConfig = case {Categories, LogLevels} of + {[], []} -> []; + {[], LogLevels} -> + io:format("Using deprecated config parameter 'log_levels'. " + "Please update your configuration file according to: " + "https://rabbitmq.com/logging.html"), + lists:map(fun({Name, Level}) -> {Name, [{level, Level}]} end, + LogLevels); + {Categories, []} -> + Categories; + {Categories, LogLevels} -> + io:format("Using the deprecated config parameter 'log_levels' together " + "with the new parameter 'categories'." + " 'log_levels' will be ignored. Please remove 'log_levels' " + "https://rabbitmq.com/logging.html"), + Categories + end, + SinkConfigs = lists:map( + fun({Name, Config}) -> + {rabbit_log:make_internal_sink_name(Name), Config} + end, + CategoriesConfig), + LagerSinks = application:get_env(lager, extra_sinks, []), + GeneratedSinks = generate_lager_sinks( + [error_logger_lager_event | list_expected_sinks()], + SinkConfigs), + Sinks = merge_lager_sink_handlers(LagerSinks, GeneratedSinks, []), + application:set_env(lager, extra_sinks, Sinks), case application:get_env(lager, error_logger_hwm) of undefined -> @@ -234,27 +238,230 @@ configure_lager() -> end, ok. -configure_extra_sinks(Sinks, [SinkName | Rest]) -> - Sink0 = proplists:get_value(SinkName, Sinks, []), - Sink1 = case proplists:is_defined(handlers, Sink0) of - false -> default_sink_config(SinkName, Sink0); - true -> Sink0 +remove_rabbit_handlers(Handlers, FormerHandlers) -> + lists:filter(fun(Handler) -> + not lists:member(Handler, FormerHandlers) + end, + Handlers). + +generate_lager_handlers() -> + LogConfig = application:get_env(rabbit, log, []), + LogHandlersConfig = lists:keydelete(categories, 1, LogConfig), + generate_lager_handlers(LogHandlersConfig). + +generate_lager_handlers(LogHandlersConfig) -> + lists:flatmap( + fun + ({file, HandlerConfig}) -> + case proplists:get_value(file, HandlerConfig, false) of + false -> []; + FileName when is_list(FileName) -> + Backend = lager_backend(file), + generate_handler(Backend, HandlerConfig) + end; + ({Other, HandlerConfig}) when Other =:= console; Other =:= syslog -> + case proplists:get_value(enabled, HandlerConfig, false) of + false -> []; + true -> + Backend = lager_backend(Other), + generate_handler(Backend, + lists:keydelete(enabled, 1, HandlerConfig)) + end + end, + LogHandlersConfig). + +lager_backend(file) -> lager_file_backend; +lager_backend(console) -> lager_console_backend; +lager_backend(syslog) -> lager_syslog_backend. + +generate_handler(Backend, HandlerConfig) -> + [{Backend, + lists:ukeymerge(1, lists:ukeysort(1, HandlerConfig), + lists:ukeysort(1, default_handler_config(Backend)))}]. + +default_handler_config(lager_syslog_backend) -> + [{level, default_config_value(level)}, + {identity, "rabbitmq"}, + {facility, daemon}, + {formatter_config, default_config_value(formatter_config)}]; +default_handler_config(lager_console_backend) -> + [{level, default_config_value(level)}, + {formatter_config, default_config_value(formatter_config)}]; +default_handler_config(lager_file_backend) -> + [{level, default_config_value(level)}, + {formatter_config, default_config_value(formatter_config)}, + {date, ""}, + {size, 0}]. + +default_config_value(level) -> info; +default_config_value(formatter_config) -> + [date, " ", time, " ", color, "[", severity, "] ", + {pid, ""}, + " ", message, "\n"]. + +prepare_rabbit_log_config() -> + %% If RABBIT_LOGS is not set, we should use console logger + DefaultFile = application:get_env(rabbit, lager_default_file, tty), + %% If RABBIT_UPGRADE_LOGS is not set, we should ignore it. + UpgradeFile = application:get_env(rabbit, lager_upgrade_file, undefined), + case DefaultFile of + false -> + set_env_default_log_disabled(); + tty -> + set_env_default_log_console(); + FileName when is_list(FileName) -> + case os:getenv("RABBITMQ_LOGS_source") of + %% The user explicitely sets $RABBITMQ_LOGS; + %% we should override a file location even + %% if it's set in rabbitmq.config + "environment" -> set_env_default_log_file(FileName, override); + _ -> set_env_default_log_file(FileName, keep) + end + end, + + %% Upgrade log file never overrides the value set in rabbitmq.config + case UpgradeFile of + %% No special env for upgrade logs - rederect to the default sink + undefined -> ok; + %% Redirect logs to default output. + DefaultFile -> ok; + UpgradeFileName when is_list(UpgradeFileName) -> + set_env_upgrade_log_file(UpgradeFileName) + end. + +set_env_default_log_disabled() -> + %% Disabling all the logs. + application:set_env(rabbit, log, []). + +set_env_default_log_console() -> + LogConfig = application:get_env(rabbit, log, []), + ConsoleConfig = proplists:get_value(console, LogConfig, []), + LogConfigConsole = + lists:keystore(console, 1, LogConfig, + {console, lists:keystore(enabled, 1, ConsoleConfig, + {enabled, true})}), + %% Remove the file handler - disable logging to file + LogConfigConsoleNoFile = lists:keydelete(file, 1, LogConfigConsole), + application:set_env(rabbit, log, LogConfigConsoleNoFile). + +set_env_default_log_file(FileName, Override) -> + LogConfig = application:get_env(rabbit, log, []), + FileConfig = proplists:get_value(file, LogConfig, []), + NewLogConfig = case proplists:get_value(file, FileConfig, undefined) of + undefined -> + lists:keystore(file, 1, LogConfig, + {file, lists:keystore(file, 1, FileConfig, + {file, FileName})}); + _ConfiguredFileName -> + case Override of + override -> + lists:keystore( + file, 1, LogConfig, + {file, lists:keystore(file, 1, FileConfig, + {file, FileName})}); + keep -> + LogConfig + end + end, + application:set_env(rabbit, log, NewLogConfig). + +set_env_upgrade_log_file(FileName) -> + LogConfig = application:get_env(rabbit, log, []), + SinksConfig = proplists:get_value(categories, LogConfig, []), + UpgradeSinkConfig = proplists:get_value(upgrade, SinksConfig, []), + FileConfig = proplists:get_value(file, SinksConfig, []), + NewLogConfig = case proplists:get_value(file, FileConfig, undefined) of + undefined -> + lists:keystore( + categories, 1, LogConfig, + {categories, + lists:keystore( + upgrade, 1, SinksConfig, + {upgrade, + lists:keystore(file, 1, UpgradeSinkConfig, + {file, FileName})})}); + %% No cahnge. We don't want to override the configured value. + _File -> LogConfig + end, + application:set_env(rabbit, log, NewLogConfig). + +generate_lager_sinks(SinkNames, SinkConfigs) -> + lists:map(fun(SinkName) -> + SinkConfig = proplists:get_value(SinkName, SinkConfigs, []), + Level = proplists:get_value(level, SinkConfig, default_config_value(level)), + SinkHandlers = case proplists:get_value(file, SinkConfig, false) of + %% If no file defined - forward everything to the default backend + false -> + [{lager_forwarder_backend, + [lager_util:make_internal_sink_name(lager), Level]}]; + %% If a file defined - add a file backend to handlers and remove all default file backends. + File -> + DefaultGeneratedHandlers = application:get_env(lager, rabbit_handlers, []), + SinkFileHandlers = case proplists:get_value(lager_file_backend, DefaultGeneratedHandlers, undefined) of + undefined -> + %% Create a new file handler. + generate_lager_handlers([{file, [{file, File}, {level, Level}]}]); + FileHandler -> + %% Replace a filename in the handler + [{lager_file_backend, + lists:ukeymerge(1, + [{file, File}, {level, Level}], + lists:ukeysort(1, FileHandler))}] + end, + %% Remove all file handlers. + AllLagerHandlers = application:get_env(lager, handlers, []), + HandlersWithoutFile = lists:filter( + fun({lager_file_backend, _}) -> false; + ({_, _}) -> true + end, + AllLagerHandlers), + %% Set level for handlers which are more verbose. + %% We don't increase verbosity in sinks so it works like forwarder backend. + HandlersWithoutFileWithLevel = lists:map(fun({Name, Handler}) -> + case handler_level_more_verbose(Handler, Level) of + true -> {Name, lists:keystore(level, 1, Handler, {level, Level})}; + false -> {Name, Handler} + end + end, + HandlersWithoutFile), + + HandlersWithoutFileWithLevel ++ SinkFileHandlers + end, + {SinkName, [{handlers, SinkHandlers}, {rabbit_handlers, SinkHandlers}]} end, - Sinks1 = lists:keystore(SinkName, 1, Sinks, {SinkName, Sink1}), - configure_extra_sinks(Sinks1, Rest); -configure_extra_sinks(Sinks, []) -> - Sinks. - -default_sink_config(rabbit_log_upgrade_lager_event, Sink) -> - Handlers = lager_handlers(application:get_env(rabbit, - lager_handler_upgrade, - tty)), - lists:keystore(handlers, 1, Sink, {handlers, Handlers}); -default_sink_config(_, Sink) -> - lists:keystore(handlers, 1, Sink, - {handlers, - [{lager_forwarder_backend, - lager_util:make_internal_sink_name(lager)}]}). + SinkNames). + +handler_level_more_verbose(Handler, Level) -> + HandlerLevel = proplists:get_value(level, Handler, default_config_value(level)), + lager_util:level_to_num(HandlerLevel) > lager_util:level_to_num(Level). + +merge_lager_sink_handlers([{Name, Sink} | RestSinks], GeneratedSinks, Agg) -> + case lists:keytake(Name, 1, GeneratedSinks) of + {value, {Name, GenSink}, RestGeneratedSinks} -> + Handlers = proplists:get_value(handlers, Sink, []), + GenHandlers = proplists:get_value(handlers, GenSink, []), + FormerRabbitHandlers = proplists:get_value(rabbit_handlers, Sink, []), + + %% Remove handlers defined in previous starts + ConfiguredHandlers = remove_rabbit_handlers(Handlers, FormerRabbitHandlers), + NewHandlers = GenHandlers ++ ConfiguredHandlers, + MergedSink = lists:keystore(rabbit_handlers, 1, + lists:keystore(handlers, 1, Sink, + {handlers, NewHandlers}), + {rabbit_handlers, GenHandlers}), + + merge_lager_sink_handlers( + RestSinks, + RestGeneratedSinks, + [{Name, MergedSink} | Agg]); + false -> + merge_lager_sink_handlers( + RestSinks, + GeneratedSinks, + [{Name, Sink} | Agg]) + end; +merge_lager_sink_handlers([], GeneratedSinks, Agg) -> GeneratedSinks ++ Agg. + list_expected_sinks() -> case application:get_env(rabbit, lager_extra_sinks) of diff --git a/test/unit_inbroker_non_parallel_SUITE.erl b/test/unit_inbroker_non_parallel_SUITE.erl index 2af6368f34cc..9c7d798ecc72 100644 --- a/test/unit_inbroker_non_parallel_SUITE.erl +++ b/test/unit_inbroker_non_parallel_SUITE.erl @@ -238,18 +238,20 @@ log_management1(_Config) -> %% logging directed to tty (first, remove handlers) ok = rabbit:stop(), ok = clean_logs([LogFile], Suffix), - ok = application:set_env(rabbit, lager_handler, tty), + ok = application:set_env(rabbit, lager_default_file, tty), + application:unset_env(rabbit, log), application:unset_env(lager, handlers), application:unset_env(lager, extra_sinks), ok = rabbit:start(), timer:sleep(200), rabbit_log:info("test info"), - [{error, enoent}] = empty_files([LogFile]), + [{error, enoent}] = non_empty_files([LogFile]), %% rotate logs when logging is turned off ok = rabbit:stop(), ok = clean_logs([LogFile], Suffix), - ok = application:set_env(rabbit, lager_handler, false), + ok = application:set_env(rabbit, lager_default_file, false), + application:unset_env(rabbit, log), application:unset_env(lager, handlers), application:unset_env(lager, extra_sinks), ok = rabbit:start(), @@ -261,7 +263,8 @@ log_management1(_Config) -> %% cleanup ok = rabbit:stop(), ok = clean_logs([LogFile], Suffix), - ok = application:set_env(rabbit, lager_handler, LogFile), + ok = application:set_env(rabbit, lager_default_file, LogFile), + application:unset_env(rabbit, log), application:unset_env(lager, handlers), application:unset_env(lager, extra_sinks), ok = rabbit:start(), @@ -279,7 +282,8 @@ log_management_during_startup1(_Config) -> %% start application with simple tty logging ok = rabbit:stop(), ok = clean_logs([LogFile], Suffix), - ok = application:set_env(rabbit, lager_handler, tty), + ok = application:set_env(rabbit, lager_default_file, tty), + application:unset_env(rabbit, log), application:unset_env(lager, handlers), application:unset_env(lager, extra_sinks), ok = rabbit:start(), @@ -289,7 +293,8 @@ log_management_during_startup1(_Config) -> delete_file(NonExistent), delete_file(filename:dirname(NonExistent)), ok = rabbit:stop(), - ok = application:set_env(rabbit, lager_handler, NonExistent), + ok = application:set_env(rabbit, lager_default_file, NonExistent), + application:unset_env(rabbit, log), application:unset_env(lager, handlers), application:unset_env(lager, extra_sinks), ok = rabbit:start(), @@ -301,7 +306,8 @@ log_management_during_startup1(_Config) -> delete_file(NoPermission1), delete_file(filename:dirname(NoPermission1)), ok = rabbit:stop(), - ok = application:set_env(rabbit, lager_handler, NoPermission1), + ok = application:set_env(rabbit, lager_default_file, NoPermission1), + application:unset_env(rabbit, log), application:unset_env(lager, handlers), application:unset_env(lager, extra_sinks), ok = try rabbit:start() of @@ -326,7 +332,8 @@ log_management_during_startup1(_Config) -> ok -> ok; {error, lager_not_running} -> ok end, - ok = application:set_env(rabbit, lager_handler, NoPermission2), + ok = application:set_env(rabbit, lager_default_file, NoPermission2), + application:unset_env(rabbit, log), application:unset_env(lager, handlers), application:unset_env(lager, extra_sinks), ok = try rabbit:start() of @@ -343,7 +350,8 @@ log_management_during_startup1(_Config) -> end, %% cleanup - ok = application:set_env(rabbit, lager_handler, LogFile), + ok = application:set_env(rabbit, lager_default_file, LogFile), + application:unset_env(rabbit, log), application:unset_env(lager, handlers), application:unset_env(lager, extra_sinks), ok = rabbit:start(), From 57825b776711e64c5815b87346dcf3679523bd90 Mon Sep 17 00:00:00 2001 From: Daniil Fedotov Date: Mon, 21 Aug 2017 16:10:13 +0100 Subject: [PATCH 2/4] Log configuration tests --- src/rabbit_lager.erl | 16 +- test/unit_log_config_SUITE.erl | 673 +++++++++++++++++++++++++++++++++ 2 files changed, 685 insertions(+), 4 deletions(-) create mode 100644 test/unit_log_config_SUITE.erl diff --git a/src/rabbit_lager.erl b/src/rabbit_lager.erl index 36f2b159bc47..b9dee6c62385 100644 --- a/src/rabbit_lager.erl +++ b/src/rabbit_lager.erl @@ -21,6 +21,9 @@ %% API -export([start_logger/0, log_locations/0, fold_sinks/2]). +%% For test purposes +-export([configure_lager/0]). + start_logger() -> application:stop(lager), ensure_lager_configured(), @@ -300,11 +303,12 @@ default_config_value(formatter_config) -> " ", message, "\n"]. prepare_rabbit_log_config() -> - %% If RABBIT_LOGS is not set, we should use console logger - DefaultFile = application:get_env(rabbit, lager_default_file, tty), + %% If RABBIT_LOGS is not set, we should ignore it. + DefaultFile = application:get_env(rabbit, lager_default_file, undefined), %% If RABBIT_UPGRADE_LOGS is not set, we should ignore it. UpgradeFile = application:get_env(rabbit, lager_upgrade_file, undefined), case DefaultFile of + undefined -> ok; false -> set_env_default_log_disabled(); tty -> @@ -403,9 +407,13 @@ generate_lager_sinks(SinkNames, SinkConfigs) -> generate_lager_handlers([{file, [{file, File}, {level, Level}]}]); FileHandler -> %% Replace a filename in the handler + FileHandlerChanges = case handler_level_more_verbose(FileHandler, Level) of + true -> [{file, File}, {level, Level}]; + false -> [{file, File}] + end, + [{lager_file_backend, - lists:ukeymerge(1, - [{file, File}, {level, Level}], + lists:ukeymerge(1, FileHandlerChanges, lists:ukeysort(1, FileHandler))}] end, %% Remove all file handlers. diff --git a/test/unit_log_config_SUITE.erl b/test/unit_log_config_SUITE.erl new file mode 100644 index 000000000000..feeebe57cfc9 --- /dev/null +++ b/test/unit_log_config_SUITE.erl @@ -0,0 +1,673 @@ +%% 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) 2016 Pivotal Software, Inc. All rights reserved. +%% + +-module(unit_log_config_SUITE). + +-include_lib("common_test/include/ct.hrl"). +-include_lib("eunit/include/eunit.hrl"). + +-compile(export_all). + +all() -> + [ + default, + env_var_tty, + config_file_handler, + config_file_handler_level, + config_file_handler_rotation, + config_console_handler, + config_syslog_handler, + config_syslog_handler_options, + config_multiple_handlers, + + env_var_overrides_config, + env_var_disable_log, + + config_sinks_level, + config_sink_file, + config_sink_file_override_config_handler_file, + + config_handlers_merged_with_lager_handlers, + sink_handlers_merged_with_lager_extra_sinks_handlers, + sink_file_rewrites_file_backends + ]. + + +init_per_testcase(_, Config) -> + application:load(rabbit), + application:load(lager), + application:unset_env(rabbit, log), + application:unset_env(rabbit, lager_log_root), + application:unset_env(rabbit, lager_default_file), + application:unset_env(rabbit, lager_upgrade_file), + application:unset_env(lager, handlers), + application:unset_env(lager, rabbit_handlers), + application:unset_env(lager, extra_sinks), + os:unsetenv("RABBITMQ_LOGS_source"), + Config. + +end_per_testcase(_, Config) -> + application:unset_env(rabbit, log), + application:unset_env(rabbit, lager_log_root), + application:unset_env(rabbit, lager_default_file), + application:unset_env(rabbit, lager_upgrade_file), + application:unset_env(lager, handlers), + application:unset_env(lager, rabbit_handlers), + application:unset_env(lager, extra_sinks), + os:unsetenv("RABBITMQ_LOGS_source"), + application:unload(rabbit), + application:unload(lager), + Config. + +sink_file_rewrites_file_backends(_) -> + application:set_env(rabbit, log, [ + %% Disable rabbit file handler + {file, [{file, false}]}, + {categories, [{federation, [{file, "federation.log"}, {level, warning}]}]} + ]), + + LagerHandlers = [ + {lager_file_backend, [{file, "lager_file.log"}, {level, error}]}, + {lager_file_backend, [{file, "lager_file_1.log"}, {level, error}]}, + {lager_console_backend, [{level, info}]} + ], + application:set_env(lager, handlers, LagerHandlers), + + rabbit_lager:configure_lager(), + + ExpectedSinks = sort_sinks(sink_rewrite_sinks()), + + ExpectedSinks = sort_sinks(application:get_env(lager, extra_sinks, undefined)). + +sink_rewrite_sinks() -> + [{error_logger_lager_event, + [{handlers,[{lager_forwarder_backend,[lager_event,info]}]}, + {rabbit_handlers,[{lager_forwarder_backend,[lager_event,info]}]}]}, + {rabbit_log_channel_lager_event, + [{handlers,[{lager_forwarder_backend,[lager_event,info]}]}, + {rabbit_handlers,[{lager_forwarder_backend,[lager_event,info]}]}]}, + {rabbit_log_connection_lager_event, + [{handlers,[{lager_forwarder_backend,[lager_event,info]}]}, + {rabbit_handlers,[{lager_forwarder_backend,[lager_event,info]}]}]}, + {rabbit_log_federation_lager_event, + [{handlers,[ + {lager_file_backend, + [{date, ""}, + {file, "federation.log"}, + {formatter_config, formatter_config()}, + {level, warning}, + {size, 0}]}, + {lager_console_backend, [{level, warning}]} + ]}, + {rabbit_handlers,[ + {lager_file_backend, + [{date, ""}, + {file, "federation.log"}, + {formatter_config, formatter_config()}, + {level, warning}, + {size, 0}]}, + {lager_console_backend, [{level, warning}]} + ]}]}, + {rabbit_log_lager_event, + [{handlers,[{lager_forwarder_backend,[lager_event,info]}]}, + {rabbit_handlers,[{lager_forwarder_backend,[lager_event,info]}]}]}, + {rabbit_log_mirroring_lager_event, + [{handlers,[{lager_forwarder_backend,[lager_event,info]}]}, + {rabbit_handlers,[{lager_forwarder_backend,[lager_event,info]}]}]}, + {rabbit_log_queue_lager_event, + [{handlers,[{lager_forwarder_backend,[lager_event,info]}]}, + {rabbit_handlers,[{lager_forwarder_backend,[lager_event,info]}]}]}, + {rabbit_log_upgrade_lager_event, + [{handlers,[{lager_forwarder_backend,[lager_event,info]}]}, + {rabbit_handlers,[{lager_forwarder_backend,[lager_event,info]}]}]} + ]. + + +sink_handlers_merged_with_lager_extra_sinks_handlers(_) -> + application:set_env(rabbit, log, [ + {file, [{file, "rabbit_file.log"}, {level, debug}]}, + {console, [{enabled, true}, {level, error}]}, + {categories, [ + {connection, [{level, debug}]}, + {channel, [{level, warning}, {file, "channel_log.log"}]} + ]} + ]), + + LagerSinks = [ + {rabbit_log_connection_lager_event, + [{handlers, + [{lager_file_backend, + [{file, "connection_lager.log"}, + {level, info}]}]}]}, + {rabbit_log_channel_lager_event, + [{handlers, + [{lager_console_backend, [{level, debug}]}, + {lager_file_backend, [{level, error}, + {file, "channel_lager.log"}]}]}]}], + application:set_env(lager, extra_sinks, LagerSinks), + + rabbit_lager:configure_lager(), + + ExpectedSinks = sort_sinks([ + {error_logger_lager_event, + [{handlers,[{lager_forwarder_backend,[lager_event,info]}]}, + {rabbit_handlers,[{lager_forwarder_backend,[lager_event,info]}]}]}, + {rabbit_log_channel_lager_event, + [{handlers,[ + {lager_console_backend, [{level, error}, + {formatter_config, formatter_config()}]}, + {lager_file_backend, + [{date, ""}, + {file, "channel_log.log"}, + {formatter_config, formatter_config()}, + {level, warning}, + {size, 0}]}, + {lager_console_backend, [{level, debug}]}, + {lager_file_backend, [{level, error}, + {file, "channel_lager.log"}]} + ]}, + {rabbit_handlers,[ + {lager_console_backend, [{level, error}, + {formatter_config, formatter_config()}]}, + {lager_file_backend, + [{date, ""}, + {file, "channel_log.log"}, + {formatter_config, formatter_config()}, + {level, warning}, + {size, 0}]}]} + ]}, + {rabbit_log_connection_lager_event, + [{handlers,[{lager_forwarder_backend,[lager_event,debug]}, + {lager_file_backend, [{file, "connection_lager.log"}, {level, info}]}]}, + {rabbit_handlers,[{lager_forwarder_backend,[lager_event,debug]}]}]}, + {rabbit_log_federation_lager_event, + [{handlers,[{lager_forwarder_backend,[lager_event,info]}]}, + {rabbit_handlers,[{lager_forwarder_backend,[lager_event,info]}]}]}, + {rabbit_log_lager_event, + [{handlers,[{lager_forwarder_backend,[lager_event,info]}]}, + {rabbit_handlers,[{lager_forwarder_backend,[lager_event,info]}]}]}, + {rabbit_log_mirroring_lager_event, + [{handlers,[{lager_forwarder_backend,[lager_event,info]}]}, + {rabbit_handlers,[{lager_forwarder_backend,[lager_event,info]}]}]}, + {rabbit_log_queue_lager_event, + [{handlers,[{lager_forwarder_backend,[lager_event,info]}]}, + {rabbit_handlers,[{lager_forwarder_backend,[lager_event,info]}]}]}, + {rabbit_log_upgrade_lager_event, + [{handlers,[{lager_forwarder_backend,[lager_event,info]}]}, + {rabbit_handlers,[{lager_forwarder_backend,[lager_event,info]}]}]}]), + + ct:pal("Expected ~p~n", [ExpectedSinks]), + ExpectedSinks = sort_sinks(application:get_env(lager, extra_sinks, undefined)). + + + +config_handlers_merged_with_lager_handlers(_) -> + application:set_env(rabbit, log, [ + {file, [{file, "rabbit_file.log"}, {level, debug}]}, + {console, [{enabled, true}, {level, error}]}, + {syslog, [{enabled, true}]} + ]), + + LagerHandlers = [ + {lager_file_backend, [{file, "lager_file.log"}, {level, info}]}, + {lager_console_backend, [{level, info}]} + ], + application:set_env(lager, handlers, LagerHandlers), + + rabbit_lager:configure_lager(), + + FileHandlers = default_expected_handlers("rabbit_file.log", debug), + ConsoleHandlers = expected_console_handler(error), + SyslogHandlers = expected_syslog_handler(), + + ExpectedRabbitHandlers = sort_handlers(FileHandlers ++ ConsoleHandlers ++ SyslogHandlers), + ExpectedHandlers = sort_handlers(ExpectedRabbitHandlers ++ LagerHandlers), + + ExpectedRabbitHandlers = sort_handlers(application:get_env(lager, rabbit_handlers, undefined)), + ExpectedHandlers = sort_handlers(application:get_env(lager, handlers, undefined)). + +config_sinks_level(_) -> + DefaultLogFile = "rabbit_default.log", + application:set_env(rabbit, lager_default_file, DefaultLogFile), + + application:set_env(rabbit, log, [ + {categories, [ + {connection, [{level, warning}]}, + {channel, [{level, debug}]}, + {mirroring, [{level, error}]} + ]} + ]), + + rabbit_lager:configure_lager(), + + ExpectedSinks = sort_sinks(level_sinks()), + ExpectedSinks = sort_sinks(application:get_env(lager, extra_sinks, undefined)). + +level_sinks() -> + [{error_logger_lager_event, + [{handlers,[{lager_forwarder_backend,[lager_event,info]}]}, + {rabbit_handlers,[{lager_forwarder_backend,[lager_event,info]}]}]}, + {rabbit_log_channel_lager_event, + [{handlers,[{lager_forwarder_backend,[lager_event,debug]}]}, + {rabbit_handlers,[{lager_forwarder_backend,[lager_event,debug]}]}]}, + {rabbit_log_connection_lager_event, + [{handlers,[{lager_forwarder_backend,[lager_event,warning]}]}, + {rabbit_handlers,[{lager_forwarder_backend,[lager_event,warning]}]}]}, + {rabbit_log_federation_lager_event, + [{handlers,[{lager_forwarder_backend,[lager_event,info]}]}, + {rabbit_handlers,[{lager_forwarder_backend,[lager_event,info]}]}]}, + {rabbit_log_lager_event, + [{handlers,[{lager_forwarder_backend,[lager_event,info]}]}, + {rabbit_handlers,[{lager_forwarder_backend,[lager_event,info]}]}]}, + {rabbit_log_mirroring_lager_event, + [{handlers,[{lager_forwarder_backend,[lager_event,error]}]}, + {rabbit_handlers,[{lager_forwarder_backend,[lager_event,error]}]}]}, + {rabbit_log_queue_lager_event, + [{handlers,[{lager_forwarder_backend,[lager_event,info]}]}, + {rabbit_handlers,[{lager_forwarder_backend,[lager_event,info]}]}]}, + {rabbit_log_upgrade_lager_event, + [{handlers,[{lager_forwarder_backend,[lager_event,info]}]}, + {rabbit_handlers,[{lager_forwarder_backend,[lager_event,info]}]}]} + ]. + +config_sink_file(_) -> + DefaultLogFile = "rabbit_default.log", + application:set_env(rabbit, lager_default_file, DefaultLogFile), + + application:set_env(rabbit, log, [ + {console, [{enabled, true}]}, + {file, [{level, error}]}, + {categories, [ + {connection, [{file, "connection.log"}, {level, warning}]} + ]} + ]), + + rabbit_lager:configure_lager(), + + ExpectedSinks = sort_sinks(file_sinks()), + ct:pal("Expected ~p~n", [ExpectedSinks]), + ExpectedSinks = sort_sinks(application:get_env(lager, extra_sinks, undefined)). + +config_sink_file_override_config_handler_file(_) -> + DefaultLogFile = "rabbit_default.log", + application:set_env(rabbit, lager_default_file, DefaultLogFile), + + NonDefaultLogFile = "rabbit_not_default.log", + + application:set_env(rabbit, log, [ + {file, [{file, NonDefaultLogFile}, {level, error}]}, + {console, [{enabled, true}]}, + {categories, [ + {connection, [{file, "connection.log"}, {level, warning}]} + ]} + ]), + + rabbit_lager:configure_lager(), + + ExpectedSinks = sort_sinks(file_sinks()), + ct:pal("Expected ~p~n", [ExpectedSinks]), + ExpectedSinks = sort_sinks(application:get_env(lager, extra_sinks, undefined)). + + +file_sinks() -> + [{error_logger_lager_event, + [{handlers,[{lager_forwarder_backend,[lager_event,info]}]}, + {rabbit_handlers,[{lager_forwarder_backend,[lager_event,info]}]}]}, + {rabbit_log_channel_lager_event, + [{handlers,[{lager_forwarder_backend,[lager_event,info]}]}, + {rabbit_handlers,[{lager_forwarder_backend,[lager_event,info]}]}]}, + {rabbit_log_connection_lager_event, + [{handlers,[ + {lager_console_backend, [{level, warning}, + {formatter_config, formatter_config()}]}, + {lager_file_backend, + [{date, ""}, + {file, "connection.log"}, + {formatter_config, formatter_config()}, + {level, error}, + {size, 0}]}]}, + {rabbit_handlers,[ + {lager_console_backend, [{level, warning}, + {formatter_config, formatter_config()}]}, + {lager_file_backend, + [{date, ""}, + {file, "connection.log"}, + {formatter_config, formatter_config()}, + {level, error}, + {size, 0}]}]} + ]}, + {rabbit_log_federation_lager_event, + [{handlers,[{lager_forwarder_backend,[lager_event,info]}]}, + {rabbit_handlers,[{lager_forwarder_backend,[lager_event,info]}]}]}, + {rabbit_log_lager_event, + [{handlers,[{lager_forwarder_backend,[lager_event,info]}]}, + {rabbit_handlers,[{lager_forwarder_backend,[lager_event,info]}]}]}, + {rabbit_log_mirroring_lager_event, + [{handlers,[{lager_forwarder_backend,[lager_event,info]}]}, + {rabbit_handlers,[{lager_forwarder_backend,[lager_event,info]}]}]}, + {rabbit_log_queue_lager_event, + [{handlers,[{lager_forwarder_backend,[lager_event,info]}]}, + {rabbit_handlers,[{lager_forwarder_backend,[lager_event,info]}]}]}, + {rabbit_log_upgrade_lager_event, + [{handlers,[{lager_forwarder_backend,[lager_event,info]}]}, + {rabbit_handlers,[{lager_forwarder_backend,[lager_event,info]}]}]} + ]. + + +config_multiple_handlers(_) -> + DefaultLogFile = "rabbit_default.log", + application:set_env(rabbit, lager_default_file, DefaultLogFile), + + application:set_env(rabbit, log, [ + %% Disable file output + {file, [{file, false}]}, + %% Enable console output + {console, [{enabled, true}]}, + %% Enable a syslog output + {syslog, [{enabled, true}, {level, error}]}]), + + rabbit_lager:configure_lager(), + + ConsoleHandlers = expected_console_handler(), + SyslogHandlers = expected_syslog_handler(error, "rabbitmq", daemon), + + ExpectedHandlers = sort_handlers(SyslogHandlers ++ ConsoleHandlers), + + ExpectedHandlers = sort_handlers(application:get_env(lager, handlers, undefined)), + ExpectedHandlers = sort_handlers(application:get_env(lager, rabbit_handlers, undefined)). + + +config_console_handler(_) -> + DefaultLogFile = "rabbit_default.log", + application:set_env(rabbit, lager_default_file, DefaultLogFile), + + application:set_env(rabbit, log, [{console, [{enabled, true}]}]), + + rabbit_lager:configure_lager(), + + FileHandlers = default_expected_handlers(DefaultLogFile), + ConsoleHandlers = expected_console_handler(), + + ExpectedHandlers = sort_handlers(FileHandlers ++ ConsoleHandlers), + + ExpectedHandlers = sort_handlers(application:get_env(lager, handlers, undefined)), + ExpectedHandlers = sort_handlers(application:get_env(lager, rabbit_handlers, undefined)). + +expected_console_handler() -> + expected_console_handler(info). + +expected_console_handler(Level) -> + [{lager_console_backend, [{level, Level}, + {formatter_config, formatter_config()}]}]. + +config_syslog_handler(_) -> + DefaultLogFile = "rabbit_default.log", + application:set_env(rabbit, lager_default_file, DefaultLogFile), + + application:set_env(rabbit, log, [{syslog, [{enabled, true}]}]), + + rabbit_lager:configure_lager(), + + FileHandlers = default_expected_handlers(DefaultLogFile), + SyslogHandlers = expected_syslog_handler(), + + ExpectedHandlers = sort_handlers(FileHandlers ++ SyslogHandlers), + + ExpectedHandlers = sort_handlers(application:get_env(lager, handlers, undefined)), + ExpectedHandlers = sort_handlers(application:get_env(lager, rabbit_handlers, undefined)). + +config_syslog_handler_options(_) -> + DefaultLogFile = "rabbit_default.log", + application:set_env(rabbit, lager_default_file, DefaultLogFile), + + application:set_env(rabbit, log, [{syslog, [{enabled, true}, + {identity, "foo"}, + {facility, local1}, + {level, warning}]}]), + + rabbit_lager:configure_lager(), + + FileHandlers = default_expected_handlers(DefaultLogFile), + SyslogHandlers = expected_syslog_handler(warning, "foo", local1), + + ExpectedHandlers = sort_handlers(FileHandlers ++ SyslogHandlers), + + ExpectedHandlers = sort_handlers(application:get_env(lager, handlers, undefined)), + ExpectedHandlers = sort_handlers(application:get_env(lager, rabbit_handlers, undefined)). + +expected_syslog_handler() -> + expected_syslog_handler(info, "rabbitmq", daemon). + +expected_syslog_handler(Level, Identity, Facility) -> + [{lager_syslog_backend, [{level, Level}, + {facility, Facility}, + {formatter_config, formatter_config()}, + {identity, Identity}]}]. + +env_var_overrides_config(_) -> + EnvLogFile = "rabbit_default.log", + application:set_env(rabbit, lager_default_file, EnvLogFile), + + ConfigLogFile = "rabbit_not_default.log", + application:set_env(rabbit, log, [{file, [{file, ConfigLogFile}]}]), + + os:putenv("RABBITMQ_LOGS_source", "environment"), + + rabbit_lager:configure_lager(), + + ExpectedHandlers = default_expected_handlers(EnvLogFile), + ExpectedHandlers = sort_handlers(application:get_env(lager, handlers, undefined)), + ExpectedHandlers = sort_handlers(application:get_env(lager, rabbit_handlers, undefined)). + +env_var_disable_log(_) -> + application:set_env(rabbit, lager_default_file, false), + + ConfigLogFile = "rabbit_not_default.log", + application:set_env(rabbit, log, [{file, [{file, ConfigLogFile}]}]), + + os:putenv("RABBITMQ_LOGS_source", "environment"), + + rabbit_lager:configure_lager(), + + ExpectedHandlers = [], + ExpectedHandlers = sort_handlers(application:get_env(lager, handlers, undefined)), + ExpectedHandlers = sort_handlers(application:get_env(lager, rabbit_handlers, undefined)). + +config_file_handler(_) -> + DefaultLogFile = "rabbit_default.log", + application:set_env(rabbit, lager_default_file, DefaultLogFile), + + NonDefaultLogFile = "rabbit_not_default.log", + application:set_env(rabbit, log, [{file, [{file, NonDefaultLogFile}]}]), + + rabbit_lager:configure_lager(), + + ExpectedHandlers = default_expected_handlers(NonDefaultLogFile), + ExpectedHandlers = sort_handlers(application:get_env(lager, handlers, undefined)), + ExpectedHandlers = sort_handlers(application:get_env(lager, rabbit_handlers, undefined)). + +config_file_handler_level(_) -> + DefaultLogFile = "rabbit_default.log", + application:set_env(rabbit, lager_default_file, DefaultLogFile), + + application:set_env(rabbit, log, [{file, [{level, warning}]}]), + + rabbit_lager:configure_lager(), + + ExpectedHandlers = default_expected_handlers(DefaultLogFile, warning), + ExpectedHandlers = sort_handlers(application:get_env(lager, handlers, undefined)), + ExpectedHandlers = sort_handlers(application:get_env(lager, rabbit_handlers, undefined)). + +config_file_handler_rotation(_) -> + DefaultLogFile = "rabbit_default.log", + application:set_env(rabbit, lager_default_file, DefaultLogFile), + + application:set_env(rabbit, log, [{file, [{date, "$D0"}, {size, 5000}, {count, 10}]}]), + + rabbit_lager:configure_lager(), + + ExpectedHandlers = sort_handlers(default_expected_handlers(DefaultLogFile, info, 5000, "$D0", [{count, 10}])), + ExpectedHandlers = sort_handlers(application:get_env(lager, handlers, undefined)), + ExpectedHandlers = sort_handlers(application:get_env(lager, rabbit_handlers, undefined)). + +default(_) -> + LogRoot = "/tmp/log_base", + application:set_env(rabbit, lager_log_root, LogRoot), + LogFile = "rabbit_default.log", + application:set_env(rabbit, lager_default_file, LogFile), + LogUpgradeFile = "rabbit_default_upgrade.log", + application:set_env(rabbit, lager_upgrade_file, LogUpgradeFile), + + rabbit_lager:configure_lager(), + + ExpectedHandlers = default_expected_handlers(LogFile), + LogRoot = application:get_env(lager, log_root, undefined), + ExpectedHandlers = sort_handlers(application:get_env(lager, handlers, undefined)), + ExpectedHandlers = sort_handlers(application:get_env(lager, rabbit_handlers, undefined)), + + ExpectedSinks = default_expected_sinks(LogUpgradeFile), + ExpectedSinks = sort_sinks(application:get_env(lager, extra_sinks, undefined)). + + +default_expected_handlers(File) -> + default_expected_handlers(File, info, 0, ""). +default_expected_handlers(File, Level) -> + default_expected_handlers(File, Level, 0, ""). +default_expected_handlers(File, Level, RotSize, RotDate) -> + default_expected_handlers(File, Level, RotSize, RotDate, []). +default_expected_handlers(File, Level, RotSize, RotDate, Extra) -> + [{lager_file_backend, + [{date, RotDate}, + {file, File}, + {formatter_config, formatter_config()}, + {level, Level}, + {size, RotSize}] ++ Extra}]. + +default_expected_sinks(UpgradeFile) -> + [{error_logger_lager_event, + [{handlers,[{lager_forwarder_backend,[lager_event,info]}]}, + {rabbit_handlers,[{lager_forwarder_backend,[lager_event,info]}]}]}, + {rabbit_log_channel_lager_event, + [{handlers,[{lager_forwarder_backend,[lager_event,info]}]}, + {rabbit_handlers,[{lager_forwarder_backend,[lager_event,info]}]}]}, + {rabbit_log_connection_lager_event, + [{handlers,[{lager_forwarder_backend,[lager_event,info]}]}, + {rabbit_handlers,[{lager_forwarder_backend,[lager_event,info]}]}]}, + {rabbit_log_federation_lager_event, + [{handlers,[{lager_forwarder_backend,[lager_event,info]}]}, + {rabbit_handlers,[{lager_forwarder_backend,[lager_event,info]}]}]}, + {rabbit_log_lager_event, + [{handlers,[{lager_forwarder_backend,[lager_event,info]}]}, + {rabbit_handlers,[{lager_forwarder_backend,[lager_event,info]}]}]}, + {rabbit_log_mirroring_lager_event, + [{handlers,[{lager_forwarder_backend,[lager_event,info]}]}, + {rabbit_handlers,[{lager_forwarder_backend,[lager_event,info]}]}]}, + {rabbit_log_queue_lager_event, + [{handlers,[{lager_forwarder_backend,[lager_event,info]}]}, + {rabbit_handlers,[{lager_forwarder_backend,[lager_event,info]}]}]}, + {rabbit_log_upgrade_lager_event, + [{handlers, + [{lager_file_backend, + [{date,[]}, + {file, UpgradeFile}, + {formatter_config, formatter_config()}, + {level,info}, + {size,0}]}]}, + {rabbit_handlers, + [{lager_file_backend, + [{date,[]}, + {file, UpgradeFile}, + {formatter_config, formatter_config()}, + {level,info}, + {size,0}]}]}]}]. + +env_var_tty(_) -> + application:set_env(rabbit, lager_log_root, "/tmp/log_base"), + application:set_env(rabbit, lager_default_file, tty), + application:set_env(rabbit, lager_upgrade_file, tty), + %% tty can only be set explicitely + os:putenv("RABBITMQ_LOGS_source", "environment"), + + rabbit_lager:configure_lager(), + + ExpectedHandlers = tty_expected_handlers(), + ExpectedHandlers = sort_handlers(application:get_env(lager, handlers, undefined)), + ExpectedHandlers = sort_handlers(application:get_env(lager, rabbit_handlers, undefined)), + + %% Upgrade sink will be different. + ExpectedSinks = tty_expected_sinks(), + ExpectedSinks = sort_sinks(application:get_env(lager, extra_sinks, undefined)). + +tty_expected_handlers() -> + [{lager_console_backend, + [{formatter_config, formatter_config()}, + {level, info}]}]. + +tty_expected_sinks() -> + [{error_logger_lager_event, + [{handlers,[{lager_forwarder_backend,[lager_event,info]}]}, + {rabbit_handlers,[{lager_forwarder_backend,[lager_event,info]}]}]}, + {rabbit_log_channel_lager_event, + [{handlers,[{lager_forwarder_backend,[lager_event,info]}]}, + {rabbit_handlers,[{lager_forwarder_backend,[lager_event,info]}]}]}, + {rabbit_log_connection_lager_event, + [{handlers,[{lager_forwarder_backend,[lager_event,info]}]}, + {rabbit_handlers,[{lager_forwarder_backend,[lager_event,info]}]}]}, + {rabbit_log_federation_lager_event, + [{handlers,[{lager_forwarder_backend,[lager_event,info]}]}, + {rabbit_handlers,[{lager_forwarder_backend,[lager_event,info]}]}]}, + {rabbit_log_lager_event, + [{handlers, [{lager_forwarder_backend,[lager_event,info]}]}, + {rabbit_handlers, [{lager_forwarder_backend,[lager_event,info]}]}]}, + {rabbit_log_mirroring_lager_event, + [{handlers,[{lager_forwarder_backend,[lager_event,info]}]}, + {rabbit_handlers,[{lager_forwarder_backend,[lager_event,info]}]}]}, + {rabbit_log_queue_lager_event, + [{handlers,[{lager_forwarder_backend,[lager_event,info]}]}, + {rabbit_handlers,[{lager_forwarder_backend,[lager_event,info]}]}]}, + {rabbit_log_upgrade_lager_event, + [{handlers,[{lager_forwarder_backend,[lager_event,info]}]}, + {rabbit_handlers,[{lager_forwarder_backend,[lager_event,info]}]}]}]. + +sort_sinks(Sinks) -> + lists:ukeysort(1, + lists:map( + fun({Name, Config}) -> + Handlers = proplists:get_value(handlers, Config), + RabbitHandlers = proplists:get_value(rabbit_handlers, Config), + {Name, lists:ukeymerge(1, + [{handlers, sort_handlers(Handlers)}, + {rabbit_handlers, sort_handlers(RabbitHandlers)}], + lists:ukeysort(1, Config))} + end, + Sinks)). + +sort_handlers(Handlers) -> + lists:keysort(1, + lists:map( + fun + ({Name, [{Atom, _}|_] = Config}) when is_atom(Atom) -> + {Name, lists:ukeysort(1, Config)}; + %% Non-proplist configuration. forwarder backend + (Other) -> + ct:pal("Skip sort ~p~n", [Other]), + Other + end, + Handlers)). + +formatter_config() -> + [date," ",time," ",color,"[",severity, "] ", {pid,[]}, " ",message,"\n"]. + From c4619d8298ef0b3341713045cf3099aac59f8f4a Mon Sep 17 00:00:00 2001 From: Michael Klishin Date: Mon, 21 Aug 2017 15:31:26 -0400 Subject: [PATCH 3/4] Wording --- src/rabbit_lager.erl | 8 ++++---- 1 file changed, 4 insertions(+), 4 deletions(-) diff --git a/src/rabbit_lager.erl b/src/rabbit_lager.erl index b9dee6c62385..db45b610725b 100644 --- a/src/rabbit_lager.erl +++ b/src/rabbit_lager.erl @@ -206,16 +206,16 @@ configure_lager() -> {[], []} -> []; {[], LogLevels} -> io:format("Using deprecated config parameter 'log_levels'. " - "Please update your configuration file according to: " + "Please update your configuration file according to " "https://rabbitmq.com/logging.html"), lists:map(fun({Name, Level}) -> {Name, [{level, Level}]} end, LogLevels); {Categories, []} -> Categories; {Categories, LogLevels} -> - io:format("Using the deprecated config parameter 'log_levels' together " - "with the new parameter 'categories'." - " 'log_levels' will be ignored. Please remove 'log_levels' " + io:format("Using the deprecated config parameter 'rabbit.log_levels' together " + "with a new parameter for log categories." + " 'rabbit.log_levels' will be ignored. Please remove it from the config. More at " "https://rabbitmq.com/logging.html"), Categories end, From f3f09fb028bcdb2b28fa51840b28862ede54ecac Mon Sep 17 00:00:00 2001 From: Michael Klishin Date: Mon, 21 Aug 2017 19:34:54 -0400 Subject: [PATCH 4/4] Use ?assertEquals where possible --- test/unit_log_config_SUITE.erl | 75 ++++++++++++++-------------------- 1 file changed, 30 insertions(+), 45 deletions(-) diff --git a/test/unit_log_config_SUITE.erl b/test/unit_log_config_SUITE.erl index feeebe57cfc9..c5a94177232e 100644 --- a/test/unit_log_config_SUITE.erl +++ b/test/unit_log_config_SUITE.erl @@ -85,12 +85,10 @@ sink_file_rewrites_file_backends(_) -> {lager_console_backend, [{level, info}]} ], application:set_env(lager, handlers, LagerHandlers), - rabbit_lager:configure_lager(), ExpectedSinks = sort_sinks(sink_rewrite_sinks()), - - ExpectedSinks = sort_sinks(application:get_env(lager, extra_sinks, undefined)). + ?assertEqual(ExpectedSinks, sort_sinks(application:get_env(lager, extra_sinks, undefined))). sink_rewrite_sinks() -> [{error_logger_lager_event, @@ -157,8 +155,8 @@ sink_handlers_merged_with_lager_extra_sinks_handlers(_) -> [{lager_console_backend, [{level, debug}]}, {lager_file_backend, [{level, error}, {file, "channel_lager.log"}]}]}]}], - application:set_env(lager, extra_sinks, LagerSinks), + application:set_env(lager, extra_sinks, LagerSinks), rabbit_lager:configure_lager(), ExpectedSinks = sort_sinks([ @@ -209,8 +207,7 @@ sink_handlers_merged_with_lager_extra_sinks_handlers(_) -> [{handlers,[{lager_forwarder_backend,[lager_event,info]}]}, {rabbit_handlers,[{lager_forwarder_backend,[lager_event,info]}]}]}]), - ct:pal("Expected ~p~n", [ExpectedSinks]), - ExpectedSinks = sort_sinks(application:get_env(lager, extra_sinks, undefined)). + ?assertEqual(ExpectedSinks, sort_sinks(application:get_env(lager, extra_sinks, undefined))). @@ -226,7 +223,6 @@ config_handlers_merged_with_lager_handlers(_) -> {lager_console_backend, [{level, info}]} ], application:set_env(lager, handlers, LagerHandlers), - rabbit_lager:configure_lager(), FileHandlers = default_expected_handlers("rabbit_file.log", debug), @@ -236,8 +232,8 @@ config_handlers_merged_with_lager_handlers(_) -> ExpectedRabbitHandlers = sort_handlers(FileHandlers ++ ConsoleHandlers ++ SyslogHandlers), ExpectedHandlers = sort_handlers(ExpectedRabbitHandlers ++ LagerHandlers), - ExpectedRabbitHandlers = sort_handlers(application:get_env(lager, rabbit_handlers, undefined)), - ExpectedHandlers = sort_handlers(application:get_env(lager, handlers, undefined)). + ?assertEqual(ExpectedRabbitHandlers, sort_handlers(application:get_env(lager, rabbit_handlers, undefined))), + ?assertEqual(ExpectedHandlers, sort_handlers(application:get_env(lager, handlers, undefined))). config_sinks_level(_) -> DefaultLogFile = "rabbit_default.log", @@ -298,8 +294,7 @@ config_sink_file(_) -> rabbit_lager:configure_lager(), ExpectedSinks = sort_sinks(file_sinks()), - ct:pal("Expected ~p~n", [ExpectedSinks]), - ExpectedSinks = sort_sinks(application:get_env(lager, extra_sinks, undefined)). + ?assertEqual(ExpectedSinks, sort_sinks(application:get_env(lager, extra_sinks, undefined))). config_sink_file_override_config_handler_file(_) -> DefaultLogFile = "rabbit_default.log", @@ -318,8 +313,7 @@ config_sink_file_override_config_handler_file(_) -> rabbit_lager:configure_lager(), ExpectedSinks = sort_sinks(file_sinks()), - ct:pal("Expected ~p~n", [ExpectedSinks]), - ExpectedSinks = sort_sinks(application:get_env(lager, extra_sinks, undefined)). + ?assertEqual(ExpectedSinks, sort_sinks(application:get_env(lager, extra_sinks, undefined))). file_sinks() -> @@ -386,14 +380,13 @@ config_multiple_handlers(_) -> ExpectedHandlers = sort_handlers(SyslogHandlers ++ ConsoleHandlers), - ExpectedHandlers = sort_handlers(application:get_env(lager, handlers, undefined)), - ExpectedHandlers = sort_handlers(application:get_env(lager, rabbit_handlers, undefined)). + ?assertEqual(ExpectedHandlers, sort_handlers(application:get_env(lager, handlers, undefined))), + ?assertEqual(ExpectedHandlers, sort_handlers(application:get_env(lager, rabbit_handlers, undefined))). config_console_handler(_) -> DefaultLogFile = "rabbit_default.log", application:set_env(rabbit, lager_default_file, DefaultLogFile), - application:set_env(rabbit, log, [{console, [{enabled, true}]}]), rabbit_lager:configure_lager(), @@ -403,8 +396,8 @@ config_console_handler(_) -> ExpectedHandlers = sort_handlers(FileHandlers ++ ConsoleHandlers), - ExpectedHandlers = sort_handlers(application:get_env(lager, handlers, undefined)), - ExpectedHandlers = sort_handlers(application:get_env(lager, rabbit_handlers, undefined)). + ?assertEqual(ExpectedHandlers, sort_handlers(application:get_env(lager, handlers, undefined))), + ?assertEqual(ExpectedHandlers, sort_handlers(application:get_env(lager, rabbit_handlers, undefined))). expected_console_handler() -> expected_console_handler(info). @@ -416,7 +409,6 @@ expected_console_handler(Level) -> config_syslog_handler(_) -> DefaultLogFile = "rabbit_default.log", application:set_env(rabbit, lager_default_file, DefaultLogFile), - application:set_env(rabbit, log, [{syslog, [{enabled, true}]}]), rabbit_lager:configure_lager(), @@ -426,13 +418,12 @@ config_syslog_handler(_) -> ExpectedHandlers = sort_handlers(FileHandlers ++ SyslogHandlers), - ExpectedHandlers = sort_handlers(application:get_env(lager, handlers, undefined)), - ExpectedHandlers = sort_handlers(application:get_env(lager, rabbit_handlers, undefined)). + ?assertEqual(ExpectedHandlers, sort_handlers(application:get_env(lager, handlers, undefined))), + ?assertEqual(ExpectedHandlers, sort_handlers(application:get_env(lager, rabbit_handlers, undefined))). config_syslog_handler_options(_) -> DefaultLogFile = "rabbit_default.log", application:set_env(rabbit, lager_default_file, DefaultLogFile), - application:set_env(rabbit, log, [{syslog, [{enabled, true}, {identity, "foo"}, {facility, local1}, @@ -445,8 +436,8 @@ config_syslog_handler_options(_) -> ExpectedHandlers = sort_handlers(FileHandlers ++ SyslogHandlers), - ExpectedHandlers = sort_handlers(application:get_env(lager, handlers, undefined)), - ExpectedHandlers = sort_handlers(application:get_env(lager, rabbit_handlers, undefined)). + ?assertEqual(ExpectedHandlers, sort_handlers(application:get_env(lager, handlers, undefined))), + ?assertEqual(ExpectedHandlers, sort_handlers(application:get_env(lager, rabbit_handlers, undefined))). expected_syslog_handler() -> expected_syslog_handler(info, "rabbitmq", daemon). @@ -465,12 +456,11 @@ env_var_overrides_config(_) -> application:set_env(rabbit, log, [{file, [{file, ConfigLogFile}]}]), os:putenv("RABBITMQ_LOGS_source", "environment"), - rabbit_lager:configure_lager(), ExpectedHandlers = default_expected_handlers(EnvLogFile), - ExpectedHandlers = sort_handlers(application:get_env(lager, handlers, undefined)), - ExpectedHandlers = sort_handlers(application:get_env(lager, rabbit_handlers, undefined)). + ?assertEqual(ExpectedHandlers, sort_handlers(application:get_env(lager, handlers, undefined))), + ?assertEqual(ExpectedHandlers, sort_handlers(application:get_env(lager, rabbit_handlers, undefined))). env_var_disable_log(_) -> application:set_env(rabbit, lager_default_file, false), @@ -479,12 +469,11 @@ env_var_disable_log(_) -> application:set_env(rabbit, log, [{file, [{file, ConfigLogFile}]}]), os:putenv("RABBITMQ_LOGS_source", "environment"), - rabbit_lager:configure_lager(), ExpectedHandlers = [], - ExpectedHandlers = sort_handlers(application:get_env(lager, handlers, undefined)), - ExpectedHandlers = sort_handlers(application:get_env(lager, rabbit_handlers, undefined)). + ?assertEqual(ExpectedHandlers, sort_handlers(application:get_env(lager, handlers, undefined))), + ?assertEqual(ExpectedHandlers, sort_handlers(application:get_env(lager, rabbit_handlers, undefined))). config_file_handler(_) -> DefaultLogFile = "rabbit_default.log", @@ -496,32 +485,30 @@ config_file_handler(_) -> rabbit_lager:configure_lager(), ExpectedHandlers = default_expected_handlers(NonDefaultLogFile), - ExpectedHandlers = sort_handlers(application:get_env(lager, handlers, undefined)), - ExpectedHandlers = sort_handlers(application:get_env(lager, rabbit_handlers, undefined)). + ?assertEqual(ExpectedHandlers, sort_handlers(application:get_env(lager, handlers, undefined))), + ?assertEqual(ExpectedHandlers, sort_handlers(application:get_env(lager, rabbit_handlers, undefined))). config_file_handler_level(_) -> DefaultLogFile = "rabbit_default.log", application:set_env(rabbit, lager_default_file, DefaultLogFile), application:set_env(rabbit, log, [{file, [{level, warning}]}]), - rabbit_lager:configure_lager(), ExpectedHandlers = default_expected_handlers(DefaultLogFile, warning), - ExpectedHandlers = sort_handlers(application:get_env(lager, handlers, undefined)), - ExpectedHandlers = sort_handlers(application:get_env(lager, rabbit_handlers, undefined)). + ?assertEqual(ExpectedHandlers, sort_handlers(application:get_env(lager, handlers, undefined))), + ?assertEqual(ExpectedHandlers, sort_handlers(application:get_env(lager, rabbit_handlers, undefined))). config_file_handler_rotation(_) -> DefaultLogFile = "rabbit_default.log", application:set_env(rabbit, lager_default_file, DefaultLogFile), application:set_env(rabbit, log, [{file, [{date, "$D0"}, {size, 5000}, {count, 10}]}]), - rabbit_lager:configure_lager(), ExpectedHandlers = sort_handlers(default_expected_handlers(DefaultLogFile, info, 5000, "$D0", [{count, 10}])), - ExpectedHandlers = sort_handlers(application:get_env(lager, handlers, undefined)), - ExpectedHandlers = sort_handlers(application:get_env(lager, rabbit_handlers, undefined)). + ?assertEqual(ExpectedHandlers, sort_handlers(application:get_env(lager, handlers, undefined))), + ?assertEqual(ExpectedHandlers, sort_handlers(application:get_env(lager, rabbit_handlers, undefined))). default(_) -> LogRoot = "/tmp/log_base", @@ -536,10 +523,10 @@ default(_) -> ExpectedHandlers = default_expected_handlers(LogFile), LogRoot = application:get_env(lager, log_root, undefined), ExpectedHandlers = sort_handlers(application:get_env(lager, handlers, undefined)), - ExpectedHandlers = sort_handlers(application:get_env(lager, rabbit_handlers, undefined)), + ?assertEqual(ExpectedHandlers, sort_handlers(application:get_env(lager, rabbit_handlers, undefined))), ExpectedSinks = default_expected_sinks(LogUpgradeFile), - ExpectedSinks = sort_sinks(application:get_env(lager, extra_sinks, undefined)). + ?assertEqual(ExpectedSinks, sort_sinks(application:get_env(lager, extra_sinks, undefined))). default_expected_handlers(File) -> @@ -604,12 +591,12 @@ env_var_tty(_) -> rabbit_lager:configure_lager(), ExpectedHandlers = tty_expected_handlers(), - ExpectedHandlers = sort_handlers(application:get_env(lager, handlers, undefined)), - ExpectedHandlers = sort_handlers(application:get_env(lager, rabbit_handlers, undefined)), + ?assertEqual(ExpectedHandlers, sort_handlers(application:get_env(lager, handlers, undefined))), + ?assertEqual(ExpectedHandlers, sort_handlers(application:get_env(lager, rabbit_handlers, undefined))), %% Upgrade sink will be different. ExpectedSinks = tty_expected_sinks(), - ExpectedSinks = sort_sinks(application:get_env(lager, extra_sinks, undefined)). + ?assertEqual(ExpectedSinks, sort_sinks(application:get_env(lager, extra_sinks, undefined))). tty_expected_handlers() -> [{lager_console_backend, @@ -663,11 +650,9 @@ sort_handlers(Handlers) -> {Name, lists:ukeysort(1, Config)}; %% Non-proplist configuration. forwarder backend (Other) -> - ct:pal("Skip sort ~p~n", [Other]), Other end, Handlers)). formatter_config() -> [date," ",time," ",color,"[",severity, "] ", {pid,[]}, " ",message,"\n"]. -