Device state updates not reported by fwupdmgr

Aleksander Morgado

unread,

Nov 24, 2020, 9:34:49 AM11/24/20

to fwupd

Hey!

I'm working on a new WWAN module firmware upgrade method, and I'm trying to understand why the "fwupdmgr upgrade" operation is showing me only the "Downloading..." progress bar, and no other progress bar afterwards. E.g.:

$ sudo fwupdmgr downgrade
Selected device: MBIM [1EAC:1001]
MBIM [1EAC:1001] and all connected devices may not be usable while updating. Continue with update? [Y|n]:
Downloading… [***************************************]
Successfully installed firmware

The plugin reports progress updates when the files are being downloaded, as seen in the verbose daemon logs, e.g.:

14:24:09:0063 FuMain Emitting PropertyChanged('Percentage'='62%')

The plugin also explicitly sets the device status where appropriate, as seen in the verbose daemon logs, e.g.:

4:22:05:0268 FuEngine Emitting PropertyChanged('Status'='device-restart')
14:22:05:0268 FuMain Emitting PropertyChanged('Status'='device-restart')
...

14:22:07:0332 FuEngine Emitting PropertyChanged('Status'='device-write')
14:22:07:0332 FuMain Emitting PropertyChanged('Status'='device-write')

I wonder what else is missing so that the client gets the device state/progress updates?

Cheers!

Richard Hughes

unread,

Nov 24, 2020, 10:41:26 AM11/24/20

to Aleksander Morgado, fwupd

On Tue, 24 Nov 2020 at 14:34, Aleksander Morgado
<aleksande...@gmail.com> wrote:
> I wonder what else is missing so that the client gets the device state/progress updates?

If you run the client with --verbose does it see new updates over DBus?

Richard.

Aleksander Morgado

unread,

Dec 2, 2020, 4:58:02 PM12/2/20

to fwupd

Hey,

> I wonder what else is missing so that the client gets the device state/progress updates?

If you run the client with --verbose does it see new updates over DBus?

Looks like the only property update seen with --verbose is the one reporting the Downloading state:

MBIM [1EAC:1001] and all connected devices may not be usable while updating. Continue with update? [Y|n]:

(fwupdmgr:1449): Fwupd-DEBUG: 22:53:51.214: downloading https://fwupd.org/downloads/xxxxxxxxxx.cab
(fwupdmgr:1449): Fwupd-DEBUG: 22:53:51.214: Emitting ::status-changed() [downloading]
Downloading… [- ](fwupdmgr:1449): Fwupd-DEBUG: 22:54:05.431: Emitting ::status-changed() [idle]
Downloading… [***************************************]

While in the daemon side I see many more updates reported:

21:54:07:0955 FuEngine             Emitting PropertyChanged('Status'='device-restart')
21:54:07:0955 FuMain               Emitting PropertyChanged('Status'='device-restart')
21:54:08:0969 FuPluginMm           opening boot host interface port...
21:54:08:0969 FuPluginMm           checking boot host interface port state...
21:54:08:0969 FuPluginMm           boot host interface port is in emergency download mode
21:54:08:0969 FuPluginMm           writing firehose prog...
21:54:10:0019 FuPluginMm           flash programmer download port available: /dev/mhi_EDL
21:54:10:0019 FuEngine             Emitting PropertyChanged('Status'='device-write')
21:54:10:0019 FuMain               Emitting PropertyChanged('Status'='device-write')

Aleksander Morgado

unread,

Dec 2, 2020, 5:16:23 PM12/2/20

to fwupd

I re-run an upgrade and this time with dbus-monitor --system on, and I can see PropertiesChanged() emissions for "Status":

signal time=1606946362.634790 sender=:1.68 -> destination=(null destination) serial=137 path=/; interface=org.freedesktop.DBus.Properties; member=PropertiesChanged
   string "org.freedesktop.fwupd"
   array [
      dict entry(
         string "Status"
         variant             uint32 5
      )
   ]
   array [
   ]

And also for "Percentage" (when "Status"==DEVICE_WRITE)

signal time=1606946373.217408 sender=:1.68 -> destination=(null destination) serial=139 path=/; interface=org.freedesktop.DBus.Properties; member=PropertiesChanged
   string "org.freedesktop.fwupd"
   array [
      dict entry(
         string "Percentage"
         variant             uint32 1
      )
   ]
   array [
   ]

And I also see full DeviceChanged() signals as well:

signal time=1606946457.601270 sender=:1.68 -> destination=(null destination) serial=148 path=/; interface=org.freedesktop.fwupd; member=DeviceChanged
   array [
      dict entry(
         string "DeviceId"
         variant             string "d2c8c37935abe0d0e98548b1d0c333f449cd0301"
      )
      dict entry(
         string "Guid"
         variant             array [
               string "4294f9ad-e7b2-53fb-bd16-be64092ebb1d"
               string "3b2b9e7f-2620-546f-becb-727b6e4b662f"
               string "8efebe65-85c5-58ff-937c-51f626d8fe2a"
            ]
      )
      dict entry(
         string "Icon"
         variant             array [
               string "network-modem"
            ]
      )
      dict entry(
         string "Name"
         variant             string "MBIM [1EAC:1001]"
      )
      dict entry(
         string "Vendor"
         variant             string "quectel"
      )
      dict entry(
         string "VendorId"
         variant             string "PCI:0x1EAC"
      )
      dict entry(
         string "Flags"
         variant             uint64 2210
      )
      dict entry(
         string "Created"
         variant             uint64 1606946266
      )
      dict entry(
         string "Modified"
         variant             uint64 1606946360
      )
      dict entry(
         string "Summary"
         variant             string "Mobile broadband device"
      )
      dict entry(
         string "Plugin"
         variant             string "modem_manager"
      )
      dict entry(
         string "Protocol"
         variant             string "com.qualcomm.firehose"
      )
      dict entry(
         string "Version"
         variant             string "EM120RGLAPR02A07"
      )
      dict entry(
         string "UpdateState"
         variant             uint32 3
      )
      dict entry(
         string "Status"
         variant             uint32 5
      )
      dict entry(
         string "VersionFormat"
         variant             uint32 1
      )
   ]

But looks like none of those end up being enough to show the state updates and progress in the fwupdmgr output?

Limonciello, Mario

unread,

Dec 2, 2020, 5:20:56 PM12/2/20

to Aleksander Morgado, fwupd

This is on master right? Can you try to revert https://github.com/fwupd/fwupd/commit/1a14d2be009ada386eba65ccd78feaa27853f109 to see if it changes it?

From: fw...@googlegroups.com <fw...@googlegroups.com> On Behalf Of Aleksander Morgado
Sent: Wednesday, December 2, 2020 16:16
To: fwupd
Subject: Re: [fwupd] Device state updates not reported by fwupdmgr

[EXTERNAL EMAIL]

--
You received this message because you are subscribed to the Google Groups "fwupd" group.
To unsubscribe from this group and stop receiving emails from it, send an email to fwupd+un...@googlegroups.com.
To view this discussion on the web, visit https://groups.google.com/d/msgid/fwupd/de8e1d5c-bf78-4ddc-96d1-72a27f7dec36n%40googlegroups.com.

Aleksander Morgado

unread,

Dec 2, 2020, 5:30:14 PM12/2/20

to fwupd

Hey!

That was it, reverting that commit made it work:

(fwupdmgr:1576): Fwupd-DEBUG: 23:28:59.702: Emitting ::status-changed() [downloading]
Downloading…             [                           |           ](fwupdmgr:1576): Fwupd-DEBUG: 23:29:13.093: Emitting ::status-changed() [idle]
Downloading…             [***************************************]
(fwupdmgr:1576): Fwupd-DEBUG: 23:29:13.336: Emitting ::status-changed() [decompressing]
Decompressing…           [      \                                ](fwupdmgr:1576): Fwupd-DEBUG: 23:29:15.061: Emitting ::status-changed() [idle]
Decompressing…           [***************************************]
(fwupdmgr:1576): Fwupd-DEBUG: 23:29:15.062: Emitting ::status-changed() [waiting-for-auth]
Authenticating…          [      \                                ]
(fwupdmgr:1576): Fwupd-DEBUG: 23:29:15.064: Emitting ::status-changed() [idle]
Authenticating…          [***************************************]
(fwupdmgr:1576): Fwupd-DEBUG: 23:29:15.659: Emitting ::status-changed() [device-restart]
Updating MBIM [1EAC:1001]…     \                                 ]
Restarting device…       [     \                                 ](fwupdmgr:1576): Fwupd-DEBUG: 23:29:15.659: Emitting ::device-changed(d2c8c37935abe0d0e98548b1d0c333f449cd0301)
Restarting device…       [                              /        ](fwupdmgr:1576): Fwupd-DEBUG: 23:29:17.723: Emitting ::status-changed() [device-write]
Writing…                 [                              /        ](fwupdmgr:1576): Fwupd-DEBUG: 23:29:17.724: Emitting ::device-changed(d2c8c37935abe0d0e98548b1d0c333f449cd0301)
Writing…                 [                                       ](fwupdmgr:1576): Fwupd-DEBUG: 23:29:28.297: Emitting ::device-changed(d2c8c37935abe0d0e98548b1d0c333f449cd0301)
Writing…                 [                                       ](fwupdmgr:1576): Fwupd-DEBUG: 23:29:28.789: Emitting ::device-changed(d2c8c37935abe0d0e98548b1d0c333f449cd0301)

Aleksander Morgado

unread,

Dec 2, 2020, 5:49:32 PM12/2/20

to fwupd

Hey,

I'm looking at fu-utils.c.

There is a default-context (NULL) GMainLoop created there in FuUtilPrivate, but for what it looks like it's never run? The "percentage" and "state" property update signals are attached to the default context.

Before change 1a14d2be009ada386eba65ccd78feaa27853f109 all the internal helper main loops in fwupd-client-sync.c were attached to the default context, and so the property update signals were emitted using those helper contexts. After that commit, all the internal helper main loops were attached to the thread-default main loop instead, which is fine, but then there is no main loop for the default context that could process the property update signals.

A solution for this would be to make sure that we run the FuUtilPrivate main loop, maybe even using the async client API in this logic. Does this analysis make sense?

Aleksander Morgado

unread,

Dec 2, 2020, 5:56:15 PM12/2/20

to fwupd

Hey,

Or, change fu_util_update_device_with_release() so that instead of using the sync fwupd_client_install_release(), we run fwupd_client_install_release_async() plus an explicit main loop for the default context at that point, and when the async operation finishes, we stop the main loop. We need a way to process those state and progress updates during the sync "install release" operation.

Aleksander Morgado

unread,

Dec 2, 2020, 6:25:03 PM12/2/20

to fwupd

Fixing up a previous comment... just for consistency

Before change 1a14d2be009ada386eba65ccd78feaa27853f109 all the internal helper main loops in fwupd-client-sync.c were attached to the default context, and so the property update signals were emitted using those helper loops. After that commit, all the internal helper main loops were attached to the thread-default main context instead, which is fine, but then there is no main loop for the default context that could process the property update signals.

Richard Hughes

unread,

Dec 3, 2020, 5:12:15 AM12/3/20

to Aleksander Morgado, fwupd

On Wed, 2 Dec 2020 at 23:25, Aleksander Morgado
<aleksande...@gmail.com> wrote:
> but then there is no main loop for the default context that could process the property update signals.

Doh, my fault. I thought g_object_notify was synchronous like
g_signal_emit is. I'm guessing
https://github.com/fwupd/fwupd/pull/2638 gets things working for you?

Richard.

Reply all

Reply to author

Forward