fwupd is eating 100% CPU for 30 minutes

[Marius Gedminas]

The fan of my laptop started going full-throttle and I ran htop to see why. I see a /usr/libexec/fwupd/fwupd eating 100% CPU for 29:55 minutes.

According to ps -o pid,lstart,etime,cmd the process was started yesterday at 22:44. The laptop was suspended yesterday at 23:15 and woken up this morning at 09:03. The time now is 11:26, so it doesn't seem to be directly related to the suspend.

perf top attributes all the time to libptrhead-2.31.so, in __pthread_rwlock_wrlock.

pstack is unable to extract a stack trace:

86826: /usr/libexec/fwupd/fwupd
(No symbols found)
crawl: Input/output error
Error tracing through process 86826
0x7f1c6e8cbe4a: ????

The journal has some interesting messages from fwupd this morning, but I hope apport will attach them.

ProblemType: Bug
DistroRelease: Ubuntu 20.04
Package: fwupd 1.3.11-1~focal1
ProcVersionSignature: Ubuntu 5.4.0-51.56-generic 5.4.65
Uname: Linux 5.4.0-51-generic x86_64
NonfreeKernelModules: zfs zunicode zavl icp zcommon znvpair
ApportVersion: 2.20.11-0ubuntu27.9
Architecture: amd64
CasperMD5CheckResult: skip
Date: Fri Oct 16 11:22:23 2020
ExecutablePath: /usr/libexec/fwupd/fwupd
InstallationDate: Installed on 2020-10-08 (7 days ago)
InstallationMedia: Ubuntu 20.04.1 LTS "Focal Fossa" - Release amd64 (20200731)
SourcePackage: fwupd
UpgradeStatus: No upgrade log present (probably fresh install)

[Marius Gedminas (mgedmin)]

So, apport didn't attach the journal, therefore

spal. 16 09:09:34 bigas systemd[1]: Finished Refresh fwupd metadata and update motd.
...
spal. 16 10:55:37 bigas fwupd[86826]: 07:55:37:0051 GLib-GObject invalid uninstantiatable type 'GParamInt64' in cast to 'FwupdDevice'
spal. 16 10:55:37 bigas fwupd[86826]: 07:55:37:0052 Fwupd fwupd_device_get_id: assertion 'FWUPD_IS_DEVICE (device)' failed
spal. 16 10:55:37 bigas fwupd[86826]: 07:55:37:0052 GLib-GObject ../../../gobject/gsignal.c:3482: invalid object type 'GParamInt64' for value type 'FuDevice'
spal. 16 10:55:37 bigas fwupd[86826]: 07:55:37:0059 GLib-GObject invalid unclassed pointer in cast to 'FuDeviceList'
spal. 16 10:55:37 bigas fwupd[86826]: 07:55:37:0059 GLib-GObject invalid unclassed pointer in cast to 'FwupdDevice'
spal. 16 10:55:37 bigas fwupd[86826]: 07:55:37:0059 Fwupd fwupd_device_get_id: assertion 'FWUPD_IS_DEVICE (device)' failed
spal. 16 10:55:37 bigas fwupd[86826]: 07:55:37:0059 GLib-GObject instance with invalid (NULL) class pointer
spal. 16 10:55:37 bigas fwupd[86826]: 07:55:37:0059 GLib-GObject g_signal_emit_valist: assertion 'G_TYPE_CHECK_INSTANCE (instance)' failed

and nothing since then, except for the 100% CPU loop

[Marius Gedminas (mgedmin)]

gdb is useless without debug symbols:

__pthread_rwlock_wrlock_full (abstime=0x0, clockid=0, rwlock=0x55af956f1a60) at pthread_rwlock_common.c:720
720 pthread_rwlock_common.c: No such file or directory.
(gdb) bt
#0 __pthread_rwlock_wrlock_full (abstime=0x0, clockid=0, rwlock=0x55af956f1a60) at pthread_rwlock_common.c:720
#1 __GI___pthread_rwlock_wrlock (rwlock=0x55af956f1a60) at pthread_rwlock_wrlock.c:27
#2 0x00007f1c6eae8b35 in g_rw_lock_writer_lock () from target:/lib/x86_64-linux-gnu/libglib-2.0.so.0
#3 0x000055af9397e5db in ?? ()
#4 0x00007f1c6ea9ca28 in ?? () from target:/lib/x86_64-linux-gnu/libglib-2.0.so.0
#5 0x00007f1c6ea9be8e in g_main_context_dispatch () from target:/lib/x86_64-linux-gnu/libglib-2.0.so.0
#6 0x00007f1c6ea9c240 in ?? () from target:/lib/x86_64-linux-gnu/libglib-2.0.so.0
#7 0x00007f1c6ea9c533 in g_main_loop_run () from target:/lib/x86_64-linux-gnu/libglib-2.0.so.0
#8 0x000055af93979e3d in main ()

[Mario Limonciello (superm1)]

Do you have a crash dump by chance? There are debug symbols available and they would as you say be immensely helpful. If you can send the crash with apport it will fetch nad process them automatically. If you can't send it via apport, here they are and you can install locally:

https://launchpad.net/ubuntu/+source/fwupd/1.3.11-1~focal1/+build/19494274/+files/fwupd-dbgsym_1.3.11-1~focal1_amd64.ddeb
https://launchpad.net/ubuntu/+source/fwupd/1.3.11-1~focal1/+build/19494274/+files/libfwupd2-dbgsym_1.3.11-1~focal1_amd64.ddeb
https://launchpad.net/ubuntu/+source/fwupd/1.3.11-1~focal1/+build/19494274/+files/libfwupdplugin1-dbgsym_1.3.11-1~focal1_amd64.ddeb

[Mario Limonciello (superm1)]

And just to confirm - you don't happen to have a bunch of libraries or other stuff in /usr/local that might be getting used? Those assertions seem quite unusual.

[Marius Gedminas (mgedmin)]

Definitely no custom stuff in /usr/local. This was a fresh install of 20.04 in a loaner laptop while mine was getting its keyboard repaired.

I'll have to boot it up and check /var/crash on Monday. I killed the misbehaving process with `kill` at the gdb prompt, IIRC. I don't know what signal it sends and whether it causes a core dump. I suspect it doesn't...

[Mario Limonciello (superm1)]

I don't think it does. If you manage to repro again please either core dump or install the symbols before back tracing. But I'm afraid it's a shot in the dark until we know more or can repro.

[Marius Gedminas (mgedmin)]

No crash file in /var/crash, unfortunately.

[Mario Limonciello (superm1)]

OK, then unfortunately nothing we can do. Please if this crops up again
1: If you attach gdb, then dump a core file
or
2: install debug symbols, attach gdb, and attach a backtrace.