fwupd / fwupd

A system daemon to allow session software to update firmware
GNU Lesser General Public License v2.1
2.78k stars 425 forks source link

systemd changes have caused fwupd-refresh.service to start to fail #3037

Closed equaeghe closed 2 years ago

equaeghe commented 3 years ago

Describe the bug I have the systemd fwupd-refresh.timer enabled. It normally triggers the fwupd-refresh.service. That service fails:

mrt 17 15:56:24 […] systemd[1]: Starting Refresh fwupd metadata and update motd...
░░ Subject: A start job for unit fwupd-refresh.service has begun execution
░░ Defined-By: systemd
░░ Support: https://gentoo.org/support/
░░ 
░░ A start job for unit fwupd-refresh.service has begun execution.
░░ 
░░ The job identifier is 4669.
mrt 17 15:56:24 […] systemd[1]: fwupd-refresh.service: Main process exited, code=exited, status=1/FAILURE
░░ Subject: Unit process exited
░░ Defined-By: systemd
░░ Support: https://gentoo.org/support/
░░ 
░░ An ExecStart= process belonging to unit fwupd-refresh.service has exited.
░░ 
░░ The process' exit code is 'exited' and its exit status is 1.
mrt 17 15:56:24 […] systemd[1]: fwupd-refresh.service: Failed with result 'exit-code'.
░░ Subject: Unit failed
░░ Defined-By: systemd
░░ Support: https://gentoo.org/support/
░░ 
░░ The unit fwupd-refresh.service has entered the 'failed' state with result 'exit-code'.
mrt 17 15:56:24 […] systemd[1]: Failed to start Refresh fwupd metadata and update motd.
░░ Subject: A start job for unit fwupd-refresh.service has failed
░░ Defined-By: systemd
░░ Support: https://gentoo.org/support/
░░ 
░░ A start job for unit fwupd-refresh.service has finished with a failure.
░░ 
░░ The job identifier is 4669 and the job result is failed.

Steps to Reproduce Seems to happen every time the service is triggered. Manually, I have managed to refresh.

Expected behavior The service generally runs without errors.

fwupd version information

client version: 1.4.6
compile-time dependency versions
        gusb:   0.3.5
        efivar: 37
daemon version: 1.4.6

Installed with Gentoo portage (emerge …)

fwupd device information

20UDS0DK00
│
├─USB3.1 Hub:
│ │   Device ID:          91c9a317b30acf7c0cd967f2ce6925d518ef19a7
│ │   Summary:            USB 3.x Hub
│ │   Current version:    13.24
│ │   Vendor:             VIA Labs, Inc. (USB:0x17EF)
│ │   Install Duration:   15 seconds
│ │   GUIDs:              227d0f95-a764-598e-85de-3d2bd0a7372f
│ │                       e0c50668-5c2e-54df-8e17-c7c2472f3eaa
│ │                       c6381f16-fe6d-5c45-a4ad-b619af4f0f0e
│ │                       fc6cfb35-d4e9-5467-a014-8863de104969
│ │                       7ae3100f-9b01-571c-9fc2-20cd4544123a
│ │                       ef65710a-3fa0-5330-9a61-5ced5e976be1
│ │                       eaf17a36-88e9-5757-8e99-a14b76fb20f3
│ │   Device Flags:       • Updatable
│ │                       • Cryptographic hash verification is available
│ │                       • Device stages updates
│ │                       • Device can recover flash failures
│ │
│ ├─USB3.1 Hub:
│ │     Device ID:        05285288b47a52d357895905caed1c00e37e22f0
│ │     Summary:          USB 3.x Hub
│ │     Current version:  13.23
│ │     Vendor:           VIA Labs, Inc. (USB:0x17EF)
│ │     Install Duration: 15 seconds
│ │     GUIDs:            7a216856-8a97-550c-882e-8233751c7cf2
│ │                       c6881bd6-7fc5-59f9-a21c-a1d525f817f4
│ │                       8b2439a7-f319-5583-950a-236eeecfe918
│ │                       41802a3a-da33-52c9-92d0-b3e4c8fc45d8
│ │                       1dff17fd-59c2-57b0-8500-690d4ed4ca8e
│ │                       bf4a4117-5351-5633-9dcf-83d67aee418e
│ │                       cf5f91c2-cb87-5e19-bef9-20ef14a2bcdb
│ │     Device Flags:     • Updatable
│ │                       • Cryptographic hash verification is available
│ │                       • Device stages updates
│ │                       • Device can recover flash failures
│ │
│ ├─ThinkPad USB-C Dock Gen2 PD Controller:
│ │     Device ID:        0578548f95398adbb50583bc26c6ce74b939e676
│ │     Summary:          CCGx Power Delivery Device
│ │     Current version:  0.0.34
│ │     Vendor:           Cypress Semiconductor (USB:0x04B4)
│ │     Install Duration: 2 minutes
│ │     GUIDs:            f6b5141d-eeb0-5ff1-b8de-ee4f02b222b7
│ │                       2c4d586a-a2a6-5957-9427-768add598121
│ │                       ebd96940-fa49-5cb1-b1a1-aa2d4dea1416
│ │                       5108e726-44a6-5eca-bd1a-fbbdabbe7bc1
│ │                       31d41b9b-361a-50ad-8bea-8dad3339fa04
│ │     Device Flags:     • Updatable
│ │                       • Requires AC power
│ │                       • Device stages updates
│ │                       • Device can recover flash failures
│ │                       
│ ├─ThinkPad USB-C Dock Gen2 USB Audio:
│ │     Device ID:        86d082eb55867f3b57b29971f95664475fe7e20c
│ │     Summary:          CX21985 USB audio device
│ │     Current version:  49-0E-14
│ │     Bootloader Version:03.01.00.00
│ │     Vendor:           Lenovo (USB:0x17EF)
│ │     Install Duration: 3 seconds
│ │     GUIDs:            a46dd995-530f-50ea-949e-81ef05951964
│ │                       98043a29-72c5-549b-ad23-de4e2db20a14
│ │                       dbb8d54c-42e6-5215-b7ac-1df16872bb06
│ │                       f26e104e-de08-5c71-a45c-81da433670d5
│ │     Device Flags:     • Updatable
│ │
│ ├─USB2.0 Hub:
│ │     Device ID:        fd94f61d160f9d39fba0f07711ec5006f32fede2
│ │     Summary:          USB 2.x Hub
│ │     Current version:  13.23
│ │     Vendor:           VIA Labs, Inc. (USB:0x17EF)
│ │     Install Duration: 15 seconds
│ │     GUIDs:            5a743458-4929-5738-a812-84cad6574a37
│ │                       7a216856-8a97-550c-882e-8233751c7cf2
│ │                       36a4a5cc-b78b-5419-a2ba-3a692148e9f5
│ │                       575dc5a0-ff9d-5df7-8777-aa9531061b0c
│ │                       9495f83b-bee0-5484-beeb-374325c67cb6
│ │                       72d3e9db-c1cd-5da6-86ab-c77cd419ea95
│ │     Device Flags:     • Updatable
│ │                       • Cryptographic hash verification is available
│ │                       • Device stages updates
│ │                       • Device can recover flash failures
│ │                       
│ └─USB2.0 Hub:
│       Device ID:        da77984c82b59c6fc69516431f467fd9a8d39a7f
│       Summary:          USB 2.x Hub
│       Current version:  13.24
│       Vendor:           VIA Labs, Inc. (USB:0x17EF)
│       Install Duration: 15 seconds
│       GUIDs:            010262bc-c6fa-5843-bffd-42be9aa16e6a
│                         227d0f95-a764-598e-85de-3d2bd0a7372f
│                         4ec36768-1858-5e9b-9d35-40e6143c3cd4
│                         b8ce86b1-5d74-5876-8d02-a9fd61b0a9ee
│                         181168b9-f5c8-51c4-a8f2-958daab8af2d
│                         c88af39f-41b7-5087-89ee-bf3bc70bf990
│       Device Flags:     • Updatable
│                         • Cryptographic hash verification is available
│                         • Device stages updates
│                         • Device can recover flash failures
│                         
├─AMD Ryzen 7 PRO 4750U with Radeon Graphics:
│     Device ID:          4bde70ba4e39b28f9eab1628f9dd6e6244c03027
│     Current version:    0x8600106
│     Vendor:             AuthenticAMD
│     GUID:               b9a2dd81-159e-5537-a7db-e7101d164d3f
│     Device Flags:       • Internal device
│
├─Integrated Camera:
│     Device ID:          54f0d9041b6c5438c7ff825f5139559c5ca1b222
│     Current version:    60.1
│     Vendor:             Azurewave (USB:0x13D3)
│     GUIDs:              c9b54303-2a5c-5da1-a441-bda12b11fff3
│                         db842a92-1141-541b-965a-2733a5726e17
│     Device Flags:       • Updatable
│
├─Prometheus:
│ │   Device ID:          50efef912094e784a03628350441f6927c4920b0
│ │   Summary:            Fingerprint reader
│ │   Current version:    10.01.3158804
│ │   Vendor:             Synaptics (USB:0x06CB)
│ │   Install Duration:   2 seconds
│ │   GUIDs:              09e8bf16-3e69-50f5-bb66-c7a040248352
│ │                       8088f861-6318-5b1e-9ce4-fbddbedb09ac
│ │   Device Flags:       • Updatable
│ │                       • Supported on remote server
│ │                       • Cryptographic hash verification is available
│ │
│ └─Prometheus IOTA Config:
│       Device ID:        30469829b6adc759baf3b0c3cf19454985aa73a2
│       Current version:  0022
│       Minimum Version:  0022
│       Vendor:           Synaptics (USB:0x06CB)
│       GUIDs:            7c5a1e62-38fa-5859-9337-09dbac6377e4
│                         21a62213-7012-552c-9f1a-a51d07c87242
│       Device Flags:     • Updatable
│                         • Supported on remote server
│
├─SKHynix HFS001TD9TNI-L2B0B:
│     Device ID:          71b677ca0f1bc2c5b804fa1d59e52064ce589293
│     Summary:            NVM Express Solid State Drive
│     Current version:    11720C10
│     Vendor:             SK hynix (NVME:0x1C5C)
│     GUIDs:              af90743d-93b0-5a7f-b3aa-08db33ab1f82
│                         85ef24c5-fc0a-57a6-ab37-5711ac8acfbb
│                         06f40517-864f-57be-9dad-d48bec1667e0
│     Device Flags:       • Internal device
│                         • Updatable
│                         • Requires AC power
│                         • Supported on remote server
│                         • Needs a reboot after installation
│                         • Device is usable for the duration of the update
│
├─System Firmware:
│     Device ID:          3f10cbb75c39627fc0d14eddd274374207a5c753
│     Current version:    0.1.29
│     Vendor:             LENOVO (DMI:LENOVO)
│     GUID:               01453b71-da0c-4832-9f4f-e378245339c7
│     Device Flags:       • Internal device
│                         • Updatable
│                         • Requires AC power
│                         • Supported on remote server
│                         • Needs a reboot after installation
│                         • Cryptographic hash verification is available
│                         • Device is usable for the duration of the update
│
├─TPM:
│ │   Device ID:          c6a80ac3a22083423992a3cb15018989f37834d6
│ │   Current version:    1.258.0.0
│ │   Vendor:             ST Microelectronics (TPM:STM)
│ │   GUIDs:              ff71992e-52f7-5eea-94ef-883e56e034c6
│ │                       84df3581-f896-54d2-bd1a-372602f04c32
│ │                       bfaed10a-bbc1-525b-a329-35da2f63e918
│ │                       70b7b833-7e1a-550a-a291-b94a12d0f319
│ │                       06f005e9-cb62-5d1a-82d9-13c534c53c48
│ │   Device Flags:       • Internal device
│ │
│ └─Event Log:
│       Device ID:        58bd405f31c48e6eca290b425f530a94c91e955c
│       GUID:             a25657fe-b5dc-5be0-8b78-8b9dfec678ff
│       Device Flags:     • Internal device
│
├─UEFI Device Firmware:
│     Device ID:          1c8d3b6c7cb08805789e84e05fc8f3b097237f1e
│     Current version:    1057227777
│     Vendor:             DMI:LENOVO
│     GUID:               3b7f92a6-36d0-49ae-a2d1-272f9a067274
│     Device Flags:       • Internal device
│                         • Updatable
│                         • Requires AC power
│                         • Needs a reboot after installation
│                         • Device is usable for the duration of the update
│
├─UEFI Device Firmware:
│     Device ID:          a1ea2f49e601f346e9540921ee09153f62464d4d
│     Current version:    16916636
│     Minimum Version:    1
│     Vendor:             DMI:LENOVO
│     GUID:               cc484fef-8758-41ce-b42f-f402f79881ac
│     Device Flags:       • Internal device
│                         • Updatable
│                         • Requires AC power
│                         • Needs a reboot after installation
│                         • Device is usable for the duration of the update
│
├─UEFI Device Firmware:
│     Device ID:          8c011dde02d2b5a0f20fb3636d48e2f7d2e9ec8a
│     Current version:    0
│     Vendor:             DMI:LENOVO
│     GUID:               1181d859-c3be-4b1d-985a-b28dca6ba6d8
│     Device Flags:       • Internal device
│                         • Updatable
│                         • Requires AC power
│                         • Needs a reboot after installation
│                         • Device is usable for the duration of the update
│
├─UEFI Device Firmware:
│     Device ID:          0309fe7d84b0b8e838ad1b2f22bd153906121cfc
│     Current version:    65565
│     Minimum Version:    65565
│     Vendor:             DMI:LENOVO
│     GUID:               4bea12df-56e3-4cdb-97dd-f133768c9051
│     Device Flags:       • Internal device
│                         • Updatable
│                         • Requires AC power
│                         • Needs a reboot after installation
│                         • Device is usable for the duration of the update
│
├─UEFI Device Firmware:
│     Device ID:          59edb884ed9f0680e4d027fa59d8f972d03044b4
│     Current version:    24577
│     Minimum Version:    1
│     Vendor:             DMI:LENOVO
│     GUID:               7d290ab6-bad9-4d27-bb17-642a3ef4cd98
│     Device Flags:       • Internal device
│                         • Updatable
│                         • Requires AC power
│                         • Needs a reboot after installation
│                         • Device is usable for the duration of the update
│
└─UEFI dbx:
      Device ID:          362301da643102b9f38477387e2193e57abaa590
      Summary:            UEFI Revocation Database
      Current version:    83
      Minimum Version:    83
      Vendor:             UEFI:Linux Foundation
      Install Duration:   1 second
      GUIDs:              14503b3d-73ce-5d06-8137-77c68972a341
                          5971a208-da00-5fce-b5f5-1234342f9cf7
                          c6682ade-b5ec-57c4-b687-676351208742
                          f8ba2887-9411-5c36-9cee-88995bb39731
      Device Flags:       • Internal device
                          • Updatable
                          • Needs a reboot after installation

Additional questions

superm1 commented 3 years ago

In the unit can you please add --verbose to the execution call and see if it provides more context on the failure?

equaeghe commented 3 years ago

It seems to give exactly the same output. (How do I check that indeed --verbose was used? I used systemctl edit fwupd-refresh.service to modify the unit file.)

superm1 commented 3 years ago

Hmm. Presumably that reloads the unit automatically.

Do you by chance have your user directories on NFS or anything else "non-standard"? LDAP?

equaeghe commented 3 years ago

No special setup. Generally typical desktop installation (on a laptop), but of course something must be atypical… Running /usr/bin/fwupdmgr refresh --no-metadata-check as in the ExecStart line of the unit file works fine. There must be something in the context created by the rest of the unit file that is the cause.

superm1 commented 3 years ago

The reason I was asking about NFS/LDAP is I know DynamicUsers in that unit has caused problems for people. I'm at a bit of a loss though. Can you strace the service maybe?

hughsie commented 3 years ago

Okay, feel free to re-open if you have any further details.

equaeghe commented 3 years ago

I looked at the issue again. For some reason, my custom service file (with --verbose added) was not used. Now it was (also including strace). So now using

ExecStart=strace /usr/bin/fwupdmgr refresh --no-metadata-check --verbose

This gave

May 05 13:43:57 TUE023621 systemd[1]: Starting Refresh fwupd metadata and update motd...
░░ Subject: A start job for unit fwupd-refresh.service has begun execution
░░ Defined-By: systemd
░░ Support: https://gentoo.org/support/
░░ 
░░ A start job for unit fwupd-refresh.service has begun execution.
░░ 
░░ The job identifier is 3979.
May 05 13:43:57 TUE023621 strace[237233]: (fwupdmgr:237233): GLib-DEBUG: 13:43:57.967: setenv()/putenv() are not thread-safe and should not be used after threads are created
May 05 13:43:57 TUE023621 systemd[1]: fwupd-refresh.service: Main process exited, code=exited, status=1/FAILURE
░░ Subject: Unit process exited
░░ Defined-By: systemd
░░ Support: https://gentoo.org/support/
░░ 
░░ An ExecStart= process belonging to unit fwupd-refresh.service has exited.
░░ 
░░ The process' exit code is 'exited' and its exit status is 1.
May 05 13:43:57 TUE023621 systemd[1]: fwupd-refresh.service: Failed with result 'exit-code'.
░░ Subject: Unit failed
░░ Defined-By: systemd
░░ Support: https://gentoo.org/support/
░░ 
░░ The unit fwupd-refresh.service has entered the 'failed' state with result 'exit-code'.
May 05 13:43:57 TUE023621 systemd[1]: Failed to start Refresh fwupd metadata and update motd.
░░ Subject: A start job for unit fwupd-refresh.service has failed
░░ Defined-By: systemd
░░ Support: https://gentoo.org/support/
░░ 
░░ A start job for unit fwupd-refresh.service has finished with a failure.
░░ 
░░ The job identifier is 3979 and the job result is failed.

There appears one GLib issue that is new. Please reopen.

superm1 commented 3 years ago

Seems that strace didn't add any value to the equation. Can you try to whittle down the extra clauses in the unit to find out what's borking things? I'd start out with taking out DynamicUsers

equaeghe commented 3 years ago

I did not see the issue any more the last few boots. An update of fwupd to 1.5.9 happened, but the first boot after that, I thought the problem was still there. In any case, I'm closing this and can always come back in case the problem turns out to still be present in some way.

mfat commented 2 years ago

This issue still affects me on a fully updated DEBIAN 11.

aleksandaratanasov commented 2 years ago

I have a freshly installed Ubuntu Server 20.04 with the latest cockpit (from the Ubuntu repos) and I am facing this issue too.

:~$ sudo systemctl status fwupd-refresh.service

fwupd-refresh.service - Refresh fwupd metadata and update motd
     Loaded: loaded (/lib/systemd/system/fwupd-refresh.service; static; vendor >
     Active: failed (Result: exit-code) since Tue 2022-04-12 18:53:17 UTC; 12h >
TriggeredBy: fwupd-refresh.timer
       Docs: man:fwupdmgr(1)
   Main PID: 204262 (code=exited, status=1/FAILURE)

If a patch has already provided I would like to ask whether it will be made available for Ubuntu Server 20.04 LTS.

superm1 commented 2 years ago

I have a freshly installed Ubuntu Server 20.04 with the latest cockpit (from the Ubuntu repos) and I am facing this issue too.

:~$ sudo systemctl status fwupd-refresh.service

fwupd-refresh.service - Refresh fwupd metadata and update motd
     Loaded: loaded (/lib/systemd/system/fwupd-refresh.service; static; vendor >
     Active: failed (Result: exit-code) since Tue 2022-04-12 18:53:17 UTC; 12h >
TriggeredBy: fwupd-refresh.timer
       Docs: man:fwupdmgr(1)
   Main PID: 204262 (code=exited, status=1/FAILURE)

If a patch has already provided I would like to ask whether it will be made available for Ubuntu Server 20.04 LTS.

What version of fwupd? Anything in the journal on the failure beyond this?

monster1612 commented 2 years ago

on my Ubuntu Server 20.04.4 LTS instance that's also running Cockpit (264 from focal-backports) and version 1.7.5-3 of the fwupd package, I get the same error even if I try to manually start the fwupd-refresh service.

sudo journalctl -xe produces this: ```Apr 15 15:38:19 server sudo[54856]: me : TTY=pts/0 ; PWD=/var/log ; USER=root ; COMMAND=/usr/bin/systemctl start fwupd-refresh Apr 15 15:38:19 server sudo[54856]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 15 15:38:19 server systemd[1]: Starting Refresh fwupd metadata and update motd... -- Subject: A start job for unit fwupd-refresh.service has begun execution -- Defined-By: systemd -- Support: http://www.ubuntu.com/support -- -- A start job for unit fwupd-refresh.service has begun execution. -- -- The job identifier is 12682. Apr 15 15:38:19 server systemd[1]: fwupd-refresh.service: Main process exited, code=exited, status=1/FAILURE -- Subject: Unit process exited -- Defined-By: systemd -- Support: http://www.ubuntu.com/support -- -- An ExecStart= process belonging to unit fwupd-refresh.service has exited. -- -- The process' exit code is 'exited' and its exit status is 1. Apr 15 15:38:19 server sudo[54856]: pam_unix(sudo:session): session closed for user root Apr 15 15:38:19 server systemd[1]: fwupd-refresh.service: Failed with result 'exit-code'. -- Subject: Unit failed -- Defined-By: systemd -- Support: http://www.ubuntu.com/support -- -- The unit fwupd-refresh.service has entered the 'failed' state with result 'exit-code'. Apr 15 15:38:19 server systemd[1]: Failed to start Refresh fwupd metadata and update motd. -- Subject: A start job for unit fwupd-refresh.service has failed -- Defined-By: systemd -- Support: http://www.ubuntu.com/support -- -- A start job for unit fwupd-refresh.service has finished with a failure. -- -- The job identifier is 12682 and the job result is failed. Apr 15 15:38:21 server sudo[54881]: me : TTY=pts/0 ; PWD=/var/log ; USER=root ; COMMAND=/usr/bin/journalctl -xe Apr 15 15:38:21 server sudo[54881]: pam_unix(sudo:session): session opened for user root by (uid=0) ```

the issue, for me, seems to have started roughly 2 days ago.

ealap commented 2 years ago

I also face the same issue after upgrading from Ubuntu 21.10 to 22.04. Modifying the service file by setting the option DynamicUser to no seems to have resolved it for me.

/usr/lib/systemd/system/fwupd-refresh.service ``` [Unit] Description=Refresh fwupd metadata and update motd Documentation=man:fwupdmgr(1) After=network.target [Service] Type=oneshot CacheDirectory=fwupdmgr StandardError=null DynamicUser=no RestrictAddressFamilies=AF_NETLINK AF_UNIX AF_INET AF_INET6 SystemCallFilter=~@mount ProtectKernelModules=yes ProtectControlGroups=yes RestrictRealtime=yes SuccessExitStatus=2 ExecStart=/usr/bin/fwupdmgr refresh --verbose ```

Reverting the value to yes will once again reproduce the issue. I just hope I am not missing out on something important by disabling this option.

daddiofaddio commented 2 years ago

Running Ubuntu Server 20.04 with fwupd version 1.7.5. Same issue as everyone above. Running "sudo journalctl -xe" produces same output as @monster1612. Started 2 days ago. As @ealap mentioned, editing /usr/lib/systemd/system/fwupd-refresh.service and changing "DynamicUser" to "no" appears to resolve the issue for now.

superm1 commented 2 years ago

I have a suspicion this is related to the permissions on the files or directories related to this process then. Maybe it's stateful based on an old version being upgraded?

If you guys can please look at /var/cache and /var/lib for fwupd related directories and look at permissions we can compare what is different from a working system.

monster1612 commented 2 years ago

I have a suspicion this is related to the permissions on the files or directories related to this process then. Maybe it's stateful based on an old version being upgraded?

If you guys can please look at /var/cache and /var/lib for fwupd related directories and look at permissions we can compare what is different from a working system.

ls -lash /var/cache/fwupd* ``` 0 lrwxrwxrwx 1 root root 16 Sep 12 2020 /var/cache/fwupdmgr -> private/fwupdmgr /var/cache/fwupd: total 4.5M 4.0K drwxr-xr-x 3 root root 4.0K Apr 15 15:26 . 4.0K drwxr-xr-x 18 root root 4.0K Jan 10 20:07 .. 4.4M -rw-r--r-- 1 root root 4.4M Apr 15 15:26 metadata.xmlb 4.0K -rw-r--r-- 1 root root 1.6K Apr 15 15:26 metainfo.xmlb 4.0K drwxr-xr-x 2 root root 4.0K Apr 15 15:21 motd.d 112K -rw-r--r-- 1 root root 112K Mar 11 22:21 quirks.xmlb ```
ls -lash /var/cache/private/fwupdmgr/fwupd* (following symlink) ``` total 736K 4.0K drwxr-xr-x 2 62803 62803 4.0K Aug 2 2021 . 4.0K drwxr-xr-x 3 62803 62803 4.0K Sep 12 2020 .. 724K -rw-r--r-- 1 62803 62803 722K Aug 2 2021 lvfs-metadata.xml.gz 4.0K -rw-r--r-- 1 62803 62803 488 Aug 2 2021 lvfs-metadata.xml.gz.asc ```
ls -lash /var/lib/fwupd* ``` total 56K 4.0K drwxr-xr-x 7 root root 4.0K Mar 11 22:21 . 4.0K drwxr-xr-x 60 root root 4.0K Apr 14 17:40 .. 4.0K drwx------ 3 root root 4.0K Apr 15 15:26 gnupg 4.0K drwxr-xr-x 3 root root 4.0K Mar 11 22:21 metadata 28K -rw-r--r-- 1 root root 28K Mar 11 22:21 pending.db 4.0K drwxr-xr-x 2 root root 4.0K Sep 12 2020 pki 4.0K drwxr-xr-x 2 root root 4.0K Mar 11 22:21 quirks.d 4.0K drwxr-xr-x 3 root root 4.0K Sep 12 2020 remotes.d ```
cybersi commented 2 years ago

Running Ubuntu Server 20.04 with fwupd version 1.7.5. Same issue as everyone above. Running "sudo journalctl -xe" produces same output as @monster1612. Started 2 days ago. As @ealap mentioned, editing /usr/lib/systemd/system/fwupd-refresh.service and changing "DynamicUser" to "no" appears to resolve the issue for now.

i'm experiencing the same on 20.04 and fwupd 1.7.5. At first I thought I caused it by (auto)removing the libfwupdplugin1 library. I did try reinstalling it but it did not help. Disabling DynamicUser does the trick.

My permissions:

ls -lash /var/cache/fwupd*
   0 lrwxrwxrwx 1 root root   16 Apr 18 11:22 /var/cache/fwupdmgr -> private/fwupdmgr

/var/cache/fwupd:
total 4.5M
4.0K drwxr-xr-x  2 root root 4.0K Apr 18 10:01 .
4.0K drwxr-xr-x 13 root root 4.0K Apr 18 11:22 ..
4.4M -rw-r--r--  1 root root 4.4M Apr 18 10:01 metadata.xmlb
4.0K -rw-r--r--  1 root root 1.6K Mar 12 23:40 metainfo.xmlb
112K -rw-r--r--  1 root root 112K Mar 12 23:40 quirks.xmlb 
ls -lash /var/lib/fwupd*
total 60K
4.0K drwxr-xr-x  7 root root 4.0K Mar 12 23:40 .
4.0K drwxr-xr-x 44 root root 4.0K Mar 12 17:55 ..
4.0K drwx------  3 root root 4.0K Apr 18 10:01 gnupg
4.0K drwxr-xr-x  3 root root 4.0K Mar 12 23:40 metadata
 32K -rw-r--r--  1 root root  32K Mar 12 23:40 pending.db
4.0K drwxr-xr-x  2 root root 4.0K Feb 25  2021 pki
4.0K drwxr-xr-x  2 root root 4.0K Mar 12 23:40 quirks.d
4.0K drwxr-xr-x  3 root root 4.0K Feb 26  2021 remotes.d
daddiofaddio commented 2 years ago

Current permissions and permissions from working backup dated 4/11/22:

**Current Permissions

ls -lash /var/cache/fwupd*
/var/cache/fwupd:
total 4.5M
4.0K drwxr-xr-x  2 root root 4.0K Apr 15 10:36 .
4.0K drwxr-xr-x 23 root root 4.0K Apr 17 08:52 ..
4.4M -rw-r--r--  1 root root 4.4M Apr 15 10:36 metadata.xmlb
4.0K -rw-r--r--  1 root root 1.6K Mar 10 10:52 metainfo.xmlb
112K -rw-r--r--  1 root root 112K Mar 10 10:52 quirks.xmlb

/var/cache/fwupdmgr:
total 12K
4.0K drwxr-xr-x  3 root root 4.0K Feb 20  2021 .
4.0K drwxr-xr-x 23 root root 4.0K Apr 17 08:52 ..
4.0K drwxr-xr-x  2 root root 4.0K Aug  9  2021 fwupd

ls -lash /var/lib/fwupd*
total 60K
4.0K drwxr-xr-x  7 root root 4.0K Mar 10 10:52 .
4.0K drwxr-xr-x 77 root root 4.0K Apr 12 10:29 ..
4.0K drwx------  3 root root 4.0K Apr 15 10:36 gnupg
4.0K drwxr-xr-x  3 root root 4.0K Mar 10 10:52 metadata
 32K -rw-r--r--  1 root root  32K Mar 10 10:52 pending.db
4.0K drwxr-xr-x  2 root root 4.0K Feb 20  2021 pki
4.0K drwxr-xr-x  2 root root 4.0K Mar 10 10:52 quirks.d
4.0K drwxr-xr-x  3 root root 4.0K Feb 20  2021 remotes.d

**Permissions from working backup - 4/11/22

ls -lash /var/cache/fwupd*
0 lrwxrwxrwx 1 root root 16 Feb 20  2021 /var/cache/fwupdmgr -> private/fwupdmgr

/var/cache/fwupd:
total 4.4M
   0 drwxr-xr-x  2 root root   83 Apr 10 20:34 .
4.0K drwxr-xr-x 22 root root 4.0K Feb 26 17:45 ..
4.3M -rw-r--r--  1 root root 4.3M Apr 10 20:34 metadata.xmlb
4.0K -rw-r--r--  1 root root 1.6K Mar 10 10:52 metainfo.xmlb
112K -rw-r--r--  1 root root 112K Mar 10 10:52 quirks.xmlb

ls -lash /var/lib/fwupd*
total 36K
   0 drwxr-xr-x  7 root root  125 Mar 10 10:52 .
4.0K drwxr-xr-x 78 root root 4.0K Feb 26 17:45 ..
   0 drwx------  3 root root  109 Apr 10 20:34 gnupg
   0 drwxr-xr-x  3 root root   26 Mar 10 10:52 metadata
 32K -rw-r--r--  1 root root  32K Mar 10 10:52 pending.db
   0 drwxr-xr-x  2 root root   54 Feb 20  2021 pki
   0 drwxr-xr-x  2 root root   10 Mar 10 10:52 quirks.d
   0 drwxr-xr-x  3 root root   26 Feb 20  2021 remotes.d
superm1 commented 2 years ago

Can those of you affected try to add "--verbose" into the launch command in the fwupd-refresh systemd unit? After you do, make sure you do systemctl daemon-reload fwupd-refresh.service. Please share the journal output from the failure with this in place.

superm1 commented 2 years ago

I'm wondering if this might actually be https://github.com/systemd/systemd/issues/22737

cybersi commented 2 years ago

Can those of you affected try to add "--verbose" into the launch command in the fwupd-refresh systemd unit? After you do, make sure you do systemctl daemon-reload fwupd-refresh.service. Please share the journal output from the failure with this in place.

Apr 18 18:13:47 borg-eth systemd[1]: Starting Refresh fwupd metadata and update motd...
Apr 18 18:13:47 borg-eth fwupdmgr[2755]: (fwupdmgr:2755): GLib-DEBUG: 18:13:47.532: setenv()/putenv() are not thread-safe and should not be used after threads are created
Apr 18 18:13:47 borg-eth fwupdmgr[2755]: (fwupdmgr:2755): GLib-GIO-DEBUG: 18:13:47.534: _g_io_module_get_default: Found default implementation dconf (DConfSettingsBackend) for ‘gsettings-backend’
Apr 18 18:13:47 borg-eth fwupdmgr[2755]: (fwupdmgr:2755): dconf-DEBUG: 18:13:47.534: watch_fast: "/system/proxy/" (establishing: 0, active: 0)
Apr 18 18:13:47 borg-eth fwupdmgr[2755]: (fwupdmgr:2755): dconf-DEBUG: 18:13:47.534: watch_fast: "/system/proxy/http/" (establishing: 0, active: 0)
Apr 18 18:13:47 borg-eth fwupdmgr[2755]: (fwupdmgr:2755): dconf-DEBUG: 18:13:47.534: watch_fast: "/system/proxy/https/" (establishing: 0, active: 0)
Apr 18 18:13:47 borg-eth fwupdmgr[2755]: (fwupdmgr:2755): dconf-DEBUG: 18:13:47.534: watch_fast: "/system/proxy/ftp/" (establishing: 0, active: 0)
Apr 18 18:13:47 borg-eth fwupdmgr[2755]: (fwupdmgr:2755): dconf-DEBUG: 18:13:47.534: watch_fast: "/system/proxy/socks/" (establishing: 0, active: 0)
Apr 18 18:13:47 borg-eth fwupdmgr[2755]: (fwupdmgr:2755): dconf-DEBUG: 18:13:47.534: watch_established: "/system/proxy/" (establishing: 1)
Apr 18 18:13:47 borg-eth fwupdmgr[2755]: (fwupdmgr:2755): dconf-DEBUG: 18:13:47.534: unwatch_fast: "/system/proxy/" (active: 1, establishing: 0)
Apr 18 18:13:47 borg-eth fwupdmgr[2755]: (fwupdmgr:2755): dconf-DEBUG: 18:13:47.534: watch_established: "/system/proxy/http/" (establishing: 1)
Apr 18 18:13:47 borg-eth fwupdmgr[2755]: (fwupdmgr:2755): dconf-DEBUG: 18:13:47.534: unwatch_fast: "/system/proxy/http/" (active: 1, establishing: 0)
Apr 18 18:13:47 borg-eth fwupdmgr[2755]: (fwupdmgr:2755): dconf-DEBUG: 18:13:47.534: watch_established: "/system/proxy/https/" (establishing: 1)
Apr 18 18:13:47 borg-eth fwupdmgr[2755]: (fwupdmgr:2755): dconf-DEBUG: 18:13:47.534: unwatch_fast: "/system/proxy/https/" (active: 1, establishing: 0)
Apr 18 18:13:47 borg-eth fwupdmgr[2755]: (fwupdmgr:2755): dconf-DEBUG: 18:13:47.534: watch_established: "/system/proxy/ftp/" (establishing: 1)
Apr 18 18:13:47 borg-eth fwupdmgr[2755]: (fwupdmgr:2755): dconf-DEBUG: 18:13:47.534: unwatch_fast: "/system/proxy/ftp/" (active: 1, establishing: 0)
Apr 18 18:13:47 borg-eth fwupdmgr[2755]: (fwupdmgr:2755): dconf-DEBUG: 18:13:47.534: watch_established: "/system/proxy/socks/" (establishing: 1)
Apr 18 18:13:47 borg-eth fwupdmgr[2755]: (fwupdmgr:2755): dconf-DEBUG: 18:13:47.534: unwatch_fast: "/system/proxy/socks/" (active: 1, establishing: 0)
Apr 18 18:13:47 borg-eth fwupdmgr[2755]: (fwupdmgr:2755): GLib-GIO-DEBUG: 18:13:47.535: _g_io_module_get_default: Found default implementation libproxy (GLibproxyResolver) for ‘gio-proxy-resolver’
Apr 18 18:13:47 borg-eth systemd[1]: fwupd-refresh.service: Main process exited, code=exited, status=1/FAILURE
Apr 18 18:13:47 borg-eth systemd[1]: fwupd-refresh.service: Failed with result 'exit-code'.
Apr 18 18:13:47 borg-eth systemd[1]: Failed to start Refresh fwupd metadata and update motd.
superm1 commented 2 years ago

Can those of you affected try to add "--verbose" into the launch command in the fwupd-refresh systemd unit? After you do, make sure you do systemctl daemon-reload fwupd-refresh.service. Please share the journal output from the failure with this in place.

sudo journalctl -fu fwupd-refresh.service
-- Logs begin at Tue 2021-12-14 08:31:44 CET. --
Apr 18 17:56:54 borg-eth fwupdmgr[2595]: (fwupdmgr:2595): dconf-DEBUG: 17:56:54.754: unwatch_fast: "/system/proxy/socks/" (active: 0, establishing: 1)
Apr 18 17:56:54 borg-eth fwupdmgr[2595]: (fwupdmgr:2595): dconf-DEBUG: 17:56:54.754: watch_established: "/system/proxy/" (establishing: 0)
Apr 18 17:56:54 borg-eth fwupdmgr[2595]: (fwupdmgr:2595): dconf-DEBUG: 17:56:54.754: watch_established: "/system/proxy/http/" (establishing: 0)
Apr 18 17:56:54 borg-eth fwupdmgr[2595]: (fwupdmgr:2595): dconf-DEBUG: 17:56:54.754: watch_established: "/system/proxy/https/" (establishing: 0)
Apr 18 17:56:54 borg-eth fwupdmgr[2595]: (fwupdmgr:2595): dconf-DEBUG: 17:56:54.754: watch_established: "/system/proxy/ftp/" (establishing: 0)
Apr 18 17:56:54 borg-eth fwupdmgr[2595]: (fwupdmgr:2595): dconf-DEBUG: 17:56:54.754: watch_established: "/system/proxy/socks/" (establishing: 0)
Apr 18 17:56:54 borg-eth fwupdmgr[2595]: (fwupdmgr:2595): GLib-GIO-DEBUG: 17:56:54.754: _g_io_module_get_default: Found default implementation libproxy (GLibproxyResolver) for ‘gio-proxy-resolver’
Apr 18 17:56:54 borg-eth systemd[1]: fwupd-refresh.service: Main process exited, code=exited, status=1/FAILURE
Apr 18 17:56:54 borg-eth systemd[1]: fwupd-refresh.service: Failed with result 'exit-code'.
Apr 18 17:56:54 borg-eth systemd[1]: Failed to start Refresh fwupd metadata and update motd.

Dang nothing too helpful there.

Can you try to prefix it with strace?

cybersi commented 2 years ago

Can those of you affected try to add "--verbose" into the launch command in the fwupd-refresh systemd unit? After you do, make sure you do systemctl daemon-reload fwupd-refresh.service. Please share the journal output from the failure with this in place.

sudo journalctl -fu fwupd-refresh.service
-- Logs begin at Tue 2021-12-14 08:31:44 CET. --
Apr 18 17:56:54 borg-eth fwupdmgr[2595]: (fwupdmgr:2595): dconf-DEBUG: 17:56:54.754: unwatch_fast: "/system/proxy/socks/" (active: 0, establishing: 1)
Apr 18 17:56:54 borg-eth fwupdmgr[2595]: (fwupdmgr:2595): dconf-DEBUG: 17:56:54.754: watch_established: "/system/proxy/" (establishing: 0)
Apr 18 17:56:54 borg-eth fwupdmgr[2595]: (fwupdmgr:2595): dconf-DEBUG: 17:56:54.754: watch_established: "/system/proxy/http/" (establishing: 0)
Apr 18 17:56:54 borg-eth fwupdmgr[2595]: (fwupdmgr:2595): dconf-DEBUG: 17:56:54.754: watch_established: "/system/proxy/https/" (establishing: 0)
Apr 18 17:56:54 borg-eth fwupdmgr[2595]: (fwupdmgr:2595): dconf-DEBUG: 17:56:54.754: watch_established: "/system/proxy/ftp/" (establishing: 0)
Apr 18 17:56:54 borg-eth fwupdmgr[2595]: (fwupdmgr:2595): dconf-DEBUG: 17:56:54.754: watch_established: "/system/proxy/socks/" (establishing: 0)
Apr 18 17:56:54 borg-eth fwupdmgr[2595]: (fwupdmgr:2595): GLib-GIO-DEBUG: 17:56:54.754: _g_io_module_get_default: Found default implementation libproxy (GLibproxyResolver) for ‘gio-proxy-resolver’
Apr 18 17:56:54 borg-eth systemd[1]: fwupd-refresh.service: Main process exited, code=exited, status=1/FAILURE
Apr 18 17:56:54 borg-eth systemd[1]: fwupd-refresh.service: Failed with result 'exit-code'.
Apr 18 17:56:54 borg-eth systemd[1]: Failed to start Refresh fwupd metadata and update motd.

Dang nothing too helpful there.

Can you try to prefix it with strace?

Apr 18 18:17:07 borg-eth systemd[1]: Starting Refresh fwupd metadata and update motd...
Apr 18 18:17:07 borg-eth strace[3301]: (fwupdmgr:3301): GLib-DEBUG: 18:17:07.798: setenv()/putenv() are not thread-safe and should not be used after threads are created
Apr 18 18:17:07 borg-eth strace[3301]: (fwupdmgr:3301): GLib-GIO-DEBUG: 18:17:07.804: _g_io_module_get_default: Found default implementation dconf (DConfSettingsBackend) for ‘gsettings-backend’
Apr 18 18:17:07 borg-eth strace[3301]: (fwupdmgr:3301): dconf-DEBUG: 18:17:07.804: watch_fast: "/system/proxy/" (establishing: 0, active: 0)
Apr 18 18:17:07 borg-eth strace[3301]: (fwupdmgr:3301): dconf-DEBUG: 18:17:07.805: watch_fast: "/system/proxy/http/" (establishing: 0, active: 0)
Apr 18 18:17:07 borg-eth strace[3301]: (fwupdmgr:3301): dconf-DEBUG: 18:17:07.805: watch_established: "/system/proxy/" (establishing: 1)
Apr 18 18:17:07 borg-eth strace[3301]: (fwupdmgr:3301): dconf-DEBUG: 18:17:07.805: watch_fast: "/system/proxy/https/" (establishing: 0, active: 0)
Apr 18 18:17:07 borg-eth strace[3301]: (fwupdmgr:3301): dconf-DEBUG: 18:17:07.805: watch_established: "/system/proxy/http/" (establishing: 1)
Apr 18 18:17:07 borg-eth strace[3301]: (fwupdmgr:3301): dconf-DEBUG: 18:17:07.805: watch_fast: "/system/proxy/ftp/" (establishing: 0, active: 0)
Apr 18 18:17:07 borg-eth strace[3301]: (fwupdmgr:3301): dconf-DEBUG: 18:17:07.805: watch_established: "/system/proxy/https/" (establishing: 1)
Apr 18 18:17:07 borg-eth strace[3301]: (fwupdmgr:3301): dconf-DEBUG: 18:17:07.805: watch_fast: "/system/proxy/socks/" (establishing: 0, active: 0)
Apr 18 18:17:07 borg-eth strace[3301]: (fwupdmgr:3301): dconf-DEBUG: 18:17:07.805: watch_established: "/system/proxy/ftp/" (establishing: 1)
Apr 18 18:17:07 borg-eth strace[3301]: (fwupdmgr:3301): dconf-DEBUG: 18:17:07.806: unwatch_fast: "/system/proxy/" (active: 1, establishing: 0)
Apr 18 18:17:07 borg-eth strace[3301]: (fwupdmgr:3301): dconf-DEBUG: 18:17:07.806: watch_established: "/system/proxy/socks/" (establishing: 1)
Apr 18 18:17:07 borg-eth strace[3301]: (fwupdmgr:3301): dconf-DEBUG: 18:17:07.806: unwatch_fast: "/system/proxy/http/" (active: 1, establishing: 0)
Apr 18 18:17:07 borg-eth strace[3301]: (fwupdmgr:3301): dconf-DEBUG: 18:17:07.806: unwatch_fast: "/system/proxy/https/" (active: 1, establishing: 0)
Apr 18 18:17:07 borg-eth strace[3301]: (fwupdmgr:3301): dconf-DEBUG: 18:17:07.806: unwatch_fast: "/system/proxy/ftp/" (active: 1, establishing: 0)
Apr 18 18:17:07 borg-eth strace[3301]: (fwupdmgr:3301): dconf-DEBUG: 18:17:07.806: unwatch_fast: "/system/proxy/socks/" (active: 1, establishing: 0)
Apr 18 18:17:07 borg-eth strace[3301]: (fwupdmgr:3301): GLib-GIO-DEBUG: 18:17:07.807: _g_io_module_get_default: Found default implementation libproxy (GLibproxyResolver) for ‘gio-proxy-resolver’
Apr 18 18:17:07 borg-eth systemd[1]: fwupd-refresh.service: Main process exited, code=exited, status=1/FAILURE
Apr 18 18:17:07 borg-eth systemd[1]: fwupd-refresh.service: Failed with result 'exit-code'.
Apr 18 18:17:07 borg-eth systemd[1]: Failed to start Refresh fwupd metadata and update motd.
superm1 commented 2 years ago

I mean to strace the launch command, we should be seeing system calls. Like this: ExecStart=strace fwupdmgr refresh --verbose

cybersi commented 2 years ago

I mean to strace the launch command, we should be seeing system calls. Like this: ExecStart=strace fwupdmgr refresh --verbose

This is what I used:

[Unit] Description=Refresh fwupd metadata and update motd Documentation=man:fwupdmgr(1) After=network.target

[Service] Type=oneshot CacheDirectory=fwupdmgr StandardError=null DynamicUser=yes RestrictAddressFamilies=AF_NETLINK AF_UNIX AF_INET AF_INET6 SystemCallFilter=~@mount ProtectKernelModules=yes ProtectControlGroups=yes RestrictRealtime=yes SuccessExitStatus=2 ExecStart=strace /usr/bin/fwupdmgr refresh --verbose

monster1612 commented 2 years ago

I mean to strace the launch command, we should be seeing system calls. Like this: ExecStart=strace fwupdmgr refresh --verbose

I modified the ExecStart command exactly as @cybersi documented, and got similar output.

sudo journalctl -xe ``` Apr 18 11:33:13 server sudo[75439]: me : TTY=pts/0 ; PWD=/home/me ; USER=root ; COMMAND=/usr/bin/systemctl start fwupd-refresh Apr 18 11:33:13 server sudo[75439]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 18 11:33:13 server systemd[1]: Starting Refresh fwupd metadata and update motd... -- Subject: A start job for unit fwupd-refresh.service has begun execution -- Defined-By: systemd -- Support: http://www.ubuntu.com/support -- -- A start job for unit fwupd-refresh.service has begun execution. -- -- The job identifier is 15836. Apr 18 11:33:13 server strace[75456]: (fwupdmgr:75456): GLib-DEBUG: 11:33:13.935: setenv()/putenv() are not thread-safe and should not be used after threads are created Apr 18 11:33:13 server strace[75456]: (fwupdmgr:75456): GLib-GIO-DEBUG: 11:33:13.964: _g_io_module_get_default: Found default implementation dconf (DConfSettingsBackend) for ‘gsettings-backend’ Apr 18 11:33:13 server strace[75456]: (fwupdmgr:75456): dconf-DEBUG: 11:33:13.965: watch_fast: "/system/proxy/" (establishing: 0, active: 0) Apr 18 11:33:13 server strace[75456]: (fwupdmgr:75456): dconf-DEBUG: 11:33:13.968: watch_fast: "/system/proxy/http/" (establishing: 0, active: 0) Apr 18 11:33:13 server strace[75456]: (fwupdmgr:75456): dconf-DEBUG: 11:33:13.969: watch_fast: "/system/proxy/https/" (establishing: 0, active: 0) Apr 18 11:33:13 server strace[75456]: (fwupdmgr:75456): dconf-DEBUG: 11:33:13.970: watch_fast: "/system/proxy/ftp/" (establishing: 0, active: 0) Apr 18 11:33:13 server strace[75456]: (fwupdmgr:75456): dconf-DEBUG: 11:33:13.971: watch_fast: "/system/proxy/socks/" (establishing: 0, active: 0) Apr 18 11:33:13 server strace[75456]: (fwupdmgr:75456): dconf-DEBUG: 11:33:13.973: watch_established: "/system/proxy/" (establishing: 1) Apr 18 11:33:13 server strace[75456]: (fwupdmgr:75456): dconf-DEBUG: 11:33:13.973: unwatch_fast: "/system/proxy/" (active: 1, establishing: 0) Apr 18 11:33:13 server strace[75456]: (fwupdmgr:75456): dconf-DEBUG: 11:33:13.974: watch_established: "/system/proxy/http/" (establishing: 1) Apr 18 11:33:13 server strace[75456]: (fwupdmgr:75456): dconf-DEBUG: 11:33:13.974: watch_established: "/system/proxy/https/" (establishing: 1) Apr 18 11:33:13 server strace[75456]: (fwupdmgr:75456): dconf-DEBUG: 11:33:13.974: watch_established: "/system/proxy/ftp/" (establishing: 1) Apr 18 11:33:13 server strace[75456]: (fwupdmgr:75456): dconf-DEBUG: 11:33:13.974: watch_established: "/system/proxy/socks/" (establishing: 1) Apr 18 11:33:13 server strace[75456]: (fwupdmgr:75456): dconf-DEBUG: 11:33:13.975: unwatch_fast: "/system/proxy/http/" (active: 1, establishing: 0) Apr 18 11:33:13 server strace[75456]: (fwupdmgr:75456): dconf-DEBUG: 11:33:13.975: unwatch_fast: "/system/proxy/https/" (active: 1, establishing: 0) Apr 18 11:33:13 server strace[75456]: (fwupdmgr:75456): dconf-DEBUG: 11:33:13.976: unwatch_fast: "/system/proxy/ftp/" (active: 1, establishing: 0) Apr 18 11:33:13 server strace[75456]: (fwupdmgr:75456): dconf-DEBUG: 11:33:13.977: unwatch_fast: "/system/proxy/socks/" (active: 1, establishing: 0) Apr 18 11:33:13 server strace[75456]: (fwupdmgr:75456): GLib-GIO-DEBUG: 11:33:13.980: _g_io_module_get_default: Found default implementation libproxy (GLibproxyResolver) for ‘gio-proxy-resolver’ Apr 18 11:33:13 server systemd[1]: fwupd-refresh.service: Main process exited, code=exited, status=1/FAILURE -- Subject: Unit process exited -- Defined-By: systemd -- Support: http://www.ubuntu.com/support -- -- An ExecStart= process belonging to unit fwupd-refresh.service has exited. -- -- The process' exit code is 'exited' and its exit status is 1. Apr 18 11:33:13 server sudo[75439]: pam_unix(sudo:session): session closed for user root Apr 18 11:33:13 server systemd[1]: fwupd-refresh.service: Failed with result 'exit-code'. -- Subject: Unit failed -- Defined-By: systemd -- Support: http://www.ubuntu.com/support -- -- The unit fwupd-refresh.service has entered the 'failed' state with result 'exit-code'. Apr 18 11:33:13 server systemd[1]: Failed to start Refresh fwupd metadata and update motd. -- Subject: A start job for unit fwupd-refresh.service has failed -- Defined-By: systemd -- Support: http://www.ubuntu.com/support -- -- A start job for unit fwupd-refresh.service has finished with a failure. -- -- The job identifier is 15836 and the job result is failed. ```
daddiofaddio commented 2 years ago

My results are also similar after changing launch to ExecStart=strace fwupdmgr refresh --verbose:

Apr 18 04:09:13 server.io systemd[1]: Starting Refresh fwupd metadata and update motd...
-- Subject: A start job for unit fwupd-refresh.service has begun execution
-- Defined-By: systemd
-- Support: http://www.ubuntu.com/support
-- 
-- A start job for unit fwupd-refresh.service has begun execution.
-- 
-- The job identifier is 8198.
Apr 18 04:09:13 server.io fwupdmgr[342231]: (fwupdmgr:342231): GLib-DEBUG: 04:09:13.113: setenv()/putenv() are not thread-safe and should not be used after threads are created
Apr 18 04:09:13 server.io fwupdmgr[342231]: (fwupdmgr:342231): GLib-GIO-DEBUG: 04:09:13.115: _g_io_module_get_default: Found default implementation dconf (DConfSettingsBackend) for ‘gsettings-backend’
Apr 18 04:09:13 server.io fwupdmgr[342231]: (fwupdmgr:342231): dconf-DEBUG: 04:09:13.115: watch_fast: "/system/proxy/" (establishing: 0, active: 0)
Apr 18 04:09:13 server.io fwupdmgr[342231]: (fwupdmgr:342231): dconf-DEBUG: 04:09:13.115: watch_fast: "/system/proxy/http/" (establishing: 0, active: 0)
Apr 18 04:09:13 server.io fwupdmgr[342231]: (fwupdmgr:342231): dconf-DEBUG: 04:09:13.115: watch_fast: "/system/proxy/https/" (establishing: 0, active: 0)
Apr 18 04:09:13 server.io fwupdmgr[342231]: (fwupdmgr:342231): dconf-DEBUG: 04:09:13.115: watch_fast: "/system/proxy/ftp/" (establishing: 0, active: 0)
Apr 18 04:09:13 server.io fwupdmgr[342231]: (fwupdmgr:342231): dconf-DEBUG: 04:09:13.115: watch_fast: "/system/proxy/socks/" (establishing: 0, active: 0)
Apr 18 04:09:13 server.io fwupdmgr[342231]: (fwupdmgr:342231): dconf-DEBUG: 04:09:13.115: watch_established: "/system/proxy/" (establishing: 1)
Apr 18 04:09:13 server.io fwupdmgr[342231]: (fwupdmgr:342231): dconf-DEBUG: 04:09:13.115: unwatch_fast: "/system/proxy/" (active: 1, establishing: 0)
Apr 18 04:09:13 server.io fwupdmgr[342231]: (fwupdmgr:342231): dconf-DEBUG: 04:09:13.115: watch_established: "/system/proxy/http/" (establishing: 1)
Apr 18 04:09:13 server.io fwupdmgr[342231]: (fwupdmgr:342231): dconf-DEBUG: 04:09:13.115: unwatch_fast: "/system/proxy/http/" (active: 1, establishing: 0)
Apr 18 04:09:13 server.io fwupdmgr[342231]: (fwupdmgr:342231): dconf-DEBUG: 04:09:13.115: watch_established: "/system/proxy/https/" (establishing: 1)
Apr 18 04:09:13 server.io fwupdmgr[342231]: (fwupdmgr:342231): dconf-DEBUG: 04:09:13.115: unwatch_fast: "/system/proxy/https/" (active: 1, establishing: 0)
Apr 18 04:09:13 server.io fwupdmgr[342231]: (fwupdmgr:342231): dconf-DEBUG: 04:09:13.115: watch_established: "/system/proxy/ftp/" (establishing: 1)
Apr 18 04:09:13 server.io fwupdmgr[342231]: (fwupdmgr:342231): dconf-DEBUG: 04:09:13.115: unwatch_fast: "/system/proxy/ftp/" (active: 1, establishing: 0)
Apr 18 04:09:13 server.io fwupdmgr[342231]: (fwupdmgr:342231): dconf-DEBUG: 04:09:13.115: watch_established: "/system/proxy/socks/" (establishing: 1)
Apr 18 04:09:13 server.io fwupdmgr[342231]: (fwupdmgr:342231): dconf-DEBUG: 04:09:13.115: unwatch_fast: "/system/proxy/socks/" (active: 1, establishing: 0)
Apr 18 04:09:13 server.io fwupdmgr[342231]: (fwupdmgr:342231): GLib-GIO-DEBUG: 04:09:13.116: _g_io_module_get_default: Found default implementation libproxy (GLibproxyResolver) for ‘gio-proxy-resolver’
Apr 18 04:09:13 server.io systemd[1]: fwupd-refresh.service: Main process exited, code=exited, status=1/FAILURE
-- Subject: Unit process exited
-- Defined-By: systemd
-- Support: http://www.ubuntu.com/support
-- 
-- An ExecStart= process belonging to unit fwupd-refresh.service has exited.
-- 
-- The process' exit code is 'exited' and its exit status is 1.
Apr 18 04:09:13 server.io systemd[1]: fwupd-refresh.service: Failed with result 'exit-code'.
-- Subject: Unit failed
-- Defined-By: systemd
-- Support: http://www.ubuntu.com/support
-- 
-- The unit fwupd-refresh.service has entered the 'failed' state with result 'exit-code'.
Apr 18 04:09:13 server.io systemd[1]: Failed to start Refresh fwupd metadata and update motd.
-- Subject: A start job for unit fwupd-refresh.service has failed
-- Defined-By: systemd
-- Support: http://www.ubuntu.com/support
-- 
-- A start job for unit fwupd-refresh.service has finished with a failure.
-- 
-- The job identifier is 8198 and the job result is failed.
superm1 commented 2 years ago

I'm really not sure then. We might need to add a lot more debugging to the code to figure out where exactly things fail for y'all with DynamicUser.

I'm tempted to remove that key, but then we would also need to create a dedicated user for the refresh process to use.

I suppose the other option is we could set up the daemon to be able to automatically refresh on its own with a forked process but that's a whole other can of worms.

ealap commented 2 years ago

I was able to print the error logs by changing the service option StandardError from null to syslog. Now I have this recorded from journalctl

Apr 19 18:14:57 [..] systemd[1]: Starting Refresh fwupd metadata and update motd...
    Subject: A start job for unit fwupd-refresh.service has begun execution
    Defined-By: systemd
    Support: http://www.ubuntu.com/support

    A start job for unit fwupd-refresh.service has begun execution.

    The job identifier is 14669.
Apr 19 18:14:57 [..] systemd[400365]: Found pre-existing public CacheDirectory= directory /var/cache/fwupdmgr, migrating to /var/cache/private/fwupdmgr.
Apr 19 18:14:57 [..] systemd[400365]: Apparently, service previously had DynamicUser= turned off, and has now turned it on.
Apr 19 18:14:57 [..] fwupdmgr[400365]: setenv()/putenv() are not thread-safe and should not be used after threads are created
Apr 19 18:14:57 [..] fwupdmgr[400365]: _g_io_module_get_default: Found default implementation dconf (DConfSettingsBackend) for ‘gsettings-backend’
Apr 19 18:14:57 [..] fwupdmgr[400365]: watch_fast: "/system/proxy/" (establishing: 0, active: 0)
Apr 19 18:14:57 [..] fwupdmgr[400365]: unable to create directory '/.cache/dconf': Read-only file system.  dconf will not work properly.
Apr 19 18:14:57 [..] fwupdmgr[400365]: watch_fast: "/system/proxy/http/" (establishing: 0, active: 0)
Apr 19 18:14:57 [..] fwupdmgr[400365]: unable to create directory '/.cache/dconf': Read-only file system.  dconf will not work properly.
Apr 19 18:14:57 [..] fwupdmgr[400365]: watch_fast: "/system/proxy/https/" (establishing: 0, active: 0)
Apr 19 18:14:57 [..] fwupdmgr[400365]: unable to create directory '/.cache/dconf': Read-only file system.  dconf will not work properly.
Apr 19 18:14:57 [..] fwupdmgr[400365]: watch_fast: "/system/proxy/ftp/" (establishing: 0, active: 0)
Apr 19 18:14:57 [..] fwupdmgr[400365]: unable to create directory '/.cache/dconf': Read-only file system.  dconf will not work properly.
Apr 19 18:14:57 [..] fwupdmgr[400365]: watch_fast: "/system/proxy/socks/" (establishing: 0, active: 0)
Apr 19 18:14:57 [..] fwupdmgr[400365]: unable to create directory '/.cache/dconf': Read-only file system.  dconf will not work properly.
Apr 19 18:14:57 [..] fwupdmgr[400365]: unwatch_fast: "/system/proxy/" (active: 0, establishing: 1)
Apr 19 18:14:57 [..] fwupdmgr[400365]: unwatch_fast: "/system/proxy/http/" (active: 0, establishing: 1)
Apr 19 18:14:57 [..] fwupdmgr[400365]: unwatch_fast: "/system/proxy/https/" (active: 0, establishing: 1)
Apr 19 18:14:57 [..] fwupdmgr[400365]: unwatch_fast: "/system/proxy/ftp/" (active: 0, establishing: 1)
Apr 19 18:14:57 [..] fwupdmgr[400365]: unwatch_fast: "/system/proxy/socks/" (active: 0, establishing: 1)
Apr 19 18:14:57 [..] fwupdmgr[400365]: _g_io_module_get_default: Found default implementation libproxy (GLibproxyResolver) for ‘gio-proxy-resolver’
Apr 19 18:14:57 [..] fwupdmgr[400365]: unable to create directory '/.cache/dconf': Read-only file system.  dconf will not work properly.
Apr 19 18:14:57 [..] fwupdmgr[400365]: watch_established: "/system/proxy/" (establishing: 0)
Apr 19 18:14:57 [..] fwupdmgr[400365]: unable to create directory '/.cache/dconf': Read-only file system.  dconf will not work properly.
Apr 19 18:14:57 [..] fwupdmgr[400365]: watch_established: "/system/proxy/http/" (establishing: 0)
Apr 19 18:14:57 [..] fwupdmgr[400365]: unable to create directory '/.cache/dconf': Read-only file system.  dconf will not work properly.
Apr 19 18:14:57 [..] fwupdmgr[400365]: watch_established: "/system/proxy/https/" (establishing: 0)
Apr 19 18:14:57 [..] fwupdmgr[400365]: unable to create directory '/.cache/dconf': Read-only file system.  dconf will not work properly.
Apr 19 18:14:57 [..] fwupdmgr[400365]: watch_established: "/system/proxy/ftp/" (establishing: 0)
Apr 19 18:14:57 [..] fwupdmgr[400365]: unable to create directory '/.cache/dconf': Read-only file system.  dconf will not work properly.
Apr 19 18:14:57 [..] fwupdmgr[400365]: Failed to connect to daemon: Exhausted all available authentication mechanisms (tried: EXTERNAL) (available: EXTERNAL)
Apr 19 18:14:57 [..] fwupdmgr[400365]: watch_established: "/system/proxy/socks/" (establishing: 0)
Apr 19 18:14:57 [..] systemd[1]: fwupd-refresh.service: Main process exited, code=exited, status=1/FAILURE
    Subject: Unit process exited
    Defined-By: systemd
    Support: http://www.ubuntu.com/support

    An ExecStart= process belonging to unit fwupd-refresh.service has exited.

    The process' exit code is 'exited' and its exit status is 1.
Apr 19 18:14:57 [..] systemd[1]: fwupd-refresh.service: Failed with result 'exit-code'.
    Subject: Unit failed
    Defined-By: systemd
    Support: http://www.ubuntu.com/support

    The unit fwupd-refresh.service has entered the 'failed' state with result 'exit-code'.
Apr 19 18:14:57 [..] systemd[1]: Failed to start Refresh fwupd metadata and update motd.
    Subject: A start job for unit fwupd-refresh.service has failed
    Defined-By: systemd
    Support: http://www.ubuntu.com/support

    A start job for unit fwupd-refresh.service has finished with a failure.

    The job identifier is 14669 and the job result is failed.

So this might be the error you need?

unable to create directory '/.cache/dconf': Read-only file system.  dconf will not work properly.
superm1 commented 2 years ago

Actually this looks like the error to me that we care about:

Failed to connect to daemon: Exhausted all available authentication mechanisms (tried: EXTERNAL) (available: EXTERNAL)

What that means is that the failure is occurring here: https://github.com/fwupd/fwupd/blob/01aaa97bcdb6d1f32ae8c52cb4c5428e28fef577/src/fu-util.c#L4406

Something about the environment that the unit is running under is preventing it from authenticating with the daemon. In one terminal if you start up sudo dbus-monitor --system interface=org.freedesktop.fwupd you can see if the daemon even gets the message from the service. I'm guessing it doesn't.

As for why, that's another layer of the onion.

Meth0d007 commented 2 years ago

Just wanted to add my +1 on this.

Since last night ubuntu 20 LTS updates (i suspect systemd) we are seeing these errors in our monitoring:

● fwupd-refresh.service - Refresh fwupd metadata and update motd
     Loaded: loaded (/lib/systemd/system/fwupd-refresh.service; static; vendor preset: disabled)
     Active: failed (Result: exit-code) since Wed 2022-04-20 11:19:05 UTC; 8min ago
TriggeredBy: ● fwupd-refresh.timer
       Docs: man:fwupdmgr(1)
    Process: 108516 ExecStart=/usr/bin/fwupdmgr refresh (code=exited, status=1/FAILURE)
   Main PID: 108516 (code=exited, status=1/FAILURE)

Apr 20 11:19:05 srvbookstack systemd[1]: Starting Refresh fwupd metadata and update motd...
Apr 20 11:19:05 srvbookstack systemd[1]: fwupd-refresh.service: Main process exited, code=exited, status=1/FAILURE
Apr 20 11:19:05 srvbookstack systemd[1]: fwupd-refresh.service: Failed with result 'exit-code'.
Apr 20 11:19:05 srvbookstack systemd[1]: Failed to start Refresh fwupd metadata and update motd.
Start-Date: 2022-04-19  19:09:48
Commandline: apt upgrade -y
Install: linux-headers-5.4.0-109:amd64 (5.4.0-109.123, automatic), linux-modules-extra-5.4.0-109-generic:amd64 (5.4.0-109.123, automatic), linux-modules-5.4.0-109-generic:amd64 (5.4.0-109.123, automatic), linux-headers-5.4.0-109-generic:amd64 (5.4.0-109.123, automatic), linux-image-5.4.0-109-generic:amd64 (5.4.0-109.123, automatic)
Upgrade: linux-headers-generic:amd64 (5.4.0.107.111, 5.4.0.109.113), libsystemd0:amd64 (245.4-4ubuntu3.15, 245.4-4ubuntu3.16), linux-image-generic:amd64 (5.4.0.107.111, 5.4.0.109.113), udev:amd64 (245.4-4ubuntu3.15, 245.4-4ubuntu3.16), libudev1:amd64 (245.4-4ubuntu3.15, 245.4-4ubuntu3.16), systemd-timesyncd:amd64 (245.4-4ubuntu3.15, 245.4-4ubuntu3.16), apport:amd64 (2.20.11-0ubuntu27.21, 2.20.11-0ubuntu27.23), python3-distupgrade:amd64 (1:20.04.37, 1:20.04.38), ubuntu-release-upgrader-core:amd64 (1:20.04.37, 1:20.04.38), python3-apport:amd64 (2.20.11-0ubuntu27.21, 2.20.11-0ubuntu27.23), systemd-sysv:amd64 (245.4-4ubuntu3.15, 245.4-4ubuntu3.16), libpam-systemd:amd64 (245.4-4ubuntu3.15, 245.4-4ubuntu3.16), systemd:amd64 (245.4-4ubuntu3.15, 245.4-4ubuntu3.16), libnss-systemd:amd64 (245.4-4ubuntu3.15, 245.4-4ubuntu3.16), linux-generic:amd64 (5.4.0.107.111, 5.4.0.109.113), python3-problem-report:amd64 (2.20.11-0ubuntu27.21, 2.20.11-0ubuntu27.23)
End-Date: 2022-04-19  19:11:00
superm1 commented 2 years ago

Just wanted to add my +1 on this.

Since last night ubuntu 20 LTS updates (i suspect systemd) we are seeing these errors in our monitoring:

● fwupd-refresh.service - Refresh fwupd metadata and update motd
     Loaded: loaded (/lib/systemd/system/fwupd-refresh.service; static; vendor preset: disabled)
     Active: failed (Result: exit-code) since Wed 2022-04-20 11:19:05 UTC; 8min ago
TriggeredBy: ● fwupd-refresh.timer
       Docs: man:fwupdmgr(1)
    Process: 108516 ExecStart=/usr/bin/fwupdmgr refresh (code=exited, status=1/FAILURE)
   Main PID: 108516 (code=exited, status=1/FAILURE)

Apr 20 11:19:05 srvbookstack systemd[1]: Starting Refresh fwupd metadata and update motd...
Apr 20 11:19:05 srvbookstack systemd[1]: fwupd-refresh.service: Main process exited, code=exited, status=1/FAILURE
Apr 20 11:19:05 srvbookstack systemd[1]: fwupd-refresh.service: Failed with result 'exit-code'.
Apr 20 11:19:05 srvbookstack systemd[1]: Failed to start Refresh fwupd metadata and update motd.
Start-Date: 2022-04-19  19:09:48
Commandline: apt upgrade -y
Install: linux-headers-5.4.0-109:amd64 (5.4.0-109.123, automatic), linux-modules-extra-5.4.0-109-generic:amd64 (5.4.0-109.123, automatic), linux-modules-5.4.0-109-generic:amd64 (5.4.0-109.123, automatic), linux-headers-5.4.0-109-generic:amd64 (5.4.0-109.123, automatic), linux-image-5.4.0-109-generic:amd64 (5.4.0-109.123, automatic)
Upgrade: linux-headers-generic:amd64 (5.4.0.107.111, 5.4.0.109.113), libsystemd0:amd64 (245.4-4ubuntu3.15, 245.4-4ubuntu3.16), linux-image-generic:amd64 (5.4.0.107.111, 5.4.0.109.113), udev:amd64 (245.4-4ubuntu3.15, 245.4-4ubuntu3.16), libudev1:amd64 (245.4-4ubuntu3.15, 245.4-4ubuntu3.16), systemd-timesyncd:amd64 (245.4-4ubuntu3.15, 245.4-4ubuntu3.16), apport:amd64 (2.20.11-0ubuntu27.21, 2.20.11-0ubuntu27.23), python3-distupgrade:amd64 (1:20.04.37, 1:20.04.38), ubuntu-release-upgrader-core:amd64 (1:20.04.37, 1:20.04.38), python3-apport:amd64 (2.20.11-0ubuntu27.21, 2.20.11-0ubuntu27.23), systemd-sysv:amd64 (245.4-4ubuntu3.15, 245.4-4ubuntu3.16), libpam-systemd:amd64 (245.4-4ubuntu3.15, 245.4-4ubuntu3.16), systemd:amd64 (245.4-4ubuntu3.15, 245.4-4ubuntu3.16), libnss-systemd:amd64 (245.4-4ubuntu3.15, 245.4-4ubuntu3.16), linux-generic:amd64 (5.4.0.107.111, 5.4.0.109.113), python3-problem-report:amd64 (2.20.11-0ubuntu27.21, 2.20.11-0ubuntu27.23)
End-Date: 2022-04-19  19:11:00

Are you sure it didn't happen before this? If so we should have a good pointer at patches that went into systemd in that version.

If you can correlate from the journal please.

Meth0d007 commented 2 years ago

Yes i am sure, we have not seen this error in our monitoring until yesterday right after the apt updates. Last night was a maintenance window where updates have beein installed via apt, after the reboot i see the failed service state was picked up by our monitoring. The only thing that changed you see in the apt/history.log above, so systemd is imho a very safe bet.

image

rdiez commented 2 years ago

After 2 weeks off, I updated my Ubuntu 20.04.4 yesterday, and I started getting this failure today. I noticed because I am running Prometheus to monitor failed systemd services.

Meth0d007 commented 2 years ago

I have confirmed this on every Ubuntu 20 LTS we operate (around 15) . All of them have gotten a bunch of updates at least yesterday and on all of them have fwupd-refresh.service failed now. The only updates i can relate to this are kernel, udev and systemd.

superm1 commented 2 years ago

Here is the changelog for that release: https://launchpad.net/ubuntu/+source/systemd/245.4-4ubuntu3.16 The most likely suspect is https://git.launchpad.net/~ubuntu-core-dev/ubuntu/+source/systemd/commit/?id=e3aacfa26e3fc6df369e6f28e740389ae0020907 which is actually the same thing I linked above with new systemd. https://github.com/systemd/systemd/issues/22737

superm1 commented 2 years ago

FYI, I can repro this with Ubuntu 22.04 as well now with the updated systemd there that I checked. Anyone else affected by this that it's filling up monitoring logs I think you should systemctl mask fwupd-refresh.service until a systemd solution is made available.

superm1 commented 2 years ago

Something I realized odd about this situation is that we actually do ship a fwupd-refresh.preset that should default the unit to disabled. So why are all of these failures happening when it's disabled?

superm1 commented 2 years ago

Maybe the preset doesn't work with static units is the reason? I just am surprised that this is only reported by Ubuntu.

zwets commented 2 years ago

Maybe the preset doesn't work with static units is the reason? I just am surprised that this is only reported by Ubuntu.

The file /usr/lib/systemd/system-preset/fwupd-refresh.preset is distributed with Ubuntu. I would indeed think that what needs disabling is the timer rather than the unit.

superm1 commented 2 years ago

So the preset doesn't work with timers of static units. But shouldn't that still affect Fedora too?

superm1 commented 2 years ago

Oh... I get it. fedora defaults to disabled if no preset, ubuntu defaults to enabled if no preset. That's why we see it in Ubuntu with timers. OK. I'll think about what can be done here from upstream fwupd perspective.

loca5790 commented 2 years ago

@superm1 I'm noticing the same issue, Ubuntu 22.04, it looks like the suggestion is mask it?

superm1 commented 2 years ago

You can either make a dedicated user, mask it, or turn off dynamic user.

DemonRx commented 2 years ago

I was able to get the service to exit successfully without changing DynamicUser=yes to no.

I just added User=root, and this resolved the service failing.

My reference for finding this solution is from https://github.com/systemd/systemd/issues/10025

Therefore the extra security of using DynamicUser will not be lost since it can remain active.

demon@Impish:~$ systemctl daemon-reload; service fwupd-refresh restart; service fwupd-refresh status
○ fwupd-refresh.service - Refresh fwupd metadata and update motd
     Loaded: loaded (/lib/systemd/system/fwupd-refresh.service; static)
     Active: inactive (dead) since Sun 2022-05-08 00:07:23 EDT; 69ms ago
TriggeredBy: ● fwupd-refresh.timer
       Docs: man:fwupdmgr(1)
    Process: 23090 ExecStart=/usr/bin/fwupdmgr refresh (code=exited, status=2)
   Main PID: 23090 (code=exited, status=2)
        CPU: 141ms

May 08 00:07:22 Impish systemd[1]: Starting Refresh fwupd metadata and update motd...
May 08 00:07:23 Impish systemd[1]: fwupd-refresh.service: Deactivated successfully.
May 08 00:07:23 Impish systemd[1]: Finished Refresh fwupd metadata and update motd.
cidrbl0ck commented 2 years ago

Wanted to comment here, I found this page while searching for a solution to the exact same issue in this thread. I didn't see mention above of what the fwupd-refresh.timer file should contain.. but mine has disable fwupd-refresh.service

Should this mean that the .service daemon should be disabled? If so, that's not what's been going on.

Also wondering if the fixes are still: "You can either make a dedicated user, mask it, or turn off dynamic user." ?

superm1 commented 2 years ago

Should this mean that the .service daemon should be disabled? If so, that's not what's been going on.

IIRC If the timer is in place it still runs even if service is disabled.

Also wondering if the fixes are still: "You can either make a dedicated user, mask it, or turn off dynamic user." ?

Debian/Ubuntu fwupd 1.8.x packages will create a dedicated user for this use. Other distros might need to adopt something similar in the packaging.

cidrbl0ck commented 2 years ago

Thanks superm1, We're really trying to keep to official LTS sources, the 'fwupd/jammer' caps out at version 1.7.5-3 if I'm looking at this correctly. But, if the .service or even the .preset can be disabled or masked without system harm then that might be the path forward for now.

superm1 commented 2 years ago

Here's the bug report for Ubuntu 22.04: https://bugs.launchpad.net/ubuntu/+source/systemd/+bug/1969976. As I type this, the SRU is in progress.