Re: How to proceed: usci_acpi: PPM init failed (-110)

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

 



Hi Heikki,

do you think we could get this back on track somehow? I'm not sure what to try next, do you have any ideas? Are there any tools to try and trace what the Windows driver does? Either from within Windows itself or intercept it somehow externally -- a hypervisor approach? Are there any tools developed for this purpose? I wasn't really able to find much.

Regards,
Samuel

On 2021-08-26 12:41, Samuel Čavoj wrote:
Hello,

On 26.08.2021 10:53, Heikki Krogerus wrote:
Hi Samuel,

>
> the command finishes instantly and does not seem to produce any error.
>
>     PS C:\Program Files (x86)\USBTest\x64> .\UcsiControl.exe Send 0 00010005
>     COMMAND:
>     AsUInt64: 10005
>     Command: 5
>     DataLength: 0
>
>     MESSAGE IN is empty.

Thanks for testing that. So UCSI is definitely working on this
platform. I guess the ACPI notifications are simply not going through.

Can you check if there are any events coming from the EC with the
following commands:

        % modprobe -r ucsi_acpi
        % modprobe -r typec_ucsi
        % grep -i acpi /proc/interrupts
        ...
        % modprobe typec_ucsi
        % modprobe ucsi_acpi
        % grep -i acpi /proc/interrupts
        ...

See if the number of interrupts increases considerable, or at all. The
ucsi drivers need to be modules of course in order for that to work.

I made four snapshots of the (filtered) /proc/interrupts file:

    1. with the modules loaded normally
    2. right after unloading them
    3. right after loading them again
    4. after the timeout expires and the init failed message is logged

Files 3 and 4 are identical. Between 1--2 and 2--3, IRQ 9 increases by
exactly 1 each time. The IRQ is described as "IR-IO-APIC 9-fasteoi acpi".
Here is the line in question from each of the files.

            CPU0       CPU1       CPU2       CPU3       CPU4
CPU5       CPU6       CPU7       CPU8       CPU9       CPU10
CPU11      CPU12      CPU13      CPU14      CPU15
   9:          0         52          0          0          0
0          0          0          0          0          0          0
      0          0          0          0  IR-IO-APIC    9-fasteoi
acpi
   9:          0         53          0          0          0
0          0          0          0          0          0          0
      0          0          0          0  IR-IO-APIC    9-fasteoi
acpi
   9:          0         54          0          0          0
0          0          0          0          0          0          0
      0          0          0          0  IR-IO-APIC    9-fasteoi
acpi
   9:          0         54          0          0          0
0          0          0          0          0          0          0
      0          0          0          0  IR-IO-APIC    9-fasteoi
acpi

To make it clear what I did in the first place, is to add a dev_err line
in the error branch right after "Enable basic notifications" in
ucsi_init. The line does get printed.

My understanding is that the PPM is completely quiet during the reset
procedure, and therefore the single notifications received should be the
completion notification for the "enable basic notifications" command.

I added a debug print to ucsi_acpi_notify, to see if the interrupt is
getting routed correctly at all (I suspected the ACPI might be
generating notifications for a different device). Another debug print
was added to ucsi_init right after the reset completes.

This is a snippet from ucsi_acpi_notify showing added printouts:

dev_err(ua->dev, "checking ua->flags: %ld, cci: %d\n", ua->flags, cci);
	if (test_bit(COMMAND_PENDING, &ua->flags) &&
	    cci & (UCSI_CCI_ACK_COMPLETE | UCSI_CCI_COMMAND_COMPLETE)) {

        dev_err(ua->dev, "complete\n");
		complete(&ua->complete);
    }

Indeed, ucsi_acpi_notify gets called once when the module loads, after
the reset procedure is completed (as long as the ordering of the
messages in dmesg is good enough to tell, they are 20ms apart).
This is the output in dmesg: (i shortened the timeout to 5s).

    [ 1397.741701] ucsi_acpi USBC000:00: PPM reset succeeded
    [ 1397.761319] ucsi_acpi USBC000:00: checking ua->flags: 2, cci: 0
[ 1402.941808] ucsi_acpi USBC000:00: failed to enable basic notifications
    [ 1402.989510] ucsi_acpi USBC000:00: PPM init failed (-110)

The completion condition is not satisfied and "complete" is not
printed. Possibly the firmware has some quirk, a cci of 0 seems wrong to
me.

Maybe there is something special that the OS should do with the EC on

I suppose either that, or the PPM deviates from the spec. I don't know
how to go about tracing what Windows does, but that would be a way to
go.

your board... There is a weird message in your dmesg.

        "ACPI: EC: interrupt blocked"

I don't know if it's relevant at all in this case, but I've just never
seen that. I'm not an EC or ACPI expert, but I think that you only see
that if the EC event interrupt is a GPIO. I would expect there to be
also a message:

        "ACPI: EC: interrupt unblocked"

There is such a message in the log, on line 475. Also on every suspend,
the interrupt is blocked before going to sleep and unblocked when waking
up, which makes sense.

But as said, I'm really not an EC expert. We probable need to ask the
ACPI guys about this, but let's first check the interrupts.

thanks,

--
heikki

Thank you very much for helping me with this.

Regards,
Samuel



[Index of Archives]     [Linux Media]     [Linux Input]     [Linux Audio Users]     [Yosemite News]     [Linux Kernel]     [Linux SCSI]     [Old Linux USB Devel Archive]

  Powered by Linux