Thunderbolt 4 Dock upgrade fails with "SPI state is busy [0x08]" after 15 mins

[rvandegrift]

I'm trying to update a ThinkPad Thunderbolt 4 Dock using a Z16 Gen1 running fwupd 1.19.14 from Debian trixie.

It tries for 15 mins, but eventually times out. This happened twice in row, with me powering off the dock and laptop in between.

ross@stgulik:~$ fwupdmgr install -v
(fwupdmgr:3666): GLib-DEBUG: 21:01:55.672: setenv()/putenv() are not thread-safe and should not be used after threads are created
(pkttyagent:3668): GLib-GIO-DEBUG: 21:01:55.678: Using cross-namespace EXTERNAL authentication (this will deadlock if server is GDBus < 2.73.3)
(fwupdmgr:3666): GLib-GIO-DEBUG: 21:01:55.684: _g_io_module_get_default: Found default implementation dconf (DConfSettingsBackend) for ‘gsettings-backend’
(fwupdmgr:3666): dconf-DEBUG: 21:01:55.684: watch_fast: "/system/proxy/" (establishing: 0, active: 0)
(fwupdmgr:3666): dconf-DEBUG: 21:01:55.685: watch_fast: "/system/proxy/http/" (establishing: 0, active: 0)
(fwupdmgr:3666): dconf-DEBUG: 21:01:55.685: watch_fast: "/system/proxy/https/" (establishing: 0, active: 0)
(fwupdmgr:3666): dconf-DEBUG: 21:01:55.685: watch_fast: "/system/proxy/ftp/" (establishing: 0, active: 0)
(fwupdmgr:3666): dconf-DEBUG: 21:01:55.685: watch_fast: "/system/proxy/socks/" (establishing: 0, active: 0)
(fwupdmgr:3666): dconf-DEBUG: 21:01:55.685: unwatch_fast: "/system/proxy/" (active: 0, establishing: 1)
(fwupdmgr:3666): dconf-DEBUG: 21:01:55.685: unwatch_fast: "/system/proxy/http/" (active: 0, establishing: 1)
(fwupdmgr:3666): dconf-DEBUG: 21:01:55.685: unwatch_fast: "/system/proxy/https/" (active: 0, establishing: 1)
(fwupdmgr:3666): dconf-DEBUG: 21:01:55.685: unwatch_fast: "/system/proxy/ftp/" (active: 0, establishing: 1)
(fwupdmgr:3666): dconf-DEBUG: 21:01:55.685: unwatch_fast: "/system/proxy/socks/" (active: 0, establishing: 1)
(fwupdmgr:3666): GLib-GIO-DEBUG: 21:01:55.693: Using cross-namespace EXTERNAL authentication (this will deadlock if server is GDBus < 2.73.3)
(fwupdmgr:3666): GLib-GIO-DEBUG: 21:01:55.698: _g_io_module_get_default: Found default implementation libproxy (GLibproxyResolver) for ‘gio-proxy-resolver’
(fwupdmgr:3666): GLib-GIO-DEBUG: 21:01:55.698: Using cross-namespace EXTERNAL authentication (this will deadlock if server is GDBus < 2.73.3)
(fwupdmgr:3666): dconf-DEBUG: 21:01:55.700: watch_established: "/system/proxy/" (establishing: 0)
(fwupdmgr:3666): dconf-DEBUG: 21:01:55.700: watch_established: "/system/proxy/http/" (establishing: 0)
(fwupdmgr:3666): dconf-DEBUG: 21:01:55.700: watch_established: "/system/proxy/https/" (establishing: 0)
(fwupdmgr:3666): dconf-DEBUG: 21:01:55.700: watch_established: "/system/proxy/ftp/" (establishing: 0)
(fwupdmgr:3666): dconf-DEBUG: 21:01:55.700: watch_established: "/system/proxy/socks/" (establishing: 0)
(fwupdmgr:3666): Fwupd-DEBUG: 21:01:55.701: Emitting ::status-changed() [idle]
0.	Cancel
1.	a083ebc5138e5e071ef7270cc9a8280722cc7adf (Embedded Controller)
2.	0fba4a8bedba53076fc9b147655e59455bc25a87 (MZVL21T0HCLR-00BL7)
3.	36efb79c255f402f619fa9eb53cd659db51f2a04 (System Firmware)
4.	cf9a31bd537d3261c5ae2979f5db1ff4b8c29721 (ThinkPad Thunderbolt 4 Dock)
5.	362301da643102b9f38477387e2193e57abaa590 (UEFI dbx)
Choose device [0-5]: 4
0.	Cancel
1.	10.16
2.	10.13
Choose release [0-2]: 1
╔══════════════════════════════════════════════════════════════════════════════╗
║ Upgrade ThinkPad Thunderbolt 4 Dock from 10.11 to 10.16?                     ║
╠══════════════════════════════════════════════════════════════════════════════╣
║ Before continuing, ensure the following:                                     ║
║                                                                              ║
║ • Your computer battery life if over 25%.                                    ║
║ • Do not unplug the dock during update.                                      ║
║ • Do not put your computer into sleep or hibernate mode during update.       ║
║ • This update typically may take up to 15 minutes depending on your          ║
║ notebook and dock firmware version.                                          ║
║ • Please ensure fwupd version is 1.9.2 or above.                             ║
║                                                                              ║
║ ThinkPad Thunderbolt 4 Dock and all connected devices may not be usable      ║
║ while updating.                                                              ║
╚══════════════════════════════════════════════════════════════════════════════╝
Perform operation? [Y|n]:
Fwupd-INFO: 21:02:07.052: downloading https://fwupd.org/downloads/95d80f78213570a9816f2216f4e2d60ab454a463fb960dea932d3d6204376d0f-1016_NoIOT.cab
(fwupdmgr:3666): Fwupd-DEBUG: 21:02:07.063: Emitting ::status-changed() [downloading]
Downloading…             [             /                         ]Fwupd-INFO: 21:02:07.538: download progress: 1%
Downloading…             [                                       ]Fwupd-INFO: 21:02:07.579: download progress: 2%
  ... [snip a bunch of downloading progress]
Downloading…             [************************************** ]Fwupd-INFO: 21:02:07.938: download progress: 100%
(fwupdmgr:3666): Fwupd-DEBUG: 21:02:07.938: Emitting ::status-changed() [idle]
Fwupd-INFO: 21:02:07.938: status-code was 200
(fwupdmgr:3666): Fwupd-DEBUG: 21:02:07.978: Emitting ::status-changed() [decompressing]
Decompressing…           [***************************************](fwupdmgr:3666): Fwupd-DEBUG: 21:02:08.243: Emitting ::status-changed() [waiting-for-auth]
Authenticating…          [***************************************](fwupdmgr:3666): Fwupd-DEBUG: 21:02:08.284: Emitting ::status-changed() [device-busy]
Waiting…                 [***************************************](fwupdmgr:3666): Fwupd-DEBUG: 21:02:08.284: Emitting ::device-changed(cf9a31bd537d3261c5ae2979f5db1ff4b8c29721)
(fwupdmgr:3666): Fwupd-DEBUG: 21:02:08.284: Emitting ::device-changed(cf9a31bd537d3261c5ae2979f5db1ff4b8c29721)
(fwupdmgr:3666): Fwupd-DEBUG: 21:02:08.298: Emitting ::device-changed(cf9a31bd537d3261c5ae2979f5db1ff4b8c29721)
(fwupdmgr:3666): Fwupd-DEBUG: 21:02:08.298: Emitting ::device-changed(cf9a31bd537d3261c5ae2979f5db1ff4b8c29721)
(fwupdmgr:3666): Fwupd-DEBUG: 21:02:08.298: Emitting ::device-changed(92d2211a864a1abdcca3284ef4d61631a07f42e3)
(fwupdmgr:3666): Fwupd-DEBUG: 21:02:08.298: Emitting ::device-changed(e05192ed8d0448e4016bf5e77cd97cd7860d8c47)
(fwupdmgr:3666): Fwupd-DEBUG: 21:02:08.298: Emitting ::device-changed(e244cfaefc61eb7670b2fbd6584c6735068d4aef)
(fwupdmgr:3666): Fwupd-DEBUG: 21:02:08.298: Emitting ::device-changed(27581012bd0cb5fbea0bcd48f66047fabf37c2ee)
(fwupdmgr:3666): Fwupd-DEBUG: 21:02:08.298: Emitting ::device-changed(f7842176e69c01741111688a90b3f2e6eeaab373)
(fwupdmgr:3666): Fwupd-DEBUG: 21:02:08.298: Emitting ::device-changed(a0693101b39156a6e6f529fc5efe86536034adf0)
(fwupdmgr:3666): Fwupd-DEBUG: 21:02:08.298: Emitting ::device-changed(dd265396ced1576c38814fd623f9e607fe24333d)
(fwupdmgr:3666): Fwupd-DEBUG: 21:02:08.298: Emitting ::device-changed(086e8a873abdd916c658621a19d1f5f272419253)
(fwupdmgr:3666): Fwupd-DEBUG: 21:02:08.298: Emitting ::device-changed(33fd60b075cf330b386a42c4e11c41648b986491)
(fwupdmgr:3666): Fwupd-DEBUG: 21:02:08.299: Emitting ::device-changed(65dd15e1f36402259279cf61ec7886779e56173f)
(fwupdmgr:3666): Fwupd-DEBUG: 21:02:08.308: Emitting ::status-changed() [device-write]
Writing…                 [                                       ](fwupdmgr:3666): Fwupd-DEBUG: 21:02:08.308: Emitting ::status-changed() [device-erase]
Erasing…                 [                                       ](fwupdmgr:3666): Fwupd-DEBUG: 21:02:08.308: Emitting ::status-changed() [device-write]
Writing…                 [                                       ](fwupdmgr:3666): Fwupd-DEBUG: 21:02:08.308: Emitting ::status-changed() [decompressing]
Decompressing…           [                                       ](fwupdmgr:3666): Fwupd-DEBUG: 21:02:08.309: Emitting ::status-changed() [device-busy]
Waiting…                 [                                       ](fwupdmgr:3666): Fwupd-DEBUG: 21:02:08.329: Emitting ::status-changed() [device-erase]
Erasing…                 [                                       ](fwupdmgr:3666): Fwupd-DEBUG: 21:02:39.738: Emitting ::device-changed(cf9a31bd537d3261c5ae2979f5db1ff4b8c29721)
(fwupdmgr:3666): Fwupd-DEBUG: 21:17:39.747: Emitting ::device-changed(cf9a31bd537d3261c5ae2979f5db1ff4b8c29721)
(fwupdmgr:3666): Fwupd-DEBUG: 21:17:39.775: Emitting ::device-changed(cf9a31bd537d3261c5ae2979f5db1ff4b8c29721)
(fwupdmgr:3666): Fwupd-DEBUG: 21:17:39.793: Emitting ::device-changed(cf9a31bd537d3261c5ae2979f5db1ff4b8c29721)

failed to wait for erase: failed after 30 retries: SPI state is busy [0x08]

[rvandegrift]

From a suggestion at [1], I was able to workaround this by updating 10.11 -> 10.13 -> 10.16. It'd be nice if fwupd could consider this constraint on updates, or at least present a release note to the user.

[1] - https://forums.lenovo.com/t5/Debian/Thunderbolt-4-Dock-upgrade-fails-with-SPI-state-is-busy-0x08-after-15-mins/m-p/5307328

[hughsie]

I've asked Lenovo to add the requirement of >=10.13 on the 10.16 firmware -- which will force fwupd to do it in two steps.

[soltysh]

I'm experiencing this exact problem when trying to update my dock on a t14 gen 5 with amd from 10.16 to 10.18.

[tomodachi]

I have the same issue even if I'm trying to upgrade
10.6 -> 10.13 before going to 10.16

"failed to wait for erase: failed after 30 retries: SPI state is busy [0x08]"

I'm on a Lenovo Thinkpad Z16
Fedora 41 Kernel 6.11.5-300