2023-11-21 11:52:10

by Paul Menzel

[permalink] [raw]
Subject: Unplugging USB-C charger cable causes `ucsi_acpi USBC000:00: ucsi_handle_connector_change: ACK failed (-110)`

Dear Linux folks,


On the Dell XPS 13, BIOS 2.21.0 06/02/2022, with Debian sid/unstable and
Linux 6.5.10, when unplugging the (Dell) USB Type-C charger cable, Linux
logs the error below:

ucsi_acpi USBC000:00: ucsi_handle_connector_change: ACK failed (-110)

As this is logged with level error, can this be somehow fixed?

drivers/usb/typec/ucsi/ucsi.c: dev_err(ucsi->dev, "%s: ACK failed
(%d)", __func__, ret);

Please find the output of `dmesg` attached.


Kind regards,

Paul


Attachments:
=?UTF-8?Q?20231121=E2=80=93dell-xps-13-9360=E2=80=93linux-6=2E5=2E10-messages=2Etxt?= (77.49 kB)

2023-11-21 14:09:53

by Heikki Krogerus

[permalink] [raw]
Subject: Re: Unplugging USB-C charger cable causes `ucsi_acpi USBC000:00: ucsi_handle_connector_change: ACK failed (-110)`

On Tue, Nov 21, 2023 at 12:50:43PM +0100, Paul Menzel wrote:
> Dear Linux folks,
>
>
> On the Dell XPS 13, BIOS 2.21.0 06/02/2022, with Debian sid/unstable and
> Linux 6.5.10, when unplugging the (Dell) USB Type-C charger cable, Linux
> logs the error below:
>
> ucsi_acpi USBC000:00: ucsi_handle_connector_change: ACK failed (-110)
>
> As this is logged with level error, can this be somehow fixed?
>
> drivers/usb/typec/ucsi/ucsi.c: dev_err(ucsi->dev, "%s: ACK failed (%d)",
> __func__, ret);
>
> Please find the output of `dmesg` attached.

Thanks. The firmware not reacting to the ACK command is weird, but I'm
not sure if it's critical. Does the interface continue working after
that? Do you see the partner devices appearing under /sys/class/typec/
when you plug them, and disappearing when you unplug them?

thanks,

--
heikki

2023-11-21 14:27:36

by Paul Menzel

[permalink] [raw]
Subject: Re: Unplugging USB-C charger cable causes `ucsi_acpi USBC000:00: ucsi_handle_connector_change: ACK failed (-110)`

Dear Heikki,


Thank you for your prompt reply.

Am 21.11.23 um 15:08 schrieb Heikki Krogerus:
> On Tue, Nov 21, 2023 at 12:50:43PM +0100, Paul Menzel wrote:

>> On the Dell XPS 13, BIOS 2.21.0 06/02/2022, with Debian sid/unstable and
>> Linux 6.5.10, when unplugging the (Dell) USB Type-C charger cable, Linux
>> logs the error below:
>>
>> ucsi_acpi USBC000:00: ucsi_handle_connector_change: ACK failed (-110)
>>
>> As this is logged with level error, can this be somehow fixed?
>>
>> drivers/usb/typec/ucsi/ucsi.c: dev_err(ucsi->dev, "%s: ACK failed (%d)", __func__, ret);
>>
>> Please find the output of `dmesg` attached.
>
> Thanks. The firmware not reacting to the ACK command is weird, but I'm
> not sure if it's critical. Does the interface continue working after
> that? Do you see the partner devices appearing under /sys/class/typec/
> when you plug them, and disappearing when you unplug them?

```
$ LANG= grep .
/sys/class/typec/port0/device/power_supply/ucsi-source-psy-USBC000\:001/*
/sys/class/typec/port0/device/power_supply/ucsi-source-psy-USBC000:001/current_max:0
/sys/class/typec/port0/device/power_supply/ucsi-source-psy-USBC000:001/current_now:0
grep:
/sys/class/typec/port0/device/power_supply/ucsi-source-psy-USBC000:001/device:
Is a directory
grep:
/sys/class/typec/port0/device/power_supply/ucsi-source-psy-USBC000:001/hwmon7:
Is a directory
/sys/class/typec/port0/device/power_supply/ucsi-source-psy-USBC000:001/online:0
grep:
/sys/class/typec/port0/device/power_supply/ucsi-source-psy-USBC000:001/power:
Is a directory
/sys/class/typec/port0/device/power_supply/ucsi-source-psy-USBC000:001/scope:System
grep:
/sys/class/typec/port0/device/power_supply/ucsi-source-psy-USBC000:001/subsystem:
Is a directory
/sys/class/typec/port0/device/power_supply/ucsi-source-psy-USBC000:001/type:USB
/sys/class/typec/port0/device/power_supply/ucsi-source-psy-USBC000:001/uevent:POWER_SUPPLY_NAME=ucsi-source-psy-USBC000:001
/sys/class/typec/port0/device/power_supply/ucsi-source-psy-USBC000:001/uevent:POWER_SUPPLY_TYPE=USB
/sys/class/typec/port0/device/power_supply/ucsi-source-psy-USBC000:001/uevent:POWER_SUPPLY_USB_TYPE=[C]
PD PD_PPS
/sys/class/typec/port0/device/power_supply/ucsi-source-psy-USBC000:001/uevent:POWER_SUPPLY_ONLINE=0
/sys/class/typec/port0/device/power_supply/ucsi-source-psy-USBC000:001/uevent:POWER_SUPPLY_VOLTAGE_MIN=5000000
/sys/class/typec/port0/device/power_supply/ucsi-source-psy-USBC000:001/uevent:POWER_SUPPLY_VOLTAGE_MAX=5000000
/sys/class/typec/port0/device/power_supply/ucsi-source-psy-USBC000:001/uevent:POWER_SUPPLY_VOLTAGE_NOW=5000000
/sys/class/typec/port0/device/power_supply/ucsi-source-psy-USBC000:001/uevent:POWER_SUPPLY_CURRENT_MAX=0
/sys/class/typec/port0/device/power_supply/ucsi-source-psy-USBC000:001/uevent:POWER_SUPPLY_CURRENT_NOW=0
/sys/class/typec/port0/device/power_supply/ucsi-source-psy-USBC000:001/uevent:POWER_SUPPLY_SCOPE=System
/sys/class/typec/port0/device/power_supply/ucsi-source-psy-USBC000:001/usb_type:[C]
PD PD_PPS
/sys/class/typec/port0/device/power_supply/ucsi-source-psy-USBC000:001/voltage_max:5000000
/sys/class/typec/port0/device/power_supply/ucsi-source-psy-USBC000:001/voltage_min:5000000
/sys/class/typec/port0/device/power_supply/ucsi-source-psy-USBC000:001/voltage_now:5000000
grep:
/sys/class/typec/port0/device/power_supply/ucsi-source-psy-USBC000:001/wakeup49:
Is a directory
```

Now I unplugged the device, and the error is *not* logged. (I had a USB
Type-C port replicator plugged in during the day before.)

The directory is still there:

```
$ LANG= grep .
/sys/class/typec/port0/device/power_supply/ucsi-source-psy-USBC000\:001/*
/sys/class/typec/port0/device/power_supply/ucsi-source-psy-USBC000:001/current_max:0
/sys/class/typec/port0/device/power_supply/ucsi-source-psy-USBC000:001/current_now:0
grep:
/sys/class/typec/port0/device/power_supply/ucsi-source-psy-USBC000:001/device:
Is a directory
grep:
/sys/class/typec/port0/device/power_supply/ucsi-source-psy-USBC000:001/hwmon7:
Is a directory
/sys/class/typec/port0/device/power_supply/ucsi-source-psy-USBC000:001/online:0
grep:
/sys/class/typec/port0/device/power_supply/ucsi-source-psy-USBC000:001/power:
Is a directory
/sys/class/typec/port0/device/power_supply/ucsi-source-psy-USBC000:001/scope:System
grep:
/sys/class/typec/port0/device/power_supply/ucsi-source-psy-USBC000:001/subsystem:
Is a directory
/sys/class/typec/port0/device/power_supply/ucsi-source-psy-USBC000:001/type:USB
/sys/class/typec/port0/device/power_supply/ucsi-source-psy-USBC000:001/uevent:POWER_SUPPLY_NAME=ucsi-source-psy-USBC000:001
/sys/class/typec/port0/device/power_supply/ucsi-source-psy-USBC000:001/uevent:POWER_SUPPLY_TYPE=USB
/sys/class/typec/port0/device/power_supply/ucsi-source-psy-USBC000:001/uevent:POWER_SUPPLY_USB_TYPE=[C]
PD PD_PPS
/sys/class/typec/port0/device/power_supply/ucsi-source-psy-USBC000:001/uevent:POWER_SUPPLY_ONLINE=0
/sys/class/typec/port0/device/power_supply/ucsi-source-psy-USBC000:001/uevent:POWER_SUPPLY_VOLTAGE_MIN=5000000
/sys/class/typec/port0/device/power_supply/ucsi-source-psy-USBC000:001/uevent:POWER_SUPPLY_VOLTAGE_MAX=5000000
/sys/class/typec/port0/device/power_supply/ucsi-source-psy-USBC000:001/uevent:POWER_SUPPLY_VOLTAGE_NOW=5000000
/sys/class/typec/port0/device/power_supply/ucsi-source-psy-USBC000:001/uevent:POWER_SUPPLY_CURRENT_MAX=0
/sys/class/typec/port0/device/power_supply/ucsi-source-psy-USBC000:001/uevent:POWER_SUPPLY_CURRENT_NOW=0
/sys/class/typec/port0/device/power_supply/ucsi-source-psy-USBC000:001/uevent:POWER_SUPPLY_SCOPE=System
/sys/class/typec/port0/device/power_supply/ucsi-source-psy-USBC000:001/usb_type:[C]
PD PD_PPS
/sys/class/typec/port0/device/power_supply/ucsi-source-psy-USBC000:001/voltage_max:5000000
/sys/class/typec/port0/device/power_supply/ucsi-source-psy-USBC000:001/voltage_min:5000000
/sys/class/typec/port0/device/power_supply/ucsi-source-psy-USBC000:001/voltage_now:5000000
grep:
/sys/class/typec/port0/device/power_supply/ucsi-source-psy-USBC000:001/wakeup49:
Is a directory
```

I guess, that is the wrong directory I look at though?

(I am going to monitor the logs over the next days.)


Kind regards,

Paul
```

2023-11-22 18:40:07

by Heikki Krogerus

[permalink] [raw]
Subject: Re: Unplugging USB-C charger cable causes `ucsi_acpi USBC000:00: ucsi_handle_connector_change: ACK failed (-110)`

On Tue, Nov 21, 2023 at 03:25:59PM +0100, Paul Menzel wrote:
> Dear Heikki,
>
>
> Thank you for your prompt reply.
>
> Am 21.11.23 um 15:08 schrieb Heikki Krogerus:
> > On Tue, Nov 21, 2023 at 12:50:43PM +0100, Paul Menzel wrote:
>
> > > On the Dell XPS 13, BIOS 2.21.0 06/02/2022, with Debian sid/unstable and
> > > Linux 6.5.10, when unplugging the (Dell) USB Type-C charger cable, Linux
> > > logs the error below:
> > >
> > > ucsi_acpi USBC000:00: ucsi_handle_connector_change: ACK failed (-110)
> > >
> > > As this is logged with level error, can this be somehow fixed?
> > >
> > > drivers/usb/typec/ucsi/ucsi.c: dev_err(ucsi->dev, "%s: ACK failed (%d)", __func__, ret);
> > >
> > > Please find the output of `dmesg` attached.
> >
> > Thanks. The firmware not reacting to the ACK command is weird, but I'm
> > not sure if it's critical. Does the interface continue working after
> > that? Do you see the partner devices appearing under /sys/class/typec/
> > when you plug them, and disappearing when you unplug them?
>
> ```
> $ LANG= grep .
> /sys/class/typec/port0/device/power_supply/ucsi-source-psy-USBC000\:001/*
> /sys/class/typec/port0/device/power_supply/ucsi-source-psy-USBC000:001/current_max:0
> /sys/class/typec/port0/device/power_supply/ucsi-source-psy-USBC000:001/current_now:0
> grep: /sys/class/typec/port0/device/power_supply/ucsi-source-psy-USBC000:001/device:
> Is a directory
> grep: /sys/class/typec/port0/device/power_supply/ucsi-source-psy-USBC000:001/hwmon7:
> Is a directory
> /sys/class/typec/port0/device/power_supply/ucsi-source-psy-USBC000:001/online:0
> grep:
> /sys/class/typec/port0/device/power_supply/ucsi-source-psy-USBC000:001/power:
> Is a directory
> /sys/class/typec/port0/device/power_supply/ucsi-source-psy-USBC000:001/scope:System
> grep: /sys/class/typec/port0/device/power_supply/ucsi-source-psy-USBC000:001/subsystem:
> Is a directory
> /sys/class/typec/port0/device/power_supply/ucsi-source-psy-USBC000:001/type:USB
> /sys/class/typec/port0/device/power_supply/ucsi-source-psy-USBC000:001/uevent:POWER_SUPPLY_NAME=ucsi-source-psy-USBC000:001
> /sys/class/typec/port0/device/power_supply/ucsi-source-psy-USBC000:001/uevent:POWER_SUPPLY_TYPE=USB
> /sys/class/typec/port0/device/power_supply/ucsi-source-psy-USBC000:001/uevent:POWER_SUPPLY_USB_TYPE=[C]
> PD PD_PPS
> /sys/class/typec/port0/device/power_supply/ucsi-source-psy-USBC000:001/uevent:POWER_SUPPLY_ONLINE=0
> /sys/class/typec/port0/device/power_supply/ucsi-source-psy-USBC000:001/uevent:POWER_SUPPLY_VOLTAGE_MIN=5000000
> /sys/class/typec/port0/device/power_supply/ucsi-source-psy-USBC000:001/uevent:POWER_SUPPLY_VOLTAGE_MAX=5000000
> /sys/class/typec/port0/device/power_supply/ucsi-source-psy-USBC000:001/uevent:POWER_SUPPLY_VOLTAGE_NOW=5000000
> /sys/class/typec/port0/device/power_supply/ucsi-source-psy-USBC000:001/uevent:POWER_SUPPLY_CURRENT_MAX=0
> /sys/class/typec/port0/device/power_supply/ucsi-source-psy-USBC000:001/uevent:POWER_SUPPLY_CURRENT_NOW=0
> /sys/class/typec/port0/device/power_supply/ucsi-source-psy-USBC000:001/uevent:POWER_SUPPLY_SCOPE=System
> /sys/class/typec/port0/device/power_supply/ucsi-source-psy-USBC000:001/usb_type:[C]
> PD PD_PPS
> /sys/class/typec/port0/device/power_supply/ucsi-source-psy-USBC000:001/voltage_max:5000000
> /sys/class/typec/port0/device/power_supply/ucsi-source-psy-USBC000:001/voltage_min:5000000
> /sys/class/typec/port0/device/power_supply/ucsi-source-psy-USBC000:001/voltage_now:5000000
> grep: /sys/class/typec/port0/device/power_supply/ucsi-source-psy-USBC000:001/wakeup49:
> Is a directory
> ```
>
> Now I unplugged the device, and the error is *not* logged. (I had a USB
> Type-C port replicator plugged in during the day before.)
>
> The directory is still there:
>
> ```
> $ LANG= grep .
> /sys/class/typec/port0/device/power_supply/ucsi-source-psy-USBC000\:001/*
> /sys/class/typec/port0/device/power_supply/ucsi-source-psy-USBC000:001/current_max:0
> /sys/class/typec/port0/device/power_supply/ucsi-source-psy-USBC000:001/current_now:0
> grep: /sys/class/typec/port0/device/power_supply/ucsi-source-psy-USBC000:001/device:
> Is a directory
> grep: /sys/class/typec/port0/device/power_supply/ucsi-source-psy-USBC000:001/hwmon7:
> Is a directory
> /sys/class/typec/port0/device/power_supply/ucsi-source-psy-USBC000:001/online:0
> grep:
> /sys/class/typec/port0/device/power_supply/ucsi-source-psy-USBC000:001/power:
> Is a directory
> /sys/class/typec/port0/device/power_supply/ucsi-source-psy-USBC000:001/scope:System
> grep: /sys/class/typec/port0/device/power_supply/ucsi-source-psy-USBC000:001/subsystem:
> Is a directory
> /sys/class/typec/port0/device/power_supply/ucsi-source-psy-USBC000:001/type:USB
> /sys/class/typec/port0/device/power_supply/ucsi-source-psy-USBC000:001/uevent:POWER_SUPPLY_NAME=ucsi-source-psy-USBC000:001
> /sys/class/typec/port0/device/power_supply/ucsi-source-psy-USBC000:001/uevent:POWER_SUPPLY_TYPE=USB
> /sys/class/typec/port0/device/power_supply/ucsi-source-psy-USBC000:001/uevent:POWER_SUPPLY_USB_TYPE=[C]
> PD PD_PPS
> /sys/class/typec/port0/device/power_supply/ucsi-source-psy-USBC000:001/uevent:POWER_SUPPLY_ONLINE=0
> /sys/class/typec/port0/device/power_supply/ucsi-source-psy-USBC000:001/uevent:POWER_SUPPLY_VOLTAGE_MIN=5000000
> /sys/class/typec/port0/device/power_supply/ucsi-source-psy-USBC000:001/uevent:POWER_SUPPLY_VOLTAGE_MAX=5000000
> /sys/class/typec/port0/device/power_supply/ucsi-source-psy-USBC000:001/uevent:POWER_SUPPLY_VOLTAGE_NOW=5000000
> /sys/class/typec/port0/device/power_supply/ucsi-source-psy-USBC000:001/uevent:POWER_SUPPLY_CURRENT_MAX=0
> /sys/class/typec/port0/device/power_supply/ucsi-source-psy-USBC000:001/uevent:POWER_SUPPLY_CURRENT_NOW=0
> /sys/class/typec/port0/device/power_supply/ucsi-source-psy-USBC000:001/uevent:POWER_SUPPLY_SCOPE=System
> /sys/class/typec/port0/device/power_supply/ucsi-source-psy-USBC000:001/usb_type:[C]
> PD PD_PPS
> /sys/class/typec/port0/device/power_supply/ucsi-source-psy-USBC000:001/voltage_max:5000000
> /sys/class/typec/port0/device/power_supply/ucsi-source-psy-USBC000:001/voltage_min:5000000
> /sys/class/typec/port0/device/power_supply/ucsi-source-psy-USBC000:001/voltage_now:5000000
> grep: /sys/class/typec/port0/device/power_supply/ucsi-source-psy-USBC000:001/wakeup49:
> Is a directory
> ```
>
> I guess, that is the wrong directory I look at though?
>
> (I am going to monitor the logs over the next days.)

Just list what you have in /sys/class/typec/ before and after plugging
a device to the port:

ls /sys/class/typec/

thanks,

--
heikki

2023-11-23 12:23:02

by Paul Menzel

[permalink] [raw]
Subject: Re: Unplugging USB-C charger cable causes `ucsi_acpi USBC000:00: ucsi_handle_connector_change: ACK failed (-110)`

Dear Heikki,


Am 22.11.23 um 09:56 schrieb Heikki Krogerus:
> On Tue, Nov 21, 2023 at 03:25:59PM +0100, Paul Menzel wrote:

>> Am 21.11.23 um 15:08 schrieb Heikki Krogerus:
>>> On Tue, Nov 21, 2023 at 12:50:43PM +0100, Paul Menzel wrote:
>>
>>>> On the Dell XPS 13, BIOS 2.21.0 06/02/2022, with Debian sid/unstable and
>>>> Linux 6.5.10, when unplugging the (Dell) USB Type-C charger cable, Linux
>>>> logs the error below:
>>>>
>>>> ucsi_acpi USBC000:00: ucsi_handle_connector_change: ACK failed (-110)
>>>>
>>>> As this is logged with level error, can this be somehow fixed?
>>>>
>>>> drivers/usb/typec/ucsi/ucsi.c: dev_err(ucsi->dev, "%s: ACK failed (%d)", __func__, ret);
>>>>
>>>> Please find the output of `dmesg` attached.
>>>
>>> Thanks. The firmware not reacting to the ACK command is weird, but I'm
>>> not sure if it's critical. Does the interface continue working after
>>> that? Do you see the partner devices appearing under /sys/class/typec/
>>> when you plug them, and disappearing when you unplug them?
>>
>> ```
>> $ LANG= grep . /sys/class/typec/port0/device/power_supply/ucsi-source-psy-USBC000\:001/*
>> /sys/class/typec/port0/device/power_supply/ucsi-source-psy-USBC000:001/current_max:0
>> /sys/class/typec/port0/device/power_supply/ucsi-source-psy-USBC000:001/current_now:0

[…]

>> ```
>>
>> Now I unplugged the device, and the error is *not* logged. (I had a USB
>> Type-C port replicator plugged in during the day before.)
>>
>> The directory is still there:
>>
>> ```
>> $ LANG= grep . /sys/class/typec/port0/device/power_supply/ucsi-source-psy-USBC000\:001/*
>> /sys/class/typec/port0/device/power_supply/ucsi-source-psy-USBC000:001/current_max:0
>> /sys/class/typec/port0/device/power_supply/ucsi-source-psy-USBC000:001/current_now:0

[…]

>> ```
>>
>> I guess, that is the wrong directory I look at though?
>>
>> (I am going to monitor the logs over the next days.)
>
> Just list what you have in /sys/class/typec/ before and after plugging
> a device to the port:
>
> ls /sys/class/typec/

Sorry, here you go:

With charger:

$ ls /sys/class/typec/
port0 port0-partner

After unplugging the charger:

$ LANG= ls /sys/class/typec/
port0

By the way, Linux logs the ucsi_handle_connector_change line around five
second after unplugging the USB Type-C charger cable.


Kind regards,

Paul


PS: In the logs since October 30th, I see the three distinct lines below:

1. ucsi_acpi USBC000:00: failed to re-enable notifications (-110)
2. ucsi_acpi USBC000:00: GET_CONNECTOR_STATUS failed (-110)
3. ucsi_acpi USBC000:00: ucsi_handle_connector_change: ACK failed (-110)

Is it documented somewhere what -100 means?

2023-11-24 12:57:11

by Heikki Krogerus

[permalink] [raw]
Subject: Re: Unplugging USB-C charger cable causes `ucsi_acpi USBC000:00: ucsi_handle_connector_change: ACK failed (-110)`

Hi,

> > Just list what you have in /sys/class/typec/ before and after plugging
> > a device to the port:
> >
> > ls /sys/class/typec/
>
> Sorry, here you go:
>
> With charger:
>
> $ ls /sys/class/typec/
> port0 port0-partner
>
> After unplugging the charger:
>
> $ LANG= ls /sys/class/typec/
> port0

Thanks. The interface does not appear to be completely stuck, which is
what I wanted to check.

> By the way, Linux logs the ucsi_handle_connector_change line around five
> second after unplugging the USB Type-C charger cable.
>
> Kind regards,
> Paul
>
> PS: In the logs since October 30th, I see the three distinct lines below:
>
> 1. ucsi_acpi USBC000:00: failed to re-enable notifications (-110)
> 2. ucsi_acpi USBC000:00: GET_CONNECTOR_STATUS failed (-110)
> 3. ucsi_acpi USBC000:00: ucsi_handle_connector_change: ACK failed (-110)
>
> Is it documented somewhere what -100 means?

That is the error code, and 110 means Timeout. The driver waits 5s,
which should be more than enough. If the firmware does not respond
within that 5s, it will most likely never respond.

Two of those errors mean that the driver has sent a command to the
firmware but the firmware never completes the command.

The ACK failure means that the driver tries to acknowledge a connector
change event (that you get for example when you plug or unplug the
cable) indicating that the driver has now processed the event, but the
firmware does not react to that acknowledgement like it should.

So the firmware is not behaving correctly in all these cases. I could
try to see if we can workaround those issues, but I would need to be
able reproduce the problems. Unfortunately I do not have XPS 13 9360.

But none of those problems are critical if the interface really
continues to work.

thanks,

--
heikki