cb22 / macbook12-spi-driver

WIP input driver for the SPI touchpad / keyboard found in the 12" MacBook (MacBook8,1 + MacBook9,1)
GNU General Public License v2.0
298 stars 103 forks source link

Keyboard/trackpad not responsive on resume for Macbook 8,1 (12" 2015) #49

Open rquast opened 6 years ago

rquast commented 6 years ago

The keyboard and trackpad don't resume after suspend for me. I am using Ubuntu 17.04 and have tried this with both the 4.10 kernel and the mainline 4.14 rc5 kernel that both have the same issue. The issue appears to have affected other models in the past: https://github.com/cb22/macbook12-spi-driver/pull/30

roadrunner2 commented 6 years ago

Were there any related errors in dmesg? I presume the relevant driver messages show up? (spi-device suspend done and spi-device resume done)

rquast commented 6 years ago

No error messages, both of those messages you mentioned appeared. Here's the output:

https://gist.github.com/rquast/519ade5d36e2eac73b20fbdf29a4fbe8

rquast commented 6 years ago

Have tested to see if this worked after fixing https://github.com/cb22/macbook12-spi-driver/issues/50 but still doesn't resume.

roadrunner2 commented 6 years ago

Since there are no error messages, let's see what's going on with the initialization command. Just before suspending (assuming a working keyboard at this point), can you set the debug param to enable logging of some of the SPI packets:

echo 0x0501 | sudo tee /sys/module/applespi/parameters/debug

After resume you can turn off that logging by setting the debug param to 0 again. This should generate a moderate amount of output (a hexdump of each 256 byte packet, one packet for each key event plus a few others). Then provide the dmesg output for that, please.

rquast commented 6 years ago

There's no debug output by the look. Is there something wrong there?

root@rquast-MacBook:/var/log# cat /sys/module/applespi/parameters/debug 1281

https://gist.github.com/rquast/8dac9b6bc946ee82f8e4b27d13f4aab1

roadrunner2 commented 6 years ago

That's very odd! Did you type anything on the (internal) keyboard after enabling the debug logs? At the very least before the suspend any such key events should've gotten logged.

rquast commented 6 years ago

Yes, there's output when typing a few keys and so on before suspend, but nothing in the suspend itself.

https://gist.github.com/rquast/8559a388330ddecfd259f37160219e01

rquast commented 6 years ago

Don't know if it helps, but the keyboard doesn't light up again after resume either. Also, no packets captured after resume.

roadrunner2 commented 6 years ago

Thanks for the info. Ok, I suspect we're running into a race here where a command is sent during shutdown but it's response is not received, and hence the write-outstanding flag is still set when we resume.

Can you do the following:

rquast commented 6 years ago

Applied the patch, but had to manually do that because it's different from master (wrong line number). Unfortunately, no change. https://gist.github.com/rquast/d5e970fb4891714fabdaf4c8839de279

rquast commented 6 years ago

My apologies.. I didn't notice the change in the debug flag. Will re-run and paste the output.

rquast commented 6 years ago

I don't think it gave any more information with the 0x507 flag: https://gist.github.com/rquast/b9dfbe14643729933fc0ba7852a9a663

roadrunner2 commented 6 years ago

Thanks. Sorry about the wrong line numbers - have some changes sitting in my tree and I figured patch would handle it.

So we're getting closer to the culprit. Can you apply this patch instead (the line numbers should be accurate now):

--- a/applespi.c
+++ b/applespi.c
@@ -674,6 +674,10 @@ applespi_send_cmd_msg(struct applespi_data *applespi)
        u16 crc;
        int sts;

+       pr_info("drain=%d cmd_msg_queued=%d init_cmd_idx=%d\n",
+               applespi->drain, applespi->cmd_msg_queued,
+               applespi->init_cmd_idx);
+
        /* check if draining */
        if (applespi->drain)
                return 0;
@@ -749,6 +753,7 @@ applespi_send_cmd_msg(struct applespi_data *applespi)

        sts = applespi_async(applespi, &applespi->wr_m,
                             applespi_async_write_complete);
+       pr_info("applespi_async: sts=%d\n", sts);

        if (sts != 0) {
                pr_warn("Error queueing async write to device: %d\n", sts);

And again show the dmesg output.

Right now it's looking like spi_async may actually be swallowing up the init request, indicating some issue with the keyboard/trackpad itself.

One reason for this could be an issue with the SIST ACPI call - try adding this patch too:

--- a/applespi.c
+++ b/applespi.c
@@ -617,9 +617,11 @@ static int applespi_enable_spi(struct applespi_data *applespi)
        long long unsigned int spi_status;

        /* Check if SPI is already enabled, so we can skip the delay below */
+       /*
        result = acpi_evaluate_integer(applespi->sist, NULL, NULL, &spi_status);
        if (ACPI_SUCCESS(result) && spi_status)
                return 0;
+       */

        /* SIEN(1) will enable SPI communication */
        result = acpi_execute_simple_method(applespi->sien, NULL, 1);
rquast commented 6 years ago

No luck, but here's the output from the new info you are logging: https://gist.github.com/rquast/7b9cfe53cfe1a94bd926ac7722e18dc3

rquast commented 6 years ago

Note: I don't have the earlier patch applied to this one. Worked from a fresh applespi.c with the new patches you provided.

roadrunner2 commented 6 years ago

Thanks - this basically confirms that the issue appears to be with the spi device or driver, rather than a logic issue in this applespi driver: we're queueing an init message, but never get a completion. So the spi device or driver is not processing the messages. I'm sorry, but this is going to take some more back and forth to figure out.

Here's another patch (I'll attach this one - I'm guessing that's easier to grab than copy pasting): resume-dbg-1.patch.txt This one will print out a bunch of flags (state) of the spi controller before and after queueing the init message on resume - trying to see if that gives us any clues as to why it's not sending the messages. Also, at this point setting the debug flag isn't necessary anymore.

rquast commented 6 years ago

No this is great! Thanks for helping like this. I am more than happy to take the time to keep working at it.

Here is the output: https://gist.github.com/rquast/b8a579ce053776784cef76512c2a5eac

roadrunner2 commented 6 years ago

@rquast Sorry for the delay - things were busy. Thank you for the output. That's helpful - the controller state looks fine, as far as what was printed. Here's an expanded version of the patch which will print some more details, especially from the low-level driver: resume-dbg-2.patch.txt - same steps as for the last one.

Oh, forgot: this latest patch requires that you have the spi-pxa2xx.h header file for your kernel (either download just that, or get the full sources for the kernel) - and then adjust the first #include in the patch to point to right location of that file.

shrijitsingh99 commented 6 years ago

Has this issue been fixed? If not is there anyway i can help in debugging?

roadrunner2 commented 6 years ago

@shrijitsingh99 No, this issue is still open AFAIK. And yes, you could help by doing the following:

So far the issue is looking to be in the existing kernel code, rather than this driver, so the next steps will most likely involve patching the kernel proper to get more debug info from there.

shrijitsingh99 commented 6 years ago

Trying to build the patched applespi module give me this make error https://gist.github.com/shrijitsingh99/b26e76aef3528c24ef6e073b6e4d379a

I made some small changes to the file to fix the build error and then built and loaded the module. This is the applespi dmesg output i am getting https://gist.github.com/shrijitsingh99/96e04ba52de206092f196617e9ce65c1

roadrunner2 commented 6 years ago

Apologies, should've tested the patch against the latest code. Here is an updated patch: resume-dbg-3.patch.txt

Rather than building via dkms it might be easier to just build the module via make and load it via sudo rmmod applespi ; sudo insmod applespi.ko - but whatever works for you.

shrijitsingh99 commented 6 years ago

Thanks for the info will use make now onwards. This is the output i am getting get https://gist.github.com/shrijitsingh99/640cf2a6dd54f0fc06792244cfe7b56c

roadrunner2 commented 6 years ago

@shrijitsingh99 Thanks for running this and getting the output. It confirms what I stated earlier: the spi message is being queued in the spi core, but for some reason the actual device-specific driver is not sending the message (we never get a completion callback). So it looks to me like the SPI controller device, or its driver, are not being woken up correctly.

@andy-shev I see you've done work on the spi-pxa2xx driver - do you have any suggestions or ideas here? FYI, the pci device is

00:15.4 Serial bus controller [0c80]: Intel Corporation Wildcat Point-LP Serial IO GSPI Controller #1 [8086:9ce6] (rev 03)

Also: the resume appears to work fine on other MacBook(Pro)'s (though it's not been widely tested, so there may be issues on some others too, but it does work fine on MBP13,3 with a 8086:a12a SPI device), and the main difference between the MB8,1 and the others is that this one uses the spi_pxa2xx_pci driver whereas the others use the intel_lpss_pci driver.

andy-shev commented 6 years ago

On Broadwell a different PCI driver is used, indeed. Though, the SPI host controller driver is still the same. We did a lot of self-test against SPI in PIO/DMA modes, so, I doubt is anything wrong there. The symptoms looks like you didn't get an interrupt on receiver side which might mean that SPI is working on MAC in half-duplex mode. I dunno if it's supported by SPI PXA2xx driver.

roadrunner2 commented 5 years ago

@TheChatty (or anybody else interested): I was just wondering if for some reason the keyboard's SPI interface needs to be forcefully re-enabled after resume on the MB8,1 (from my reading of the DSDT it should already be re-enabling the SPI interface on resume, but...). Can you try this quick patch:

--- a/applespi.c
+++ b/applespi.c
@@ -813,9 +813,11 @@ static int applespi_enable_spi(struct applespi_data *applespi)
        unsigned long long spi_status;

        /* check if SPI is already enabled, so we can skip the delay below */
+       /*
        result = acpi_evaluate_integer(applespi->sist, NULL, NULL, &spi_status);
        if (ACPI_SUCCESS(result) && spi_status)
                return 0;
+       */

        /* SIEN(1) will enable SPI communication */
        result = acpi_execute_simple_method(applespi->sien, NULL, 1);

If that doesn't work, then maybe this:

--- a/applespi.c
+++ b/applespi.c
@@ -813,11 +813,16 @@ static int applespi_enable_spi(struct applespi_data *applespi)
        unsigned long long spi_status;

        /* check if SPI is already enabled, so we can skip the delay below */
+       /*
        result = acpi_evaluate_integer(applespi->sist, NULL, NULL, &spi_status);
        if (ACPI_SUCCESS(result) && spi_status)
                return 0;
+       */

        /* SIEN(1) will enable SPI communication */
+       result = acpi_execute_simple_method(applespi->sien, NULL, 0);
+       if (ACPI_FAILURE(result))
+               pr_err("SIEN(0) failed: %s\n", acpi_format_exception(result));
        result = acpi_execute_simple_method(applespi->sien, NULL, 1);
        if (ACPI_FAILURE(result)) {
                pr_err("SIEN failed: %s\n", acpi_format_exception(result));
TheChatty commented 5 years ago

@roadrunner2: I tested your first and second patch and later even added info output that SIEN(0|1) get called even but to no avail. After resume the SPI transfers still time out. rmmod and modprobe of applespi doesn't help either.

denisix commented 5 years ago

the same issue for me, Ubuntu 19.04, kernel 4.16.0-041600-generic, after resume - keyboard & touch doesnt work, tried the patches, alse the patch with SIEN(0|1), tried even multiple times calling applespi_enable_spi() and added some timeouts before SIEN(1), but still no luck:

applied debug using echo 0x0507 | sudo tee /sys/module/applespi/parameters/debug and gathered the logs - dmesg, lspci -vvv, lsmod before (ok) and after(fail): https://gist.github.com/denisix/dcd12689bcc01a6022427d3b848933f6

please let me know if you need any other information! thanks!

roadrunner2 commented 5 years ago

@denisix Looking at the dmesg.fail log, it looks like you are unloading applespi and some of the pxa2xx modules before suspend and loading them again after resume? Can you tell me exactly which modules are being unloaded/loaded? Also, I'm a bit confused by the following: according to your dmesg.fail at least the applespi, spi_pxa2xx_platform, and spi_pxa2xx_pci modules are failing to load after resume, however your lsmod.fail shows them loaded - any idea what's going on?

denisix commented 5 years ago

@roadrunner2 I experimented in many different ways and it was configured in /etc/hibernate/common.conf:

UnloadAllModules no
UnloadBlacklistedModules no
LoadModules auto
LoadModulesFromFile /etc/modules

now I commented all these options, tried with the provided modifications of applespi.c but still no result (i'm suspending my system with hibernate-ram, and pm-suspend if that makes sense).

The other strange situation detected after system resume, when I tried to unload the module with rmmod applespi - command just freeze, from lsmod i see the following:

applespi               28672  -1

attached logs: dmesg.rmmod.txt lspci.fail.txt lsmod.fail.txt dmesg.fail.txt lspci.ok.txt lsmod.ok.txt dmesg.ok.txt

thank you!

denisix commented 4 years ago

sorry, any update on this? what can I do to help perform some debugging/investigations during the suspend/wakup procedures?

oevermod commented 3 years ago

@roadrunner2 Hi! I tried your suggested patch with the current source:

diff --git a/drivers/input/keyboard/applespi.c b/drivers/input/keyboard/applespi.c
index eda1b23002b5..9e59dfa4f239 100644
--- a/drivers/input/keyboard/applespi.c
+++ b/drivers/input/keyboard/applespi.c
@@ -688,12 +688,20 @@ static int applespi_enable_spi(struct applespi_data *applespi)
        unsigned long long spi_status;

        /* check if SPI is already enabled, so we can skip the delay below */
+       /*
        acpi_sts = acpi_evaluate_integer(applespi->sist, NULL, NULL,
                                         &spi_status);
        if (ACPI_SUCCESS(acpi_sts) && spi_status)
                return 0;
+       */

        /* SIEN(1) will enable SPI communication */
+        acpi_sts = acpi_execute_simple_method(applespi->sien, NULL, 0);
+        if (ACPI_FAILURE(acpi_sts)) {
+               dev_err(&applespi->spi->dev, "SIEN failed: %s\n",
+                       acpi_format_exception(acpi_sts));
+               return -ENODEV;
+       }
        acpi_sts = acpi_execute_simple_method(applespi->sien, NULL, 1);
        if (ACPI_FAILURE(acpi_sts)) {
                dev_err(&applespi->spi->dev, "SIEN failed: %s\n",

Here is the dmesg output with and without applying the patch: dmesg_without_patch.txt dmesg_with_patch.txt

I also tried to turn on the debugging as suggested:

# echo 0x507 | tee /sys/module/applespi/parameters/debug
tee: /sys/module/applespi/parameters/debug: Permission denied

Is it still being done like that or is there another way? What i did do is enabling the CONFIG_SPI_DEBUG kernel config option.

i also tried to apply the patch resume-dbg-3.patch.txt that you provided earlier: applespi_resume-dbg-3.patch.diff.txt but cannot compile it:

$ make -j $(nproc) && make -j $(nproc) modules_install
  DESCEND objtool
  CALL    scripts/atomic/check-atomics.sh
  CALL    scripts/checksyscalls.sh
  CHK     include/generated/compile.h
  CC [M]  drivers/input/keyboard/applespi.o
In file included from ./include/linux/printk.h:7,
                 from ./include/linux/kernel.h:19,
                 from ./include/linux/list.h:9,
                 from ./include/linux/kobject.h:19,
                 from ./include/linux/of.h:17,
                 from ./include/linux/irqdomain.h:35,
                 from ./include/linux/acpi.h:13,
                 from drivers/input/keyboard/applespi.c:44:
drivers/input/keyboard/applespi.c: In function ‘applespi_send_cmd_msg’:
./include/linux/kern_levels.h:5:18: warning: format ‘%d’ expects argument of type ‘int’, but argument 3 has type ‘ktime_t’ {aka ‘long long int’} [-Wformat=]
    5 | #define KERN_SOH "\001"  /* ASCII Start Of Header */
      |                  ^~~~~~
./include/linux/kern_levels.h:14:19: note: in expansion of macro ‘KERN_SOH’
   14 | #define KERN_INFO KERN_SOH "6" /* informational */
      |                   ^~~~~~~~
./include/linux/printk.h:420:9: note: in expansion of macro ‘KERN_INFO’
  420 |  printk(KERN_INFO pr_fmt(fmt), ##__VA_ARGS__)
      |         ^~~~~~~~~
drivers/input/keyboard/applespi.c:771:2: note: in expansion of macro ‘pr_info’
  771 |  pr_info("drain=%d cmd_msg_queued=%d\n",
      |  ^~~~~~~
drivers/input/keyboard/applespi.c: At top level:
drivers/input/keyboard/applespi.c:1925:10: fatal error: spi-pxa2xx.h: No such file or directory
 1925 | #include "spi-pxa2xx.h"
      |          ^~~~~~~~~~~~~~
compilation terminated.
make[3]: *** [scripts/Makefile.build:271: drivers/input/keyboard/applespi.o] Error 1
make[2]: *** [scripts/Makefile.build:514: drivers/input/keyboard] Error 2
make[1]: *** [scripts/Makefile.build:514: drivers/input] Error 2
make[1]: *** Waiting for unfinished jobs....
make: *** [Makefile:1841: drivers] Error 2

Unsure why it cannot find the spi-pxa2xx.h header file, maybe you have an idea?

I would be happy to assist in any way needed to get this to work on macbook 8,1

andy-shev commented 3 years ago

i also tried to apply the patch resume-dbg-3.patch.txt that you provided earlier: applespi_resume-dbg-3.patch.diff.txt but cannot compile it:

drivers/input/keyboard/applespi.c:1925:10: fatal error: spi-pxa2xx.h: No such file or directory
 1925 | #include "spi-pxa2xx.h"

Unsure why it cannot find the spi-pxa2xx.h header file, maybe you have an idea?

In newer kernels the header has been moved under include/linux/spi/ folder IIRC.

oevermod commented 3 years ago

Thanks! Have managed to compile it now with the following changes: applespi_resume-dbg-3.patch.diff.txt

Here is the dmesg log from suspend and resume: dmesg_with_dbg_patch.txt

Maybe it already provides some insight.

The third pr_info block sadly does not compile because of the following two errors:

error: ‘struct driver_data’ has no member named ‘cur_transfer’
error: ‘struct driver_data’ has no member named ‘pump_transfers’

full log: applespi_compile_log.txt

I guess the pxa-2xx code has changed in the meantime, but i am really new to kernel and C development so i have not been able to figure out how to fix it.

andy-shev commented 3 years ago

Thanks! Have managed to compile it now with the following changes: applespi_resume-dbg-3.patch.diff.txt

Here is the dmesg log from suspend and resume: dmesg_with_dbg_patch.txt

Maybe it already provides some insight.

The third pr_info block sadly does not compile because of the following two errors:

error: ‘struct driver_data’ has no member named ‘cur_transfer’
error: ‘struct driver_data’ has no member named ‘pump_transfers’

full log: applespi_compile_log.txt

I guess the pxa-2xx code has changed in the meantime, but i am really new to kernel and C development so i have not been able to figure out how to fix it.

Yes. code changed a lot lately. This one removed the custom pump transfer loop.

Nevertheless, if you really want to debug SPI transfers, you need to enable SPI trace events (/sys/kernel/trace/events/spi/enable IIRC, but you may google for it) and collect corresponding events during the driver's resume/suspend cycle. Note, you may also enable / disable events programmatically from SPI client driver.

anomaly256 commented 2 years ago

Hi, are there any known workarounds for this issue currently?

denisix commented 2 years ago

Hi, any ideas on this issue? Maybe we need to setup bounty for this issue? :)

anomaly256 commented 1 year ago

Still not working after resume in current kernels 😞

muojp commented 1 year ago

I'm posting my personal workaround here; Turn off suspend/resume feature and make the OS automatically shutdown if the laptop is folded without a power plug for a long time.

It suits my use-case because I just want to prevent my Mac from draining too much battery in "suspended" state. Of course this workaround makes you lose all unsaved documents but it doesn't matter for me because I mostly use VSCode for editing texts and the editor is robust for sudden shutdown.

Add an user to perform auto-shutdown

sudo useradd autoshutdown

Put an auto-shutdown script

#!/bin/bash

STATUS='closed'
STATUS_POWER='0'
FILE="/opt/autoshutdown/closed_count"
THRESHOLD=30

IS_CLOSED=$(grep $STATUS /proc/acpi/button/lid/LID0/state)
IS_POWER_DISCONNECTED=$(grep $STATUS_POWER /sys/class/power_supply/ADP1/online)

function reset() {
    echo -n 0 > $FILE
}

if [ "$IS_CLOSED" != '' ] && [ "$IS_POWER_DISCONNECTED" != '' ]; then
    NUM=$(cat $FILE)
    ((NUM=NUM+1))
    if [[ $NUM -ge $THRESHOLD ]]; then
        reset
        sync ; sync
        sudo poweroff
    else
        echo -n $NUM > $FILE
    fi
else
        reset
fi

Save as /opt/autoshutdown/shutdown-by-continuous-lid-close.sh and make it executable along with invoked every minute using cron.

Setup a cron entry

sudo crontab -u autoshutdown -e
* * * * * /opt/autoshutdown/shutdown-by-continuous-lid-close.sh

Make it enable for cron-invoked processes to call poweroff

/etc/sudoers.d/autoshutdown

autoshutdown ALL=NOPASSWD: /sbin/poweroff
muojp commented 1 year ago

By the way, do you folks managed to use Bluetooth on Macbook8,1? I'm stuck in UART Bluetooth chip for several months: https://github.com/leifliddy/macbook12-bluetooth-driver/issues/18

skyostil commented 5 months ago

Just to offer another workaround, you can use suspend-to-idle (s2idle, aka. S0ix) instead of deep suspend (S3) to avoid the broken keyboard and touchpad on resume. s2idle keeps more of the system running, so the power draw is higher, but at least you can use your computer afterwards :)

On my macbook8,1 the difference is about 1.1% battery drain per hour with deep suspend and 1.9% with s2idle.

To switch to s2idle, run this command and reboot:

echo 'w /sys/power/mem_sleep - - - - s2idle' | sudo tee /etc/tmpfiles.d/sleep-mode.conf

(To undo the change, sudo rm /etc/tmpfiles.d/sleep-mode.conf)

skyostil commented 5 months ago

FWIW, I spent some time fiddling around with various ACPI commands and insmod/rmmod sequences, but nothing seems to bring the SPI channel back from the dead after an S3 resume. Any other ideas?