This service will be undergoing maintenance at 00:00 UTC, 2017-10-23 It is expected to last about 30 minutes
Bug 303341 - rsyslogd logs messages from vixie-cron with incorrect timestamps
rsyslogd logs messages from vixie-cron with incorrect timestamps
Status: CLOSED RAWHIDE
Product: Fedora
Classification: Fedora
Component: rsyslog (Show other bugs)
rawhide
All Linux
low Severity low
: ---
: ---
Assigned To: Peter Vrabec
Fedora Extras Quality Assurance
:
Depends On:
Blocks:
  Show dependency treegraph
 
Reported: 2007-09-24 11:31 EDT by Will Woods
Modified: 2007-11-30 17:12 EST (History)
4 users (show)

See Also:
Fixed In Version: 1.19.6-2.fc8
Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of:
Environment:
Last Closed: 2007-09-25 12:36:01 EDT
Type: ---
Regression: ---
Mount Type: ---
Documentation: ---
CRM:
Verified Versions:
Category: ---
oVirt Team: ---
RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: ---


Attachments (Terms of Use)
Proposed patch (1.13 KB, patch)
2007-09-25 04:22 EDT, Tomas Mraz
no flags Details | Diff

  None (edit)
Description Will Woods 2007-09-24 11:31:00 EDT
(See bug #296741, where this started)

I'm using vixie-cron-4.2-2.fc8 and rsyslog-1.19.2-1.fc8.

I also have vnstat installed, which has a cron job that runs every 5 minutes. I
have confirmed that the job does run every 5 minutes, as expected, but the the
logging messages from this job have the wrong timestamps:

Sep 24 08:01:01 localhost CROND[23396]: (root) CMD (run-parts /etc/cron.hourly)
Sep 24 08:05:01 localhost CROND[23410]: (vnstat) CMD (/usr/sbin/vnstat.cron)
Sep 24 08:05:01 localhost CROND[23410]: (vnstat) CMD (/usr/sbin/vnstat.cron)
Sep 24 08:05:01 localhost CROND[23410]: (vnstat) CMD (/usr/sbin/vnstat.cron)
Sep 24 08:05:01 localhost CROND[23410]: (vnstat) CMD (/usr/sbin/vnstat.cron)
Sep 24 08:05:01 localhost CROND[23410]: (vnstat) CMD (/usr/sbin/vnstat.cron)
Sep 24 08:05:01 localhost CROND[23410]: (vnstat) CMD (/usr/sbin/vnstat.cron)
Sep 24 08:05:01 localhost CROND[23410]: (vnstat) CMD (/usr/sbin/vnstat.cron)
Sep 24 08:05:01 localhost CROND[23410]: (vnstat) CMD (/usr/sbin/vnstat.cron)
Sep 24 08:05:01 localhost CROND[23410]: (vnstat) CMD (/usr/sbin/vnstat.cron)
Sep 24 08:05:01 localhost CROND[23410]: (vnstat) CMD (/usr/sbin/vnstat.cron)
Sep 24 08:05:01 localhost CROND[23410]: (vnstat) CMD (/usr/sbin/vnstat.cron)
Sep 24 08:05:01 localhost CROND[23410]: (vnstat) CMD (/usr/sbin/vnstat.cron)
Sep 24 09:01:01 localhost CROND[23552]: (root) CMD (run-parts /etc/cron.hourly)
Sep 24 09:05:01 localhost CROND[23566]: (vnstat) CMD (/usr/sbin/vnstat.cron)
Sep 24 09:05:01 localhost CROND[23566]: (vnstat) CMD (/usr/sbin/vnstat.cron)
Sep 24 09:05:01 localhost CROND[23566]: (vnstat) CMD (/usr/sbin/vnstat.cron)
Sep 24 09:05:01 localhost CROND[23566]: (vnstat) CMD (/usr/sbin/vnstat.cron)
Sep 24 09:05:01 localhost CROND[23566]: (vnstat) CMD (/usr/sbin/vnstat.cron)
Sep 24 09:05:01 localhost CROND[23566]: (vnstat) CMD (/usr/sbin/vnstat.cron)
Sep 24 09:05:01 localhost CROND[23566]: (vnstat) CMD (/usr/sbin/vnstat.cron)
Sep 24 09:05:01 localhost CROND[23566]: (vnstat) CMD (/usr/sbin/vnstat.cron)
Sep 24 09:05:01 localhost CROND[23566]: (vnstat) CMD (/usr/sbin/vnstat.cron)
Sep 24 09:05:01 localhost CROND[23566]: (vnstat) CMD (/usr/sbin/vnstat.cron)
Sep 24 09:05:01 localhost CROND[23566]: (vnstat) CMD (/usr/sbin/vnstat.cron)
Sep 24 09:05:01 localhost CROND[23566]: (vnstat) CMD (/usr/sbin/vnstat.cron)

Note that the pid is also wrong.
Comment 1 Robert Scheck 2007-09-24 11:45:26 EDT
Just FYI, -e as parameter to rsyslogd looks better. Either set this as default 
or really fix this problem...
Comment 2 Will Woods 2007-09-24 17:42:20 EDT
Some extra info: vixie-cron uses the following calls for logging:

if (!syslog_open) {
    openlog("CROND",LOG_PID,LOG_CRON);
    syslog_open = 1;
}
syslog(LOG_INFO,"(%s) %s (%s)", username, event, detail)

So. Every 5 minutes, we're getting the same syslog() call from vixie-cron. And
turning on the "print every message" flag fixes the problem. So it's obviously a
bug in the ReduceRepeat code.

I think using -e is a good workaround until we can be sure this is fixed.
Comment 3 Will Woods 2007-09-24 17:57:51 EDT
For the record, this is still unfixed in upstream rsyslog-1.19.6.
Comment 4 Tomas Mraz 2007-09-25 04:22:22 EDT
Created attachment 204961 [details]
Proposed patch

This patch corrects the duplicated message suppression.
Comment 5 Will Woods 2007-09-25 12:36:01 EDT
Fix confirmed with rsyslog-1.19.6-2.fc8. We should make sure that patch gets
upstream. 
Comment 6 Tomas Mraz 2007-09-25 13:04:42 EDT
Rainer, see the attached patch for the duplicated message suppression.
Comment 7 Rainer Gerhards 2007-09-26 03:44:39 EDT
I applied the patch I received via mail yesterday, its now in CVS.

Note You need to log in before you can comment on or make changes to this bug.