Many error message such as "Start request repeated too quickly."

[Laurent Bonnaud]

* Analysis:

The error messages are caused by a bad interaction between systemd and laptop-mode-tools.

* Fixes:

There is a fix in systemd:
https://github.com/systemd/systemd/pull/3148

The problem can also be fixed by updating laptop-mode-tools.

* Symptoms:

Apr 08 20:23:50 xeelee systemd[1]: systemd-binfmt.service: Start request repeated too quickly.
Apr 08 20:23:50 xeelee systemd[1]: Failed to start Set Up Additional Binary Formats.
Apr 08 20:23:50 xeelee systemd[1]: friendly-recovery.service: Start request repeated too quickly.
Apr 08 20:23:50 xeelee systemd[1]: Failed to start Recovery mode menu.
Apr 08 20:23:50 xeelee systemd[1]: sys-kernel-config.mount: Start request repeated too quickly.
Apr 08 20:23:50 xeelee systemd[1]: Failed to mount Configuration File System.
Apr 08 20:23:50 xeelee systemd[1]: systemd-fsck-root.service: Start request repeated too quickly.
Apr 08 20:23:50 xeelee systemd[1]: Failed to start File System Check on Root Device.
Apr 08 20:23:50 xeelee systemd[1]: Started Show Plymouth Boot Screen.
Apr 08 20:23:50 xeelee systemd[1]: systemd-hwdb-update.service: Start request repeated too quickly.
Apr 08 20:23:50 xeelee systemd[1]: Failed to start Rebuild Hardware Database.
Apr 08 20:23:50 xeelee systemd[1]: systemd-binfmt.service: Start request repeated too quickly.
Apr 08 20:23:50 xeelee systemd[1]: Failed to start Set Up Additional Binary Formats.
Apr 08 20:23:50 xeelee systemd[1]: Starting Show Plymouth Boot Screen...
Apr 08 20:23:50 xeelee systemd[1]: friendly-recovery.service: Start request repeated too quickly.
Apr 08 20:23:50 xeelee systemd[1]: Failed to start Recovery mode menu.
Apr 08 20:23:50 xeelee systemd[1]: systemd-fsck-root.service: Start request repeated too quickly.
Apr 08 20:23:50 xeelee systemd[1]: Failed to start File System Check on Root Device.
Apr 08 20:23:50 xeelee systemd[1]: sys-kernel-config.mount: Start request repeated too quickly.
Apr 08 20:23:50 xeelee systemd[1]: Failed to mount Configuration File System.
Apr 08 20:23:50 xeelee systemd[1]: systemd-binfmt.service: Start request repeated too quickly.
Apr 08 20:23:50 xeelee systemd[1]: Failed to start Set Up Additional Binary Formats.
Apr 08 20:23:50 xeelee systemd[1]: systemd-hwdb-update.service: Start request repeated too quickly.
Apr 08 20:23:50 xeelee systemd[1]: Failed to start Rebuild Hardware Database.
Apr 08 20:23:50 xeelee systemd[1]: friendly-recovery.service: Start request repeated too quickly.
Apr 08 20:23:50 xeelee systemd[1]: Failed to start Recovery mode menu.
Apr 08 20:23:50 xeelee systemd[1]: systemd-fsck-root.service: Start request repeated too quickly.
Apr 08 20:23:50 xeelee systemd[1]: Failed to start File System Check on Root Device.
Apr 08 20:23:50 xeelee systemd[1]: sys-kernel-config.mount: Start request repeated too quickly.
Apr 08 20:23:50 xeelee systemd[1]: Failed to mount Configuration File System.
Apr 08 20:23:50 xeelee systemd[1]: Started Show Plymouth Boot Screen.
Apr 08 20:23:50 xeelee systemd[1]: friendly-recovery.service: Start request repeated too quickly.
Apr 08 20:23:50 xeelee systemd[1]: Failed to start Recovery mode menu.
Apr 08 20:23:50 xeelee systemd[1]: systemd-fsck-root.service: Start request repeated too quickly.
Apr 08 20:23:50 xeelee systemd[1]: Failed to start File System Check on Root Device.
Apr 08 20:23:50 xeelee systemd[1]: systemd-hwdb-update.service: Start request repeated too quickly.
Apr 08 20:23:50 xeelee systemd[1]: Failed to start Rebuild Hardware Database.
Apr 08 20:23:50 xeelee systemd[1]: sys-kernel-config.mount: Start request repeated too quickly.
Apr 08 20:23:50 xeelee systemd[1]: Failed to mount Configuration File System.
Apr 08 20:23:50 xeelee systemd[1]: systemd-binfmt.service: Start request repeated too quickly.
Apr 08 20:23:50 xeelee systemd[1]: Failed to start Set Up Additional Binary Formats.
Apr 08 20:23:50 xeelee systemd[1]: plymouth-start.service: Start request repeated too quickly.
Apr 08 20:23:50 xeelee systemd[1]: Failed to start Show Plymouth Boot Screen.
Apr 08 20:23:50 xeelee systemd[1]: systemd-ask-password-console.path: Start request repeated too quickly.
Apr 08 20:23:50 xeelee systemd[1]: Failed to start Dispatch Password Requests to Console Directory Watch.
Apr 08 20:23:50 xeelee systemd[1]: plymouth-start.service: Start request repeated too quickly.
Apr 08 20:23:50 xeelee systemd[1]: Failed to start Show Plymouth Boot Screen.
Apr 08 20:23:50 xeelee systemd[1]: systemd-binfmt.service: Start request repeated too quickly.
Apr 08 20:23:50 xeelee systemd[1]: Failed to start Set Up Additional Binary Formats.
Apr 08 20:23:50 xeelee systemd[1]: friendly-recovery.service: Start request repeated too quickly.
Apr 08 20:23:50 xeelee systemd[1]: Failed to start Recovery mode menu.
Apr 08 20:23:50 xeelee systemd[1]: sys-kernel-config.mount: Start request repeated too quickly.
Apr 08 20:23:50 xeelee systemd[1]: Failed to mount Configuration File System.
Apr 08 20:23:50 xeelee systemd[1]: systemd-ask-password-console.path: Start request repeated too quickly.
Apr 08 20:23:50 xeelee systemd[1]: Failed to start Dispatch Password Requests to Console Directory Watch.
Apr 08 20:23:50 xeelee systemd[1]: systemd-fsck-root.service: Start request repeated too quickly.
Apr 08 20:23:50 xeelee systemd[1]: Failed to start File System Check on Root Device.
Apr 08 20:23:50 xeelee systemd[1]: systemd-hwdb-update.service: Start request repeated too quickly.
Apr 08 20:23:50 xeelee systemd[1]: Failed to start Rebuild Hardware Database.

ProblemType: Bug
DistroRelease: Ubuntu 16.04
Package: systemd 229-4ubuntu1
Uname: Linux 4.5.0-040500-lowlatency x86_64
ApportVersion: 2.20.1-0ubuntu1
Architecture: amd64
CurrentDesktop: KDE
Date: Fri Apr 8 20:41:02 2016
MachineType: To Be Filled By O.E.M. To Be Filled By O.E.M.
ProcEnviron:
 TERM=xterm
 PATH=(custom, no user)
 XDG_RUNTIME_DIR=<set>
 LANG=en_US.UTF-8
 SHELL=/bin/bash
ProcKernelCmdLine: BOOT_IMAGE=/boot/vmlinuz-4.5.0-040500-lowlatency root=UUID=347d095b-3b19-412b-841e-acfd162e2c53 ro quiet splash nomdmonddf nomdmonisw vt.handoff=7
SourcePackage: systemd
UpgradeStatus: Upgraded to xenial on 2016-03-31 (8 days ago)
dmi.bios.date: 03/25/2013
dmi.bios.vendor: American Megatrends Inc.
dmi.bios.version: P1.50
dmi.board.name: HM77-HT
dmi.board.vendor: ASRock
dmi.chassis.asset.tag: To Be Filled By O.E.M.
dmi.chassis.type: 3
dmi.chassis.vendor: To Be Filled By O.E.M.
dmi.chassis.version: To Be Filled By O.E.M.
dmi.modalias: dmi:bvnAmericanMegatrendsInc.:bvrP1.50:bd03/25/2013:svnToBeFilledByO.E.M.:pnToBeFilledByO.E.M.:pvrToBeFilledByO.E.M.:rvnASRock:rnHM77-HT:rvr:cvnToBeFilledByO.E.M.:ct3:cvrToBeFilledByO.E.M.:
dmi.product.name: To Be Filled By O.E.M.
dmi.product.version: To Be Filled By O.E.M.
dmi.sys.vendor: To Be Filled By O.E.M.
mtime.conffile..etc.systemd.timesyncd.conf: 2015-10-21T22:12:17.831478

[Martin Pitt (pitti)]

What is the output of "sudo systemctl status --no-pager systemd-binfmt.service" in such a case? Just this log excerpt is not really helpful as it doesn't show what the actual problem is.

Can you please do "sudo journalctl -b > /tmp/journal.txt" and attach /tmp/journal.txt here?

[Laurent Bonnaud (laurent-bonnaud)]

# systemctl status --no-pager systemd-binfmt.service
● systemd-binfmt.service - Set Up Additional Binary Formats
   Loaded: loaded (/lib/systemd/system/systemd-binfmt.service; static; vendor preset: enabled)
   Active: inactive (dead)
Condition: start condition failed at Fri 2016-04-08 20:23:50 CEST; 5 days ago
     Docs: man:systemd-binfmt.service(8)
           man:binfmt.d(5)
           https://www.kernel.org/doc/Documentation/binfmt_misc.txt

Apr 08 20:23:50 xeelee systemd[1]: systemd-binfmt.service: Start request repeated too quickly.
Apr 08 20:23:50 xeelee systemd[1]: Failed to start Set Up Additional Binary Formats.
Apr 08 20:23:50 xeelee systemd[1]: systemd-binfmt.service: Start request repeated too quickly.
Apr 08 20:23:50 xeelee systemd[1]: Failed to start Set Up Additional Binary Formats.
Apr 08 20:23:50 xeelee systemd[1]: systemd-binfmt.service: Start request repeated too quickly.
Apr 08 20:23:50 xeelee systemd[1]: Failed to start Set Up Additional Binary Formats.
Apr 08 20:23:50 xeelee systemd[1]: systemd-binfmt.service: Start request repeated too quickly.
Apr 08 20:23:50 xeelee systemd[1]: Failed to start Set Up Additional Binary Formats.
Apr 08 20:23:50 xeelee systemd[1]: systemd-binfmt.service: Start request repeated too quickly.
Apr 08 20:23:50 xeelee systemd[1]: Failed to start Set Up Additional Binary Formats.

[Laurent Bonnaud (laurent-bonnaud)]

Here is the journal.

[Laurent Bonnaud (laurent-bonnaud)]

Note that my system has 2 binfmt.d directories

$ locate binfmt.d
/etc/binfmt.d
/usr/lib/binfmt.d
[...]

and that both are empty. Running systemd-binfmt manually gives no error and a 0 exit status:

# /lib/systemd/systemd-binfmt
# echo $?
0

[Martin Pitt (pitti)]

By default the various binfmt.d directories are indeed empty, that's normal and the 'condition failed' in systemctl status is entirely expected. So maybe what happens is that some other service repeatedly tries to run systemd-binfmt.service. Can you please give me the output of

  systemctl show systemd-binfmt.service |grep By

?

What might also help me is to run

  systemd-analyze dump > /tmp/dump.txt

and attach /tmp/dump.txt here.

Thanks!

[jondee (jonathandilks)]

I am having the exact same issue as the original poster. I see they haven't replied so I'll give you my output: :)

` systemctl show systemd-binfmt.service |grep By`:
WantedBy=sysinit.target

[jondee (jonathandilks)]

BTW I am running Ubuntu 16.04 (Release) upgraded from Ubuntu 15.10.

[Laurent Bonnaud (laurent-bonnaud)]

Same output on my system:

# systemctl show systemd-binfmt.service | grep By
WantedBy=sysinit.target

(systemd-analyze dump already attached by another user).

[Launchpad Janitor (janitor)]

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

[Laurent Bonnaud (laurent-bonnaud)]

Launchpad did not let me add the following URLs to external bug trackers:

https://bugs.archlinux.org/task/48267
https://github.com/systemd/systemd/issues/2684

There is also a patch:

https://github.com/systemd/systemd/pull/3148

[Laurent Bonnaud (laurent-bonnaud)]

Reading the other bug reports points to a problem in laptop-mode-tools.

A fix in recent laptop-mode-tools versions is also available.

[Laurent Bonnaud (laurent-bonnaud)]

I confirm that purging laptop-mode-tools from my system fixed the problem.

[Martin Pitt (pitti)]

This patch is in 230, so marking as fixed in yakkety. Thanks for investigating!

[Laurent Bonnaud (laurent-bonnaud)]

How about a backport for xenial ?

[Martin Pitt (pitti)]

AFAICS this should be https://github.com/systemd/systemd/pull/3148/commits/8b26cdbd2a9 and https://github.com/systemd/systemd/pull/3148/commits/7629ec4642, I'll see how well this backports.

[Martin Pitt (pitti)]

I backported the two patches and put a test package into https://launchpad.net/~pitti/+archive/ubuntu/sru-test (it's the only package there, so safe to upgrade). Feedback appreciated!

[Laurent Bonnaud (laurent-bonnaud)]

I tried to add your PPA the easy way, but it fails:

# apt-add-repository ppa:pitti/sru-test
Traceback (most recent call last):
  File "/usr/bin/apt-add-repository", line 95, in <module>
    sp = SoftwareProperties(options=options)
  File "/usr/lib/python3/dist-packages/softwareproperties/SoftwareProperties.py", line 109, in __init__
    self.reload_sourceslist()
  File "/usr/lib/python3/dist-packages/softwareproperties/SoftwareProperties.py", line 599, in reload_sourceslist
    self.distro.get_sources(self.sourceslist)
  File "/usr/lib/python3/dist-packages/aptsources/distro.py", line 89, in get_sources
    (self.id, self.codename))
aptsources.distro.NoDistroTemplateException: Error: could not find a distribution template for neon/xenial

I will add it manually to try it nevertheless...

[Martin Pitt (pitti)]

Laurent Bonnaud [2016-07-01 11:10 -0000]:
> aptsources.distro.NoDistroTemplateException: Error: could not find a distribution template for neon/xenial

Hmm, any idea where the "neon" comes from? That should be "ubuntu"
surely?

[Laurent Bonnaud (laurent-bonnaud)]

> Hmm, any idea where the "neon" comes from?

Yes it comes from KDE neon packages that I installed on my system and have the very bad idea to modify /etc/lsb-release. I already reported a bug, but the maintainers ignored it :<.

I will fix my system and report back for this SRU...

[Laurent Bonnaud (laurent-bonnaud)]

I tried to boot my system with this package version:

Package: systemd
Version: 229-4ubuntu6pitti1

both with and without the laptop-mode-tools package. In both cases my system boots and is usable.

Without laptop-mode-tools, there are no "Start request repeated too quickly" error messages.

With laptop-mode-tools, I get the following error messages:

juil. 01 17:45:19 vougeot systemd[1]: plymouth-read-write.service: Start request repeated too quickly.
juil. 01 17:45:19 vougeot systemd[1]: Failed to start Tell Plymouth To Write Out Runtime Data.
juil. 01 17:45:19 vougeot systemd[1]: plymouth-start.service: Start request repeated too quickly.
juil. 01 17:45:19 vougeot systemd[1]: Failed to start Show Plymouth Boot Screen.
juil. 01 17:45:19 vougeot systemd-udevd[383]: Process '/lib/udev/hdparm' failed with exit code 5.
juil. 01 17:45:19 vougeot systemd[1]: plymouth-read-write.service: Start request repeated too quickly.
juil. 01 17:45:19 vougeot systemd[1]: Failed to start Tell Plymouth To Write Out Runtime Data.
juil. 01 17:45:19 vougeot systemd[1]: plymouth-start.service: Start request repeated too quickly.
juil. 01 17:45:19 vougeot systemd[1]: Failed to start Show Plymouth Boot Screen.
juil. 01 17:45:19 vougeot systemd[1]: Found device SAMSUNG_SSD_830_Series 5.
juil. 01 17:45:19 vougeot systemd[1]: Starting Cryptography Setup for cryptswap1...
juil. 01 17:45:19 vougeot systemd[1]: plymouth-start.service: Start request repeated too quickly.
juil. 01 17:45:19 vougeot systemd[1]: Failed to start Show Plymouth Boot Screen.
juil. 01 17:45:19 vougeot systemd[1]: plymouth-read-write.service: Start request repeated too quickly.
juil. 01 17:45:19 vougeot systemd[1]: Failed to start Tell Plymouth To Write Out Runtime Data.

and more of the same kind a bit later (I will post complete boot logs...).

[Chris J Arges (arges)]

Hello Laurent, or anyone else affected,

Accepted systemd into xenial-proposed. The package will build now and be available at https://launchpad.net/ubuntu/+source/systemd/229-4ubuntu7 in a few hours, and then in the -proposed repository.

Please help us by testing this new package. See https://wiki.ubuntu.com/Testing/EnableProposed for documentation how to enable and use -proposed. Your feedback will aid us getting this update out to other Ubuntu users.

If this package fixes the bug for you, please add a comment to this bug, mentioning the version of the package you tested, and change the tag from verification-needed to verification-done. If it does not fix the bug for you, please add a comment stating that, and change the tag to verification-failed. In either case, details of your testing will help us make a better decision.

Further information regarding the verification process can be found at https://wiki.ubuntu.com/QATeam/PerformingSRUVerification . Thank you in advance!

[Launchpad Janitor (janitor)]

This bug was fixed in the package systemd - 229-4ubuntu7

---------------
systemd (229-4ubuntu7) xenial-proposed; urgency=medium

  * Add pre-dependency to dpkg >= 1.17.14 on udev, to ensure that
    dpkg-maintscript-helper symlink_to_dir is available. (LP: #1585406)
  * Add activation rate limiting for socket units. (LP: #1568094)
  * Split out udev rule to name USB network interfaces by MAC address into
    73-usb-net-by-mac.rules, so that it's easier to disable. (Closes: #824025)
  * 73-usb-net-by-mac.rules: Disable when net.ifnames=0 is specified on the
    kernel command line or if /etc/udev/rules.d/80-net-setup-link.rules is a
    symlink to /dev/null, to be consistent with disabling the *.link files and
    the documented way to disable ifnames. (Closes: #824491, LP: #1593379)
  * coredump: Fix "Coredump file descriptor missing". (LP: #1602256)

 -- Martin Pitt <email address hidden> Tue, 12 Jul 2016 17:37:25 +0200