Re: ihidev: fix data request size

2021-08-23 Thread Thomas Frohwein
On Mon, Aug 23, 2021 at 08:57:59AM -0500, joshua stein wrote:
> On Sun, 22 Aug 2021 at 22:37:51 -0600, Thomas Frohwein wrote:
[...]
> > I thought I had the same problem on my new Asus Expertbook B9400CEA.
> > During boot, while reordering libraries and later it would print:
> > 
> > dwiic2: timed out reading remaining 16
> > 
> > This is accompanied by generalized slowness of the system - boot is
> > noticeably slow, xenodm takes about 20 seconds to get to the login
> > window, and glxgears(1) slows down visibly with any mouse movement.
> 
> That is because dwiic has to use polling while being invoked by 
> ihidev's interrupt handler or else it panics in tsleep.  It has to 
> wait longer than normal using delay(), so it blocks other kernel 
> processing.
> 
> As for why the timeouts are happening in the first place, it could 
> be a similar issue with the max report size being bogus.  Does this 
> diff change anything?

Thanks for taking a look. The only thing that seems to change is that
the message is now:

dwiic2: timed out reading remaining 4

... not 16 anymore.

dmesg from a kernel built with this patch attached.

> 
> 
> diff --git sys/dev/i2c/ihidev.c sys/dev/i2c/ihidev.c
> index 92778c679ad..0baba616329 100644
> --- sys/dev/i2c/ihidev.c
> +++ sys/dev/i2c/ihidev.c
> @@ -152,7 +152,7 @@ ihidev_attach(struct device *parent, struct device *self, 
> void *aux)
>   }
>  
>   /* find largest report size and allocate memory for input buffer */
> - sc->sc_isize = letoh16(sc->hid_desc.wMaxInputLength);
> + sc->sc_isize = 4;
>   for (repid = 0; repid < sc->sc_nrepid; repid++) {
>   repsz = hid_report_size(sc->sc_report, sc->sc_reportlen,
>   hid_input, repid);
> @@ -643,7 +643,7 @@ ihidev_intr(void *arg)
>  
>   iic_acquire_bus(sc->sc_tag, I2C_F_POLL);
>   res = iic_exec(sc->sc_tag, I2C_OP_READ_WITH_STOP, sc->sc_addr, NULL, 0,
> - sc->sc_ibuf, letoh16(sc->hid_desc.wMaxInputLength), I2C_F_POLL);
> + sc->sc_ibuf, sc->sc_isize, I2C_F_POLL);
>   iic_release_bus(sc->sc_tag, I2C_F_POLL);
>  
>   /*
> 
OpenBSD 7.0-beta (GENERIC.MP) #1: Mon Aug 23 08:20:12 MDT 2021
t...@thfr.my.domain:/usr/src/sys/arch/amd64/compile/GENERIC.MP
real mem = 16825262080 (16045MB)
avail mem = 16299372544 (15544MB)
random: good seed from bootblocks
mpath0 at root
scsibus0 at mpath0: 256 targets
mainbus0 at root
bios0 at mainbus0: SMBIOS rev. 3.3 @ 0x5a4b2000 (95 entries)
bios0: vendor ASUSTeK COMPUTER INC. version "B9400CEA.304" date 06/02/2021
bios0: ASUSTeK COMPUTER INC. ASUS EXPERTBOOK B9400CEA_B9450CEA
acpi0 at bios0: ACPI 6.2
acpi0: sleep states S0 S3 S4 S5
acpi0: tables DSDT FACP MCFG SSDT FIDT ECDT MSDM SSDT SSDT SSDT SSDT HPET APIC 
SSDT NHLT LPIT SSDT DBGP DBG2 SSDT DMAR SSDT SSDT TPM2 BGRT PTDT WSMT FPDT
acpi0: wakeup devices PEGP(S4) PEGP(S4) PEGP(S4) PEG0(S4) PEGP(S4) GLAN(S4) 
XHCI(S3) XDCI(S4) HDAS(S4) CNVW(S4) TXHC(S3) TDM0(S4) TRP0(S3) PXSX(S4) 
TRP1(S3) PXSX(S4) [...]
acpitimer0 at acpi0: 3579545 Hz, 24 bits
acpimcfg0 at acpi0
acpimcfg0: addr 0xc000, bus 0-255
acpiec0 at acpi0
acpihpet0 at acpi0: 1920 Hz
acpimadt0 at acpi0 addr 0xfee0: PC-AT compat
cpu0 at mainbus0: apid 0 (boot processor)
cpu0: 11th Gen Intel(R) Core(TM) i7-1165G7 @ 2.80GHz, 68555.29 MHz, 06-8c-01
cpu0: 
FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,CFLUSH,DS,ACPI,MMX,FXSR,SSE,SSE2,SS,HTT,TM,PBE,SSE3,PCLMUL,DTES64,MWAIT,DS-CPL,VMX,EST,TM2,SSSE3,SDBG,FMA3,CX16,xTPR,PDCM,PCID,SSE4.1,SSE4.2,x2APIC,MOVBE,POPCNT,DEADLINE,AES,XSAVE,AVX,F16C,RDRAND,NXE,PAGE1GB,RDTSCP,LONG,LAHF,ABM,3DNOWP,PERF,ITSC,FSGSBASE,TSC_ADJUST,BMI1,AVX2,SMEP,BMI2,ERMS,INVPCID,AVX512F,AVX512DQ,RDSEED,ADX,SMAP,AVX512IFMA,CLFLUSHOPT,CLWB,PT,AVX512CD,SHA,AVX512BW,AVX512VL,AVX512VBMI,UMIP,PKU,MD_CLEAR,IBRS,IBPB,STIBP,L1DF,SSBD,SENSOR,ARAT,XSAVEOPT,XSAVEC,XGETBV1,XSAVES
cpu0: 256KB 64b/line disabled L2 cache
cpu0: smt 0, core 0, package 0
mtrr: Pentium Pro MTRR support, 10 var ranges, 88 fixed ranges
cpu0: apic clock running at 38MHz
cpu0: mwait min=64, max=64, C-substates=0.2.0.1.2.1.1.1, IBE
cpu1 at mainbus0: apid 2 (application processor)
cpu1: 11th Gen Intel(R) Core(TM) i7-1165G7 @ 2.80GHz, 4689.20 MHz, 06-8c-01
cpu1: 
FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,CFLUSH,DS,ACPI,MMX,FXSR,SSE,SSE2,SS,HTT,TM,PBE,SSE3,PCLMUL,DTES64,MWAIT,DS-CPL,VMX,EST,TM2,SSSE3,SDBG,FMA3,CX16,xTPR,PDCM,PCID,SSE4.1,SSE4.2,x2APIC,MOVBE,POPCNT,DEADLINE,AES,XSAVE,AVX,F16C,RDRAND,NXE,PAGE1GB,RDTSCP,LONG,LAHF,ABM,3DNOWP,PERF,ITSC,FSGSBASE,TSC_ADJUST,BMI1,AVX2,SMEP,BMI2,ERMS,INVPCID,AVX512F,AVX512DQ,RDSEED,ADX,SMAP,AVX512IFMA,CLFLUSHOPT,CLWB,PT,AVX512CD,SHA,AVX512BW,AVX512VL,AVX512VBMI,UMIP,PKU,MD_CLEAR,IBRS,IBPB,STIBP,L1DF,SSBD,SENSOR,ARAT,XSAVEOPT,XSAVEC,XGETBV1,XSAVES
cpu1: 256KB 64b/line disabled L2 cache
cpu1: disabling user TSC (skew=-1036510775)
cpu1: smt 0, core 1, package 0
cpu2 at mainbus0: apid 4 (application processor)
cpu2: 11th Gen Intel(R) Core(TM) i7-116

Re: ihidev: fix data request size

2021-08-23 Thread joshua stein
On Sun, 22 Aug 2021 at 22:37:51 -0600, Thomas Frohwein wrote:
> On Sun, Aug 22, 2021 at 09:50:15PM -0500, joshua stein wrote:
> > On a particular laptop with a touchpad behind ihidev, dwiic would 
> > report a timeout every time it had to fetch touch data:
> > 
> > dwiic0: timed out reading remaining 2
> > 
> > On re-reading the i2c HID spec, the size supplied by wMaxInputLength 
> > is already supposed to account for the size and report id bytes so 
> > we shouldn't be adding them after the fact.  Otherwise ihidev would 
> > ask for more data than can be available and, on this laptop anyway, 
> > dwiic would have to wait for this transaction to timeout and fail.
> > 
> > This fix matches how the Linux i2c-hid driver operates.  I've tested 
> > this on 3 laptops with touchpads and touchscreens and it doesn't 
> > cause any regressions here while fixing the touchpad on one of them.  
> > I'd appreciate tests on other laptops to make sure it doesn't break 
> > anything and perhaps fixes your issue if you've also seen constant 
> > dwiic timeouts.
> > 
> 
> I thought I had the same problem on my new Asus Expertbook B9400CEA.
> During boot, while reordering libraries and later it would print:
> 
> dwiic2: timed out reading remaining 16
> 
> This is accompanied by generalized slowness of the system - boot is
> noticeably slow, xenodm takes about 20 seconds to get to the login
> window, and glxgears(1) slows down visibly with any mouse movement.

That is because dwiic has to use polling while being invoked by 
ihidev's interrupt handler or else it panics in tsleep.  It has to 
wait longer than normal using delay(), so it blocks other kernel 
processing.

As for why the timeouts are happening in the first place, it could 
be a similar issue with the max report size being bogus.  Does this 
diff change anything?


diff --git sys/dev/i2c/ihidev.c sys/dev/i2c/ihidev.c
index 92778c679ad..0baba616329 100644
--- sys/dev/i2c/ihidev.c
+++ sys/dev/i2c/ihidev.c
@@ -152,7 +152,7 @@ ihidev_attach(struct device *parent, struct device *self, 
void *aux)
}
 
/* find largest report size and allocate memory for input buffer */
-   sc->sc_isize = letoh16(sc->hid_desc.wMaxInputLength);
+   sc->sc_isize = 4;
for (repid = 0; repid < sc->sc_nrepid; repid++) {
repsz = hid_report_size(sc->sc_report, sc->sc_reportlen,
hid_input, repid);
@@ -643,7 +643,7 @@ ihidev_intr(void *arg)
 
iic_acquire_bus(sc->sc_tag, I2C_F_POLL);
res = iic_exec(sc->sc_tag, I2C_OP_READ_WITH_STOP, sc->sc_addr, NULL, 0,
-   sc->sc_ibuf, letoh16(sc->hid_desc.wMaxInputLength), I2C_F_POLL);
+   sc->sc_ibuf, sc->sc_isize, I2C_F_POLL);
iic_release_bus(sc->sc_tag, I2C_F_POLL);
 
/*



Re: ihidev: fix data request size

2021-08-22 Thread Thomas Frohwein
On Sun, Aug 22, 2021 at 09:50:15PM -0500, joshua stein wrote:
> On a particular laptop with a touchpad behind ihidev, dwiic would 
> report a timeout every time it had to fetch touch data:
> 
> dwiic0: timed out reading remaining 2
> 
> On re-reading the i2c HID spec, the size supplied by wMaxInputLength 
> is already supposed to account for the size and report id bytes so 
> we shouldn't be adding them after the fact.  Otherwise ihidev would 
> ask for more data than can be available and, on this laptop anyway, 
> dwiic would have to wait for this transaction to timeout and fail.
> 
> This fix matches how the Linux i2c-hid driver operates.  I've tested 
> this on 3 laptops with touchpads and touchscreens and it doesn't 
> cause any regressions here while fixing the touchpad on one of them.  
> I'd appreciate tests on other laptops to make sure it doesn't break 
> anything and perhaps fixes your issue if you've also seen constant 
> dwiic timeouts.
> 

I thought I had the same problem on my new Asus Expertbook B9400CEA.
During boot, while reordering libraries and later it would print:

dwiic2: timed out reading remaining 16

This is accompanied by generalized slowness of the system - boot is
noticeably slow, xenodm takes about 20 seconds to get to the login
window, and glxgears(1) slows down visibly with any mouse movement.

Oddly enough these issues don't occur if I boot into bsd.rd before
booting regularly.

I built a kernel with your diff, but the problem persists. dmesg is
attached. If I disable the internal pointing device in the bios, the
apparent touchpad (via ihidev0 in the dmesg) is not present anymore,
but the problems still persist including the "timed out..." message.

No regression observed though.

> 
> 
> Index: sys/dev/i2c/ihidev.c
> ===
> RCS file: /cvs/src/sys/dev/i2c/ihidev.c,v
> retrieving revision 1.23
> diff -u -p -u -p -r1.23 ihidev.c
> --- sys/dev/i2c/ihidev.c  9 Jul 2020 21:01:55 -   1.23
> +++ sys/dev/i2c/ihidev.c  23 Aug 2021 02:38:21 -
> @@ -106,7 +106,6 @@ ihidev_attach(struct device *parent, str
>   struct device *dev;
>   int repid, repsz;
>   int repsizes[256];
> - int isize;
>  
>   sc->sc_tag = ia->ia_tag;
>   sc->sc_addr = ia->ia_addr;
> @@ -158,12 +157,8 @@ ihidev_attach(struct device *parent, str
>   repsz = hid_report_size(sc->sc_report, sc->sc_reportlen,
>   hid_input, repid);
>   repsizes[repid] = repsz;
> -
> - isize = repsz + 2; /* two bytes for the length */
> - isize += (sc->sc_nrepid != 1); /* one byte for the report ID */
> - if (isize > sc->sc_isize)
> - sc->sc_isize = isize;
> -
> + if (repsz > sc->sc_isize)
> + sc->sc_isize = repsz;
>   if (repsz != 0)
>   DPRINTF(("%s: repid %d size %d\n", sc->sc_dev.dv_xname,
>   repid, repsz));
> @@ -648,7 +643,7 @@ ihidev_intr(void *arg)
>  
>   iic_acquire_bus(sc->sc_tag, I2C_F_POLL);
>   res = iic_exec(sc->sc_tag, I2C_OP_READ_WITH_STOP, sc->sc_addr, NULL, 0,
> - sc->sc_ibuf, sc->sc_isize, I2C_F_POLL);
> + sc->sc_ibuf, letoh16(sc->hid_desc.wMaxInputLength), I2C_F_POLL);
>   iic_release_bus(sc->sc_tag, I2C_F_POLL);
>  
>   /*
> 
OpenBSD 7.0-beta (GENERIC.MP) #0: Sun Aug 22 21:55:30 MDT 2021
t...@thfr.my.domain:/usr/src/sys/arch/amd64/compile/GENERIC.MP
real mem = 16825262080 (16045MB)
avail mem = 16299376640 (15544MB)
random: good seed from bootblocks
mpath0 at root
scsibus0 at mpath0: 256 targets
mainbus0 at root
bios0 at mainbus0: SMBIOS rev. 3.3 @ 0x5a4b2000 (95 entries)
bios0: vendor ASUSTeK COMPUTER INC. version "B9400CEA.304" date 06/02/2021
bios0: ASUSTeK COMPUTER INC. ASUS EXPERTBOOK B9400CEA_B9450CEA
acpi0 at bios0: ACPI 6.2
acpi0: sleep states S0 S3 S4 S5
acpi0: tables DSDT FACP MCFG SSDT FIDT ECDT MSDM SSDT SSDT SSDT SSDT HPET APIC 
SSDT NHLT LPIT SSDT DBGP DBG2 SSDT DMAR SSDT SSDT TPM2 BGRT PTDT WSMT FPDT
acpi0: wakeup devices PEGP(S4) PEGP(S4) PEGP(S4) PEG0(S4) PEGP(S4) GLAN(S4) 
XHCI(S3) XDCI(S4) HDAS(S4) CNVW(S4) TXHC(S3) TDM0(S4) TRP0(S3) PXSX(S4) 
TRP1(S3) PXSX(S4) [...]
acpitimer0 at acpi0: 3579545 Hz, 24 bits
acpimcfg0 at acpi0
acpimcfg0: addr 0xc000, bus 0-255
acpiec0 at acpi0
acpihpet0 at acpi0: 1920 Hz
acpimadt0 at acpi0 addr 0xfee0: PC-AT compat
cpu0 at mainbus0: apid 0 (boot processor)
cpu0: 11th Gen Intel(R) Core(TM) i7-1165G7 @ 2.80GHz, 68549.21 MHz, 06-8c-01
cpu0: 
FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,CFLUSH,DS,ACPI,MMX,FXSR,SSE,SSE2,SS,HTT,TM,PBE,SSE3,PCLMUL,DTES64,MWAIT,DS-CPL,VMX,EST,TM2,SSSE3,SDBG,FMA3,CX16,xTPR,PDCM,PCID,SSE4.1,SSE4.2,x2APIC,MOVBE,POPCNT,DEADLINE,AES,XSAVE,AVX,F16C,RDRAND,NXE,PAGE1GB,RDTSCP,LONG,LAHF,ABM,3DNOWP,PERF,ITSC,FSGSBASE,TSC_ADJUST,BMI1,AVX2,SMEP,BMI2,ERMS,INVPCID,AVX512F,AVX512DQ,RDSEED,ADX,

ihidev: fix data request size

2021-08-22 Thread joshua stein
On a particular laptop with a touchpad behind ihidev, dwiic would 
report a timeout every time it had to fetch touch data:

dwiic0: timed out reading remaining 2

On re-reading the i2c HID spec, the size supplied by wMaxInputLength 
is already supposed to account for the size and report id bytes so 
we shouldn't be adding them after the fact.  Otherwise ihidev would 
ask for more data than can be available and, on this laptop anyway, 
dwiic would have to wait for this transaction to timeout and fail.

This fix matches how the Linux i2c-hid driver operates.  I've tested 
this on 3 laptops with touchpads and touchscreens and it doesn't 
cause any regressions here while fixing the touchpad on one of them.  
I'd appreciate tests on other laptops to make sure it doesn't break 
anything and perhaps fixes your issue if you've also seen constant 
dwiic timeouts.



Index: sys/dev/i2c/ihidev.c
===
RCS file: /cvs/src/sys/dev/i2c/ihidev.c,v
retrieving revision 1.23
diff -u -p -u -p -r1.23 ihidev.c
--- sys/dev/i2c/ihidev.c9 Jul 2020 21:01:55 -   1.23
+++ sys/dev/i2c/ihidev.c23 Aug 2021 02:38:21 -
@@ -106,7 +106,6 @@ ihidev_attach(struct device *parent, str
struct device *dev;
int repid, repsz;
int repsizes[256];
-   int isize;
 
sc->sc_tag = ia->ia_tag;
sc->sc_addr = ia->ia_addr;
@@ -158,12 +157,8 @@ ihidev_attach(struct device *parent, str
repsz = hid_report_size(sc->sc_report, sc->sc_reportlen,
hid_input, repid);
repsizes[repid] = repsz;
-
-   isize = repsz + 2; /* two bytes for the length */
-   isize += (sc->sc_nrepid != 1); /* one byte for the report ID */
-   if (isize > sc->sc_isize)
-   sc->sc_isize = isize;
-
+   if (repsz > sc->sc_isize)
+   sc->sc_isize = repsz;
if (repsz != 0)
DPRINTF(("%s: repid %d size %d\n", sc->sc_dev.dv_xname,
repid, repsz));
@@ -648,7 +643,7 @@ ihidev_intr(void *arg)
 
iic_acquire_bus(sc->sc_tag, I2C_F_POLL);
res = iic_exec(sc->sc_tag, I2C_OP_READ_WITH_STOP, sc->sc_addr, NULL, 0,
-   sc->sc_ibuf, sc->sc_isize, I2C_F_POLL);
+   sc->sc_ibuf, letoh16(sc->hid_desc.wMaxInputLength), I2C_F_POLL);
iic_release_bus(sc->sc_tag, I2C_F_POLL);
 
/*