[GTALUG] logrotate problem

[Michael Galea]

On 2019-10-17 1:59 p.m., Giles Orr via talk wrote:
> 
> We have a bunch of new(ish) Debian 10 VMs, and logrotate is failing to 
> rotate our non-standard logs.  Unfortunately we deleted all the old 
> Debian 9 VMs before I noticed this problem, so they're not readily 
> available for comparison.  The logrotate config files worked fine on 
> Debian 9 (provisioning is with Ansible, so it's consistent).  The 
> failures aren't detailed enough to help.  Here's the config:
> 
>      # /etc/logrotate.d/ruby
>      /opt/rubyapp/log/*.log {
>              daily
>              missingok
>              rotate 28
>              compress
>              delaycompress
>              copytruncate
>      }
> 
> The parent configuration is standard Debian 10:
> 
>      # /etc/logrotate.conf
>      # (system-supplied comments removed)
>      weekly
>      rotate 4
>      create
>      include /etc/logrotate.d
> 
> Unfortunately my paranoia is such that I'm redacting or modifying 
> machine names and folder names ... I apologize for that.  But I don't 
> think the path involved is the problem.
> 
> Here's one of the errors:
> 
>      # systemctl status logrotate.service
>      ● logrotate.service - Rotate log files
>         Loaded: loaded (/lib/systemd/system/logrotate.service; static; 
> vendor preset: enabled)
>         Active: failed (Result: exit-code) since Thu 2019-10-17 00:00:17 
> EDT; 12h ago
>           Docs: man:logrotate(8)
>                 man:logrotate.conf(5)
>        Process: 29004 ExecStart=/usr/sbin/logrotate /etc/logrotate.conf 
> (code=exited, status=1/FAILURE)
>       Main PID: 29004 (code=exited, status=1/FAILURE)
> 
>      Oct 17 00:00:01 acctserver systemd[1]: Starting Rotate log files...
>      Oct 17 00:00:14 acctserver logrotate[8621]: error: unable to open 
> /opt/rubyapp/log/newrelic_agent.log.1 for compression
>      Oct 17 00:00:14 acctserver logrotate[8621]: error: unable to open 
> /opt/rubyapp/log/puma.stderr.log.1 for compression
>      Oct 17 00:00:14 acctserver logrotate[8621]: error: unable to open 
> /opt/rubyapp/log/puma.stdout.log.1 for compression
>      Oct 17 00:00:14 acctserver logrotate[8621]: error: unable to open 
> /opt/rubyapp/log/traffic.log.1 for compression
>      Oct 17 00:00:17 acctserver systemd[1]: logrotate.service: Main 
> process exited, code=exited, status=1/FAILURE
>      Oct 17 00:00:17 acctserver systemd[1]: logrotate.service: Failed 
> with result 'exit-code'.
>      Oct 17 00:00:17 acctserver systemd[1]: Failed to start Rotate log 
> files.
> 
> Here's the folder contents:
> 
>      # cd /opt/rubyapp/log
>      # ls -l
>      -rw-rw-r--+ 1 root root        1982 Oct 16 15:08 newrelic_agent.log
>      -rw-rw-r--+ 1 root root        7194 Oct 16 13:37 newrelic_agent.log.1
>      -rw-rw-r--+ 1 root root        2549 Oct 10 17:45 
> newrelic_agent.log.2.gz
>      -rw-rw-r--+ 1 root root      154290 Oct 17 12:34 puma.stderr.log
>      -rw-rw-r--+ 1 root root      573253 Oct 16 13:37 puma.stderr.log.1
>      -rw-rw-r--+ 1 root root      512648 Oct 10 17:45 puma.stderr.log.2.gz
>      -rw-rw-r--+ 1 root root         238 Oct 16 15:08 puma.stdout.log
>      -rw-rw-r--+ 1 root root         722 Oct 16 13:37 puma.stdout.log.1
>      -rw-rw-r--+ 1 root root         701 Oct 10 17:45 puma.stdout.log.2.gz
>      -rw-rw-r--+ 1 root root  4747006453 Oct 17 12:37 traffic.log
>      -rw-rw-r--+ 1 root root 15668065757 Oct 10 17:55 traffic.log.1
>      -rw-rw-r--+ 1 root root   850646513 Sep 20 18:12 traffic.log.2.gz
> 
> I note that in /var/log/ - where logrotate continues to work fine - that 
> files are owned mostly root:adm (what is 'adm', and does it matter in 
> this context?) and the permissions are 640 rather than 664.  There are 
> ACLs attached to the files/folder shown above ... does _that_ matter?  
> Where this gets weirder is that if I run 'logrotate --force 
> /etc/logrotate.d/ruby' it gets rotated fine.  It runs fine if run by 
> hand, it fails if run on a SystemD timer.  Which suggests a difference 
> in permissions, but don't timers run as root:root?
> 
> Any thoughts appreciated.  As you can see, these are damn big logs, and 
> we have this problem across multiple machines so I'd really like to fix 
> it ...
> 
> Errors on other servers aren't always consistent with this: a fix for 
> this may or may not help with them, so I may be coming back for more.
> 
> Thanks all.
> 
> -- 
> Giles
> https://www.gilesorr.com/
> gilesorr at gmail.com <mailto:gilesorr at gmail.com>
> 
> ---
> Post to this mailing list talk at gtalug.org
> Unsubscribe from this mailing list https://gtalug.org/mailman/listinfo/talk
>
I note that the versions of logrotate in stable (and also in unstable) 
have Bug
"#831764 [logrotate] logrotate: does not rotate logs if delaycompress is 
used" logged against them. I'm not sure your problem sounds like the one 
posted in the bug report though.

I think I remember from a previous life that logrotate will fail if the 
logging entity (rubyapp?) holds the file open. In that case you can try 
and use the post-rotate directive to "killall -hup .. " the entity, 
which should kick it off the file.

Does /var/lib/logrotate/status have anything to say about the log? It 
should indicate when the last rotate occurred.

-- 
Michael Galea