Bug 280290 - hms(4): Broken fresh after boot, fixed by resume
Summary: hms(4): Broken fresh after boot, fixed by resume
Status: Closed FIXED
Alias: None
Product: Base System
Classification: Unclassified
Component: kern (show other bugs)
Version: 15.0-CURRENT
Hardware: Any Any
: --- Affects Only Me
Assignee: Vladimir Kondratyev
URL:
Keywords: regression
: 280972 (view as bug list)
Depends on:
Blocks:
 
Reported: 2024-07-15 09:33 UTC by Edward Tomasz Napierala
Modified: 2024-11-26 00:25 UTC (History)
6 users (show)

See Also:


Attachments

Note You need to log in before you can comment on or make changes to this bug.
Description Edward Tomasz Napierala freebsd_committer freebsd_triage 2024-07-15 09:33:50 UTC
Fresh after power up or reboot, according to 'libinput debug-events' the touchpad doesn't send any events.  A suspend/resume cycle fixes it.  I don't remember seeing this behaviour before, so it probably started in the last few months?

The hardware is Dell Latitude 7280, hms is:

iichid0: <DLL079F:00 044E:120B I2C HID device> at addr 0x2c irq 51 on iicbus6
hidbus0: <HID bus> on iichid0
hms0: <DLL079F:00 044E:120B Mouse> on hidbus0
hms0: 3 buttons and [XYWH] coordinates ID=1
Comment 1 Emmanuel Vadot freebsd_committer freebsd_triage 2024-07-23 20:59:31 UTC
Can you give more info about the hardware ?
Also please tell if you have hw.usb.usbhid.enable=1 set in loader.conf or not.

Thanks,
Comment 2 Vladimir Kondratyev freebsd_committer freebsd_triage 2024-07-23 21:07:53 UTC
There were no recent big changes in iichid code. Only some polling improvements from @mav at the end of 2023.

You may try to take some debugging log.

rebuild kernel with IICHID_DEBUG option enabled than set sysctl hw.iichid.debug=1 and than kldunload iichid kernel module. Devd will load it again and you will get device initialization log at console.
Comment 3 Vladimir Kondratyev freebsd_committer freebsd_triage 2024-07-23 21:09:16 UTC
(In reply to Emmanuel Vadot from comment #1)

hw.usb.usbhid.enable=1 does not affect I2C devices. It is for USB only.
Comment 4 Emmanuel Vadot freebsd_committer freebsd_triage 2024-07-23 21:36:52 UTC
(In reply to Vladimir Kondratyev from comment #3)

Yes indeed, I've missed the info that this was i2c :)
Comment 5 david 2024-10-26 16:40:22 UTC
I recently noticed this behavior on the laptop (a Dell Precision 7520) I use when I go to other countries.  I had used it without issue in June (2024) and had mostly been merely updating it by logging in to it from my "normal" laptop, so I hadn't noticed the problem until a few days ago.

But on seeing this bug report, I tried suspend/resume ... and that did cause the mouse to start functioning.

Here's what dmesg says about the mouse-related hardware:

g1-48(14.2-P)[1] grep -C 3 hid /var/run/dmesg.boot
ig4iic1: <Intel Sunrise Point-H I2C Controller-1> mem 0xed356000-0xed356fff irq 17 at device 21.1 on pci0
ig4iic1: Using MSI
iicbus8: <Philips I2C bus (ACPI-hinted)> on ig4iic1
iichid0: <DLL07B0:00 044E:120B I2C HID device> at addr 0x2c irq 51 on iicbus8
hidbus0: <HID bus> on iichid0
hms0: <DLL07B0:00 044E:120B Mouse> on hidbus0
hms0: 3 buttons and [XYWH] coordinates ID=1
hkbd0: <DLL07B0:00 044E:120B Keyboard> on hidbus0
kbd2 at hkbd0
iic8: <I2C generic I/O> on iicbus8
iicsmb8: <SMBus over I2C bridge> on iicbus8

This is while the machine is running:
g1-48(14.2-P)[3] uname -aUK
FreeBSD g1-48.catwhisker.org 14.2-PRERELEASE FreeBSD 14.2-PRERELEASE #264 stable/14-n269310-bbd018d0aaaf: Sat Oct 26 10:42:44 UTC 2024     root@g1-48.catwhisker.org:/common/S1/obj/usr/src/amd64.amd64/sys/CANARY amd64 1401503 1401503

Now, after rebooting to head (and re-testing; yes, the behavior is the same), it's running:
g1-48(15.0-C)[2] uname -aUK
FreeBSD g1-48.catwhisker.org 15.0-CURRENT FreeBSD 15.0-CURRENT #113 main-n273250-9d585fc395c3: Sat Oct 26 11:17:40 UTC 2024     root@g1-48.catwhisker.org:/common/S4/obj/usr/src/amd64.amd64/sys/CANARY amd64 1500026 1500026

and here is what I find in dmesg.boot (after doing the suspend/resume):
g1-48(15.0-C)[3] grep -C 3 hid /var/run/dmesg.boot
ig4iic1: <Intel Sunrise Point-H I2C Controller-1> mem 0xed356000-0xed356fff irq 17 at device 21.1 on pci0
ig4iic1: Using MSI
iicbus8: <Philips I2C bus (ACPI-hinted)> on ig4iic1
iichid0: <DLL07B0:00 044E:120B I2C HID device> at addr 0x2c irq 51 on iicbus8
hidbus0: <HID bus> on iichid0
hms0: <DLL07B0:00 044E:120B Mouse> on hidbus0
hms0: 3 buttons and [XYWH] coordinates ID=1
hkbd0: <DLL07B0:00 044E:120B Keyboard> on hidbus0
kbd2 at hkbd0
iic8: <I2C generic I/O> on iicbus8
iicsmb8: <SMBus over I2C bridge> on iicbus8
--
ig4iic1: <Intel Sunrise Point-H I2C Controller-1> mem 0xed356000-0xed356fff irq 17 at device 21.1 on pci0
ig4iic1: Using MSI
iicbus8: <Philips I2C bus (ACPI-hinted)> on ig4iic1
iichid0: <DLL07B0:00 044E:120B I2C HID device> at addr 0x2c irq 51 on iicbus8
hidbus0: <HID bus> on iichid0
hkbd0: <DLL07B0:00 044E:120B Keyboard> on hidbus0
kbd2 at hkbd0
iic8: <I2C generic I/O> on iicbus8
iicsmb8: <SMBus over I2C bridge> on iicbus8
--
em0: link state changed to UP
Security policy loaded: MAC/ntpd (mac_ntpd)
wlan0: link state changed to UP
hms0: <DLL07B0:00 044E:120B Mouse> on hidbus0
hms0: 3 buttons and [XYWH] coordinates ID=1

I will rebuild the kernel with IICHID_DEBUG enabled & update again when I have more information.
Comment 6 david 2024-10-26 16:56:28 UTC
Well, I tried it -- I rebuilt the kernel with:
options         IICHID_DEBUG

rebooted, then:
g1-48(15.0-C)[1] sudo sysctl hw.iichid.debug=1
Password:
hw.iichid.debug: 0 -> 1
g1-48(15.0-C)[2] sudo kldunload iichid
g1-48(15.0-C)[3] kldstat -n iichid
Id Refs Address                Size Name
35    1 0xffffffff86e37000     330c iichid.ko


and... nothing on vty0, in /var/log/console.log, or in the xterm from which I was logged in.  Maybe I misunderstood?
Comment 7 Vladimir Kondratyev freebsd_committer freebsd_triage 2024-10-26 20:30:46 UTC
(In reply to david from comment #6)
> g1-48(15.0-C)[1] sudo sysctl hw.iichid.debug=1
I wrote misleading message #2. I am sorry

After sudo sysctl hw.iichid.debug=1 you cannot do klduload iichid.ko as it unloads sysctl value too. You should do `devctl disable iichid0; devctl enable iichid0`

Or alternatively add hw.iichid.debug=1 to /boot/loader.conf and reboot

I am sorry, again
Comment 8 david 2024-10-26 22:13:21 UTC
(In reply to Vladimir Kondratyev from comment #7)
No worries! :-)

I appended

# For debugging the hms (mouse)
hw.iichid.debug=1

to /boot/loader.conf, then rebooted (verbosely, in case that might shed additional light).

Still nothing iich-related in /var/log/console.log, but /var/log/messages has:

g1-48(15.0-C)[14] grep -i iich /var/log/messages
<2>1 2024-10-26T11:01:50.461180+00:00 g1-48.catwhisker.org kernel - - - iichid0: <DLL07B0:00 044E:120B I2C HID device> at addr 0x2c irq 51 on iicbus8
<2>1 2024-10-26T11:01:50.461191+00:00 g1-48.catwhisker.org kernel - - - hidbus0: <HID bus> on iichid0
<2>1 2024-10-26T11:32:59.567441+00:00 g1-48.catwhisker.org kernel - - - Preloaded elf obj module "/boot/kernel/iichid.ko" at 0xffffffff82ef3050.
<2>1 2024-10-26T11:32:59.591939+00:00 g1-48.catwhisker.org kernel - - - iichid0: <DLL07B0:00 044E:120B I2C HID device> at addr 0x2c irq 51 on iicbus8
<2>1 2024-10-26T11:32:59.591965+00:00 g1-48.catwhisker.org kernel - - - hidbus0: <HID bus> on iichid0
<2>1 2024-10-26T11:36:15.737156+00:00 g1-48.catwhisker.org kernel - - - iichid0: <DLL07B0:00 044E:120B I2C HID device> at addr 0x2c irq 51 on iicbus8
<2>1 2024-10-26T11:36:15.737167+00:00 g1-48.catwhisker.org kernel - - - hidbus0: <HID bus> on iichid0
<2>1 2024-10-26T15:32:14.805002+00:00 g1-64.catwhisker.org kernel - - - iichid0: <DLL07B0:00 044E:120B I2C HID device> at addr 0x2c irq 51 on iicbus8
<2>1 2024-10-26T15:32:14.805010+00:00 g1-64.catwhisker.org kernel - - - hidbus0: <HID bus> on iichid0
<2>1 2024-10-26T15:50:08.682212+00:00 g1-64.catwhisker.org kernel - - - iichid0: <DLL07B0:00 044E:120B I2C HID device> at addr 0x2c irq 51 on iicbus8
<2>1 2024-10-26T15:50:08.682223+00:00 g1-64.catwhisker.org kernel - - - hidbus0: <HID bus> on iichid0
<2>1 2024-10-26T16:02:16.598252+00:00 g1-64.catwhisker.org kernel - - - iichid0: <DLL07B0:00 044E:120B I2C HID device> at addr 0x2c irq 51 on iicbus8
<2>1 2024-10-26T16:02:16.598263+00:00 g1-64.catwhisker.org kernel - - - hidbus0: <HID bus> on iichid0
<2>1 2024-10-26T16:12:59.568215+00:00 g1-48.catwhisker.org kernel - - - iichid0: <DLL07B0:00 044E:120B I2C HID device> at addr 0x2c irq 51 on iicbus8
<2>1 2024-10-26T16:12:59.568219+00:00 g1-48.catwhisker.org kernel - - - hidbus0: <HID bus> on iichid0
<2>1 2024-10-26T16:28:25.980090+00:00 g1-48.catwhisker.org kernel - - - iichid0: <DLL07B0:00 044E:120B I2C HID device> at addr 0x2c irq 51 on iicbus8
<2>1 2024-10-26T16:28:25.980098+00:00 g1-48.catwhisker.org kernel - - - hidbus0: <HID bus> on iichid0
<2>1 2024-10-26T16:49:35.247032+00:00 g1-48.catwhisker.org kernel - - - iichid0: <DLL07B0:00 044E:120B I2C HID device> at addr 0x2c irq 51 on iicbus8
<2>1 2024-10-26T16:49:35.247044+00:00 g1-48.catwhisker.org kernel - - - hidbus0: <HID bus> on iichid0
<2>1 2024-10-26T16:51:13.720991+00:00 g1-48.catwhisker.org kernel - - - iichid0: iichid device close
<2>1 2024-10-26T16:51:13.721049+00:00 g1-48.catwhisker.org kernel - - - iichid0: detached
<2>1 2024-10-26T16:51:13.721083+00:00 g1-48.catwhisker.org kernel - - - iichid0: <DLL07B0:00 044E:120B I2C HID device> at addr 0x2c irq 51 on iicbus8
<2>1 2024-10-26T16:51:13.721100+00:00 g1-48.catwhisker.org kernel - - - hidbus0: <HID bus> on iichid0
<2>1 2024-10-26T21:55:39.168783+00:00 g1-48.catwhisker.org kernel - - - iichid0: <DLL07B0:00 044E:120B I2C HID device> at addr 0x2c irq 51 on iicbus8
<2>1 2024-10-26T21:55:39.168796+00:00 g1-48.catwhisker.org kernel - - - hidbus0: <HID bus> on iichid0
<2>1 2024-10-26T21:59:35.596384+00:00 g1-48.catwhisker.org kernel - - - Preloaded elf obj module "/boot/kernel/iichid.ko" at 0xffffffff82ef5108.
<2>1 2024-10-26T21:59:35.617157+00:00 g1-48.catwhisker.org kernel - - - iichid0:   IICbus addr       : 0x2C
<2>1 2024-10-26T21:59:35.617166+00:00 g1-48.catwhisker.org kernel - - - iichid0:   HID descriptor reg: 0x20
<2>1 2024-10-26T21:59:35.617175+00:00 g1-48.catwhisker.org kernel - - - iichid0: HID command I2C_HID_CMD_DESCR at 0x20
<2>1 2024-10-26T21:59:35.617184+00:00 g1-48.catwhisker.org kernel - - - iichid0: HID descriptor: 1e 00 00 01 b2 00 02 00 03 00 53 00 00 00 00 00 05 00 06 00 4e 04 0b 12 23 01 00 00 00 00
<2>1 2024-10-26T21:59:35.617194+00:00 g1-48.catwhisker.org kernel - - - iichid0: <DLL07B0:00 044E:120B I2C HID device> at addr 0x2c irq 51 on iicbus8
<2>1 2024-10-26T21:59:35.617203+00:00 g1-48.catwhisker.org kernel - - - iichid0: HID command I2C_HID_CMD_SET_POWER(0)
<2>1 2024-10-26T21:59:35.617213+00:00 g1-48.catwhisker.org kernel - - - iichid0: HID command I2C_HID_CMD_RESET
<2>1 2024-10-26T21:59:35.617222+00:00 g1-48.catwhisker.org kernel - - - iichid0: allocated irq at 0xfffff8004078fb00 and rid 0
<2>1 2024-10-26T21:59:35.617240+00:00 g1-48.catwhisker.org kernel - - - iichid0: successfully setup interrupt
<2>1 2024-10-26T21:59:35.617249+00:00 g1-48.catwhisker.org kernel - - - hidbus0: <HID bus> on iichid0
<2>1 2024-10-26T21:59:35.617259+00:00 g1-48.catwhisker.org kernel - - - iichid0: HID command I2C_HID_REPORT_DESCR at 0x2 with size 178
<2>1 2024-10-26T21:59:35.617268+00:00 g1-48.catwhisker.org kernel - - - iichid0: HID report descriptor: 05 01 09 02 a1 01 85 01 09 01 a1 00 05 09 19 01 29 03 15 00 25 01 75 01 95 03 81 02 75 05 95 01 81 03 05 01 09 30 09 31 15 81 25 7f 75 08 95 02 81 06 a1 02 09 38 95 01 81 06 c0 a1 02 05 0c 0a 38 02 81 06 c0 c0 c0 05 01 09 06 a1 01 85 02 05 07 19 e0 29 e7 15 00 25 01 75 01 95 08 81 02 75 08 95 01 81 01 05 07 19 00 29 73 15 00 26 73 00 75 08 95 06 81 00 c0 06 01 ff 09 01 a1 01 85 03 09 01 15 00 26 ff 00 95 1b 81 02 85 04 09 02 95 50 81 02 85 05 09 03 95 07 b1 02 85 06 09 04 81 02 c0 06 02 ff 09 01 a1 01 85 07 09 05 95 86 b1 02 c0
<2>1 2024-10-26T21:59:35.617306+00:00 g1-48.catwhisker.org kernel - - - iichid0: iichid device open
<2>1 2024-10-26T21:59:35.617315+00:00 g1-48.catwhisker.org kernel - - - iichid0: HID command I2C_HID_CMD_SET_POWER(1)

Note that as of the point I captured the above, I had:
* rebooted the machine;
* logged in (via ssh)
so I have not logged in via xdm (as I would normally for a laptop), nor have I subjected it to a suspend/resume cycle.

I'm happy to poke at it in various ways, given suitable clues.
Comment 9 Vladimir Kondratyev freebsd_committer freebsd_triage 2024-10-26 22:48:19 UTC
(In reply to david from comment #8)

Report descriptor has been read, so I2C interface looks basically working

You may raise hw.iichid.debug up to 5 via sysctl or loader tunable and then touch surface. Kernel will print data coming in through I2C interface if any.

And dmesg command output is closer to what you see on console than /var/log/messages for kernel messages
Comment 10 david 2024-10-26 23:04:25 UTC
(In reply to Vladimir Kondratyev from comment #9)
OK; so:
g1-48(15.0-C)[21] date -u && sudo sysctl hw.iichid.debug=5
Sat Oct 26 22:52:28 UTC 2024
Password:
hw.iichid.debug: 1 -> 5

I then ran my finger on the touchpad, then pushed the trackpoint around, then pressed (& released) some mouse buttons...

No new output in `dmesg`, /var/log/console.log, /var/log/messages, or vty0 that I can see.
Comment 11 Vladimir Kondratyev freebsd_committer freebsd_triage 2024-10-26 23:48:10 UTC
How the value of iichid0 counter in `vmstat -i` output changes when you touch the surface?
Comment 12 david 2024-10-26 23:56:18 UTC
(In reply to Vladimir Kondratyev from comment #11)
No apparent change.

First:

g1-48(15.0-C)[34] date -u && vmstat -i | grep -i iich && date
Sat Oct 26 23:53:17 UTC 2024
irq51: iichid0                         1          0
Sat Oct 26 16:53:17 PDT 2024


I then wiggled my finger on the touchpad for a few seconds, then:

g1-48(15.0-C)[35] date -u && vmstat -i | grep -i iich && date
Sat Oct 26 23:53:32 UTC 2024
irq51: iichid0                         1          0
Sat Oct 26 16:53:32 PDT 2024

I then wiggled the trackpoint a bit, then pressed/released mouse button 1, then:
g1-48(15.0-C)[36] date -u && vmstat -i | grep -i iich && date
Sat Oct 26 23:53:49 UTC 2024
irq51: iichid0                         1          0
Sat Oct 26 16:53:49 PDT 2024
Comment 13 Vladimir Kondratyev freebsd_committer freebsd_triage 2024-10-27 00:03:12 UTC
Hmmm... No interrupts. May try to workaround it with `sysctl dev.iichid.0.sampling_rate_slow=80`
Comment 14 david 2024-10-27 00:10:00 UTC
(In reply to Vladimir Kondratyev from comment #13)
Hmmm.... I suspect that the result is not at all expected:

g1-48(15.0-C)[38] date -u && sudo sysctl dev.iichid.0.sampling_rate_slow=80 && date -u
Sun Oct 27 00:06:12 UTC 2024
dev.iichid.0.sampling_rate_slow: -1 -> 80
Sun Oct 27 00:06:12 UTC 2024
g1-48(15.0-C)[39] date -u && vmstat -i | grep -i iich && date
Sun Oct 27 00:06:16 UTC 2024

I then pushed my finger around on the touchpad for a few seconds, then:

g1-48(15.0-C)[40] date -u && vmstat -i | grep -i iich && date
Sun Oct 27 00:06:37 UTC 2024
g1-48(15.0-C)[41]

(Note that I still have not subjected the machine to a suspend/resume cycle.)
Comment 15 Vladimir Kondratyev freebsd_committer freebsd_triage 2024-10-27 00:15:21 UTC
(In reply to david from comment #14)
vmstat should not change in sampling mode. Check if it works in any way e.g. with 'libinput debug-events' or running grafical session
Comment 16 david 2024-10-27 00:37:44 UTC
(In reply to Vladimir Kondratyev from comment #15)
Ah.  Well, while I was doing "other stuff," the screen had blanked out (as normal).  (Recall, I had only logged in via ssh -- trying to do X11 stuff without a functioning mouse (and a window manager that defaults to "lazy focus") is ... challenging.)

So I tried moving my finger on the touchpad ... nothing.

Pressed the left-hand shift key; the screen lit up.  Further attempts to prod the mouse seemed quite ... ineffective.

To me, it seems as if the machine has no clue that anything is happening to the mouse (until after suspend/resume).
Comment 17 Vladimir Kondratyev freebsd_committer freebsd_triage 2024-10-27 00:48:37 UTC
Do you have `device hidbus` in your kernel config? If yes, try to remove it and recompile kernel.
Comment 18 david 2024-10-27 00:59:09 UTC
(In reply to Vladimir Kondratyev from comment #17)
I was about to claim that I did not, but then I recalled that my kernel config starts by including GENERIC -- which does have it. :-}

So I appended

nodevice      hidbus

to the kernel config and fired off a rebuild of the kernel.  Which turned out to be rather shorter than intended:

Building /common/S4/obj/usr/src/amd64.amd64/sys/CANARY/modules/usr/src/sys/modules/usb/g_mouse/opt_usb.h
Building /common/S4/obj/usr/src/amd64.amd64/sys/CANARY/modules/usr/src/sys/modules/usb/template/opt_usb.h
--- kernel.full ---
ld: error: undefined symbol: hidbus_lookup_driver_info
>>> referenced by hkbd.c:757 (/usr/src/sys/dev/hid/hkbd.c:757)
>>>               hkbd.o:(hkbd_probe)

ld: error: undefined symbol: hidbus_set_desc
>>> referenced by hkbd.c:761 (/usr/src/sys/dev/hid/hkbd.c:761)
>>>               hkbd.o:(hkbd_probe)

ld: error: undefined symbol: hid_get_device_info
>>> referenced by hkbd.c:870 (/usr/src/sys/dev/hid/hkbd.c:870)
>>>               hkbd.o:(hkbd_attach)

ld: error: undefined symbol: hidbus_set_intr
>>> referenced by hkbd.c:896 (/usr/src/sys/dev/hid/hkbd.c:896)
>>>               hkbd.o:(hkbd_attach)

ld: error: undefined symbol: hid_get_report_descr
>>> referenced by hkbd.c:924 (/usr/src/sys/dev/hid/hkbd.c:924)
>>>               hkbd.o:(hkbd_attach)

ld: error: undefined symbol: hidbus_locate
>>> referenced by hkbd.c:785 (/usr/src/sys/dev/hid/hkbd.c:785)
>>>               hkbd.o:(hkbd_parse_hid)
>>> referenced by hkbd.c:794 (/usr/src/sys/dev/hid/hkbd.c:794)
>>>               hkbd.o:(hkbd_parse_hid)
>>> referenced by hkbd.c:804 (/usr/src/sys/dev/hid/hkbd.c:804)
>>>               hkbd.o:(hkbd_parse_hid)
>>> referenced 4 more times
*** [kernel.full] Error code 1

make[2]: stopped making "all" in /common/S4/obj/usr/src/amd64.amd64/sys/CANARY
.ERROR_TARGET='kernel.full'
.ERROR_META_FILE='/common/S4/obj/usr/src/amd64.amd64/sys/CANARY/kernel.full.meta'
.MAKE.LEVEL='2'
....

So clearly that alone won't do.  I'm happy to try again, given a clue.
Comment 19 Vladimir Kondratyev freebsd_committer freebsd_triage 2024-10-27 01:07:20 UTC
(In reply to david from comment #18)
Comment out `device hkbd` as well
Comment 20 david 2024-10-27 01:20:43 UTC
(In reply to Vladimir Kondratyev from comment #19)
OK; kernel build succeeded; rebooting (verbosely).... and at the xdm login screen, moving my finger on the touchpad causes the mouse cursor to move similarly. :-}

What would you like me to try next?
Comment 21 Vladimir Kondratyev freebsd_committer freebsd_triage 2024-10-27 01:36:34 UTC
(In reply to david from comment #20)
I have no idea. Inclusion of hidbus and hkbd in GENERIC config in june of 2024 is the only related commit known to me in this year.

You may try to include all iichid, hidbus, hms and hkbd into kernel config or preload them via /boot/loader.conf to have module configuration similar to resume  one.

Or do git bisect if you have last known good commit.
Comment 22 david 2024-10-27 01:54:22 UTC
(In reply to Vladimir Kondratyev from comment #21)
Hmmm.... OK; I see that the change was MFCed to stable/14 on Mon Jul 29 18:36:42 2024 +0200; the original commit to head was Wed Jul 10 08:05:25 2024 +0200.  I had been out of town much of June and 04 - 07 July, so I probably hadn't been paying much attention to the mouse on that laptop then.  (My main laptop is much older, and does not use i2c for the mouse.)  TL;DR: I don't really have a "last known good commit."

From the commit message, it looks as if the change was intended to make ... something ... better, so I think the best option would be to try your "You may try to include all" suffestion (probably via loader.conf).  And since he's cited as a reviewer, maybe pick Warner's brain sometime if we both get to a meeting a bit early. :-)

I plan to follow up with a progress update (once I have some progress to mention).

Thank you very much for your help!
Comment 23 david 2024-10-27 02:50:22 UTC
Well...  Adding stuff to loader.conf has not helped.  And hms.ko is getting loaded whether or not I specify hms_load="YES" in loader.conf.  Devices hkbd, hid, hidbus, evdev, and the "EVDEV_SUPPORT" option are all in GENERIC (so loading them via loader.conf would seem redundant, at best).

I do note that on resume, a message is logged -- e.g.:
<2>1 2024-10-27T02:41:30.501701+00:00 g1-48.catwhisker.org kernel - - - iichid0: set ACPI power state D0 on \_SB_.PCI0.I2C1.TPD1

I wonder if (somehow) iichid0 might be in some other ACPI power state after boot (and before the first suspend/resume)...?  I did not see an obvious way to check.  [For those (like me) who do not have ACPI power states memorized, D0 is "fully on".]
Comment 24 Edward Tomasz Napierala freebsd_committer freebsd_triage 2024-10-27 13:38:09 UTC
Hah, good call with that ACPI thing.  This patch fixes it for me:

diff --git a/sys/dev/iicbus/iichid.c b/sys/dev/iicbus/iichid.c
index fc9f5c2a68b3..03b951b22878 100644
--- a/sys/dev/iicbus/iichid.c
+++ b/sys/dev/iicbus/iichid.c
@@ -1207,6 +1207,13 @@ iichid_attach(device_t dev)
 done:
        (void)iichid_set_power(sc, I2C_HID_POWER_OFF);
        sc->power_on = false;
+
+       error = iichid_set_power_state(sc, IICHID_PS_NULL, IICHID_PS_ON);
+       if (error != 0)
+               DPRINTF(sc, "Could not set power_state, error: %d\n", error);
+       else
+               DPRINTF(sc, "Successfully set power_state\n");
+
        return (error);
 }
Comment 25 david 2024-10-27 13:42:23 UTC
(In reply to Edward Tomasz Napierala from comment #24)
Oh, excellent!  [Got lucky -- 7 decades or so of "breaking stuff" does come in handy, at times....]
Comment 26 Edward Tomasz Napierala freebsd_committer freebsd_triage 2024-10-27 14:18:17 UTC
Okay, I think I know what's going on.  I've added some strategic printfs, and it looks like this:

iichid_attach: start
hidbus0: <HID bus> on iichid0
hkbd0: <DLL079F:00 044E:120B Keyboard> on hidbus0
kbd2 at hkbd0
iichid_intr_start: done
iichid_attach: done

What seems to happen is that iichid_intr_start() sets the power correctly, but then iichid_attach() sets it back off, just before returning.
Comment 27 david 2024-10-27 14:38:43 UTC
(In reply to Edward Tomasz Napierala from comment #24)
OK; I just tried your patch on my laptop.  It works for me -- both in head:

g1-48(15.0-C)[1] uname -aUK
FreeBSD g1-48.catwhisker.org 15.0-CURRENT FreeBSD 15.0-CURRENT #118 main-n273270-cadb71e4b013: Sun Oct 27 11:14:36 UTC 2024     root@g1-48.catwhisker.org:/common/S4/obj/usr/src/amd64.amd64/sys/CANARY amd64 1500026 1500026


and in stable/14:

g1-48(14.2-P)[1] uname -aUK
FreeBSD g1-48.catwhisker.org 14.2-PRERELEASE FreeBSD 14.2-PRERELEASE #265 stable/14-n269315-b21c677ed28a: Sun Oct 27 10:42:50 UTC 2024     root@g1-48.catwhisker.org:/common/S1/obj/usr/src/amd64.amd64/sys/CANARY amd64 1401503 1401503
Comment 28 Mikael Urankar freebsd_committer freebsd_triage 2024-10-27 17:36:08 UTC
(In reply to Edward Tomasz Napierala from comment #24)
it also fixes the issue for me.
Thank you.
Comment 29 Mikael Urankar freebsd_committer freebsd_triage 2024-10-27 17:36:26 UTC
*** Bug 280972 has been marked as a duplicate of this bug. ***
Comment 30 John Baldwin freebsd_committer freebsd_triage 2024-10-28 13:50:42 UTC
Any state that the interrupt handler depends on or can modify should be fully initialized before interrupts are enabled on the device.  If the device has some sort of command register that can mask interrupts, the attach routine should probably be masking interrupts until the attach has fully initialized things.  You can also defer bus_setup_intr() until after the device is initialized, though you potentially risk spurious interrupts if the device can raise an interrupt before the driver has attached the handler.
Comment 31 Edward Tomasz Napierala freebsd_committer freebsd_triage 2024-10-28 14:10:04 UTC
Okay, after talking to jhb@ it appears the child devices are attaching too early, and the easiest way to solve it is to move the call to bus_generic_attach() further down, after power off.  Here's the proposed patch:

diff --git a/sys/dev/iicbus/iichid.c b/sys/dev/iicbus/iichid.c
index fc9f5c2a68b3..a2c0878697f6 100644
--- a/sys/dev/iicbus/iichid.c
+++ b/sys/dev/iicbus/iichid.c
@@ -1124,7 +1124,7 @@ iichid_attach(device_t dev)
        if (error) {
                device_printf(dev, "failed to reset hardware: %d\n", error);
                error = ENXIO;
-               goto done;
+               goto fail;
        }

        sc->power_on = true;
@@ -1162,7 +1162,7 @@ iichid_attach(device_t dev)
                        bus_release_resource(dev, SYS_RES_IRQ, sc->irq_rid,
                            sc->irq_res);
                error = ENXIO;
-               goto done;
+               goto fail;
 #endif
        }

@@ -1195,16 +1195,21 @@ iichid_attach(device_t dev)
                device_printf(sc->dev, "Could not add I2C device\n");
                iichid_detach(dev);
                error = ENOMEM;
-               goto done;
+               goto fail;
        }

+       (void)iichid_set_power(sc, I2C_HID_POWER_OFF);
+       sc->power_on = false;
+
        device_set_ivars(child, &sc->hw);
        error = bus_generic_attach(dev);
        if (error) {
                device_printf(dev, "failed to attach child: error %d\n", error);
                iichid_detach(dev);
        }
-done:
+       return (error);
+
+fail:
        (void)iichid_set_power(sc, I2C_HID_POWER_OFF);
        sc->power_on = false;
        return (error);
Comment 32 david 2024-10-28 14:31:09 UTC
(In reply to Edward Tomasz Napierala from comment #31)
I will be happy to test this -- after I'm home from work (and can see what trying to manipulate the mouse actually does).  I just got in, so it will be a few hours, yet.
Comment 33 Mikael Urankar freebsd_committer freebsd_triage 2024-10-28 14:45:22 UTC
(In reply to Edward Tomasz Napierala from comment #31)
This patch also works.
Comment 34 Vladimir Kondratyev freebsd_committer freebsd_triage 2024-10-28 14:53:10 UTC
Try this patch (untested):

diff --git a/sys/dev/iicbus/iichid.c b/sys/dev/iicbus/iichid.c
index 6f0563d4e55..397c0917d43 100644
--- a/sys/dev/iicbus/iichid.c
+++ b/sys/dev/iicbus/iichid.c
@@ -1250,8 +1250,12 @@ iichid_attach(device_t dev)
 		iichid_detach(dev);
 	}
 done:
-	(void)iichid_set_power(sc, I2C_HID_POWER_OFF);
-	sc->power_on = false;
+	iicbus_request_bus(device_get_parent(dev), dev, IIC_WAIT);
+	if (!sc->open) {
+		(void)iichid_set_power(sc, I2C_HID_POWER_OFF);
+		sc->power_on = false;
+	}
+	iicbus_release_bus(device_get_parent(dev), dev);
 	return (error);
 }
Comment 35 Vladimir Kondratyev freebsd_committer freebsd_triage 2024-10-28 15:06:37 UTC
There is one more actor here. It is called hkbd(4). In your systems it can be found on the same hidbus with hms(4). It requests interrupts right from attach handler and in current iichid it seems to break its internal state.
Comment 36 John Baldwin freebsd_committer freebsd_triage 2024-10-28 20:10:03 UTC
(In reply to Vladimir Kondratyev from comment #34)
Don't you need a lock to protect the check of 'sc->open' and prevent races?
Comment 37 Vladimir Kondratyev freebsd_committer freebsd_triage 2024-10-28 22:12:26 UTC
(In reply to John Baldwin from comment #36)
I take a lock in parent bus with iicbus_request_bus() to prevent races
Comment 38 John Baldwin freebsd_committer freebsd_triage 2024-10-29 14:01:40 UTC
Ah, ok.
Comment 39 Edward Tomasz Napierala freebsd_committer freebsd_triage 2024-10-30 14:37:20 UTC
Just tested the last patch, works fine!
Comment 40 Mikael Urankar freebsd_committer freebsd_triage 2024-11-06 12:24:39 UTC
(In reply to Vladimir Kondratyev from comment #34)
It works for me too.
Thanks!
Comment 41 Colin Percival freebsd_committer freebsd_triage 2024-11-08 17:30:27 UTC
Can we get this committed ASAP so it will be fixed in 14.2-RELEASE?
Comment 42 commit-hook freebsd_committer freebsd_triage 2024-11-09 05:12:57 UTC
A commit in branch main references this bug:

URL: https://cgit.FreeBSD.org/src/commit/?id=018cb11cb7d412b031e1be681a6a19e734473f99

commit 018cb11cb7d412b031e1be681a6a19e734473f99
Author:     Vladimir Kondratyev <wulf@FreeBSD.org>
AuthorDate: 2024-11-08 19:23:38 +0000
Commit:     Vladimir Kondratyev <wulf@FreeBSD.org>
CommitDate: 2024-11-09 05:11:09 +0000

    iichid(4): Do not power down opened device in attach handler

    Some iichid(4) child devices, currently hkbd(4) only, opens parent
    device in their attach handlers. That breaks internal iichid(4) state
    leading to rejecting any incoming data on software and hardware levels.

    Fix it with adding of extra state check in iichid(4) attach handler.

    Reported by:    many
    Submitted by:   trasz (initial version)
    PR:             280290
    MFC after:      3 days

 sys/dev/iicbus/iichid.c | 8 ++++++--
 1 file changed, 6 insertions(+), 2 deletions(-)
Comment 43 commit-hook freebsd_committer freebsd_triage 2024-11-12 04:11:28 UTC
A commit in branch stable/14 references this bug:

URL: https://cgit.FreeBSD.org/src/commit/?id=c53ec86f0ee97f07f80c0902b189c845bf448e7d

commit c53ec86f0ee97f07f80c0902b189c845bf448e7d
Author:     Vladimir Kondratyev <wulf@FreeBSD.org>
AuthorDate: 2024-11-08 19:23:38 +0000
Commit:     Vladimir Kondratyev <wulf@FreeBSD.org>
CommitDate: 2024-11-12 04:08:33 +0000

    iichid(4): Do not power down opened device in attach handler

    Some iichid(4) child devices, currently hkbd(4) only, opens parent
    device in their attach handlers. That breaks internal iichid(4) state
    leading to rejecting any incoming data on software and hardware levels.

    Fix it with adding of extra state check in iichid(4) attach handler.

    Reported by:    many
    Submitted by:   trasz (initial version)
    PR:             280290
    MFC after:      3 days

    (cherry picked from commit 018cb11cb7d412b031e1be681a6a19e734473f99)

 sys/dev/iicbus/iichid.c | 8 ++++++--
 1 file changed, 6 insertions(+), 2 deletions(-)
Comment 44 commit-hook freebsd_committer freebsd_triage 2024-11-12 23:29:00 UTC
A commit in branch releng/14.2 references this bug:

URL: https://cgit.FreeBSD.org/src/commit/?id=b8276743e4bbff1c11e910eef1599cbdfd88bc38

commit b8276743e4bbff1c11e910eef1599cbdfd88bc38
Author:     Vladimir Kondratyev <wulf@FreeBSD.org>
AuthorDate: 2024-11-08 19:23:38 +0000
Commit:     Vladimir Kondratyev <wulf@FreeBSD.org>
CommitDate: 2024-11-12 23:27:30 +0000

    iichid(4): Do not power down opened device in attach handler

    Some iichid(4) child devices, currently hkbd(4) only, opens parent
    device in their attach handlers. That breaks internal iichid(4) state
    leading to rejecting any incoming data on software and hardware levels.

    Fix it with adding of extra state check in iichid(4) attach handler.

    Approved by:    re (cperciva)
    Reported by:    many
    Submitted by:   trasz (initial version)
    PR:             280290
    MFC after:      3 days

    (cherry picked from commit 018cb11cb7d412b031e1be681a6a19e734473f99)
    (cherry picked from commit c53ec86f0ee97f07f80c0902b189c845bf448e7d)

 sys/dev/iicbus/iichid.c | 8 ++++++--
 1 file changed, 6 insertions(+), 2 deletions(-)