Debugging with Beverage

Fixing an Apache cron log rotation error

If you manage a Unix-like server, every now and then, you might get an email from the server notifying you of important errors that occur in your server. Here’s one that I got earlier today from an Ubuntu 18.04 server of mine:

Cron <root@terresquall> test -x /usr/sbin/anacron || ( cd / && run-parts –report /etc/cron.daily )

/etc/cron.daily/logrotate:
error: error running shared postrotate script for ‘/var/log/apache2/*.log ‘
run-parts: /etc/cron.daily/logrotate exited with return code 1

Mail sent at 06:39

It’s never fun to receive server admin emails like this, because it means that your server has issues, but the message tends to be really ambiguous, so it’s really hard to figure out what the issue is. Obviously, I didn’t know what the issues were, so I had to do some research.

cron

The email title tells us that the error has something to do with cron — a program that runs scripts (called cron jobs) on the server at intervals. If you got your server up through a standard installation, you’ll most likely find your cron routines in these files and folders:

  • /etc/crontab
    • /etc/cron.daily
    • /etc/cron.hourly
    • /etc/cron.weekly
    • /etc/cron.monthly
  • /etc/cron.d

If you’re wondering why the /etc/crontab file has 4 bullets under it, that’s because it contains instructions to run the all the cron jobs in these 4 folders hourly, daily, weekly, or monthly.

Cron jobs that don’t fit into these time categories are normally stored in the /etc/cron.d folder, though you can also add these jobs directly into the etc/crontab file. For more on the differences between these two files, check out this topic on Stack Exchange.

Anyway, back to the problem: the email is telling me that one of the cron jobs in /etc/cron.daily/ called logrotate ran into an error while running (i.e. “exited with return code 1”).

logrotate

This is a program in Unix-like systems that manages the log files on the server for every program. It assigns new log files to each program every now and then, compresses old log files, and deletes even older ones. The program can be configured by changing the settings in the /etc/logrotate.conf file. Each program can also have unique log rotation instructions written for it in the /etc/logrotate.d directory.

/etc/cron.daily/logrotate (which “exited with return code 1”) is a cron job that logrotate uses to rotate logs daily. It ran into an error while trying to rotate Apache’s logs as per the instructions in /etc/logrotate.d/apache2 — specifically, according to the error message, in the postrotate script, which reloads Apache after log rotation.

/etc/logrotate.d/apache2

/var/log/apache2/*.log {
         daily
         missingok
         rotate 14
         compress
         delaycompress
         notifempty
         create 640 root adm
         sharedscripts
         postrotate
                 if invoke-rc.d apache2 status > /dev/null 2>&1; then \
                     invoke-rc.d apache2 reload > /dev/null 2>&1; \
                 fi;
         endscript
         prerotate
                 if [ -d /etc/logrotate.d/httpd-prerotate ]; then \
                         run-parts /etc/logrotate.d/httpd-prerotate; \
                 fi; \
         endscript
 }

Article continues after the advertisement:


What’s wrong with Apache?

A look at the files in Apache’s log directory (/var/log/apache2) with the ls -la command yields the following file listings:

-rw-r-----  1 root adm          0 Feb 24 06:39 access.log
-rw-r-----  1 root adm     641686 Feb 24 19:59 access.log.1
-rw-r-----  1 root adm      34274 Feb 23 06:27 access.log.2.gz
-rw-r-----  1 root adm          0 Feb 24 06:39 error.log
-rw-r-----  1 root adm     499918 Feb 24 19:55 error.log.1
-rw-r-----  1 root adm      22140 Feb 23 06:29 error.log.2.gz
-rw-r-----  1 root adm          0 Feb 24 06:39 modsec_audit.log
-rw-r-----  1 root adm    1745050 Feb 24 19:55 modsec_audit.log.1
-rw-r-----  1 root adm     130971 Feb 23 06:29 modsec_audit.log.2.gz
-rw-r-----  1 root adm          0 Feb 24 06:39 other_vhosts_access.log
-rw-r-----  1 root adm    3144379 Feb 24 19:55 other_vhosts_access.log.1
-rw-r-----  1 root adm      80183 Feb 23 06:29 other_vhosts_access.log.2.gz 

The logs were rotated at 06:39 (when the error message was sent out), but the new logs are not being used (they are all 0 bytes). Checking Apache’s status with service apache2 status yields the following output:

Feb 23 06:29:48 terresquall systemd[1]: Reloaded The Apache HTTP Server.
Feb 24 06:39:38 terresquall systemd[1]: Reloading The Apache HTTP Server.
Feb 24 06:39:38 terresquall apachectl[14521]: AH00112: Warning: DocumentRoot [/var/www/html/domain.com] does not exist
Feb 24 06:39:38 terresquall apachectl[14521]: AH00112: Warning: DocumentRoot [/var/www/html/domain.com] does not exist
Feb 24 06:39:38 terresquall apachectl[14521]: AH00526: Syntax error on line 61 of /etc/apache2/sites-enabled/default-ssl.conf:
Feb 24 06:39:38 terresquall apachectl[14521]: SSLCertificateFile: file '/etc/letsencrypt/live/www.domain.com/fullchain.pem' does not exist or is empty
Feb 24 06:39:38 terresquall apachectl[14521]: Action 'graceful' failed.
Feb 24 06:39:38 terresquall apachectl[14521]: The Apache error log may have more information.
Feb 24 06:39:38 terresquall systemd[1]: apache2.service: Control process exited, code=exited status=1
Feb 24 06:39:38 terresquall systemd[1]: Reload failed for The Apache HTTP Server.

These messages were also logged at 06:39, which means they are likely also related to the error. The log contains a failed reload, likely initiated by /etc/logrotate.d/apache2, which caused the error. The reload failed because of a syntax error in one of Apache’s configuration files. Fixing the offending line in the file and restarting Apache with service apache2 restart fixed the problem and rotated the Apache logs.

Looking at the file listing for Apache’s logs, we can also see that the logs have been rotated, as the new logs are now being used.

-rw-r-----  1 root adm     128447 Feb 24 22:15 access.log
-rw-r-----  1 root adm     642524 Feb 24 20:05 access.log.1
-rw-r-----  1 root adm      34274 Feb 23 06:27 access.log.2.gz
-rw-r-----  1 root adm      79165 Feb 24 22:11 error.log
-rw-r-----  1 root adm     500024 Feb 24 20:05 error.log.1
-rw-r-----  1 root adm      22140 Feb 23 06:29 error.log.2.gz
-rw-r-----  1 root adm     250789 Feb 24 22:11 modsec_audit.log
-rw-r-----  1 root adm    1745050 Feb 24 19:55 modsec_audit.log.1
-rw-r-----  1 root adm     130971 Feb 23 06:29 modsec_audit.log.2.gz
-rw-r-----  1 root adm      66324 Feb 24 22:15 other_vhosts_access.log
-rw-r-----  1 root adm    3153564 Feb 24 20:05 other_vhosts_access.log.1
-rw-r-----  1 root adm      80183 Feb 23 06:29 other_vhosts_access.log.2.gz

Article continues after the advertisement:


Leave a Reply

Your email address will not be published.