Bug#927458: apt-daily.timer Adding random time every 5 seconds

[Julian Andres Klode]

Control: reassign -1 systemd

On Sat, Apr 20, 2019 at 04:30:24AM +0000, Boylan, Ross wrote:
> Package: apt
> Version: 1.4.9
> Severity: normal
> 
> Dear Maintainer,

It would be nice to include a bug description here (even if it's
just repeating the subject). Let me do that:

The problem is that the timer adds random time every 5 seconds.

> 
> Severity note: This appears to be relatively trivial problem in its impact 
> on the system.  However, it has two possible more serious consequences:
> 1. The logs will end up taking a lot of space because of the constant messges.
> 2. The repeated randomization may end up producing really wild random numbers,
> as a result of which the timers may fire either way too fast or way too slow.
> 
> The log spam also makes it more difficult to identify interesting things in the log (I know 
> there are ways around that), and the whole process must impose some performance penalty.
> 
>    * What led up to the situation?
> After a recent upgrade to stretch, my logs are filled with messages like this
> Apr 19 12:38:27 ross-mail systemd[1]: apt-daily.timer: Adding 9h 57min 34.907602s random time.
> Apr 19 12:38:27 ross-mail systemd[1]: apt-daily-upgrade.timer: Adding 51min 17.211953s random time.
> Apr 19 12:38:32 ross-mail systemd[1]: Time has been changed
> Apr 19 12:38:32 ross-mail systemd[1]: apt-daily.timer: Adding 11h 36min 18.852889s random time.
> Apr 19 12:38:32 ross-mail systemd[1]: apt-daily-upgrade.timer: Adding 7min 19.203357s random time.
> Apr 19 12:38:37 ross-mail systemd[1]: Time has been changed
> Apr 19 12:38:37 ross-mail systemd[1]: apt-daily.timer: Adding 11h 4min 53.484274s random time.
> Apr 19 12:38:37 ross-mail systemd[1]: apt-daily-upgrade.timer: Adding 4min 43.246953s random time.
> Apr 19 12:38:42 ross-mail systemd[1]: Time has been changed
> Apr 19 12:38:42 ross-mail systemd[1]: apt-daily.timer: Adding 6h 27min 36.345186s random time.
> Apr 19 12:38:42 ross-mail systemd[1]: apt-daily-upgrade.timer: Adding 15min 43.087263s random time.
> Apr 19 12:38:47 ross-mail systemd[1]: Time has been changed
> Apr 19 12:38:47 ross-mail systemd[1]: apt-daily.timer: Adding 4h 46min 3.780698s random time.
> Apr 19 12:38:47 ross-mail systemd[1]: apt-daily-upgrade.timer: Adding 2min 25.572155s random time.
> Apr 19 12:38:52 ross-mail systemd[1]: Time has been changed
> Apr 19 12:38:52 ross-mail systemd[1]: apt-daily.timer: Adding 6h 54min 42.591556s random time.
> Apr 19 12:38:52 ross-mail systemd[1]: apt-daily-upgrade.timer: Adding 18min 42.538730s random time.
> Apr 19 12:38:57 ross-mail systemd[1]: Time has been changed
> Apr 19 12:38:57 ross-mail systemd[1]: apt-daily.timer: Adding 40min 9.786990s random time.
> repeating endlessly.
> 
> The system is running under HyperV, which I gather resets the clock every 5 seconds.
> 
>    * What exactly did you do (or not do) that was effective (or
>      ineffective)?
> Searching turned up Debian bug 600262, which sounds similar.  However, the solution
> to it was to switch to the systemd timer, which seems to be source of the current problem.
> 
> https://askubuntu.com/questions/888493/var-log-syslog-systemd1-time-has-been-changed-message-every-5-seconds/890354#890354?newreg=0c5a628a4d8a4809a9298176c94d004e
> reports a similar problem.  The top-rated solution is to disable the time update in HyperV.  Apart from the fact that I lack
> the necessary rights, this seems liable to cause clock drift.
> 
> An alternate solution is to modify the filters for the log file to keep out the messages.
> This is probably what I'll do, though I'm not sure the mechanics are is given there.
> The suggestion modified /etc/rsyslog.d/, and I thought systemd was now doing the logging.
> 
> The same alternate solution says another alternative is to disable host time sync on VMBUS.  
> It's not explained, and once again completely breaking the connection seems extreme.
> 
>    * What was the outcome of this action?
> Nothing done yet.  If I succeed in quieting the log, I'll still have the repeated timer updates.
> I do not know if the repeated random times are additive, or simply replace the previous one.
> In the former case, the effects seem likely to be bad.  E.g., if the times added accumulate,
> the timer may never fire.
> 
>    * What outcome did you expect instead?
>    I would like for my VM time to remain syncronized with the host,
>    for my log not to be filled a huge number of junk messages,
>    and for the random timers to be reset just once.
> 

There's nothing we can do here in apt. 

Now, maybe systemd should not log that excessively or not adjust its
timers for miniscule time changes.
-- 
debian developer - deb.li/jak | jak-linux.org - free software dev
ubuntu core developer                              i speak de, en