` On Mon, May 1, 2023 at 10:12 PM Dmitry Torokhov <dmitry.torokhov@xxxxxxxxx> wrote: > Link: https://lore.kernel.org/r/89456fcd-a113-4c82-4b10-a9bcaefac68f@xxxxxxxxxx > > Which should have ensured that PS/2 device is resumed first, before > trying to resume RMI interface. I wonder why it is not working for you. > > Can you enable logging and see if the order of resume is correct or not. > If it is still wrong we need to figure out why setting the link between > the devices does not have the desired effect. I have a Lenovo T440p with a similar issue that fails on resume in rmi_smb_resume's call to rmi_smb_get_version. I've patched rmi_smb_get_version adding a sleep and retry loop in an attempt to see if it could avoid some race condition. I've attached a dmesg log from a 6.3.1 kernel, pm debug messages on and with my retry patch. In this log it succeeds due to the retry loop. I believe I'm seeing the suspend order of rmi_smbus then PS/2 first and PS/2 then rmi_smbus on resume. dmesg during suspend: [ 96.357933] rmi4_smbus 0-002c: PM: calling rmi_smb_suspend+0x0/0x44 [rmi_smbus] @ 2375, parent: i2c-0 ... [ 96.358521] psmouse serio1: PM: calling serio_suspend+0x0/0x1c @ 4517, parent: i8042 dmesg during resume with debugging showing the retry loop around getting the smbus version number: [ 97.048216] psmouse serio1: PM: calling serio_resume+0x0/0x8c @ 4517, parent: i8042 [ 97.051545] psmouse serio1: PM: serio_resume+0x0/0x8c returned 0 after 3325 usecs ... [ 97.051557] rmi4_smbus 0-002c: PM: calling rmi_smb_resume+0x0/0x67 [rmi_smbus] @ 4577, parent: i2c-0 ... [ 97.051725] [4577] i2c_i801:i801_check_post:414: i801_smbus 0000:00:1f.3: No response [ 97.051730] rmi4_smbus 0-002c: failed to get SMBus version number! [ 97.051732] rmi4_smbus 0-002c: sleeping to try again [ 97.052780] [4577] i2c_i801:i801_check_post:414: i801_smbus 0000:00:1f.3: No response [ 97.052785] rmi4_smbus 0-002c: failed to get SMBus version number! [ 97.052786] rmi4_smbus 0-002c: sleeping to try again [ 97.053531] snd_hda_intel 0000:00:03.0: PM: pci_pm_resume+0x0/0xdf returned 0 after 2275 usecs [ 97.053790] [4577] i2c_i801:i801_check_post:414: i801_smbus 0000:00:1f.3: No response [ 97.053795] rmi4_smbus 0-002c: failed to get SMBus version number! [ 97.053796] rmi4_smbus 0-002c: sleeping to try again [ 97.054783] [4577] i2c_i801:i801_check_post:414: i801_smbus 0000:00:1f.3: No response [ 97.054788] rmi4_smbus 0-002c: failed to get SMBus version number! [ 97.054789] rmi4_smbus 0-002c: sleeping to try again [ 97.055779] [4577] i2c_i801:i801_check_post:414: i801_smbus 0000:00:1f.3: No response [ 97.055784] rmi4_smbus 0-002c: failed to get SMBus version number! [ 97.055785] rmi4_smbus 0-002c: sleeping to try again [ 97.057117] rmi4_smbus 0-002c: JAM: time to return 6ms [ 97.057893] rmi4_smbus 0-002c: wrote 4 bytes at 0x86: 0 (4c 00 01 00) ... [ 97.067335] rmi4_smbus 0-002c: wrote 1 bytes at 0x07: 0 (80) [ 97.067340] rmi4_f11 rmi4-00.fn11: Resuming... [ 97.067342] rmi4_smbus 0-002c: PM: rmi_smb_resume+0x0/0x67 [rmi_smbus] returned 0 after 15783 usecs WIth this short timeout loop it seems to take between 6ms to 12ms before the calls to `i2c_smbus_read_byte_data` stop returning -ENXIO from "No response" log lines from i2c_i801. I have seen this on various versions such as 5.15, 5.10 (with the https://lore.kernel.org/r/89456fcd-a113-4c82-4b10-a9bcaefac68f@xxxxxxxxxx patch applied), 6.1 and reproduced here on the 6.3.1 kernel. I don't know what the delay is waiting on and if there is some other way to deal with it. In these logs it appears that there are a few calls occuring at the same time as rmi_smb_resume. None of them return just before the retry loop ends and I'm not sure if they are related. I'm not sure if there is more information during this time that would be useful to look at while it's resuming? If I apply the patch to `device_disable_async_suspend(&client->dev);` in rmi_smb_probe it doesn't seem to need the delay. I could post dmesg output with the disable in rmi_smb_probe applied if the timing is possibly interesting to see the ordering and timing in that case. If there is anything else you would like me to try, please let me know. Is it possible there's just some sort of delay occurring here for the i801 bus to come up that can be handled in a different way? Thanks, Jeff
Attachment:
dmesg-6-3-1-retry.out.xz
Description: application/xz
From fd4e87a0d1d8efa0f3a924a5e5cdd47f10b336dc Mon Sep 17 00:00:00 2001
From: Jeffery Miller <jefferymiller@xxxxxxxxxx>
Date: Thu, 20 Apr 2023 11:35:59 -0500
Subject: [PATCH] Input: synaptics-rmi4 - retry reading SMBus version on resume
When resuming from suspend there is a delay where
getting the version data from the smbus returns
-ENXIO. This causes the rmi4 resume to fail and
the touchpad to stop working after resume.
In lieu of finding what this really needs to wait
on just retry a few times so it works.
The limit of 100ms is arbitrary.
My tests have shown this to take an extra 7-12ms
on resume to succeed on the Lenovo t440p machine.
Logs on resume now look something like:
```
[ 108.622951] rmi4_smbus 0-002c: calling rmi_smb_resume+0x0/0x63 [rmi_smbus] @ 3975, parent: i2c-0
...
[ 108.623132] rmi4_smbus 0-002c: failed to get SMBus version number!
[ 108.623134] rmi4_smbus 0-002c: sleeping to try again
[ 108.626003] rmi4_smbus 0-002c: failed to get SMBus version number!
[ 108.626005] rmi4_smbus 0-002c: sleeping to try again
[ 108.629025] rmi4_smbus 0-002c: failed to get SMBus version number!
[ 108.629028] rmi4_smbus 0-002c: sleeping to try again
[ 108.632017] rmi4_smbus 0-002c: failed to get SMBus version number!
[ 108.632019] rmi4_smbus 0-002c: sleeping to try again
[ 108.636172] rmi4_smbus 0-002c: wrote 4 bytes at 0x86: 0 (4c 00 01 00)
```
Signed-off-by: Jeffery Miller <jefferymiller@xxxxxxxxxx>
---
drivers/input/rmi4/rmi_smbus.c | 24 +++++++++++++++++++-----
1 file changed, 19 insertions(+), 5 deletions(-)
diff --git a/drivers/input/rmi4/rmi_smbus.c b/drivers/input/rmi4/rmi_smbus.c
index 4bf0e1df6a4a..1fccad5811cf 100644
--- a/drivers/input/rmi4/rmi_smbus.c
+++ b/drivers/input/rmi4/rmi_smbus.c
@@ -9,6 +9,7 @@
#include <linux/delay.h>
#include <linux/i2c.h>
#include <linux/interrupt.h>
+#include <linux/jiffies.h>
#include <linux/kconfig.h>
#include <linux/lockdep.h>
#include <linux/module.h>
@@ -44,14 +45,27 @@ static int rmi_smb_get_version(struct rmi_smb_xport *rmi_smb)
struct i2c_client *client = rmi_smb->client;
int retval;
+ unsigned long deadline = jiffies + msecs_to_jiffies(100);
+ unsigned long before = jiffies;
+
/* Check if for SMBus new version device by reading version byte. */
- retval = i2c_smbus_read_byte_data(client, SMB_PROTOCOL_VERSION_ADDRESS);
- if (retval < 0) {
+ while (time_before(jiffies, deadline)) {
+
+ retval = i2c_smbus_read_byte_data(client,
+ SMB_PROTOCOL_VERSION_ADDRESS);
+ if (retval >= 0) {
+ retval++;
+ break;
+ }
+
dev_err(&client->dev, "failed to get SMBus version number!\n");
- return retval;
+ if (retval != -ENXIO)
+ break;
+ dev_warn(&client->dev, "sleeping to try again\n");
+ fsleep(500);
}
-
- return retval + 1;
+ dev_warn(&client->dev, "JAM: time to return %ums", jiffies_to_msecs(jiffies - before));
+ return retval;
}
/* SMB block write - wrapper over ic2_smb_write_block */
--
2.40.1.495.gc816e09b53d-goog
