Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Pluggable logging backends #94

Closed
michaelklishin opened this issue Apr 1, 2015 · 29 comments
Closed

Pluggable logging backends #94

michaelklishin opened this issue Apr 1, 2015 · 29 comments
Assignees
Milestone

Comments

@michaelklishin
Copy link
Member

People keep asking for it. We should make Lager dead easy to use with RabbitMQ. Or even consider switching to it entirely.

@willejs
Copy link

willejs commented Apr 20, 2015

👍

@willejs
Copy link

willejs commented Apr 29, 2015

@michaelklishin are there plans to implement this any time soon? I am very interested in it!

@michaelklishin
Copy link
Member Author

@willejs we are pretty busy with other things. It should be very realistic to ship this with 3.6.0.

@michaelklishin
Copy link
Member Author

@willejs that said, #128 is something we can finish by early may. Might give you some options.

@willejs
Copy link

willejs commented Apr 29, 2015

Cheers @michaelklishin its good enough that this is on the horizon 😄 . Adding this issue to the 3.6.0 milestone would be cool 😉

@willejs
Copy link

willejs commented Jun 24, 2015

@michaelklishin sorry to keep bothering you! Is it on a roadmap? Is there anyway to speed this up, apart from learning erlang? ;) I'l donate to the project in any way if i can!

@videlalvaro
Copy link
Collaborator

There's this already that can help a bit: https://github.com/hyperthunk/rabbitmq-lager I'm using it on a plugin that I'm building

@michaelklishin
Copy link
Member Author

@willejs this is not getting any attention yet for one reason: we are a tiny team. It's still on the roadmap for 3.6.0 and we'll see if we can squeeze it into the list of things for July.

@willejs
Copy link

willejs commented Jun 24, 2015

I understand, hence apologising! July would be great!

@willejs
Copy link

willejs commented Nov 2, 2015

@michaelklishin me again :) Hows this looking?

@michaelklishin
Copy link
Member Author

@willejs it will not be in 3.6. However, now that we've moved to erlang.mk for the build system, introducing new dependencies is trivial, so this becomes easier.

@michaelklishin
Copy link
Member Author

There were logging changes in Erlang/OTP 18.1, which 3.7 will likely require, that make me wonder if Lager is really necessary for this to work.

@hairyhum
Copy link
Contributor

hairyhum commented Dec 4, 2015

Lager receives messages from error_logger, so it's possible to just start lager application on rabbitmq node and set logging app_env and logs will go to lager. (without lagers fancy formatting, which is parse_transform).
So in first approach we can just add log location to rabbitmq.config to lager application.

@hairyhum
Copy link
Contributor

hairyhum commented Dec 8, 2015

Do anyone know why is there append_file and then delete instead of just rename in log rotation? https://github.com/rabbitmq/rabbitmq-server/blob/master/src/rabbit_error_logger_file_h.erl#L170

@michaelklishin
Copy link
Member Author

@hairyhum see the comment on rabbit_file:append_file/2.

@michaelklishin
Copy link
Member Author

@hairyhum apparently the change dates back to 59d0dcc. Also note that rabbit_file:append_file/2 actually can perform rotation, despite the name.

@hairyhum
Copy link
Contributor

hairyhum commented Dec 9, 2015

We have following config variables:

RABBITMQ_LOG_BASE
RABBITMQ_LOGS - general logs (default %RABBITMQ_LOG_BASE%%RABBITMQ_NODENAME%.log)
RABBITMQ_SASL_LOGS - sasl logs (default %RABBITMQ_LOG_BASE%%RABBITMQ_NODENAME%-sasl.log)

RABBITMQ_LOGS and RABBITMQ_SASL_LOGS can be set to absolute filename or - which means log to console.
This configs transform to application env variables error_logger and sasl_error_logger, which can be
either tty or {file, FileName}.

Lager log_root and handlers for logs can be configured from .config file for different loglevels and console/file/something else backends.
So I think it is better way to configure non-default logging, rather than env variables.
Currently log_root is set to RABBITMQ_LOG_BASE if not set in .config
handlers also can be formaed from env variables if no handlers config present.
So RABBITMQ_LOGS="-" becomes {lager_console_backend, debug}
RABBITMQ_LOGS="filaname" becomes {lager_file_backend, [{file, "filename"}, {level, debug}]}

There are change in log rotation. Customers can rely on logrotate with 'suffix', which
is copying file to a new location and creating new empty one.

While using lager it is possible just to move file or delete it (if suffix = '')
Difference will be in that there could be no logfile after rotating until lager log something in it.
Lager is checking if file exist on every log and create new ones without loosing messages

Lager itself supports log rotation by date and file size and can keep given count of
rotated files, which could be useful.
But it is possible to leave existing rotate_logs command.

So main changes so far will be:
error_logge app config variable is not relevant anymore.
After rotate_logs, there could be no log file until next log.
Application config for lager will override ENV variables.

@hairyhum
Copy link
Contributor

hairyhum commented Dec 9, 2015

And I didn't found out yet how to separate sasl and general logs so far.

@michaelklishin
Copy link
Member Author

@hairyhum note that we can log something after rotation, e.g. "opening a new log file after rotation". error_logger config settings are not commonly used and there is an alternative, so breaking that is fine.

@hairyhum
Copy link
Contributor

hairyhum commented Dec 9, 2015

Found an option to separate sasl and general logs. It is lager sinks. It even allows us to log different categories rabbitmq_log:log(Category, Level, Msg) in different files. Maybe it can be useful.

@hairyhum
Copy link
Contributor

Currently lager has it's own way to format error_logger messages. This format skips stack trace in some cases, which could be inconvenient.

@michaelklishin
Copy link
Member Author

@hairyhum can it be overridden?

@hairyhum
Copy link
Contributor

@michaelklishin unfortunately, not in current implementation. And they are not too quick at accepting pull requests right now. But we can use forked version, if it's an option.

@michaelklishin
Copy link
Member Author

@dumbbell @videlalvaro @essen what are your thoughts on using a Lager fork to get more informative crash reports (with stack traces)?

@hairyhum can you be more specific what the "some cases" are?

@hairyhum
Copy link
Contributor

As I can tell from code, stacktraces are omitted if errors are from gen_server, state_machine, en_event and supervisor. So it's should be OTP messages.
It also reformats ranch and cowboy messages, but there are stacktrace in this cases.

@michaelklishin
Copy link
Member Author

We can live without stack traces in the regular log but SASL log really could benefit from having stack traces. I'm not a fan of using forks but if that's what we have to do, I'm fine with it.

@videlalvaro
Copy link
Collaborator

I think whatever we fork we should actively try to incorporate upstream,
otherwise not sure the team should invest resources on maintaining a fork.
On Mon, Dec 14, 2015 at 6:44 PM Michael Klishin notifications@github.com
wrote:

We can live without stack traces in the regular log but SASL log really
could benefit from having stack traces. I'm not a fan of using forks but if
that's what we have to do, I'm fine with it.


Reply to this email directly or view it on GitHub
#94 (comment)
.

@hairyhum
Copy link
Contributor

I mentioned fork because lager team are too busy right now to deal with PR, like they said. So I hope it could be merged eventually.

@michaelklishin
Copy link
Member Author

This is on its finish line. As part of this, we will pipe the majority of log entries (everything but Erlang process crash reports) to rabbit.log and get access to the debug level, which is quite verbose.

See #491 for more details.

dumbbell pushed a commit that referenced this issue Jan 13, 2016
By default, RabbitMQ now logs messages to a single file
($RABBITMQ_LOGS). The $RABBITMQ_SASL_LOGS variable is unused. To
configure how and which messages are logged, it's recommended to do it
from rabbitmq.config, not from the environment variable.

The old `log_levels` parameter is unsupported and categories are
replaced by Lager extra sinks. If you had in your rabbitmq.config:
    {rabbit, [
        {log_levels, [{connection, info}]}
      ]}
You can now configure Lager like this:
    {lager, [
        {extra_sinks, [
            {rabbit_connection_lager_event, [
                {handlers, [{lager_forwarder_backend, [lager_event, info]}]}
              ]}
          ]}
      ]}

rabbitmq-build.mk from rabbitmq-common is included in the top-level
Makefile. It sets the appropriate compiler options to enable Lager's
lager_transform parse_transform module.

rabbit_log calls are now converted by this parse_transform to direct
calls to lager:log(). To keep backward compatibility with other plugins,
the rabbit_log module still implements all the <level>() functions.
Compared to the parse_transformed calls, the main difference is the
logged message does not carry the file:line metadata.

Fixes #94.
dumbbell added a commit to rabbitmq/rabbitmq-common that referenced this issue Jan 13, 2016
rabbitmq-build.mk centralizes common compiler options for all RabbitMQ
components. Currently, it includes options specific to Lager:
    o  It enables lager_transform parse_transform module.
    o  It lists all our specific extra sinks

rabbit_log is the default sink we use for messages logged using
rabbit_log:<level>().

The other sinks correspond to the previous categories we supported. To
use those sinks, one needs to log messages using eg.:
    rabbit_channel:info("Message")

lager_forwarder_backend forwards messages from one sink to another. This
allows RabbitMQ to use a single file to for several sinks:

    lager_event (default sink) --> lager_file_backend --> "rabbit.log"
    ^
    |
    +------------------------+---+--+
                             |   |  |
    rabbit_log_lager_event --+   |  |
    rabbit_channel_lager_event --+  |
    rabbit_connection_lager_event --+

rabbit_channel.erl and rabbit_reader.erl are modified to use the new
API.

References rabbitmq/rabbitmq-server#94.
dumbbell pushed a commit that referenced this issue Jan 13, 2016
By default, RabbitMQ now logs messages to a single file
($RABBITMQ_LOGS). The $RABBITMQ_SASL_LOGS variable is unused. To
configure how and which messages are logged, it's recommended to do it
from rabbitmq.config, not from the environment variable.

The old `log_levels` parameter is unsupported and categories are
replaced by Lager extra sinks. If you had in your rabbitmq.config:
    {rabbit, [
        {log_levels, [{connection, info}]}
      ]}
You can now configure Lager like this:
    {lager, [
        {extra_sinks, [
            {rabbit_connection_lager_event, [
                {handlers, [{lager_forwarder_backend, [lager_event, info]}]}
              ]}
          ]}
      ]}

rabbitmq-build.mk from rabbitmq-common is included in the top-level
Makefile. It sets the appropriate compiler options to enable Lager's
lager_transform parse_transform module.

rabbit_log calls are now converted by this parse_transform to direct
calls to lager:log(). To keep backward compatibility with other plugins,
the rabbit_log module still implements all the <level>() functions.
Compared to the parse_transformed calls, the main difference is the
logged message does not carry the file:line metadata.

Fixes #94.
dumbbell pushed a commit to rabbitmq/rabbitmq-test that referenced this issue Jan 13, 2016
dumbbell added a commit to rabbitmq/rabbitmq-management-agent that referenced this issue Jan 15, 2016
Keys `log_file` and `sasl_log_file` are replaced by a single key
`log_files` which returns a list.

References rabbitmq/rabbitmq-server#94.
dumbbell added a commit to rabbitmq/rabbitmq-management that referenced this issue Jan 15, 2016
This key contains a list of files. If the node sends messages to stdout,
the list contains "<stdout>", therefore it needs to be escaped in an
HTML context.

While here, escape `config_files` as well.

References rabbitmq/rabbitmq-server#94.
dcorbacho pushed a commit that referenced this issue May 27, 2016
Do not use ?= operator in make target env variables setup
dumbbell added a commit to rabbitmq/rabbitmq-management that referenced this issue Nov 28, 2017
That change was already committed in commit
9b923e2. However, it was lost later,
probably because we merge `stable` into `master.

References rabbitmq/rabbitmq-server#94.
dcorbacho pushed a commit that referenced this issue Jul 5, 2023
* Handle potential retention race condition

If a stream member is being deleted whilst retention is evaluating
the retention process could crash if there are no index / segment
files.

* Add a file size function that doesn't just return 0 for files that
do not exist. This throws "missing_file" instead to allow retries
higher up the stack.

* Change where errors are caught in init_offset_reader

And implement a simple retry limit

Throw missing_file whenever a file_size operation
fails instead of returning 0.

Remove all nested missing_file handling in favour of entry
point handling + retry

* improve some logging

* Delete index file before segment

As this should somewhat reduce the chances of hitting missing_file
issues.

* Use a different file_size function when evaluating retention

As returning 0 when segment file is missing is ok in this case.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

4 participants