Built-in log rotation behavior when RABBITMQ_LOGS, log.file.rotation.size and log.file.rotation.date are all set

[qc-mq]

Describe the bug

When deploying RabbitMQ version 3.12 in a Kubernetes environment and configuring log rotation parameters according to https://rabbitmq.com/logging.html documentation, the RabbitMQ logs are not rotating as expected.
The output from the rabbitmq-diagnostics environment command regarding log-related parameters is as follows:

The kernel log parameter is as follower:

As the result, we set log.file.size with 10M, but log file not rotating new file.

Reproduction steps

1. set rabbitmq log parameters:
   log.file.rotation.size=10485760
   log.file.rotation.date=$D0
   log.file.rotation.count=10
   2.start rabbitmq
   ...

Expected behavior

expect log file rotate, like rabbitmq.log.0,rabbitmq.log.1,rabbitmq.log.2..

Additional context

This issue only occurs in version 3.12; version 3.8 does not exhibit this problem.

[michaelklishin]

RabbitMQ 3.12 is out of community support.

IIRC in 3.12 some of those settings were not supported after a migration to a different logger library internally (the settings pre-date the migration, not every library supports every rotation feature).

I recommend that you upgrade to 3.13.6 and switch to logrotate which is more configurable and will work the same way with any RabbitMQ version, including future 4.x ones.

[qc-mq]

now, we deploy rabbitmq with 3.13, but the log already not rotate.

[michaelklishin]

Please stop using images and paste text.

[michaelklishin]

As I demonstrate below, I cannot reproduce. Log rotation works perfectly fine for me.

Neither I recall this being reported elsewhere.

[michaelklishin]

@qc-mq it's maddening that you paste textual output as images because I cannot copy anything but in
your example max_no_bytes is set to infinity, so something is off with your configuration.

I have shared mine below. It matches the docs.

[michaelklishin]

My best guess is that if you set both log.file.rotation.size and log.file.rotation.date, the latter will "overwrite" the former. So you have to pick one, and in my example below log.file.rotation.size works perfectly fine (and log.file.rotation.date is not used).

[michaelklishin]

@qc-mq GitHub does not send out notifications for discussions, so I have to use an explicit mention.

[absolute8511]

We have the same issue in the newest 3.13 version. Although the logrotate is an alternative solution, it is not as simple as the official solution in the container. If it is not supported rotate log anymore using the official configure, maybe the official document should mention that the log.file.rotation.size will not work anymore in new version.

[michaelklishin]

You are making claims without providing any evidence.

I have provided evidence that it does and pointed out that in @qc-mq's logger configuration, max_no_bytes is somehow set to infinity while in my example it is set to 15000 (15 kiB).

If max_no_bytes is set to infinity then obviously file size-based rotation won't work.

[michaelklishin]

Here is a doc update that mentions that either log.file.rotation.size should be used or log.file.rotation.date but not both. The documentation is open source so you could have
submitted a PR instead of asking someone else to do it.

rabbitmq/rabbitmq-website@2a8d9ea

[michaelklishin]

@qc-mq @absolute8511 the following config:

log.file.level = debug
log.console = false

log.file = /tmp/rabbitmq.file.rotation.size.log

log.file.rotation.size = 15000
log.file.rotation.count = 5
log.file.rotation.compress = true

and the following Bunny REPL session to generate some log messages:

1000.times { c = Bunny.new(port: 5672); c.start; c.close }

Makes 3.13.6 rotate logs perfectly fine:

ls -lh /tmp

# (elided)  13K Aug  1 00:36 rabbitmq.file.rotation.size.log
# (elided) 1.3K Aug  1 00:35 rabbitmq.file.rotation.size.log.0.gz
# (elided) 1.3K Aug  1 00:35 rabbitmq.file.rotation.size.log.1.gz
# (elided) 1.4K Aug  1 00:35 rabbitmq.file.rotation.size.log.2.gz
# (elided) 1.4K Aug  1 00:35 rabbitmq.file.rotation.size.log.3.gz
# (elided) 1.4K Aug  1 00:35 rabbitmq.file.rotation.size.log.4.gz

My best guess is that if you set both log.file.rotation.size and log.file.rotation.date as in @qc-mq's example, the latter will "overwrite" the former.

So you have to pick one, and in my example below log.file.rotation.size works perfectly fine (and log.file.rotation.date is not used).

[michaelklishin]

Logger handler configuration is as follows:

[#{id => rmq_1_file_1,module => rabbit_logger_std_h,
   config =>
       #{type => file,file => "/tmp/rabbitmq.file.rotation.size.log",
         burst_limit_enable => false,drop_mode_qlen => 200,flush_qlen => 1000,
         sync_mode_qlen => 10,overload_kill_restart_after => 5000,
         burst_limit_max_count => 500,burst_limit_window_time => 1000,
         overload_kill_enable => false,overload_kill_mem_size => 3000000,
         overload_kill_qlen => 20000,compress_on_rotate => true,
         file_check => 0,max_no_bytes => 15000,max_no_files => 5,
         modes => [delayed_write,raw,append],
         filesync_repeat_interval => 5000,rotate_on_date => false},
   level => debug,
   filters =>
       [{progress_reports,{fun logger_filters:progress/2,log}},
        {rmqlog_filter,{#Fun<rabbit_prelaunch_logging.15.46658893>,
                        #{global => debug,queue => debug,connection => debug,
                          upgrade => debug,mirroring => debug,ra => debug,
                          federation => debug,channel => debug}}}],
   filter_default => log,
   formatter =>
       {rabbit_logger_text_fmt,#{single_line => false,use_colors => false,
                                 prefix_format =>
                                     [time," [",level,"] ",pid," "],
                                 level_format => lc,
                                 time_format => {rfc3339,32,[]},
                                 color_esc_seqs => #{},
                                 line_format => [msg]}}},
 #{id => ssl_handler,module => logger_std_h,
   config =>
       #{type => standard_io,burst_limit_enable => true,drop_mode_qlen => 200,
         flush_qlen => 1000,sync_mode_qlen => 10,
         overload_kill_restart_after => 5000,burst_limit_max_count => 500,
         burst_limit_window_time => 1000,overload_kill_enable => false,
         overload_kill_mem_size => 3000000,overload_kill_qlen => 20000,
         filesync_repeat_interval => no_repeat},
   level => debug,
   filters =>
       [{filter_non_ssl,{fun logger_filters:domain/2,{log,sub,[otp,ssl]}}}],
   filter_default => stop,
   formatter => {ssl_logger,#{}}}]

[qc-mq]

I have identified the issue. Setting RABBITMQ_LOGS in the environment variables overrides the log configuration options in the configuration file.
The environment variable mentioned, RABBITMQ_LOGS, according to https://www.rabbitmq.com/docs/logging, should only affect the log.file parameter, which differs from the observed behavior during testing.

Additionally, in version 3.8, there are no issues observed when setting both the RABBITMQ_LOGS environment variable and configuring the log settings in the file simultaneously.

[absolute8511]

seems the RABBITMQ_LOGS did affect the other log.file.rotation.* parameter, however the RABBITMQ_LOG_BASE seems not affect the other parameter. Maybe it is somehow a unexpected behavior?

[absolute8511]

output of rabbitmq-diagnostics environment, showed the log.file.rotation.size in configuration file is worked as expected in log->file->size

{log,
          [{categories,
               [{default,[{compress_on_rotate,false}]},
                {ra,[{compress_on_rotate,false}]},
                {upgrade,[{compress_on_rotate,false}]},
                {federation,[{compress_on_rotate,false}]},
                {queue,[{compress_on_rotate,false}]},
                {mirroring,[{compress_on_rotate,false}]},
                {channel,[{compress_on_rotate,false}]},
                {connection,[{compress_on_rotate,false}]}]},
           {file,
               [{count,10},
                {size,10485760},
                {compress,false},
                {date,"$D0"},
                {level,debug},
                {file,"/var/log/rabbitmq/rabbitmq.log"},
                {formatter,
                    {rabbit_logger_text_fmt,
                        #{color_esc_seqs => #{},level_format => lc,
                          line_format => [msg],
                          prefix_format => [time," [",level,"] ",pid," "],
                          single_line => false,
                          time_format => {rfc3339,32,[]},
                          use_colors => false}}}]},

however, the output of rabbitmqctl eval "logger:get_handler_config()." showed the config is not mapping to the max_no_bytes in log handler if RABBITMQ_LOGS env is setting.

[#{id => rmq_1_file_1,module => rabbit_logger_std_h,
   config =>
       #{type => file,file => "/var/log/rabbitmq/rabbitmq.log",
         burst_limit_enable => false,drop_mode_qlen => 200,flush_qlen => 1000,
         sync_mode_qlen => 10,overload_kill_restart_after => 5000,
         burst_limit_max_count => 500,burst_limit_window_time => 1000,
         overload_kill_enable => false,overload_kill_mem_size => 3000000,
         overload_kill_qlen => 20000,compress_on_rotate => false,
         file_check => 0,max_no_bytes => infinity,max_no_files => 0,
         modes => [delayed_write,raw,append],
         filesync_repeat_interval => 5000,rotate_on_date => false},
   level => debug,

After removing RABBITMQ_LOGS, the max_no_bytes is working like a charm.

[michaelklishin]

RABBITMQ_LOGS is an alternative way of configuring logging. It is only good for very basic configurations, namely using standard streams.

It was never a design goal to allow rabbitmq.conf settings to be combined with RABBITMQ_LOGS. I suggest that you only use RABBITMQ_LOGS if you want to set it to - (to log to standard streams), otherwise use the configuration file.

[michaelklishin]

The environment variable mentioned, RABBITMQ_LOGS, according to
https://www.rabbitmq.com/docs/logging, should only affect the log.file parameter, which differs
from the observed behavior during testing.

No documentation guide can be 100% explicit and mention every single parameter (from a closely related group) affected.

That section does communicate the general idea: use the environment variable OR use the configuration file (which supports a lot more options) but combining them means that one will override the other.

[michaelklishin]

After asking the maintainers of the Docker image to consider including log rotate, another RabbitMQ core team member has shared this opinion on local logging in containerized environments, which I agree with.