logrotate没有rotate的排查过程

前言

背景

xxx，你过来把squid的日志检查一下，是否做了日志切割；于是乎开启了logrotate没有切割日志的排查旅程，em～～。只能说过程很爽，平时疲于应付繁琐的事情，难得有点时间能一条线慢慢的捋清楚一件事情。现在唯一想做的事情就是慢慢的把技术知识一点一点捋顺了，查漏补缺，然后深入。

排查过程

知道logrotate这个东西，但是仅限于知道，只能一点点的边学习，边排查。重点在于他依赖于定时任务，在这个地方又是另一个知识点了，其实很多东西都是由基础的东西构成的。排查定时任务的时候卡在了两种定时任务Crontab和Systemd timer；其实logrotate使用这两种方式都可以，只是刚开始的时候脑袋太乱了，因此没搞明白。下面就把这两种方式总结一下。

方式一、Crontab模式

刚开始的时候是往Crontab方向排查的，采用由外到内的方式；

1）检查Cron服务的状态

systemctl status cron.service

2）检查执行Logrotate的定时任务

#cat /etc/crontab 
17 *    * * *   root    cd / && run-parts --report /etc/cron.hourly
25 6   * * *   root    test -x /usr/sbin/anacron || ( cd / && run-parts --report /etc/cron.daily )
47 6    * * 7   root    test -x /usr/sbin/anacron || ( cd / && run-parts --report /etc/cron.weekly )
52 6    1 * *   root    test -x /usr/sbin/anacron || ( cd / && run-parts --report /etc/cron.monthly )

定时任务不执行一般问题都出现在后面的命令，所以检查一下，手动执行“test -x /usr/sbin/anacron || ( cd / && run-parts --report /etc/cron.daily )”，看是否报错，这里我的就是anacron是没有安装。

3）检查系统日志cron是否有在规定的时间执行

cat /var/log/syslog，可以看到定时任务是有在规定时间执行的

Dec  8 06:25:01 (root) CMD (test -x /usr/sbin/anacron || ( cd / && run-parts --report /etc/cron.daily ))

4）检查定时任务下logrotate脚本

cat /etc/cron.daily/logrotate

#!/bin/sh
 
# skip in favour of systemd timer
if [ -d /run/systemd/system ]; then
    exit 0
fi
 
# this cronjob persists removals (but not purges)
if [ ! -x /usr/sbin/logrotate ]; then
    exit 0
fi
 
/usr/sbin/logrotate /etc/logrotate.conf
EXITVALUE=$?
if [ $EXITVALUE != 0 ]; then
    /usr/bin/logger -t logrotate "ALERT exited abnormally with [$EXITVALUE]"
fi
exit $EXITVALUE

因为我的squid的定时切割是每天，所以需要/etc/cron.daily；同样可以手动执行（bash -x logrotate）一次这个脚本，看是否能成功，在这里，发现我的脚本在执行第一个检查的时候这一步退出了；然后花了大量的时候查找为什么会做这一步检查，后来经过网上的搜索发现/run/systemd/system这个目录下放着与时间相关的Systemd任务，所以这一步的判断是为了检测是否用了方式二Systemd timer做了定时任务，如果有这个目录，则不再做Crontab的定时任务；

# bash -x /etc/cron.daily/logrotate 
if [ -d /run/systemd/system ]; then
    exit 0
fi

因此到了这里发现了logrotate是有两种方式做定时任务的，如果使用Crontab模式，则把 /etc/cron.daily/logrotate这个文件里检测/run/systemd/system目录的这3行注释掉就可以；然后停掉logrotate.timer（systemctl stop logrotate.timer）;

5）检查logrotate服务的状态

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 Wed 2021-12-08 00:00:03 +08; 16h ago
TriggeredBy: ● logrotate.timer
       Docs: man:logrotate(8)
             man:logrotate.conf(5)
   Main PID: 2811680 (code=exited, status=1/FAILURE)
 
Dec 08 00:00:01 systemd[1]: Starting Rotate log files...
Dec 08 00:00:03 logrotate[2811680]: error: failed to rename /usr/squid/logs/access.log to /usr/squid/logs/access.log-20211208: Read-only file system

这里通过TriggeredBy：logrotate.timer可以发现logrotate确实是通过Systemd timer的方式来做定时任务的。

方式二：Systemd模式

使用Systemd timer模式主要是两个服务，一个是logrotate.service，logrotate.timer

1）查看logrotate.service的状态

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 Wed 2021-12-08 00:00:03 +08; 16h ago
TriggeredBy: ● logrotate.timer
       Docs: man:logrotate(8)
             man:logrotate.conf(5)
   Main PID: 2811680 (code=exited, status=1/FAILURE)
 
Dec 08 00:00:01 systemd[1]: Starting Rotate log files...
Dec 08 00:00:03 logrotate[2811680]: error: failed to rename /usr/squid/logs/access.log to /usr/squid/logs/access.log-20211208: Read-only file system

TriggeredBy: logrotate.timer，这里可以知道这个服务是由logrotate.timer触发执行的；这里有Read-only file system的报错，主要是Systemd的logrotate.service文件中，对logrotate加了文件读写保护，当 ProtectSystem=full这个参数时，会把 /usr/, /boot, /efi, /etc 挂载为只读，如果是 ProtectSystem=strict 那么整个文件系统都会挂载为只读。刚好我的日志目录就在/usr/下，因此需要再加一个参数：ReadWritePaths=/usr/squid/logs即可，然后systemctl daemon-reload && systemctl restart logrotate.service。这里需要思考的问题是日志目录设置在/usr/下是否合理？

[Unit]
Description=Rotate log files
Documentation=man:logrotate(8) man:logrotate.conf(5)
ConditionACPower=true
 
[Service]
Type=oneshot
ExecStart=/usr/sbin/logrotate /etc/logrotate.conf
 
# performance options
Nice=19
IOSchedulingClass=best-effort
IOSchedulingPriority=7
 
# hardening options
#  details: https://www.freedesktop.org/software/systemd/man/systemd.exec.html
#  no ProtectHome for userdir logs
#  no PrivateNetwork for mail deliviery
#  no ProtectKernelTunables for working SELinux with systemd older than 235
#  no MemoryDenyWriteExecute for gzip on i686
PrivateDevices=true
PrivateTmp=true
ProtectControlGroups=true
ProtectKernelModules=true
ProtectSystem=full
RestrictRealtime=true
ReadWritePaths=/usr/squid/logs

2）检查logrotate.timer的状态

systemctl status logrotate.timer

● logrotate.timer - Daily rotation of log files
     Loaded: loaded (/lib/systemd/system/logrotate.timer; enabled; vendor preset: enabled)
     Active: active (waiting) since Thu 2021-08-05 11:08:00 +08; 4 months 3 days ago
    Trigger: Thu 2021-12-09 00:00:00 +08; 7h left
   Triggers: ● logrotate.service
       Docs: man:logrotate(8)
             man:logrotate.conf(5)

Trigger：可以看出他的触发时间

Triggers：可以看出他将触发的服务

查看logrotate.timer的配置

[Unit]
Description=Daily rotation of log files
Documentation=man:logrotate(8) man:logrotate.conf(5)
 
[Timer]
OnCalendar=daily
AccuracySec=12h
Persistent=true
#Unit：真正要执行的任务，默认是同名的带有.service后缀的单元
 
[Install]
WantedBy=timers.target

3）检查logrotate脚本

使用logrotate切割的脚本一般都放在/etc/logrotate.d/ 下，因此我的squid切割也在这个目录下，可以通过logrotate -d /etc/logrotate.d/squid 检测一下，-d表示debug模式；在这里debug时候发现logrotate有一个status状态文件/var/lib/logrotate/status，也就是记录下文件logrotate的时间，在今天有做过rotate的话，那么就不会再一次进行，如果想要测试，可以编辑这个文件你想要测试的文件的时间，比如发现里面有一条日志："/usr/squid/logs/access.log" 2021-12-9-14:33:28 说明今天做了切割了，还想做测试则可以改为："/usr/squid/logs/access.log" 2021-12-7-14:33:28，那么就可以再一次测试了。注意：这个status的状态只能改时间，直接删除这一条是不生效的。

4）验证

重新执行systemctl restart logrotate.service后，就可以看到被切割的日志；如：access.log-20211209等