PinePhone eg25 firmware upgrade: "failed to get device before update: failed to wait for detach replug: device 976c4a39e87f61e6940ea6a8d39c583cfa99615f did not come back"

[tomfitzhenry]

Describe the bug

I'm working on bringing support of https://dylanvanassche.be/blog/2022/pinephone-modem-upgrade/ to NixOS. I've upgraded fwupd to 1.7.6 (not yet merged into NixOS, see NixOS/nixpkgs#161935), and followed the instructions on https://wiki.postmarketos.org/wiki/Fwupd (logs below).

fwupdmgr switch-branch 976c4a39e87f61e6940ea6a8d39c583cfa99615f failed at Writing? with failed to get device before update: failed to wait for detach replug: device 976c4a39e87f61e6940ea6a8d39c583cfa99615f did not come back.

Steps to Reproduce
On a PinePhone (NixOS, ModemManager 1.18.4), execute fwupdmgr switch-branch 976c4a39e87f61e6940ea6a8d39c583cfa99615f.

Actual behaviour

WARNING: UEFI capsule updates not available or enabled in firmware setup
  See https://github.com/fwupd/fwupd/wiki/PluginFlag:capsules-unsupported for more information.
????????????????????????????????????????????????????????????????????????????????
? Switch branch from default to community?                                     ?
????????????????????????????????????????????????????????????????????????????????
? The firmware from Pine64 is not supplied by QUALCOMM INCORPORATED, the       ?
? hardware vendor.                                                             ?
?                                                                              ?
? Your hardware may be damaged using this firmware, and installing this        ?
? release may void any warranty with QUALCOMM INCORPORATED.                    ?
?                                                                              ?
? This release brings the following fixes and improvements:                    ?
?                                                                              ?
? ? Allow calls to be delayed for more than 999 seconds                        ?
? ? Ensure we send a RING_IN pulse to the Pinephone when making simulated      ?
? calls, to be able to wake the Pinephone from crust                           ?
? ? Force resync of the RT5616 registers in the external codec (Pinephone      ?
? Pro) so call audio keeps working after suspend                               ?
????????????????????????????????????????????????????????????????????????????????

Do you understand the consequences of changing the firmware branch? [y|N]: y
????????????????????????????????????????????????????????????????????????????????
? Downgrade QUECTEL Mobile Broadband Module from EG25GGBR07A08M2G - 0580079E   ?
? to 0.5.9?                                                                    ?
????????????????????????????????????????????????????????????????????????????????
? This release brings the following fixes and improvements:                    ?
?                                                                              ?
? ? Allow calls to be delayed for more than 999 seconds                        ?
? ? Ensure we send a RING_IN pulse to the Pinephone when making simulated      ?
? calls, to be able to wake the Pinephone from crust                           ?
? ? Force resync of the RT5616 registers in the external codec (Pinephone      ?
? Pro) so call audio keeps working after suspend                               ?
?                                                                              ?
? QUECTEL Mobile Broadband Module and all connected devices may not be usable  ?
? while updating.                                                              ?
????????????????????????????????????????????????????????????????????????????????

Perform operation? [Y|n]: y
Downloading?             [***************************************]
Downloading?             [***************************************] Less than one minute remaining?
Decompressing?           [***************************************]
Decompressing?           [***************************************]
Authenticating?          [***************************************]
Authenticating?          [***************************************]
Restarting device?       [***************************************]
Writing?                 [***************************************]
Writing?                 [                                       ]failed to get device before update: failed to wait for detach replug: device 976c4a39e87f61e6940ea6a8d39c583cfa99615f did not come back

Expected behavior
Firmware is switched to https://github.com/Biktorgj/pinephone_modem_sdk .

fwupd version information
Please provide the version of the daemon and client.

$ fwupdmgr --version
runtime   org.freedesktop.fwupd         1.7.7
compile   org.freedesktop.gusb          0.3.7
runtime   org.kernel                    5.16.4
compile   com.hughsie.libjcat           0.1.10
compile   org.freedesktop.fwupd         1.7.7
runtime   org.freedesktop.gusb          0.3.7

Please note how you installed it (apt, dnf, pacman, source, etc): NixOS.

fwupd device information
Please provide the output of the fwupd devices recognized in your system.

$ fwupdmgr get-devices --show-all-devices
WARNING: UEFI capsule updates not available or enabled in firmware setup
  See https://github.com/fwupd/fwupd/wiki/PluginFlag:capsules-unsupported for more information.
Pine64 PinePhone (1.2)
│
├─DA4032:
│     Device ID:          0e0c93c8b4bb222157feedbde8f863e23bd1a8f7
│     Current version:    0x3034313430363139
│     Vendor:             EMMC:0x000045
│     GUIDs:              8c6f96d4-f406-53fa-84ca-a367cd368dfc
│                         add792f2-7053-5638-80e7-20987fd16769
│                         5500994c-1b73-52b4-acf4-bb574b6f3029
│     Device Flags:       • Internal device
│                         • Updatable
│   
└─QUECTEL Mobile Broadband Module:
      Device ID:          976c4a39e87f61e6940ea6a8d39c583cfa99615f
      Summary:            Quectel EG25-G modem
      Current version:    EG25GGBR07A08M2G - 0580079E
      Vendor:             QUALCOMM INCORPORATED (USB:0x2C7C)
      GUIDs:              db379a33-254f-5140-b37e-d36ae7e5c039
                          a4a39f11-e255-518f-854f-9627ccd66873
                          1a2996cb-f86e-5583-a464-e1b96e1c6ae9
                          587bf468-6859-5522-93a7-6cce552a0aa3
                          22ae45db-f68e-5c55-9c02-4557dca238ec
      Device Flags:       • Updatable
                          • System requires external power source
                          • Supported on remote server
                          • Device supports switching to a different branch of firmware

Additional questions

• Operating system and version: NixOS, master.
• Have you tried rebooting? Yes. The device came back, but was still on the old firmware. I repeated the steps and had the same results.
• Is this a regression? I'm aware that others have succeeded in switching firmwares via fwupdmgr, but I have not.

[tomfitzhenry]

Here's the firmware report: fwupd-firmware-report.txt

[superm1]

I think for @DylanVanAssche to look at this it probably need a verbose daemon log to see more of what's really going on. Can you share that?

[tomfitzhenry]

I have re-run this with the --verbose flag on fwupd:

fwupdmgr: fwupdmgr.txt
fwupd --verbose: fwupd-verbose.txt

[tomfitzhenry]

Mobile NixOS (which I use) uses Megi's modem-power driver ( https://xnux.eu/devices/feature/modem-pp.html ), along with a Mobile NixOS specific modem-control.service unit to bind the udev device to the modem power state: https://github.com/NixOS/mobile-nixos/blob/master/devices/pine64-pinephone/modem.nix .

I see this was powering off the modem around the time that fwupdmgr was running:

$ journalctl -u modem-control -b
-- Journal begins at Tue 1980-01-01 11:00:02 AEDT, ends at Sun 2022-02-27 01:31:54 AEDT. --
Feb 27 01:16:19 nixos systemd[1]: Starting modem-control.service...
Feb 27 01:16:19 nixos qhx7v4zpaa3fnmwc9dfhs9w49zdwx4m0-start-modem[624]: Powering modem on...
Feb 27 01:16:19 nixos systemd[1]: Finished modem-control.service.
Feb 27 01:16:20 nixos systemd[1]: Stopping modem-control.service...
Feb 27 01:16:20 nixos 45688nq2zifgx4qxfc5vyalr9c9z5al2-stop-modem[710]: Powering modem off...
Feb 27 01:16:20 nixos systemd[1]: modem-control.service: Deactivated successfully.
Feb 27 01:16:20 nixos systemd[1]: Stopped modem-control.service.
Feb 27 01:16:33 nixos systemd[1]: Starting modem-control.service...
Feb 27 01:16:33 nixos qhx7v4zpaa3fnmwc9dfhs9w49zdwx4m0-start-modem[952]: Powering modem on...
Feb 27 01:16:33 nixos systemd[1]: Finished modem-control.service.
Feb 27 01:19:02 nixos systemd[1]: Stopping modem-control.service...
Feb 27 01:19:02 nixos 45688nq2zifgx4qxfc5vyalr9c9z5al2-stop-modem[1775]: Powering modem off...
Feb 27 01:19:02 nixos systemd[1]: modem-control.service: Deactivated successfully.
Feb 27 01:19:02 nixos systemd[1]: Stopped modem-control.service.

I will disable this and see if the issue recurs.

[tomfitzhenry]

Yes, disabling modem-control.service resulted in the firmware installing successfully: Successfully installed firmware! Woo.

Sorry for the false positive!

I've raised NixOS/mobile-nixos#463 to track the Mobile NixOS issue.

[superm1]

I'm not super familiar with the ecosystem, but @DylanVanAssche is this something that maybe the plugin in fwupd should detect and inhibit while updating? If it doesn't support inhibition then the plugin should probably either stop it or avoid updating (issue an error) if it's found running.

[DylanVanAssche]

@superm1 For the PinePhone & PinePhone Pro there are 2 'drivers' for the modem:

• modem-power: an out-of-tree Linux kernel driver which toggles some GPIO pins to boot the modem, not intended to be upstreamed.
• eg25-manager: an userspace daemon which does the GPIO pins, handles AGPS data, etc. Almost all distros use this one.

Both drivers conflicts of course.

[superm1]

Thanks for explaining. So could you detect the out of tree one and make the plugin inhibit updates?

[DylanVanAssche]

@superm1 The out-of-tree driver exposes some sysfs entries, would that work?

[DylanVanAssche]

What about testing a sysfs entry presence with g_test_file and inhibit updates this way?

Source: https://docs.gtk.org/glib/func.file_test.html

[superm1]

Yup, I think that's a nice easy way to check for it. You can either check for them during probe and inhibit at that time or do it in update_prepare and "fail" the update. I can see arguments for both ways.

[tomfitzhenry]

FWIW, in NixOS/mobile-nixos#463 I expect Mobile NixOS will remove its use of the out-of-tree modem-power driver, and migrate to eg25-manager.

[DylanVanAssche]

@superm1 Is there a way to print a message then why the update fails?

[superm1]

@DylanVanAssche yeah so if you do this in an update prepare callback it would be something like this:

1. Client calls the update
2. Daemon runs the plugin's callbacks
3. Update prepare checks if a sysfs file exists
4. If it does update_prepare fails
5. Failure is relayed back up to the client

The advantage you have here is that the module can be unloaded at runtime and this conflict fixed. The disadvantage is you don't know that it is a problem "until" you try to run an update.

If you did it in the inhibit it would be in plugin probe routine. It means that fwupdmgr get-devices would show a message that updates are inhibited because $REASON. You could only fix it by either:

1. Restarting daemon
2. Setting up an inotitfy on the paths listed.

I personally prefer the first method, particularly since firmware updating your modem is likely to be infrequent but up to you which way you want to go.

[DylanVanAssche]

If you did it in the inhibit it would be in plugin probe routine. It means that fwupdmgr get-devices would show a message that updates are inhibited because $REASON. You could only fix it by either:

You would need to install a different kernel anyway which means rebooting, so inotitfy looks overkill :P
Is there an example of update_prepare? I didn't find any in the plugins dir.

[superm1]

Sorry I forgot we renamed the symbol. Look for prepare_firmware