Skip to content

[BUG] Race condition with logwatch and logrotate #2108

@andrewlow

Description

@andrewlow

Bug Report

I'm seeing intermittent behaviour in my logwatch output.

Context

Using the environment variables to enable a daily logwatch
LOGWATCH_INTERVAL=daily
[email protected]

Sometimes (but rarely) I will see a 'normal' logwatch email arrive. It will contain output for postfix and dovecot sections.
Other times, I will not see those sections - despite the fact that I know email is coming and going as normal from my mail server.

What is affected by this bug?

The daily logwatch email will not contain information about your mail traffic

When does this occur?

Intermittently. This is because I believe it is a race condition.

How do we replicate the issue?

  1. Enable logwatch
  2. Get lucky

Expected Behavior

I should get a daily email that contains details about the email flow through my server

Your Environment

  • version: v10.0.0
  • available RAM: 16GB
  • Docker version: v20.10.7, build f0df350

Environment Variables

LOGWATCH_INTERVAL=daily
[email protected]

My suspicion

If we docker exec -it mailserver bash into the mail container, we can poke around at what is going on.

The directory: /etc/cron.daily/ has files for logrotate and logwatch. As far as I can tell - these two jobs will run at the same time, or maybe with a bit of delay https://unix.stackexchange.com/questions/342302/crontab-run-parts

Let's first dig into logwatch:

Logwatch points at the following mail logs /usr/share/logwatch/default.conf/logfiles/maillog.conf
here is the meat of that file

# What actual file?  Defaults to LogPath if not absolute path....
LogFile = maillog
LogFile = syslog
LogFile = mail.log
LogFile = mail.log.0
LogFile = mail


# If the archives are searched, here is one or more line
# (optionally containing wildcards) that tell where they are...
#If you use a "-" in naming add that as well -mgt
Archive = maillog.*
Archive = maillog-*
Archive = syslog.*
Archive = syslog-*
Archive = archiv/maillog.*
Archive = archiv/maillog-*
Archive = mail.log.*.gz
Archive = mail.log-*.gz
Archive = mail-*

Now let's go look at logrotate

The logrotate is setup to rotate the mail log files in /etc/logrotate.d/maillog
The contents of this file are

/var/log/mail/mail.log
{
  compress
  copytruncate
  delaycompress
  rotate 4
  daily
}

The keen observer will notice that while logwatch is pointed at /var/log/mail.log - logrotate is working with /var/log/mail/mail.log

So what's going on?

# ls -l /var/log/mail.log
lrwxrwxrwx 1 root root 22 Jun  1 07:38 /var/log/mail.log -> /var/log/mail/mail.log
# ls /var/log/mail
clamav.log    clamav.log.2.gz  freshclam.log.1     mail.err    mail.info    mail.info.2.gz  mail.log.1     mail.log.3.gz  mail.warn    mail.warn.2.gz
clamav.log.1  freshclam.log    freshclam.log.2.gz  mail.err.1  mail.info.1  mail.log        mail.log.2.gz  mail.log.4.gz  mail.warn.1

The cron daily processing is done using run-parts - this script will sometimes insert a long enough delay between the logwatch and logrotate that the /var/log/mail.log file will still contain yesterdays data. However, many times the logrotate has happened and since

#! /bin/bash
/usr/sbin/logwatch --range Yesterday --hostname mail.mydomain.com --mailto [email protected]

is filtered on Yesterday - it is pretty likely that the newly rotated /var/log/mail.log is empty.

Metadata

Metadata

Assignees

Type

No type

Projects

No projects

Milestone

No milestone

Relationships

None yet

Development

No branches or pull requests

Issue actions