[Bug 2098668] Re: DPCD accesses with nouveau fail; leading to other problems

Mario Limonciello 2098668 at bugs.launchpad.net
Mon Feb 17 16:49:19 UTC 2025 

> 2. Once it is up and running, starting the firmware-updater.firmware-notifier service produced this message:
> 15:55:12.499 FuPluginLinuxLockdown failed to ensure attribute fix flags: missing executable grubby in PATH

This message is to be expected; Ubuntu doesn't use grubby.

> 1. For some reason the fwupd program needs 20 minutes to recognize the
TPM module in my computer:

OK; if it's narrowed down to TPM then you can experiment with disabling
the TPM plugin for fwupd.  You can see about the DisabledPlugins key in
this:

https://fwupd.github.io/libfwupdplugin/fwupd.conf.html#daemon-parameters

If this helps, I feel we need to turn on some of the TPM library
debugging to characterize, we can follow up with the environment
variables that do this after we see if disabling the TPM plugin helps.

** Also affects: fwupd (Ubuntu)
   Importance: Undecided
       Status: New

** Summary changed:

- DPCD accesses with nouveau fail; leading to other problems
+ fwupd daemon hangs for a while during TPM access

-- 
You received this bug notification because you are a member of Ubuntu
Foundations Bugs, which is subscribed to fwupd in Ubuntu.
https://bugs.launchpad.net/bugs/2098668

Title:
  fwupd daemon hangs for a while during TPM access

Status in fwupd package in Ubuntu:
  New
Status in linux package in Ubuntu:
  New

Bug description:
  I was reviewing logs while trying to find evidence of an unrelated
  issue and found that fwupd.service fails to start due to a timeout.
  The logs below contain only the failure, I could not find the startup:

  2025-02-16T00:03:39.859015+01:00 user-ASUS-TUF-Gaming-A15-FA507NU-FA507NU systemd[1]: fwupd.service: Failed with result 'timeout'.
  2025-02-16T00:03:39.859180+01:00 user-ASUS-TUF-Gaming-A15-FA507NU-FA507NU systemd[1]: Failed to start fwupd.service - Firmware update daemon.
  2025-02-16T00:03:39.859258+01:00 user-ASUS-TUF-Gaming-A15-FA507NU-FA507NU systemd[1]: fwupd.service: Consumed 1min 3.456s CPU time.

  Here is another, probably incomplete instance. I attached the complete
  section of the log so maybe you can glean out what I missed. Here it
  is:

  2025-02-16T00:03:58.952797+01:00 user-ASUS-TUF-Gaming-A15-FA507NU-FA507NU systemd[1]: Starting fwupd.service - Firmware update daemon...
  2025-02-16T00:06:59.072774+01:00 user-ASUS-TUF-Gaming-A15-FA507NU-FA507NU systemd[1]: fwupd.service: start operation timed out. Terminating.
  2025-02-16T00:09:59.072836+01:00 user-ASUS-TUF-Gaming-A15-FA507NU-FA507NU systemd[1]: fwupd.service: State 'stop-sigterm' timed out. Killing.
  2025-02-16T00:09:59.073019+01:00 user-ASUS-TUF-Gaming-A15-FA507NU-FA507NU systemd[1]: fwupd.service: Killing process 1192141 (fwupd) with signal S
  2025-02-16T00:10:48.774997+01:00 user-ASUS-TUF-Gaming-A15-FA507NU-FA507NU systemd[1]: fwupd.service: Failed with result 'timeout'.
  2025-02-16T00:10:48.775165+01:00 user-ASUS-TUF-Gaming-A15-FA507NU-FA507NU systemd[1]: Failed to start fwupd.service - Firmware update daemon.
  2025-02-16T00:10:48.775230+01:00 user-ASUS-TUF-Gaming-A15-FA507NU-FA507NU systemd[1]: fwupd.service: Consumed 1min 3.020s CPU time.

  There is another service called snap.firmware-updater.firmware-
  notifier.service that fails to start and is repeatedly trying to
  restart. My gut says it fails because it needs fwupd.service to be
  running. Here are some of the logs:

  2025-02-16T00:00:11.588457+01:00 user-ASUS-TUF-Gaming-A15-FA507NU-FA507NU systemd[2477]: Started snap.firmware-updater.firmware-notifier.service - Service for snap application firmware-updater.firmware-notifier.
  2025-02-16T00:00:11.669261+01:00 user-ASUS-TUF-Gaming-A15-FA507NU-FA507NU kernel: audit: type=1400 audit(1739660411.667:15250): apparmor="DENIED" operation="open" class="file" profile="snap.firmware-updater.firmware-notifier" name="/proc/sys/vm/max_map_count" pid=1191308 comm="firmware-notifi" requested_mask="r" denied_mask="r" fsuid=1000 ouid=0
  2025-02-16T00:00:11.672348+01:00 user-ASUS-TUF-Gaming-A15-FA507NU-FA507NU dbus-daemon[1184]: [system] Activating via systemd: service name='org.freedesktop.fwupd' unit='fwupd.service' requested by ':1.19925' (uid=1000 pid=1191308 comm="/snap/firmware-updater/167/bin/firmware-notifier" label="snap.firmware-updater.firmware-notifier (enforce)")
  2025-02-16T00:00:36.677585+01:00 user-ASUS-TUF-Gaming-A15-FA507NU-FA507NU firmware-updater.firmware-notifier[1191308]: Unhandled exception:
  2025-02-16T00:00:36.677686+01:00 user-ASUS-TUF-Gaming-A15-FA507NU-FA507NU firmware-updater.firmware-notifier[1191308]: org.freedesktop.DBus.Error.TimedOut: Failed to activate service 'org.freedesktop.fwupd': timed out (service_start_timeout=25000ms)
  2025-02-16T00:00:36.677704+01:00 user-ASUS-TUF-Gaming-A15-FA507NU-FA507NU firmware-updater.firmware-notifier[1191308]: #0      DBusClient._callMethod (package:dbus/src/dbus_client.dart:1130)
  2025-02-16T00:00:36.677717+01:00 user-ASUS-TUF-Gaming-A15-FA507NU-FA507NU firmware-updater.firmware-notifier[1191308]: <asynchronous suspension>
  2025-02-16T00:00:36.677730+01:00 user-ASUS-TUF-Gaming-A15-FA507NU-FA507NU firmware-updater.firmware-notifier[1191308]: #1      DBusClient.callMethod (package:dbus/src/dbus_client.dart:621)
  2025-02-16T00:00:36.677743+01:00 user-ASUS-TUF-Gaming-A15-FA507NU-FA507NU firmware-updater.firmware-notifier[1191308]: <asynchronous suspension>
  2025-02-16T00:00:36.677754+01:00 user-ASUS-TUF-Gaming-A15-FA507NU-FA507NU firmware-updater.firmware-notifier[1191308]: #2      DBusRemoteObject.getAllProperties (package:dbus/src/dbus_remote_object.dart:142)
  2025-02-16T00:00:36.677774+01:00 user-ASUS-TUF-Gaming-A15-FA507NU-FA507NU firmware-updater.firmware-notifier[1191308]: <asynchronous suspension>
  2025-02-16T00:00:36.677786+01:00 user-ASUS-TUF-Gaming-A15-FA507NU-FA507NU firmware-updater.firmware-notifier[1191308]: #3      FwupdClient.connect (package:fwupd/src/fwupd_client.dart:133)
  2025-02-16T00:00:36.677799+01:00 user-ASUS-TUF-Gaming-A15-FA507NU-FA507NU firmware-updater.firmware-notifier[1191308]: <asynchronous suspension>
  2025-02-16T00:00:36.677809+01:00 user-ASUS-TUF-Gaming-A15-FA507NU-FA507NU firmware-updater.firmware-notifier[1191308]: #4      getUpdates (package:firmware_notifier/firmware_notifier.dart:10)
  2025-02-16T00:00:36.677826+01:00 user-ASUS-TUF-Gaming-A15-FA507NU-FA507NU firmware-updater.firmware-notifier[1191308]: <asynchronous suspension>
  2025-02-16T00:00:36.677836+01:00 user-ASUS-TUF-Gaming-A15-FA507NU-FA507NU firmware-updater.firmware-notifier[1191308]: #5      main (file:///build/firmware-updater/parts/firmware-notifier/build/apps/firmware_notifier/bin/firmware_notifier.dart:7)
  2025-02-16T00:00:36.677848+01:00 user-ASUS-TUF-Gaming-A15-FA507NU-FA507NU firmware-updater.firmware-notifier[1191308]: <asynchronous suspension>
  2025-02-16T00:00:36.678149+01:00 user-ASUS-TUF-Gaming-A15-FA507NU-FA507NU systemd[2477]: snap.firmware-updater.firmware-notifier.service: Main process exited, code=exited, status=255/EXCEPTION
  2025-02-16T00:00:36.678230+01:00 user-ASUS-TUF-Gaming-A15-FA507NU-FA507NU systemd[2477]: snap.firmware-updater.firmware-notifier.service: Failed with result 'exit-code'.
  2025-02-16T00:00:36.822693+01:00 user-ASUS-TUF-Gaming-A15-FA507NU-FA507NU systemd[2477]: snap.firmware-updater.firmware-notifier.service: Scheduled restart job, restart counter is at 14969.
  2025-02-16T00:00:36.837572+01:00 user-ASUS-TUF-Gaming-A15-FA507NU-FA507NU systemd[2477]: Started snap.firmware-updater.firmware-notifier.service - Service for snap application firmware-updater.firmware-notifier.
  2025-02-16T00:00:36.918257+01:00 user-ASUS-TUF-Gaming-A15-FA507NU-FA507NU kernel: audit: type=1400 audit(1739660436.917:15251): apparmor="DENIED" operation="open" class="file" profile="snap.firmware-updater.firmware-notifier" name="/proc/sys/vm/max_map_count" pid=1191382 comm="firmware-notifi" requested_mask="r" denied_mask="r" fsuid=1000 ouid=0
  2025-02-16T00:00:36.921046+01:00 user-ASUS-TUF-Gaming-A15-FA507NU-FA507NU dbus-daemon[1184]: [system] Activating via systemd: service name='org.freedesktop.fwupd' unit='fwupd.service' requested by ':1.19926' (uid=1000 pid=1191382 comm="/snap/firmware-updater/167/bin/firmware-notifier" label="snap.firmware-updater.firmware-notifier (enforce)")
  2025-02-16T00:01:01.932464+01:00 user-ASUS-TUF-Gaming-A15-FA507NU-FA507NU firmware-updater.firmware-notifier[1191382]: Unhandled exception:
  2025-02-16T00:01:01.932575+01:00 user-ASUS-TUF-Gaming-A15-FA507NU-FA507NU firmware-updater.firmware-notifier[1191382]: org.freedesktop.DBus.Error.TimedOut: Failed to activate service 'org.freedesktop.fwupd': timed out (service_start_timeout=25000ms)
  2025-02-16T00:01:01.932599+01:00 user-ASUS-TUF-Gaming-A15-FA507NU-FA507NU firmware-updater.firmware-notifier[1191382]: #0      DBusClient._callMethod (package:dbus/src/dbus_client.dart:1130)
  2025-02-16T00:01:01.932612+01:00 user-ASUS-TUF-Gaming-A15-FA507NU-FA507NU firmware-updater.firmware-notifier[1191382]: <asynchronous suspension>
  2025-02-16T00:01:01.932631+01:00 user-ASUS-TUF-Gaming-A15-FA507NU-FA507NU firmware-updater.firmware-notifier[1191382]: #1      DBusClient.callMethod (package:dbus/src/dbus_client.dart:621)
  2025-02-16T00:01:01.932644+01:00 user-ASUS-TUF-Gaming-A15-FA507NU-FA507NU firmware-updater.firmware-notifier[1191382]: <asynchronous suspension>
  2025-02-16T00:01:01.932655+01:00 user-ASUS-TUF-Gaming-A15-FA507NU-FA507NU firmware-updater.firmware-notifier[1191382]: #2      DBusRemoteObject.getAllProperties (package:dbus/src/dbus_remote_object.dart:142)
  2025-02-16T00:01:01.932668+01:00 user-ASUS-TUF-Gaming-A15-FA507NU-FA507NU firmware-updater.firmware-notifier[1191382]: <asynchronous suspension>
  2025-02-16T00:01:01.932679+01:00 user-ASUS-TUF-Gaming-A15-FA507NU-FA507NU firmware-updater.firmware-notifier[1191382]: #3      FwupdClient.connect (package:fwupd/src/fwupd_client.dart:133)
  2025-02-16T00:01:01.932692+01:00 user-ASUS-TUF-Gaming-A15-FA507NU-FA507NU firmware-updater.firmware-notifier[1191382]: <asynchronous suspension>
  2025-02-16T00:01:01.932703+01:00 user-ASUS-TUF-Gaming-A15-FA507NU-FA507NU firmware-updater.firmware-notifier[1191382]: #4      getUpdates (package:firmware_notifier/firmware_notifier.dart:10)
  2025-02-16T00:01:01.932718+01:00 user-ASUS-TUF-Gaming-A15-FA507NU-FA507NU firmware-updater.firmware-notifier[1191382]: <asynchronous suspension>
  2025-02-16T00:01:01.932729+01:00 user-ASUS-TUF-Gaming-A15-FA507NU-FA507NU firmware-updater.firmware-notifier[1191382]: #5      main (file:///build/firmware-updater/parts/firmware-notifier/build/apps/firmware_notifier/bin/firmware_notifier.dart:7)
  2025-02-16T00:01:01.932741+01:00 user-ASUS-TUF-Gaming-A15-FA507NU-FA507NU firmware-updater.firmware-notifier[1191382]: <asynchronous suspension>
  2025-02-16T00:01:01.933936+01:00 user-ASUS-TUF-Gaming-A15-FA507NU-FA507NU systemd[2477]: snap.firmware-updater.firmware-notifier.service: Main process exited, code=exited, status=255/EXCEPTION
  2025-02-16T00:01:01.934014+01:00 user-ASUS-TUF-Gaming-A15-FA507NU-FA507NU systemd[2477]: snap.firmware-updater.firmware-notifier.service: Failed with result 'exit-code'.
  2025-02-16T00:01:02.072709+01:00 user-ASUS-TUF-Gaming-A15-FA507NU-FA507NU systemd[2477]: snap.firmware-updater.firmware-notifier.service: Scheduled restart job, restart counter is at 14970.
  2025-02-16T00:01:02.083553+01:00 user-ASUS-TUF-Gaming-A15-FA507NU-FA507NU systemd[2477]: Started snap.firmware-updater.firmware-notifier.service - Service for snap application firmware-updater.firmware-notifier.
  2025-02-16T00:01:02.167251+01:00 user-ASUS-TUF-Gaming-A15-FA507NU-FA507NU kernel: audit: type=1400 audit(1739660462.166:15252): apparmor="DENIED" operation="open" class="file" profile="snap.firmware-updater.firmware-notifier" name="/proc/sys/vm/max_map_count" pid=1191451 comm="firmware-notifi" requested_mask="r" denied_mask="r" fsuid=1000 ouid=0
  2025-02-16T00:01:02.169670+01:00 user-ASUS-TUF-Gaming-A15-FA507NU-FA507NU dbus-daemon[1184]: [system] Activating via systemd: service name='org.freedesktop.fwupd' unit='fwupd.service' requested by ':1.19927' (uid=1000 pid=1191451 comm="/snap/firmware-updater/167/bin/firmware-notifier" label="snap.firmware-updater.firmware-notifier (enforce)")
  2025-02-16T00:01:17.342552+01:00 user-ASUS-TUF-Gaming-A15-FA507NU-FA507NU NetworkManager[1299]: <info>  [1739660477.3421] dhcp6 (eno1): state changed new lease, address=2a02:ab04:23b:7d00::f1
  2025-02-16T00:01:17.343437+01:00 user-ASUS-TUF-Gaming-A15-FA507NU-FA507NU dbus-daemon[1184]: [system] Activating via systemd: service name='org.freedesktop.nm_dispatcher' unit='dbus-org.freedesktop.nm-dispatcher.service' requested by ':1.14' (uid=0 pid=1299 comm="/usr/sbin/NetworkManager --no-daemon" label="unconfined")
  2025-02-16T00:01:17.365889+01:00 user-ASUS-TUF-Gaming-A15-FA507NU-FA507NU systemd[1]: Starting NetworkManager-dispatcher.service - Network Manager Script Dispatcher Service...
  2025-02-16T00:01:17.371061+01:00 user-ASUS-TUF-Gaming-A15-FA507NU-FA507NU dbus-daemon[1184]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher'
  2025-02-16T00:01:17.371210+01:00 user-ASUS-TUF-Gaming-A15-FA507NU-FA507NU systemd[1]: Started NetworkManager-dispatcher.service - Network Manager Script Dispatcher Service.
  2025-02-16T00:01:27.179156+01:00 user-ASUS-TUF-Gaming-A15-FA507NU-FA507NU firmware-updater.firmware-notifier[1191451]: Unhandled exception:
  2025-02-16T00:01:27.179283+01:00 user-ASUS-TUF-Gaming-A15-FA507NU-FA507NU firmware-updater.firmware-notifier[1191451]: org.freedesktop.DBus.Error.TimedOut: Failed to activate service 'org.freedesktop.fwupd': timed out (service_start_timeout=25000ms)
  2025-02-16T00:01:27.179300+01:00 user-ASUS-TUF-Gaming-A15-FA507NU-FA507NU firmware-updater.firmware-notifier[1191451]: #0      DBusClient._callMethod (package:dbus/src/dbus_client.dart:1130)
  2025-02-16T00:01:27.179315+01:00 user-ASUS-TUF-Gaming-A15-FA507NU-FA507NU firmware-updater.firmware-notifier[1191451]: <asynchronous suspension>
  2025-02-16T00:01:27.179330+01:00 user-ASUS-TUF-Gaming-A15-FA507NU-FA507NU firmware-updater.firmware-notifier[1191451]: #1      DBusClient.callMethod (package:dbus/src/dbus_client.dart:621)
  2025-02-16T00:01:27.179344+01:00 user-ASUS-TUF-Gaming-A15-FA507NU-FA507NU firmware-updater.firmware-notifier[1191451]: <asynchronous suspension>
  2025-02-16T00:01:27.179355+01:00 user-ASUS-TUF-Gaming-A15-FA507NU-FA507NU firmware-updater.firmware-notifier[1191451]: #2      DBusRemoteObject.getAllProperties (package:dbus/src/dbus_remote_object.dart:142)
  2025-02-16T00:01:27.179368+01:00 user-ASUS-TUF-Gaming-A15-FA507NU-FA507NU firmware-updater.firmware-notifier[1191451]: <asynchronous suspension>
  2025-02-16T00:01:27.179379+01:00 user-ASUS-TUF-Gaming-A15-FA507NU-FA507NU firmware-updater.firmware-notifier[1191451]: #3      FwupdClient.connect (package:fwupd/src/fwupd_client.dart:133)
  2025-02-16T00:01:27.179392+01:00 user-ASUS-TUF-Gaming-A15-FA507NU-FA507NU firmware-updater.firmware-notifier[1191451]: <asynchronous suspension>
  2025-02-16T00:01:27.179403+01:00 user-ASUS-TUF-Gaming-A15-FA507NU-FA507NU firmware-updater.firmware-notifier[1191451]: #4      getUpdates (package:firmware_notifier/firmware_notifier.dart:10)
  2025-02-16T00:01:27.179418+01:00 user-ASUS-TUF-Gaming-A15-FA507NU-FA507NU firmware-updater.firmware-notifier[1191451]: <asynchronous suspension>
  2025-02-16T00:01:27.179430+01:00 user-ASUS-TUF-Gaming-A15-FA507NU-FA507NU firmware-updater.firmware-notifier[1191451]: #5      main (file:///build/firmware-updater/parts/firmware-notifier/build/apps/firmware_notifier/bin/firmware_notifier.dart:7)
  2025-02-16T00:01:27.179442+01:00 user-ASUS-TUF-Gaming-A15-FA507NU-FA507NU firmware-updater.firmware-notifier[1191451]: <asynchronous suspension>
  2025-02-16T00:01:27.180555+01:00 user-ASUS-TUF-Gaming-A15-FA507NU-FA507NU systemd[2477]: snap.firmware-updater.firmware-notifier.service: Main process exited, code=exited, status=255/EXCEPTION
  2025-02-16T00:01:27.180667+01:00 user-ASUS-TUF-Gaming-A15-FA507NU-FA507NU systemd[2477]: snap.firmware-updater.firmware-notifier.service: Failed with result 'exit-code'.
  2025-02-16T00:01:27.322698+01:00 user-ASUS-TUF-Gaming-A15-FA507NU-FA507NU systemd[2477]: snap.firmware-updater.firmware-notifier.service: Scheduled restart job, restart counter is at 14971.

  ProblemType: Bug
  DistroRelease: Ubuntu 24.04
  Package: fwupd 1.9.27-0ubuntu1~24.04.1
  ProcVersionSignature: Ubuntu 6.8.0-53.55-generic 6.8.12
  Uname: Linux 6.8.0-53-generic x86_64
  ApportVersion: 2.28.1-0ubuntu3.3
  Architecture: amd64
  CasperMD5CheckResult: pass
  CurrentDesktop: ubuntu:GNOME
  Date: Mon Feb 17 13:32:34 2025
  InstallationDate: Installed on 2024-02-14 (369 days ago)
  InstallationMedia: Ubuntu 22.04.3 LTS "Jammy Jellyfish" - Release amd64 (20230807.2)
  ProcEnviron:
   PATH=(custom, no user)
   SHELL=/bin/bash
   TERM=xterm-256color
   XDG_RUNTIME_DIR=<set>
  SourcePackage: fwupd
  UpgradeStatus: Upgraded to noble on 2025-01-30 (18 days ago)
  modified.conffile..etc.fwupd.daemon.conf: [deleted]
  modified.conffile..etc.fwupd.fwupd.conf: [inaccessible: [Errno 13] Permission denied: '/etc/fwupd/fwupd.conf']
  modified.conffile..etc.fwupd.msr.conf: [deleted]
  modified.conffile..etc.fwupd.redfish.conf: [deleted]
  modified.conffile..etc.fwupd.thunderbolt.conf: [deleted]
  modified.conffile..etc.fwupd.uefi_capsule.conf: [deleted]

To manage notifications about this bug go to:
https://bugs.launchpad.net/ubuntu/+source/fwupd/+bug/2098668/+subscriptions

More information about the foundations-bugs mailing list