From owner-freebsd-questions@FreeBSD.ORG Sat Nov 8 22:27:14 2014 Return-Path: Delivered-To: freebsd-questions@freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [8.8.178.115]) (using TLSv1.2 with cipher AECDH-AES256-SHA (256/256 bits)) (No client certificate requested) by hub.freebsd.org (Postfix) with ESMTPS id 702C4402 for ; Sat, 8 Nov 2014 22:27:14 +0000 (UTC) Received: from mario.brtsvcs.net (mario.brtsvcs.net [199.48.128.182]) (using TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)) (Client did not present a certificate) by mx1.freebsd.org (Postfix) with ESMTPS id 486105F7 for ; Sat, 8 Nov 2014 22:27:13 +0000 (UTC) Received: from chombo.houseloki.net (c-73-37-112-64.hsd1.or.comcast.net [73.37.112.64]) by mario.brtsvcs.net (Postfix) with ESMTPSA id 00A3C2C160E for ; Sat, 8 Nov 2014 22:27:05 +0000 (UTC) Received: from [IPv6:2601:7:2580:674:baca:3aff:fe83:bd29] (unknown [IPv6:2601:7:2580:674:baca:3aff:fe83:bd29]) by chombo.houseloki.net (Postfix) with ESMTPSA id 7DF4F197 for ; Sat, 8 Nov 2014 14:27:03 -0800 (PST) Message-ID: <545E98B1.7080004@bluerosetech.com> Date: Sat, 08 Nov 2014 14:26:57 -0800 From: Darren Pilgrim User-Agent: Mozilla/5.0 (Windows NT 6.1; WOW64; rv:24.0) Gecko/20100101 Thunderbird/24.6.0 MIME-Version: 1.0 To: freebsd-questions@freebsd.org Subject: Cron executing jobs at innacurate times (observing "jitter" of up to 1 hour) Content-Type: text/plain; charset=ISO-8859-1; format=flowed Content-Transfer-Encoding: 7bit X-BeenThere: freebsd-questions@freebsd.org X-Mailman-Version: 2.1.18-1 Precedence: list List-Id: User questions List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Sat, 08 Nov 2014 22:27:14 -0000 I recently upgraded a pair of servers from 9.3 to 10.0 via freebsd-update. After the upgrade, I noticed my logs were not rotating on the hour, but at some random time within the hour following the scheduled time (the logs in question were set * for size and $D0 or @T00 for when in newsyslog.conf). Some testing revealed that cron is no longer executing tasks in /etc/crontab on the specified time. For example, a job scheduled to run hourly at the zeroth minute would actually execute sometime within an hour, not on the hour as it used to. I created a simple test to see this behaviour. I have six servers: - catnip (amd64 9.3-p3, freebsd-update only) - chombo (amd64 9.1-P6, source updates only) - pug (amd64 10.0-p10, freebsd-update only) - poodle (amd64 10.0-p10, freebsd-update only) - luigi (i386 10.0-p10, freebsd-update only, Xen VPS) - mario (i386 10.0-p10, freebsd-update only, Xen VPS) The behaviour test: All six have a job in /etc/crontab as follows: * * * * * root date >>/var/log/test/0000 2>&1 That is, log the output of date every minute. For catnip, chombo, pug, and poodle, the logs from 13:50 to 14:05 PST today look like this: Sat Nov 8 13:50:00 PST 2014 Sat Nov 8 13:51:00 PST 2014 Sat Nov 8 13:52:00 PST 2014 Sat Nov 8 13:53:00 PST 2014 Sat Nov 8 13:54:00 PST 2014 Sat Nov 8 13:55:00 PST 2014 Sat Nov 8 13:56:00 PST 2014 Sat Nov 8 13:57:00 PST 2014 Sat Nov 8 13:58:00 PST 2014 Sat Nov 8 13:59:00 PST 2014 Sat Nov 8 14:00:00 PST 2014 Sat Nov 8 14:01:00 PST 2014 Sat Nov 8 14:02:00 PST 2014 Sat Nov 8 14:03:00 PST 2014 Sat Nov 8 14:04:00 PST 2014 Sat Nov 8 14:05:00 PST 2014 This is luigi's: Sat Nov 8 21:51:00 UTC 2014 Sat Nov 8 21:51:55 UTC 2014 Sat Nov 8 21:53:47 UTC 2014 Sat Nov 8 21:54:38 UTC 2014 Sat Nov 8 21:54:59 UTC 2014 Sat Nov 8 21:56:34 UTC 2014 Sat Nov 8 21:57:34 UTC 2014 Sat Nov 8 21:58:29 UTC 2014 Sat Nov 8 22:00:38 UTC 2014 Sat Nov 8 22:00:59 UTC 2014 Sat Nov 8 22:02:47 UTC 2014 Sat Nov 8 22:03:38 UTC 2014 Sat Nov 8 22:04:34 UTC 2014 And this is mario's: Sat Nov 8 21:50:34 UTC 2014 Sat Nov 8 21:51:29 UTC 2014 Sat Nov 8 21:53:34 UTC 2014 Sat Nov 8 21:54:29 UTC 2014 Sat Nov 8 21:56:34 UTC 2014 Sat Nov 8 21:57:34 UTC 2014 Sat Nov 8 21:58:25 UTC 2014 Sat Nov 8 21:59:55 UTC 2014 Sat Nov 8 22:01:51 UTC 2014 Sat Nov 8 22:02:12 UTC 2014 Sat Nov 8 22:03:12 UTC 2014 Sat Nov 8 22:05:00 UTC 2014 Backing off the frequency to every 5 minutes see the variance increase to a couple of minutes. For the production jobs running hourly, variance is 0 to 59 minutes late. This is particularly problematic for things like newsyslog. All machines have ntpd running and synchronized. All of the machines except luigi run cron with the defaults. For luigi, the following is in /etc/rc.conf: cron_dst="NO" cron_flags="-J 1 -o" My HV provider hasn't heard of anything causing this. Before I go reloading things back to 9.3, has anyone observed this?