Description

Error message "CMDOUT (error: error renaming temp state file /var/lib/logrotate.status.tmp)" is generated every 15 minutes.

Symptoms

Log rotate can be summoned by any daemon to rotate their logs. In a particular case, 2 CRON jobs are triggered concurrently.

There is an issue happened with the unlinking sequence of the internal status file(logrotate.status.tmp) of the logrotate.

Hence the rename does not happen, and we keep getting the error message every 15 minutes.

 

*** messages ***

Mar 27 10:15:01 PTX10008-re0 CROND[24843]: (root) CMDOUT (error: error renaming temp state file /var/lib/logrotate.status.tmp)

Mar 27 10:30:01 PTX10008-re0 CROND[23289]: (root) CMDOUT (error: error renaming temp state file /var/lib/logrotate.status.tmp)

Mar 27 10:45:01 PTX10008-re0 CROND[21705]: (root) CMDOUT (error: error renaming temp state file /var/lib/logrotate.status.tmp)

Mar 27 11:00:01 PTX10008-re0 CROND[20030]: (root) CMDOUT (error: error renaming temp state file /var/lib/logrotate.status.tmp)

Mar 27 11:15:01 PTX10008-re0 CROND[18419]: (root) CMDOUT (error: error renaming temp state file /var/lib/logrotate.status.tmp)

Mar 27 11:30:01 PTX10008-re0 CROND[16785]: (root) CMDOUT (error: error renaming temp state file /var/lib/logrotate.status.tmp)

Mar 27 11:45:01 PTX10008-re0 CROND[15256]: (root) CMDOUT (error: error renaming temp state file /var/lib/logrotate.status.tmp)

Mar 27 12:00:02 PTX10008-re0 CROND[13491]: (root) CMDOUT (error: error renaming temp state file /var/lib/logrotate.status.tmp)

Mar 27 12:15:01 PTX10008-re0 CROND[11878]: (root) CMDOUT (error: error renaming temp state file /var/lib/logrotate.status.tmp)

 

Solution

Rsyslog logrotate needs a status file for saving the state during rotation. The logrotate for rsyslog is triggered without a status file, 

due to which there is a race condition while creating a common status file, when there is another app trying to rotate the logs as well. 

PR1747722 implemented a status flag for rsyslog logrotate. Hence the race condition is avoided.

 

Without fix of PR1747722, below logrotate does not have individual status files and can conflict.

 

/usr/sbin/logrotate /etc/logrotate.d/libgnss_logrotate.conf

/usr/sbin/logrotate /etc/logrotate.d/rsyslog

 

Apr 27 20:15:01.580 ptx10008-re0 CROND[15873]: %CRON-6: (root) CMD (/usr/sbin/logrotate /etc/logrotate.d/libsi_logrotate.conf --state /var/lib/libsi_logrotate.status)

Apr 27 20:15:01.581 ptx10008-re0 CROND[15875]: %CRON-6: (root) CMD (/usr/evo/fpc_log_symlink.sh)

Apr 27 20:15:01.581 ptx10008-re0 CROND[15876]: %CRON-6: (root) CMD (/usr/sbin/logrotate /etc/logrotate.d/rsyslog)

Apr 27 20:15:01.581 ptx10008-re0 CROND[15877]: %CRON-6: (root) CMD (  /usr/sbin/logrotate /etc/logrotate.d/bcm_logrotate.conf --state /var/lib/logrotate_bcm.status)

Apr 27 20:15:01.582 ptx10008-re0 CROND[15878]: %CRON-6: (root) CMD (  /usr/sbin/logrotate /etc/logrotate.d/libgnss_logrotate.conf)

Apr 27 20:15:01.582 ptx10008-re0 CROND[15879]: %CRON-6: (root) CMD (  test ! -f /tmp/.pkid_sync_done && /usr/sbin/pkid-sync.sh > /dev/null 2>&1)

Apr 27 20:15:01.582 ptx10008-re0 CROND[15880]: %CRON-6: (root) CMD (/bin/bash /usr/sbin/manage_fpc_logs.sh)

Apr 27 20:15:01.593 ptx10008-re0 CROND[15871]: %CRON-6: (root) CMDOUT (error: error renaming temp state file /var/lib/logrotate.status.tmp)

 

With fix of PR1747722, below logrotate has individual status files, hence we do not conflict with /var/lib/logrotate.status.

 

/usr/sbin/logrotate /etc/logrotate.d/bcm_logrotate.conf --state /var/lib/logrotate_bcm.status

/usr/sbin/logrotate /etc/logrotate.d/libsi_logrotate.conf --state /var/lib/libsi_logrotate.status

 

Apr 27 05:15:01.448 ptx10008-re0 CROND[6553]: %CRON-6: (root) CMD (/usr/sbin/logrotate /etc/logrotate.d/libsi_logrotate.conf --state /var/lib/libsi_logrotate.status)

Apr 27 05:15:01.449 ptx10008-re0 CROND[6555]: %CRON-6: (root) CMD (/usr/sbin/ehmd_logrotate_update.sh)

Apr 27 05:15:01.449 ptx10008-re0 CROND[6557]: %CRON-6: (root) CMD (/usr/evo/fpc_log_symlink.sh)

Apr 27 05:15:01.449 ptx10008-re0 CROND[6558]: %CRON-6: (root) CMD (/usr/sbin/logrotate /etc/logrotate.d/rsyslog --state /var/lib/rsyslog.status) <<<<<<< status file for rsyslog appears

Apr 27 05:15:01.449 ptx10008-re0 CROND[6560]: %CRON-6: (root) CMD (/usr/sbin/logrotate /etc/logrotate.d/bcm_logrotate.conf --state /var/lib/logrotate_bcm.status)

Apr 27 05:15:01.450 ptx10008-re0 CROND[6561]: %CRON-6: (root) CMD (/usr/sbin/logrotate /etc/logrotate.d/libgnss_logrotate.conf)

Apr 27 05:15:01.450 ptx10008-re0 CROND[6562]: %CRON-6: (root) CMD (/bin/bash /usr/sbin/manage_fpc_logs.sh)

Apr 27 05:15:01.450 ptx10008-re0 CROND[6563]: %CRON-6: (root) CMD (test ! -f /tmp/.pkid_sync_done && /usr/sbin/pkid-sync.sh > /dev/null 2>&1)

Apr 27 05:15:01.455 ptx10008-re0 CROND[6559]: %CRON-6: (root) CMDEND (test ! -f /tmp/.pkid_sync_done && /usr/sbin/pkid-sync.sh > /dev/null 2>&1)

Apr 27 05:15:01.458 ptx10008-re0 CROND[6556]: %CRON-6: (root) CMDEND (/bin/bash /usr/sbin/manage_fpc_logs.sh)

Apr 27 05:15:01.462 ptx10008-re0 CROND[6552]: %CRON-6: (root) CMDEND (/usr/sbin/logrotate /etc/logrotate.d/bcm_logrotate.conf --state /var/lib/logrotate_bcm.status)

Apr 27 05:15:01.462 ptx10008-re0 CROND[6549]: %CRON-6: (root) CMDEND (/usr/sbin/ehmd_logrotate_update.sh)

Apr 27 05:15:01.466 ptx10008-re0 CROND[6551]: %CRON-6: (root) CMDEND (/usr/sbin/logrotate /etc/logrotate.d/rsyslog --state /var/lib/rsyslog.status) <<<< status file for rsyslog appears

Apr 27 05:15:01.466 ptx10008-re0 CROND[6548]: %CRON-6: (root) CMDEND (/usr/sbin/logrotate /etc/logrotate.d/libsi_logrotate.conf --state /var/lib/libsi_logrotate.status)

Apr 27 05:15:01.468 ptx10008-re0 CROND[6554]: %CRON-6: (root) CMDEND (/usr/sbin/logrotate /etc/logrotate.d/libgnss_logrotate.conf)

Apr 27 05:15:01.468 ptx10008-re0 CROND[6550]: %CRON-6: (root) CMDEND (/usr/evo/fpc_log_symlink.sh)

Modification History

2024-04-28 : Article Created