26

Have you ever seen wrong order in /var/log/syslog ? I think that it causes only crontab.

Jun 28 22:20:01 alex CRON[2327]: (root) CMD (something > /dev/null)
Jun 28 22:21:01 alex CRON[2700]: (root) CMD (something > /dev/null)
Jun 21 03:49:01 alex CRON[2753]: (root) CMD (something > /dev/null)
Jun 28 22:23:01 alex CRON[2754]: (root) CMD (something > /dev/null)
Jun 27 05:08:01 alex CRON[2813]: (root) CMD (something > /dev/null)
Jun 26 00:19:01 alex CRON[2816]: (root) CMD (something > /dev/null)
Jun 28 22:25:01 alex CRON[2816]: (munin) CMD (if [ -x /usr/bin/munin-cron ]; then /usr/bin/munin-cron; fi)
Jun 28 22:25:01 alex CRON[2821]: (root) CMD (something > /dev/null)
Jun 28 22:27:01 alex CRON[3225]: (root) CMD (something > /dev/null)
Jun 28 22:28:01 alex CRON[3240]: (root) CMD (something > /dev/null)
Jun 28 22:30:01 alex CRON[3290]: (root) CMD (something > /dev/null)
Jun 26 12:03:01 alex CRON[3291]: message repeated 2 times: [ (root) CMD (something > /dev/null)]
Jun 28 22:30:01 alex CRON[3291]: (munin) CMD (if [ -x /usr/bin/munin-cron ]; then /usr/bin/munin-cron; fi)
Jun 28 22:31:01 alex CRON[3659]: (root) CMD (something > /dev/null)
Jun 28 22:32:01 alex CRON[3754]: (root) CMD (something > /dev/null)
Jun 16 06:41:01 alex CRON[3846]: (root) CMD (something > /dev/null)
Jun 28 22:35:58 alex cron[909]: (CRON) INFO (pidfile fd = 3)
Jun 28 22:35:58 alex cron[944]: (CRON) STARTUP (fork ok)
Jun 28 22:35:58 alex cron[944]: (CRON) INFO (Running @reboot jobs)
Jun 28 22:36:01 alex CRON[1428]: (root) CMD (something > /dev/null)
Jun 28 22:37:01 alex CRON[3050]: (root) CMD (something > /dev/null)
Jun 28 22:38:01 alex CRON[3082]: (root) CMD (something > /dev/null)
Jun 28 22:39:01 alex CRON[3114]: (root) CMD (something > /dev/null)

As you can see, there is bad time order between lines. It is just crontab error, or there is some problem with system clock, or something?

I am running the latest Ubuntu 14.04 kernel:

Linux alex 3.13.0-30-generic #54-Ubuntu SMP Mon Jun 9 22:45:01 UTC 2014 x86_64 x86_64 x86_64 GNU/Linux
5
  • 1
    Is really the order wrong or just the timestamps? In the first case syslog should be responsible, otherwise cron or your clock.
    – wonce
    Jun 29, 2014 at 2:36
  • It looks like the other logs except cron are OK. I added logging time by "something" script, not just cron and syslog.
    – Tomasz
    Jun 29, 2014 at 10:12
  • 1
    This happened on a box of mine running fedora, it turned out that rsyslog had crashed, but journald did keep logs which it did forward to rsyslog once it started, resulting in old messages got mixed with new. This was in fedora 20 though.
    – Petter H
    Jun 30, 2014 at 20:52
  • 2
    I have encountered the same problem on Ubuntu 14.04. About 1 in every 20 cron messages has a date about 5-7 days in the past. Only with cron messages and the problem persists after a reboot. Jul 4, 2014 at 20:56
  • 1
    I can confirm this problem, Ubuntu 14.04, happens with cron messages.
    – thor
    Dec 24, 2014 at 7:16

2 Answers 2

28

This is a tricksy one, and it's actually a bug in rsyslog, specifically RepeatedMsgReduction On, and a change in behaviour with the version released with Trusty (compared to earlier versions)

See http://bugzilla.adiscon.com/show_bug.cgi?id=527 for the gory details.

In short, turn off RepeatedMsgReduction on Trusty (i.e. sudo sed -i -r 's/^\$RepeatedMsgReduction.*/$RepeatedMsgReduction off/' /etc/rsyslog.conf). It's not helpful, and does dumb things.

4
  • 2
    Please don't post the exact same answer twice. Use comments instead to refer to your first answer. Best option is to vote for close as duplicate.
    – Sven
    Dec 28, 2014 at 9:36
  • The irony... looks like you might want RepeatedMsgReduction set to on! :D Jul 21, 2017 at 22:38
  • What makes you say that, Anonymous Penguin? Jul 23, 2017 at 0:01
  • 1
    Seems that version 7.4.4-1ubuntu2.7 of the rsyslog package fixes this problem: changelogs.ubuntu.com/changelogs/pool/main/r/rsyslog/… Jan 18, 2018 at 14:44
0

Did your machine perhaps restart right around then? Based on your log it seems that cron got restarted at least. It's possible you have a bad CMOS battery, and your machine isn't keeping accurate time when powered off.

Is this a virtual machine? Perhaps it was migrated to a different host, and the clock became incorrect during the migration?

Does your 'something' script perhaps set the time by accident?

Really, this could be any number of things. This is not normal behavior though.

1
  • it looks like just syslog problem, because I made independent login right to running script ant it looks fine, without spaces, or mixed order.
    – Tomasz
    Jul 3, 2014 at 21:27

You must log in to answer this question.

Not the answer you're looking for? Browse other questions tagged .