timer messages unnecessarily sent to /dev/kmsg

Bug #1576536 reported by Adam Conrad
54
This bug affects 12 people
Affects Status Importance Assigned to Milestone
systemd (Ubuntu)
Won't Fix
Undecided
Unassigned

Bug Description

The random adjustments to the apt timer seem to spam the kernel ringbuffer, which is entirely unnecessary:

[ 5452.648222] systemd[1]: apt-daily.timer: Adding 10h 42min 21.562799s random time.
[ 5454.038740] systemd[1]: apt-daily.timer: Adding 7h 11min 7.994692s random time.
[ 5457.381779] systemd[1]: apt-daily.timer: Adding 10h 43min 34.008994s random time.
[ 5457.495120] systemd[1]: apt-daily.timer: Adding 7h 9min 28.335411s random time.
[ 5457.743417] systemd[1]: apt-daily.timer: Adding 7h 5min 47.291509s random time.
[ 5778.374365] systemd[1]: apt-daily.timer: Adding 8h 26min 267.164ms random time.
[ 5778.495711] systemd[1]: apt-daily.timer: Adding 9h 52min 9.289682s random time.
[ 5778.667351] systemd[1]: apt-daily.timer: Adding 8h 39min 41.199389s random time.
[ 5778.924784] systemd[1]: apt-daily.timer: Adding 2h 38min 40.786228s random time.
[ 5779.035421] systemd[1]: apt-daily.timer: Adding 10h 48min 34.808379s random time.
[ 5779.107951] systemd[1]: apt-daily.timer: Adding 6h 19min 45.904476s random time.
[ 7236.115354] systemd[1]: apt-daily.timer: Adding 5h 12min 18.073639s random time.
[ 7268.716558] systemd[1]: apt-daily.timer: Adding 7h 19min 40.411960s random time.
[ 7269.151388] systemd[1]: apt-daily.timer: Adding 8h 21min 54.857412s random time.
[ 7270.702642] systemd[1]: apt-daily.timer: Adding 8h 33min 10.633964s random time.
[ 7281.835523] systemd[1]: apt-daily.timer: Adding 11h 43min 43.923801s random time.
[ 7339.639840] systemd[1]: apt-daily.timer: Adding 9h 8.911515s random time.
[ 7340.512389] systemd[1]: apt-daily.timer: Adding 1h 45min 25.722497s random time.
[ 7343.611383] systemd[1]: apt-daily.timer: Adding 22min 8.489125s random time.
[ 7344.186645] systemd[1]: apt-daily.timer: Adding 10h 6min 50.541602s random time.
[ 7346.111888] systemd[1]: apt-daily.timer: Adding 11h 47min 57.661764s random time.
[ 7350.893164] systemd[1]: apt-daily.timer: Adding 3h 10min 23.393765s random time.
[ 7355.747731] systemd[1]: apt-daily.timer: Adding 1h 2min 54.946554s random time.
[ 7355.825972] systemd[1]: apt-daily.timer: Adding 4h 40min 28.148047s random time.
[ 7529.692671] systemd[1]: apt-daily.timer: Adding 10h 20min 39.786553s random time.
[ 7539.109562] systemd[1]: apt-daily.timer: Adding 7h 45min 54.766189s random time.
[ 7539.187368] systemd[1]: apt-daily.timer: Adding 2h 20min 28.098533s random time.
[ 7539.617356] systemd[1]: apt-daily.timer: Adding 10h 36min 4.411352s random time.
[ 7540.960539] systemd[1]: apt-daily.timer: Adding 43min 17.875784s random time.
[ 7541.477412] systemd[1]: apt-daily.timer: Adding 5h 33min 59.201230s random time.
[ 7550.068289] systemd[1]: apt-daily.timer: Adding 6h 41min 2.480405s random time.
[ 7734.981411] systemd[1]: apt-daily.timer: Adding 9h 54min 39.888137s random time.
[ 7735.230060] systemd[1]: apt-daily.timer: Adding 6h 8min 31.925492s random time.
[ 7736.287077] systemd[1]: apt-daily.timer: Adding 4h 56min 30.657866s random time.
---
ApportVersion: 2.20.1-0ubuntu2
Architecture: amd64
CurrentDesktop: Unity
DistroRelease: Ubuntu 16.10
InstallationDate: Installed on 2015-07-13 (291 days ago)
InstallationMedia: Ubuntu 15.04 "Vivid Vervet" - Release amd64 (20150422)
MachineType: LENOVO 20BXCTO1WW
Package: systemd 229-4ubuntu4
PackageArchitecture: amd64
ProcKernelCmdLine: BOOT_IMAGE=/boot/vmlinuz-4.4.0-21-lowlatency.efi.signed root=UUID=6fe2ef4e-b82c-468b-a35a-86d8753787d1 ro quiet splash vt.handoff=7
ProcVersionSignature: Ubuntu 4.4.0-21.37-lowlatency 4.4.6
SystemdDelta:
 [EXTENDED] /lib/systemd/system/systemd-timesyncd.service → /lib/systemd/system/systemd-timesyncd.service.d/disable-with-time-daemon.conf
 [EXTENDED] /lib/systemd/system/rc-local.service → /lib/systemd/system/rc-local.service.d/debian.conf
 [EXTENDED] /etc/systemd/system/display-manager.service → /lib/systemd/system/display-manager.service.d/xdiagnose.conf

 3 overridden configuration files found.
Tags: yakkety
Uname: Linux 4.4.0-21-lowlatency x86_64
UpgradeStatus: No upgrade log present (probably fresh install)
UserGroups: adm cdrom dialout dip kvm lpadmin plugdev sambashare sbuild sudo
_MarkForUpload: True
dmi.bios.date: 01/27/2016
dmi.bios.vendor: LENOVO
dmi.bios.version: JBET56WW (1.21 )
dmi.board.asset.tag: Not Available
dmi.board.name: 20BXCTO1WW
dmi.board.vendor: LENOVO
dmi.board.version: SDK0E50512 STD
dmi.chassis.asset.tag: No Asset Information
dmi.chassis.type: 10
dmi.chassis.vendor: LENOVO
dmi.chassis.version: None
dmi.modalias: dmi:bvnLENOVO:bvrJBET56WW(1.21):bd01/27/2016:svnLENOVO:pn20BXCTO1WW:pvrThinkPadT450s:rvnLENOVO:rn20BXCTO1WW:rvrSDK0E50512STD:cvnLENOVO:ct10:cvrNone:
dmi.product.name: 20BXCTO1WW
dmi.product.version: ThinkPad T450s
dmi.sys.vendor: LENOVO

Revision history for this message
Adam Conrad (adconrad) wrote : CurrentDmesg.txt

apport information

tags: added: apport-collected yakkety
description: updated
Revision history for this message
Adam Conrad (adconrad) wrote : Dependencies.txt

apport information

Revision history for this message
Adam Conrad (adconrad) wrote : JournalErrors.txt

apport information

Revision history for this message
Adam Conrad (adconrad) wrote : Lspci.txt

apport information

Revision history for this message
Adam Conrad (adconrad) wrote : Lsusb.txt

apport information

Revision history for this message
Adam Conrad (adconrad) wrote : ProcCpuinfo.txt

apport information

Revision history for this message
Adam Conrad (adconrad) wrote : ProcEnviron.txt

apport information

Revision history for this message
Adam Conrad (adconrad) wrote : ProcInterrupts.txt

apport information

Revision history for this message
Adam Conrad (adconrad) wrote : ProcModules.txt

apport information

Revision history for this message
Adam Conrad (adconrad) wrote : UdevDb.txt

apport information

Revision history for this message
Launchpad Janitor (janitor) wrote :

Status changed to 'Confirmed' because the bug affects multiple users.

Changed in systemd (Ubuntu):
status: New → Confirmed
Revision history for this message
Pheeble (enpheebled-git) wrote :

This seems to be a problem with any systemd timer that contains a 'RandomizedDelaySec' value in the [Timer] section. Multiple randomization adjustments to a timer will often occur in quick succession, sometimes simultaneously, and for no purpose that I can see.

Perhaps systemd timers need a flag to indicate that timer randomization has already occurred since the relevant service was last run, so don't do it again.

This is the result of 'journalctl -b | grep "random time"' covering just the first hour after booting Xubuntu 16.04.1 this morning:

Nov 03 05:02:18 Phil-Desktop systemd[1]: hosts_append.timer: Adding 14.771780s random time.
Nov 03 05:02:18 Phil-Desktop systemd[1]: emachine-mount-nfs.timer: Adding 3.905842s random time.
Nov 03 05:02:18 Phil-Desktop systemd[1]: apt-daily.timer: Adding 11h 10min 46.989419s random time.
Nov 03 05:02:18 Phil-Desktop systemd[1]: send_boot_notify.timer: Adding 12.437715s random time.
Nov 03 05:02:18 Phil-Desktop systemd[1]: send_apt_upgrades_list.timer: Adding 41min 20.509782s random time.
Nov 03 05:02:18 Phil-Desktop systemd[1]: send_journald_log_list.timer: Adding 3min 48.321721s random time.
Nov 03 05:02:19 Phil-Desktop systemd[1]: send_apt_upgrades_list.timer: Adding 2min 53.039364s random time.
Nov 03 05:02:19 Phil-Desktop systemd[1]: send_journald_log_list.timer: Adding 9min 39.120834s random time.
Nov 03 05:02:19 Phil-Desktop systemd[1]: send_boot_notify.timer: Adding 649.932ms random time.
Nov 03 05:02:19 Phil-Desktop systemd[1]: apt-daily.timer: Adding 10h 36min 12.532296s random time.
Nov 03 05:02:19 Phil-Desktop systemd[1]: hosts_append.timer: Adding 4.994423s random time.
Nov 03 05:03:39 Phil-Desktop systemd[1]: apt-daily.timer: Adding 4h 53min 16.440349s random time.
Nov 03 05:03:39 Phil-Desktop systemd[1]: apt-daily.timer: Adding 8h 44min 23.219990s random time.
Nov 03 06:03:45 Phil-Desktop systemd[1]: send_apt_upgrades_list.timer: Adding 55min 558.055ms random time.
Nov 03 06:03:45 Phil-Desktop systemd[1]: send_apt_upgrades_list.timer: Adding 25min 6.210969s random time.

Revision history for this message
Pheeble (enpheebled-git) wrote :

Also, it appears that this bug is present in Debian: https://lists.debian.org/deity/2016/04/msg00047.html

Dan Streetman (ddstreet)
Changed in systemd (Ubuntu):
status: Confirmed → Won't Fix
To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.