Error renaming logrotate.status.tmp file on every execution from cron

[peterjanes]

On a specific set of hosts, logrotate exits with an error code and reports error renaming temp state file /var/lib/logrotate/logrotate.status.tmp every time it runs. There are no errors reported by the files being rotated, the logrotate.status.tmp file is removed, and the logrotate.status file is updated, so I think the error is spurious.

Info

version: logrotate-3.14.0-1.fc28.x86_64
os: Fedora 28
error: error renaming temp state file /var/lib/logrotate.status.tmp
use: A cron job invoked every hour

What I've Tried

Manual execution of logrotate -v /etc/logrotate.conf produced no errors.

Specifying an alternative state file that doesn't initially exist, i.e. using logrotate -s /tmp/logrotate.status /etc/logrotate.conf in the cron job, reported the error on the second and subsequent executions (pointing to /tmp/logrotate.status.tmp instead of the default). Similarly, removing the default status file /var/lib/logrotate.status before executing the cron job reported the error on the second and subsequent executions.

I've attached the output of ltrace -s 256 -S logrotate -l syslog /etc/logrotate.conf as suggested in #197, which looked similar but appears to be unrelated.

[peterjanes]

This is an ltrace of a successful (non-cron) run, invoked using the same cron script run from the command line, in case it shows anything useful. Just browsing a diff between the two, I don't see anything particularly interesting until the rename@SYS() succeeds with 0, where it failed with -2 in the original.

[kdudka]

This looks like there are two processes of logrotate running at the same time. In the failing case, /var/lib/logrotate/logrotate.status.tmp is first unlinked, then created again, the data is written and successfully flushed using the file descriptor. But, when logrotate wants to rename /var/lib/logrotate/logrotate.status.tmp to /var/lib/logrotate/logrotate.status, it fails with ENOENT. I think it means that something else (most likely another process of logrotate) must have unlinked /var/lib/logrotate/logrotate.status.tmp already.

I don't see anything particularly interesting until the rename@SYS() succeeds with 0, where it failed with -2 in the original.

There is actually one more difference: In the failing case, /var/lib/logrotate/logrotate.status.tmp is successfully unlinked before it is created. logrotate does it to cleanup in case the previous run of logrotate was interrupted unexpectedly. But this may also happen when you run two processes of logrotate in parallel.

[peterjanes]

Aha, you're right: somehow run-parts is being triggered twice every hour, which is triggering the logrotate job. (I usually look at the logs with a journalctl output mode that hides the PIDs, so I didn't see that there were two.) Thanks for identifying the problem, and apologies for the distraction!

[kdudka]

No problem. Thanks for confirmation!

[YouveGotMeowxy]

Sorry for the necropost, but what is the actual solution to this? I have the same error.

[kdudka]

@YouveGotMeowxy Which version of logrotate are you using? State file locking was introduced in logrotate-3.17.0.

[YouveGotMeowxy]

@YouveGotMeowxy Which version of logrotate are you using? State file locking was introduced in logrotate-3.17.0.

oh wow. Looks like I'm way behind. Looks like I'm using 1.3(!) lol. I'm using the :latest tag from heer: https://hub.docker.com/r/blacklabelops/logrotate

Where can I get the docker version of the actual latest?

Update:

Oops, looks like I'm using 3.14.0

[kdudka]

There is ARG LOGROTATE_VERSION=latest in the Dockerfile: https://github.com/blacklabelops/logrotate/blob/bb989e5808a610d3c1da9ccbfc638cc07afb1c37/Dockerfile#L4 so just rebuilding the image might help.

[kdudka]

In any case, we as logrotate upstream developers do not maintain the images. Upstream releases of logrotate are available here: https://github.com/logrotate/logrotate/releases

[YouveGotMeowxy]

@kdudka ok, ty.

Yes, I just tried to rebuild the image, but no luck:

 ---> Running in 33f88a5e213d

fetch http://dl-cdn.alpinelinux.org/alpine/v3.8/main/x86_64/APKINDEX.tar.gz

fetch http://dl-cdn.alpinelinux.org/alpine/v3.8/community/x86_64/APKINDEX.tar.gz

(1/1) Installing wget (1.20.3-r0)

Executing busybox-1.28.4-r1.trigger

OK: 44 MiB in 26 packages

ERROR: unsatisfiable constraints:

  logrotate-3.14.0-r0:

    breaks: world[logrotate=3.19.0]

The command '/bin/sh -c export CONTAINER_USER=logrotate &&     export CONTAINER_GROUP=logrotate &&     addgroup -g $CONTAINER_GID logrotate &&     adduser -u $CONTAINER_UID -G logrotate -h /usr/bin/logrotate.d -s /bin/bash -S logrotate &&     apk add --update       tar       gzip       wget       tzdata &&     if  [ "${LOGROTATE_VERSION}" = "latest" ];       then apk add logrotate ;       else apk add "logrotate=${LOGROTATE_VERSION}" ;     fi &&     mkdir -p /usr/bin/logrotate.d &&     wget --no-check-certificate -O /tmp/go-cron.tar.gz https://github.com/michaloo/go-cron/releases/download/v0.0.2/go-cron.tar.gz &&     tar xvf /tmp/go-cron.tar.gz -C /usr/bin &&     apk del       wget &&     rm -rf /var/cache/apk/* && rm -rf /tmp/*' returned a non-zero code: 1

Other than that simple change I know nothing about making dockerfiles, so I guess I'll head over to the guy's page who made the container and try nagging him to update it for me, lol