Update loop for Thunderbolt NVM for Xps notebook 9360. Installed version is not recognized (00.00)

Bug #1768627 reported by Andrei Susanu on 2018-05-02
70
This bug affects 13 people
Affects Status Importance Assigned to Milestone
fwupd (Ubuntu)
Medium
Unassigned
Bionic
Undecided
Unassigned
Cosmic
Medium
Unassigned

Bug Description

The fix for this particular issue is tracked in SRU bug https://bugs.launchpad.net/ubuntu/+source/fwupd/+bug/1791999

Regression potential:
Fixes for this bug have the potential to manifest in thunderbolt controllers not being enumerated.

Test case:
1) Enumerate devices (# fwupdmgr get-devices)
2) Verify the Thunderbolt controller is present and has a non-00.00 version.

Original description:
Software & Updates keeps notifying me there is a new update available related to Thunderbolt NVM for Xps notebook 9360, from version 00.00 to version 21.00. See the attached screenshot.

The updated is successfully installed via the interface or CLI, but after that the notification is displayed again.

Here is the CLI install log:

$ sudo fwupdmgr update
No upgrades for XPS 13 9360 System Firmware, current is 0.2.6.2: 0.2.6.2=same, 0.2.5.1=older, 0.2.4.2=older
Downloading 21.00 for XPS13 9360 Thunderbolt Controller...
Updating 21.00 on XPS13 9360 Thunderbolt Controller...
Decompressing… [***************************************]
Authenticating… [***************************************]
Restarting device… [***************************************]

$ sudo fwupdmgr update
No upgrades for XPS 13 9360 System Firmware, current is 0.2.6.2: 0.2.6.2=same, 0.2.5.1=older, 0.2.4.2=older
No upgrades for XPS13 9360 Thunderbolt Controller, current is 21.00: 21.00=same

Operating System
Description: Ubuntu 18.04 LTS
Release: 18.04

Package Version
apt-cache policy fwupd
fwupd:
  Installed: 1.0.6-2
  Candidate: 1.0.6-2
  Version table:
 *** 1.0.6-2 500
        500 http://archive.ubuntu.com/ubuntu bionic/main amd64 Packages
        100 /var/lib/dpkg/status

Andrei Susanu (andrei-susanu) wrote :
tags: added: fwupdmgr

Version 00.00 sounds like it might be safe mode.

Can you please rerun daemon in verbose mode?
/use/lib/fwupd/fwupd -v

And share output across a thunderbolt attempt?

On Wed, May 2, 2018, 13:50 Andrei Susanu <email address hidden> wrote:

> Public bug reported:
>
> Software & Updates keeps notifying me there is a new update available
> related to Thunderbolt NVM for Xps notebook 9360, from version 00.00 to
> version 21.00. See the attached screenshot.
>
> The updated is successfully installed via the interface or CLI, but
> after that the notification is displayed again.
>
> Here is the CLI install log:
>
> $ sudo fwupdmgr update
> No upgrades for XPS 13 9360 System Firmware, current is 0.2.6.2:
> 0.2.6.2=same, 0.2.5.1=older, 0.2.4.2=older
> Downloading 21.00 for XPS13 9360 Thunderbolt Controller...
> Updating 21.00 on XPS13 9360 Thunderbolt Controller...
> Decompressing… [***************************************]
> Authenticating… [***************************************]
> Restarting device… [***************************************]
>
> $ sudo fwupdmgr update
> No upgrades for XPS 13 9360 System Firmware, current is 0.2.6.2:
> 0.2.6.2=same, 0.2.5.1=older, 0.2.4.2=older
> No upgrades for XPS13 9360 Thunderbolt Controller, current is 21.00:
> 21.00=same
>
>
> Operating System
> Description: Ubuntu 18.04 LTS
> Release: 18.04
>
> Package Version
> apt-cache policy fwupd
> fwupd:
> Installed: 1.0.6-2
> Candidate: 1.0.6-2
> Version table:
> *** 1.0.6-2 500
> 500 http://archive.ubuntu.com/ubuntu bionic/main amd64 Packages
> 100 /var/lib/dpkg/status
>
> ** Affects: fwupd (Ubuntu)
> Importance: Undecided
> Status: New
>
>
> ** Tags: fwupdmgr
>
> ** Attachment added: "Screenshot with Softwared & Updates"
>
> https://bugs.launchpad.net/bugs/1768627/+attachment/5132347/+files/software.png
>
> ** Tags added: fwupdmgr
>
> --
> You received this bug notification because you are subscribed to fwupd
> in Ubuntu.
> Matching subscriptions: fwupd bugs
> https://bugs.launchpad.net/bugs/1768627
>
> Title:
> Update loop for Thunderbolt NVM for Xps notebook 9360. Installed
> version is not recognized (00.00)
>
> To manage notifications about this bug go to:
> https://bugs.launchpad.net/ubuntu/+source/fwupd/+bug/1768627/+subscriptions
>

Andrei Susanu (andrei-susanu) wrote :

Attached.

Andrei Susanu (andrei-susanu) wrote :

The thunderbolt works fine, the driver is functional.

It's just a problem with updating the package... the system see the installed version as 00.00 and wants to updated it to 21.00.

Mario Limonciello (superm1) wrote :

That's odd, I don't see that the thunderbolt in safe mode. Can you please show the fwupdmgr get-devices output? It's still showing 0.00 there too?

Can you please check in /sys/bus/thunderbolt/devices and find your controller there. is it also showing the same under nvm_version?

Andrei Susanu (andrei-susanu) wrote :

Here is the output of get-devices:

XPS13 9360 Thunderbolt Controller
  DeviceId: 590e67e817585cbde0a07e8562d13d0d3a06776d
  Guid: 4d86f168-e1cc-5995-afd3-ae9df6a14f5e
  Guid: dfd51125-338f-56ff-b721-fa3bea8e534e
  Summary: Unmatched performance for high-speed I/O
  Plugin: thunderbolt
  Flags: internal|updatable|supported|registered
  Vendor: Dell
  VendorId: TBT:0x00D4
  Version: 00.00
  Icon: computer
  Created: 2018-05-04

The full report is attached.

Andrei Susanu (andrei-susanu) wrote :

Sorry, but /sys/bus/thunderbolt/devices is empty.

/sys/bus/thunderbolt/devices$ ll
total 0
drwxr-xr-x 2 root root 0 May 5 00:07 ./
drwxr-xr-x 4 root root 0 May 5 00:07 ../

Mario Limonciello (superm1) wrote :

During this boot that you collected this information did you have anything plugged into the Type-C port? If so, was it a Thunderbolt device? Do you have any thunderbolt devices that you can connect and see if they work properly?

Can you please check your syslog for anything related to thunderbolt?

This behavior sounds like Thunderbolt was turned of before the NVM version could be read, but your logs don't seem to indicate that.

Andrei Susanu (andrei-susanu) wrote :
Download full text (5.1 KiB)

Nothing was connected to the Type-C port. I don't have any thunderbolt devices...

I am connecting my mobile phone (Nexus 6P) using the Type-C port and works fine.

Here is what I have in syslog related to thunderbolt:

May 3 09:32:07 xps13 kernel: [ 2015.028567] thunderbolt 0000:03:00.0: NHI initialized, starting thunderbolt
May 3 09:32:07 xps13 kernel: [ 2015.028579] thunderbolt 0000:03:00.0: allocating TX ring 0 of size 10
May 3 09:32:07 xps13 kernel: [ 2015.028621] thunderbolt 0000:03:00.0: allocating RX ring 0 of size 10
May 3 09:32:07 xps13 kernel: [ 2015.028663] thunderbolt 0000:03:00.0: control channel created
May 3 09:32:07 xps13 kernel: [ 2015.028667] thunderbolt 0000:03:00.0: control channel starting...
May 3 09:32:07 xps13 kernel: [ 2015.028672] thunderbolt 0000:03:00.0: starting TX ring 0
May 3 09:32:07 xps13 kernel: [ 2015.028685] thunderbolt 0000:03:00.0: enabling interrupt at register 0x38200 bit 0 (0x0 -> 0x1)
May 3 09:32:07 xps13 kernel: [ 2015.028690] thunderbolt 0000:03:00.0: starting RX ring 0
May 3 09:32:07 xps13 kernel: [ 2015.028702] thunderbolt 0000:03:00.0: enabling interrupt at register 0x38200 bit 12 (0x1 -> 0x1001)
May 3 09:32:07 xps13 boltd[1531]: probing: adding /sys/devices/pci0000:00/0000:00:1c.0/0000:01:00.0 to roots
May 3 09:32:07 xps13 boltd[1531]: probing: started [1000]
May 3 09:32:07 xps13 kernel: [ 2015.128615] thunderbolt 0000:03:00.0: current switch config:
May 3 09:32:07 xps13 kernel: [ 2015.128625] thunderbolt 0000:03:00.0: Switch: 8086:1576 (Revision: 4, TB Version: 2)
May 3 09:32:07 xps13 kernel: [ 2015.128630] thunderbolt 0000:03:00.0: Max Port Number: 11
May 3 09:32:07 xps13 kernel: [ 2015.128634] thunderbolt 0000:03:00.0: Config:
May 3 09:32:07 xps13 kernel: [ 2015.128642] thunderbolt 0000:03:00.0: Upstream Port Number: 5 Depth: 0 Route String: 0x0 Enabled: 1, PlugEventsDelay: 254ms
May 3 09:32:07 xps13 kernel: [ 2015.128648] thunderbolt 0000:03:00.0: unknown1: 0x0 unknown4: 0x0
May 3 09:32:07 xps13 kernel: [ 2015.173943] thunderbolt 0000:03:00.0: 0: uid: 0xd45fb13821cd00
May 3 09:32:07 xps13 kernel: [ 2015.175350] thunderbolt 0000:03:00.0: Port 0: 8086:1576 (Revision: 4, TB Version: 1, Type: Port (0x1))
May 3 09:32:07 xps13 kernel: [ 2015.175354] thunderbolt 0000:03:00.0: Max hop id (in/out): 7/7
May 3 09:32:07 xps13 kernel: [ 2015.175356] thunderbolt 0000:03:00.0: Max counters: 8
May 3 09:32:07 xps13 kernel: [ 2015.175359] thunderbolt 0000:03:00.0: NFC Credits: 0x800000
May 3 09:32:07 xps13 kernel: [ 2015.175859] thunderbolt 0000:03:00.0: Port 1: 8086:1576 (Revision: 4, TB Version: 1, Type: Port (0x1))
May 3 09:32:07 xps13 kernel: [ 2015.175862] thunderbolt 0000:03:00.0: Max hop id (in/out): 15/15
May 3 09:32:07 xps13 kernel: [ 2015.175865] thunderbolt 0000:03:00.0: Max counters: 16
May 3 09:32:07 xps13 kernel: [ 2015.175868] thunderbolt 0000:03:00.0: NFC Credits: 0x3c00000
May 3 09:32:07 xps13 kernel: [ 2015.176399] thunderbolt 0000:03:00.0: Port 2: 8086:1576 (Revision: 4, TB Version: 1, Type: Port (0x1))
May 3 09:32:07 xps13 kernel: [ 2015.176403] thunderbolt 0000:03:00.0: Max hop id (in/out): 15/15
May 3 09:32:07 xps13 kernel: [ 201...

Read more...

Gianluca Masci (g-masci) wrote :

i have the same problem

Andrei Susanu (andrei-susanu) wrote :

The problem persists on my side.

Mario Limonciello (superm1) wrote :

OK can you both please do the following:

0) Observe where the end of your current dmesg output is
1) Manually turn on force power
# echo 1 | sudo tee
/sys/bus/wmi/devices/86CCFD48-205E-4A77-9C48-2021CBEDE341/force_power

2) Check in /sys/bus/thunderbolt/devices/0-0/ and read the NVM version sysfs node
3) Turn off force power
# echo 0 | sudo tee
/sys/bus/wmi/devices/86CCFD48-205E-4A77-9C48-2021CBEDE341/force_power
4) Collect all messages after the end of dmesg output notated in 0 (Not just thunderbolt ones)

Changed in fwupd (Ubuntu):
status: New → Triaged
status: Triaged → Incomplete
importance: Undecided → Medium
Launchpad Janitor (janitor) wrote :

[Expired for fwupd (Ubuntu) because there has been no activity for 60 days.]

Changed in fwupd (Ubuntu):
status: Incomplete → Expired
Mauro Frigerio (mauro-frigi) wrote :

Hi, I have the same bug and regular I receive the notification of new firmware version.

I have made the steps in the post #12. Is possible to reopen the bug?

Changed in fwupd (Ubuntu):
status: Expired → Confirmed
Mario Limonciello (superm1) wrote :

@Mauro,

It looks like you skipped step 2.

Would you please upgrade to NVM 26 and see if it's still happening? It's available here:
https://github.com/dell/thunderbolt-nvm-linux/issues/11

Mauro Frigerio (mauro-frigi) wrote :

Thank's Mario for the super fast response. I have made the update to the version 26, after a reboot is ok. But it was the same situation with version 21.

I will wait for some days to check if it still ok with 26.

Mauro Frigerio (mauro-frigi) wrote :

After some days of reboot and work I still have the message of upgrading the Thunderbolt. The message is like before, actual version is 00.00.

Mario Limonciello (superm1) wrote :

OK. So is it happening reproducibly like every boot for you now?

If so, can you please try to do the steps in #12 I listed above, but please make sure that step 2 is included? That's what I'm most interested to see.

Mauro Frigerio (mauro-frigi) wrote :

I have found I way to reproduce the problem.

1) boot with a thunderbolt device connected
2) sudo fwupdmgr get-devices get version 26.1
3) restart without thunderbolt device
4) sudo fwupdmgr get-devices get version 00.00

The attached file is the output of the #12 procedure, result of step 2 is 26.1

Joan Fisbein (joan-fisbein) wrote :

I have the same problem I installed update 28.00, but after reboot it detects 00.00.
How can I help you to solve the problem?

Mario Limonciello (superm1) wrote :

So I think I might have a PR that will help this bug. Can you please try this PR?
https://github.com/hughsie/fwupd/pull/605#issuecomment-407097175

You can generate Ubuntu 18.04 packages following instructions here:
https://github.com/hughsie/fwupd/tree/master/contrib

If it persists, can you please:
1) Modify the fwupd.service systemd unit to add "-v" to ExecStart
2) Power off your machine and power it back on. See if the behavior continues to happen.
3) If it does happen please share the journal output generated by fwupd.service (the verbose in it will help to see if this timing is still off).

Mauro Frigerio (mauro-frigi) wrote :

Hi Mario, I am not a Git specialist and software engineer. But with some help from my girlfriend I have made almost all the points.

During the generation of the Deb package I receive an error at the point fu-self-test (3/13 fu-self-test FAIL 4.36 s (killed by signal 6 SIGABRT)) log is in attachment.

What I do wrong?

Mario Limonciello (superm1) wrote :

This was built in docker? Or built locally? That's odd if in docker since CI ran the same test just fine.

One solution can be to turn off unit tests (locally add to the environment DEB_BUILD_OPTIONS=nocheck)
http://www.ducea.com/2008/12/07/deb_build_optionsnocheck/

To do this with docker you would pass the variable like this:
# docker run -e DEB_BUILD_OPTIONS=nocheck -t -v `pwd`:/build fwupd-ubuntu-x86_64

Mauro Frigerio (mauro-frigi) wrote :

Hi Mario,

after installing the new version of fwupd (generated with docker). Like the post #17, i still have the problem. I would like to do the other steps proposed in #21, but I have some trouble (sorry I'm not a specialist) to exec them.

Can you please explain me (like a dummies), thank's.

1) Modify the fwupd.service systemd unit to add "-v" to ExecStart
2) Power off your machine and power it back on. See if the behavior continues to happen.
3) If it does happen please share the journal output generated by fwupd.service (the verbose in it will help to see if this timing is still off).

Mario Limonciello (superm1) wrote :

@Mauro,

Thanks for checking, that's unfortunate that it's still happening.

To modify that file open it with an editor as root. For example:
sudo nano /lib/systemd/system/fwupd.service
or
sudo gedit /lib/systemd/system/fwupd.service

To view output from the journal:
journalctl -u fwupd.service

You can redirect that to a file like this:
journalctl -u fwupd.service > fwupd_journal.txt

Based on the output from that file I might have another recommendation to try to bump the TBT_NEW_DEVICE_TIMEOUT to something bigger (it's currently "2", try to set it to "3" instead).
This is in tree at plugins/thunderbolt-power/fu-plugin-thunderbolt-power.c

I'd like to see your journal output first though before you add that new variable in however.

Mauro Frigerio (mauro-frigi) wrote :

Thank you for the patience.

As attachment the output of the journal.

Mario Limonciello (superm1) wrote :

@Mauro,

Okay, perfect thanks. So from this debug log we can tell for sure that this isn't caused by thunderbolt power, but rather the value read from the kernel immediately is invalid.
This tells me that this is probably a case of fwupd racing with the kernel based off the uevent that came through.

I've filed an issue upstream that we can discuss this more with relevant developers to see if we can come up with a better solution.
https://github.com/hughsie/fwupd/issues/608

Mario Limonciello (superm1) wrote :

If you can please test this branch instead to see if it helps for you. Same thing provide the debug log if it isn't helping still.

Mauro Frigerio (mauro-frigi) wrote :

Hi Mario, at the moment with the last PR #29 it works.

Mario Limonciello (superm1) wrote :

That's good to hear. Would you mind confirming that in your debug log it is trying to read a second time? When you have verbose mode activated it will log a message indicating it retried.

Mauro Frigerio (mauro-frigi) wrote :

This is the log of today

Mauro Frigerio (mauro-frigi) wrote :

with the file ;-)

Mario Limonciello (superm1) wrote :

Great!

I do see this:
15:14:06:0715 Thunderbolt Attempt 0: Failed to read NVM version

Which means it did use the new logic. Please leave a comment in the PR on GitHub to assist in it getting accepted.

Mario Limonciello (superm1) wrote :

The fix is contained in https://github.com/hughsie/fwupd/commit/60c845627d3b5ad0beb56d85fbe5bdd47ad7d70e for the 1_0_X branch and will be in the 1.0.9 release of fwupd and master (https://github.com/hughsie/fwupd/commit/25d51d14297713b4817ef9644f83e07e71344b0a) which will be in the 1.2.0 release of fwupd.

Changed in fwupd (Ubuntu Cosmic):
status: Confirmed → Fix Released
Changed in fwupd (Ubuntu Bionic):
status: New → Triaged
description: updated

Hello Andrei, or anyone else affected,

Accepted fwupd into bionic-proposed. The package will build now and be available at https://launchpad.net/ubuntu/+source/fwupd/1.0.9-0ubuntu1 in a few hours, and then in the -proposed repository.

Please help us by testing this new package. See https://wiki.ubuntu.com/Testing/EnableProposed for documentation on how to enable and use -proposed. Your feedback will aid us getting this update out to other Ubuntu users.

If this package fixes the bug for you, please add a comment to this bug, mentioning the version of the package you tested and change the tag from verification-needed-bionic to verification-done-bionic. If it does not fix the bug for you, please add a comment stating that, and change the tag to verification-failed-bionic. In either case, without details of your testing we will not be able to proceed.

Further information regarding the verification process can be found at https://wiki.ubuntu.com/QATeam/PerformingSRUVerification . Thank you in advance for helping!

N.B. The updated package will be released to -updates after the bug(s) fixed by this package have been verified and the package has been in -proposed for a minimum of 7 days.

Changed in fwupd (Ubuntu Bionic):
status: Triaged → Fix Committed
tags: added: verification-needed verification-needed-bionic
Brian Murray (brian-murray) wrote :

Hello Andrei, or anyone else affected,

Accepted fwupd into bionic-proposed. The package will build now and be available at https://launchpad.net/ubuntu/+source/fwupd/1.0.9-0ubuntu2 in a few hours, and then in the -proposed repository.

Please help us by testing this new package. See https://wiki.ubuntu.com/Testing/EnableProposed for documentation on how to enable and use -proposed. Your feedback will aid us getting this update out to other Ubuntu users.

If this package fixes the bug for you, please add a comment to this bug, mentioning the version of the package you tested and change the tag from verification-needed-bionic to verification-done-bionic. If it does not fix the bug for you, please add a comment stating that, and change the tag to verification-failed-bionic. In either case, without details of your testing we will not be able to proceed.

Further information regarding the verification process can be found at https://wiki.ubuntu.com/QATeam/PerformingSRUVerification . Thank you in advance for helping!

N.B. The updated package will be released to -updates after the bug(s) fixed by this package have been verified and the package has been in -proposed for a minimum of 7 days.

Mario Limonciello (superm1) wrote :

I've tested that the controller doesn't show up as 00.00 any more after upgrading to 1.0.9-0ubuntu2.

tags: added: verification-done verification-done-bionic
removed: verification-needed verification-needed-bionic
To post a comment you must log in.
This report contains Public information  Edit
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.