rabbitmq-server/deps/rabbitmq_cli/test/diagnostics/log_tail_command_test.exs

Ignoring revisions in .git-blame-ignore-revs. Click here to bypass and see the normal blame view.

126 lines
3.4 KiB
Elixir
Raw Normal View History

## This Source Code Form is subject to the terms of the Mozilla Public
## License, v. 2.0. If a copy of the MPL was not distributed with this
## file, You can obtain one at https://mozilla.org/MPL/2.0/.
2019-06-28 01:46:08 +08:00
##
2020-03-10 22:39:56 +08:00
## Copyright (c) 2007-2020 VMware, Inc. or its affiliates. All rights reserved.
2019-06-28 01:46:08 +08:00
defmodule LogTailCommandTest do
use ExUnit.Case, async: false
2019-06-28 01:46:08 +08:00
import TestHelper
@command RabbitMQ.CLI.Diagnostics.Commands.LogTailCommand
setup_all do
RabbitMQ.CLI.Core.Distribution.start()
start_rabbitmq_app()
2022-10-03 01:54:11 +08:00
ExUnit.configure(max_cases: 1)
2019-06-28 01:46:08 +08:00
on_exit([], fn ->
start_rabbitmq_app()
end)
:ok
end
setup context do
2022-10-03 01:54:11 +08:00
{:ok,
opts: %{
node: get_rabbit_hostname(),
timeout: context[:test_timeout] || 30000,
number: 50
}}
2019-06-28 01:46:08 +08:00
end
2019-07-06 18:47:39 +08:00
test "merge_defaults: number is 50" do
assert @command.merge_defaults([], %{}) == {[], %{number: 50}}
2019-06-28 01:46:08 +08:00
end
test "validate: treats positional arguments as a failure" do
assert @command.validate(["extra-arg"], %{}) == {:validation_failure, :too_many_args}
end
test "validate: treats empty positional arguments and default switches as a success", context do
assert @command.validate([], context[:opts]) == :ok
end
@tag test_timeout: 3000
test "run: targeting an unreachable node throws a badrpc", context do
2022-10-03 01:54:11 +08:00
assert match?(
{:badrpc, _},
@command.run([], Map.merge(context[:opts], %{node: :jake@thedog, timeout: 100}))
)
2019-06-28 01:46:08 +08:00
end
2019-07-06 18:47:39 +08:00
test "run: shows last 50 lines from the log by default", context do
clear_log_files()
2022-10-03 01:54:11 +08:00
2019-06-28 01:46:08 +08:00
log_messages =
2022-10-03 01:54:11 +08:00
Enum.map(
:lists.seq(1, 50),
fn n ->
message = "Getting log tail #{n}"
:rpc.call(get_rabbit_hostname(), :rabbit_log, :error, [to_charlist(message)])
message
end
)
2019-07-06 18:47:39 +08:00
wait_for_log_message("Getting log tail 50")
2019-06-28 01:46:08 +08:00
lines = @command.run([], context[:opts])
2019-07-06 18:47:39 +08:00
assert Enum.count(lines) == 50
2019-06-28 01:46:08 +08:00
2022-10-03 01:54:11 +08:00
Enum.map(
Enum.zip(log_messages, lines),
fn {message, line} ->
assert String.match?(line, Regex.compile!(message))
end
)
2019-06-28 01:46:08 +08:00
end
test "run: returns N lines", context do
## Log a bunch of lines
2022-10-03 01:54:11 +08:00
Enum.map(
:lists.seq(1, 50),
fn n ->
message = "More lines #{n}"
:rpc.call(get_rabbit_hostname(), :rabbit_log, :error, [to_charlist(message)])
message
end
)
wait_for_log_message("More lines 50")
assert Enum.count(@command.run([], Map.merge(context[:opts], %{number: 20}))) == 20
assert Enum.count(@command.run([], Map.merge(context[:opts], %{number: 30}))) == 30
assert Enum.count(@command.run([], Map.merge(context[:opts], %{number: 40}))) == 40
2019-06-28 01:46:08 +08:00
end
test "run: may return less than N lines if N is high", context do
2019-07-06 18:47:39 +08:00
clear_log_files()
2019-06-28 01:46:08 +08:00
## Log a bunch of lines
2022-10-03 01:54:11 +08:00
Enum.map(
:lists.seq(1, 100),
fn n ->
message = "More lines #{n}"
:rpc.call(get_rabbit_hostname(), :rabbit_log, :error, [to_charlist(message)])
message
end
)
2019-06-28 01:46:08 +08:00
wait_for_log_message("More lines 50")
assert Enum.count(@command.run([], Map.merge(context[:opts], %{number: 50}))) == 50
assert Enum.count(@command.run([], Map.merge(context[:opts], %{number: 200}))) < 200
end
2019-07-06 18:47:39 +08:00
def clear_log_files() do
2022-10-03 01:54:11 +08:00
[_ | _] = logs = :rpc.call(get_rabbit_hostname(), :rabbit, :log_locations, [])
Enum.map(logs, fn log ->
Switch from Lager to the new Erlang Logger API for logging The configuration remains the same for the end-user. The only exception is the log root directory: it is now set through the `log_root` application env. variable in `rabbit`. People using the Cuttlefish-based configuration file are not affected by this exception. The main change is how the logging facility is configured. It now happens in `rabbit_prelaunch_logging`. The `rabbit_lager` module is removed. The supported outputs remain the same: the console, text files, the `amq.rabbitmq.log` exchange and syslog. The message text format slightly changed: the timestamp is more precise (now to the microsecond) and the level can be abbreviated to always be 4-character long to align all messages and improve readability. Here is an example: 2021-03-03 10:22:30.377392+01:00 [dbug] <0.229.0> == Prelaunch DONE == 2021-03-03 10:22:30.377860+01:00 [info] <0.229.0> 2021-03-03 10:22:30.377860+01:00 [info] <0.229.0> Starting RabbitMQ 3.8.10+115.g071f3fb on Erlang 23.2.5 2021-03-03 10:22:30.377860+01:00 [info] <0.229.0> Licensed under the MPL 2.0. Website: https://rabbitmq.com The example above also shows that multiline messages are supported and each line is prepended with the same prefix (the timestamp, the level and the Erlang process PID). JSON is also supported as a message format and now for any outputs. Indeed, it is possible to use it with e.g. syslog or the exchange. Here is an example of a JSON-formatted message sent to syslog: Mar 3 11:23:06 localhost rabbitmq-server[27908] <0.229.0> - {"time":"2021-03-03T11:23:06.998466+01:00","level":"notice","msg":"Logging: configured log handlers are now ACTIVE","meta":{"domain":"rabbitmq.prelaunch","file":"src/rabbit_prelaunch_logging.erl","gl":"<0.228.0>","line":311,"mfa":["rabbit_prelaunch_logging","configure_logger",1],"pid":"<0.229.0>"}} For quick testing, the values accepted by the `$RABBITMQ_LOGS` environment variables were extended: * `-` still means stdout * `-stderr` means stderr * `syslog:` means syslog on localhost * `exchange:` means logging to `amq.rabbitmq.log` `$RABBITMQ_LOG` was also extended. It now accepts a `+json` modifier (in addition to the existing `+color` one). With that modifier, messages are formatted as JSON intead of plain text. The `rabbitmqctl rotate_logs` command is deprecated. The reason is Logger does not expose a function to force log rotation. However, it will detect when a file was rotated by an external tool. From a developer point of view, the old `rabbit_log*` API remains supported, though it is now deprecated. It is implemented as regular modules: there is no `parse_transform` involved anymore. In the code, it is recommended to use the new Logger macros. For instance, `?LOG_INFO(Format, Args)`. If possible, messages should be augmented with some metadata. For instance (note the map after the message): ?LOG_NOTICE("Logging: switching to configured handler(s); following " "messages may not be visible in this log output", #{domain => ?RMQLOG_DOMAIN_PRELAUNCH}), Domains in Erlang Logger parlance are the way to categorize messages. Some predefined domains, matching previous categories, are currently defined in `rabbit_common/include/logging.hrl` or headers in the relevant plugins for plugin-specific categories. At this point, very few messages have been converted from the old `rabbit_log*` API to the new macros. It can be done gradually when working on a particular module or logging. The Erlang builtin console/file handler, `logger_std_h`, has been forked because it lacks date-based file rotation. The configuration of date-based rotation is identical to Lager. Once the dust has settled for this feature, the goal is to submit it upstream for inclusion in Erlang. The forked module is calld `rabbit_logger_std_h` and is based `logger_std_h` in Erlang 23.0.
2021-01-13 00:55:27 +08:00
case log do
'<stdout>' -> :ok
2022-10-03 01:54:11 +08:00
_ -> File.write(log, "")
Switch from Lager to the new Erlang Logger API for logging The configuration remains the same for the end-user. The only exception is the log root directory: it is now set through the `log_root` application env. variable in `rabbit`. People using the Cuttlefish-based configuration file are not affected by this exception. The main change is how the logging facility is configured. It now happens in `rabbit_prelaunch_logging`. The `rabbit_lager` module is removed. The supported outputs remain the same: the console, text files, the `amq.rabbitmq.log` exchange and syslog. The message text format slightly changed: the timestamp is more precise (now to the microsecond) and the level can be abbreviated to always be 4-character long to align all messages and improve readability. Here is an example: 2021-03-03 10:22:30.377392+01:00 [dbug] <0.229.0> == Prelaunch DONE == 2021-03-03 10:22:30.377860+01:00 [info] <0.229.0> 2021-03-03 10:22:30.377860+01:00 [info] <0.229.0> Starting RabbitMQ 3.8.10+115.g071f3fb on Erlang 23.2.5 2021-03-03 10:22:30.377860+01:00 [info] <0.229.0> Licensed under the MPL 2.0. Website: https://rabbitmq.com The example above also shows that multiline messages are supported and each line is prepended with the same prefix (the timestamp, the level and the Erlang process PID). JSON is also supported as a message format and now for any outputs. Indeed, it is possible to use it with e.g. syslog or the exchange. Here is an example of a JSON-formatted message sent to syslog: Mar 3 11:23:06 localhost rabbitmq-server[27908] <0.229.0> - {"time":"2021-03-03T11:23:06.998466+01:00","level":"notice","msg":"Logging: configured log handlers are now ACTIVE","meta":{"domain":"rabbitmq.prelaunch","file":"src/rabbit_prelaunch_logging.erl","gl":"<0.228.0>","line":311,"mfa":["rabbit_prelaunch_logging","configure_logger",1],"pid":"<0.229.0>"}} For quick testing, the values accepted by the `$RABBITMQ_LOGS` environment variables were extended: * `-` still means stdout * `-stderr` means stderr * `syslog:` means syslog on localhost * `exchange:` means logging to `amq.rabbitmq.log` `$RABBITMQ_LOG` was also extended. It now accepts a `+json` modifier (in addition to the existing `+color` one). With that modifier, messages are formatted as JSON intead of plain text. The `rabbitmqctl rotate_logs` command is deprecated. The reason is Logger does not expose a function to force log rotation. However, it will detect when a file was rotated by an external tool. From a developer point of view, the old `rabbit_log*` API remains supported, though it is now deprecated. It is implemented as regular modules: there is no `parse_transform` involved anymore. In the code, it is recommended to use the new Logger macros. For instance, `?LOG_INFO(Format, Args)`. If possible, messages should be augmented with some metadata. For instance (note the map after the message): ?LOG_NOTICE("Logging: switching to configured handler(s); following " "messages may not be visible in this log output", #{domain => ?RMQLOG_DOMAIN_PRELAUNCH}), Domains in Erlang Logger parlance are the way to categorize messages. Some predefined domains, matching previous categories, are currently defined in `rabbit_common/include/logging.hrl` or headers in the relevant plugins for plugin-specific categories. At this point, very few messages have been converted from the old `rabbit_log*` API to the new macros. It can be done gradually when working on a particular module or logging. The Erlang builtin console/file handler, `logger_std_h`, has been forked because it lacks date-based file rotation. The configuration of date-based rotation is identical to Lager. Once the dust has settled for this feature, the goal is to submit it upstream for inclusion in Erlang. The forked module is calld `rabbit_logger_std_h` and is based `logger_std_h` in Erlang 23.0.
2021-01-13 00:55:27 +08:00
end
2019-06-28 01:46:08 +08:00
end)
end
end