Thread (3 messages) 3 messages, 2 authors, 2024-11-06

Hyper-V HID driver failure in linux-next-20241101

From: Michael Kelley <hidden>
Date: 2024-11-03 05:17:22
Also in: linux-hyperv

I was running the linux-next-20241101 kernel in a Hyper-V guest VM today,
and the Hyper-V guest HID (mouse) driver is failing to probe during boot.
I bisected the problem to commit 8b7fd6a15f8c:

    HID: bpf: move HID-BPF report descriptor fixup earlier

Without that commit, the good case probing output looks like this:

[    0.306586] hid: raw HID events driver (C) Jiri Kosina
[    0.357690] hv_vmbus: registering driver hid_hyperv
[    0.372669] input: Microsoft Vmbus HID-compliant Mouse as /devices/0006:045E:0621.0001/input/input1
[    0.373202] hid-generic 0006:045E:0621.0001: input: VIRTUAL HID v0.01 Mouse [Microsoft Vmbus HID-compliant Mouse] on

With that commit, the relevant probing output is this:

[    0.294685] hid: raw HID events driver (C) Jiri Kosina
[    0.295977] hv_vmbus: registering driver hid_hyperv
[    0.296957] ------------[ cut here ]------------
[    0.297086] WARNING: CPU: 0 PID: 11 at drivers/hid/hid-core.c:1234 hid_open_report+0x268/0x2f0 [hid]
[    0.297232] Modules linked in: hid_hyperv(E) hv_storvsc(E) hv_netvsc(E+) hid(E) scsi_transport_fc(E) hv_utils(E) hyperv_keyboard(E) crct10dif_pclmul(E) crc32_pclmul(E) ghash_clmulni_intel(E) sha512_ssse3(E) sha256_ssse3(E) sha1_ssse3(E) hv_vmbus(E) aesni_intel(E) crypto_simd(E) cryptd(E)
[    0.297694] CPU: 0 UID: 0 PID: 11 Comm: kworker/u32:0 Tainted: G            E      6.12.0-rc1+ #11
[    0.297835] Tainted: [E]=UNSIGNED_MODULE
[    0.297997] Hardware name: Microsoft Corporation Virtual Machine/Virtual Machine, BIOS Hyper-V UEFI Release v4.1 09/04/2024
[    0.298160] Workqueue: async async_run_entry_fn
[    0.298323] RIP: 0010:hid_open_report+0x268/0x2f0 [hid]
[    0.298509] Code: 35 49 8d bd d0 18 00 00 48 c7 c6 80 8c 72 c0 e8 fe a7 d4 f7 b8 ea ff ff ff e9 37 ff ff ff 0f 0b b8 f0 ff ff ff e9 53 ff ff ff <0f> 0b b8 ed ff ff ff e9 47 ff ff ff 4c 89 ef 89 45 b4 e8 c1 d7 ff
[    0.298953] RSP: 0018:ffffafd980093cc8 EFLAGS: 00010246
[    0.299139] RAX: 0000000000000000 RBX: 0000000000000000 RCX: ffffffffb8446780
[    0.299325] RDX: 0000000000000000 RSI: 000000000000011b RDI: 0000000000000000
[    0.299516] RBP: ffffafd980093d18 R08: 0000000000000000 R09: 0000000000000001
[    0.299698] R10: 0000000000000092 R11: ffff958e815733f8 R12: ffff958e988f0000
[    0.299861] R13: ffff958e8905c000 R14: ffff958e8905c000 R15: ffff958e803a06c0
[    0.300045] FS:  0000000000000000(0000) GS:ffff958f87a00000(0000) knlGS:0000000000000000
[    0.300230] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[    0.300424] CR2: 000056324c394f10 CR3: 00000001172d0000 CR4: 0000000000350ef0
[    0.301087] Call Trace:
[    0.301280]  <TASK>
[    0.301470]  ? show_regs+0x6b/0x80
[    0.301662]  ? __warn+0x97/0x160
[    0.301848]  ? hid_open_report+0x268/0x2f0 [hid]
[    0.302044]  ? report_bug+0x1bb/0x1d0
[    0.302228]  ? handle_bug+0x60/0xa0
[    0.302879]  ? exc_invalid_op+0x1d/0x80
[    0.303053]  ? asm_exc_invalid_op+0x1f/0x30
[    0.303230]  ? __pfx___device_attach_driver+0x10/0x10
[    0.303410]  ? hid_open_report+0x268/0x2f0 [hid]
[    0.303592]  ? hid_add_device+0x10c/0x2b0 [hid]
[    0.303780]  mousevsc_probe+0x1b4/0x230 [hid_hyperv]
[    0.303963]  vmbus_probe+0x3f/0xa0 [hv_vmbus]
[    0.304148]  really_probe+0xea/0x380
[    0.304327]  __driver_probe_device+0x7e/0x160
[    0.304507]  driver_probe_device+0x23/0xa0
[    0.304685]  __driver_attach_async_helper+0x40/0xa0
[    0.304866]  async_run_entry_fn+0x34/0x120
[    0.305043]  process_scheduled_works+0xa3/0x440
[    0.305351]  worker_thread+0x133/0x270
[    0.305541]  ? __pfx_worker_thread+0x10/0x10
[    0.305734]  kthread+0xf6/0x130
[    0.305920]  ? __pfx_kthread+0x10/0x10
[    0.306090]  ret_from_fork+0x3d/0x60
[    0.306245]  ? __pfx_kthread+0x10/0x10
[    0.306365]  ret_from_fork_asm+0x1a/0x30
[    0.306652]  </TASK>
[    0.306799] ---[ end trace 0000000000000000 ]---
[    0.306953] hid-generic 0006:045E:0621.0001: parse failed
[    0.307190] ------------[ cut here ]------------
[    0.307334] WARNING: CPU: 1 PID: 11 at drivers/base/devres.c:691 devres_release_group+0x107/0x120
[    0.307491] Modules linked in: hid_generic(E) hid_hyperv(E) hv_storvsc(E) hv_netvsc(E+) hid(E) scsi_transport_fc(E) hv_utils(E) hyperv_keyboard(E) crct10dif_pclmul(E) crc32_pclmul(E) ghash_clmulni_intel(E) sha512_ssse3(E) sha256_ssse3(E) sha1_ssse3(E) hv_vmbus(E) aesni_intel(E) crypto_simd(E) cryptd(E)
[    0.307945] CPU: 1 UID: 0 PID: 11 Comm: kworker/u32:0 Tainted: G        W   E      6.12.0-rc1+ #11
[    0.308101] Tainted: [W]=WARN, [E]=UNSIGNED_MODULE
[    0.308259] Hardware name: Microsoft Corporation Virtual Machine/Virtual Machine, BIOS Hyper-V UEFI Release v4.1 09/04/2024
[    0.308419] Workqueue: async async_run_entry_fn
[    0.308579] RIP: 0010:devres_release_group+0x107/0x120
[    0.308736] Code: f8 5b 41 5c 41 5d 41 5e 41 5f 5d c3 cc cc cc cc 48 8b 57 28 48 8d 47 28 48 39 c2 74 8f 48 8b 7f 08 48 39 f7 0f 85 6d ff ff ff <0f> 0b 4c 89 c6 4c 89 f7 45 31 ff e8 e9 4a 50 00 eb af e8 f2 5b 4f
[    0.309069] RSP: 0018:ffffafd980093ba0 EFLAGS: 00010046
[    0.309237] RAX: 0000000000000246 RBX: 0000000000000000 RCX: 0000000000000000
[    0.309407] RDX: 0000000000000001 RSI: ffff958e8905db70 RDI: ffff958e8905db70
[    0.309592] RBP: ffffafd980093be8 R08: 0000000000000246 R09: ffff958e81fc7d98
[    0.309765] R10: ffffafd980093b60 R11: ffff958e8023f718 R12: ffff958e8905d8d0
[    0.309940] R13: ffffafd980093ba8 R14: ffff958e8905db6c R15: ffff958e8905d8d0
[    0.310114] FS:  0000000000000000(0000) GS:ffff958f87a80000(0000) knlGS:0000000000000000
[    0.310293] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[    0.310475] CR2: 000056324c398260 CR3: 00000001172d0000 CR4: 0000000000350ef0
[    0.310657] Call Trace:
[    0.310833]  <TASK>
[    0.310834]  ? show_regs+0x6b/0x80
[    0.311150]  ? __warn+0x97/0x160
[    0.311481]  ? devres_release_group+0x107/0x120
[    0.312169]  ? report_bug+0x1bb/0x1d0
[    0.313692]  ? handle_bug+0x60/0xa0
[    0.313894]  ? exc_invalid_op+0x1d/0x80
[    0.314132]  ? asm_exc_invalid_op+0x1f/0x30
[    0.314336]  ? devres_release_group+0x107/0x120
[    0.314541]  hid_device_remove+0x5b/0xb0 [hid]
[    0.314746]  device_remove+0x43/0x70
[    0.314947]  device_release_driver_internal+0xbd/0x140
[    0.315154]  device_release_driver+0x16/0x20
[    0.315353]  bus_remove_device+0xcf/0x130
[    0.315552]  device_del+0x16a/0x3c0
[    0.315750]  hid_destroy_device+0x69/0x80 [hid]
[    0.315948]  mousevsc_probe+0x19b/0x230 [hid_hyperv]
[    0.316146]  vmbus_probe+0x3f/0xa0 [hv_vmbus]
[    0.316338]  really_probe+0xea/0x380
[    0.316519]  __driver_probe_device+0x7e/0x160
[    0.316698]  driver_probe_device+0x23/0xa0
[    0.316874]  __driver_attach_async_helper+0x40/0xa0
[    0.317052]  async_run_entry_fn+0x34/0x120
[    0.317221]  process_scheduled_works+0xa3/0x440
[    0.317389]  worker_thread+0x133/0x270
[    0.317552]  ? __pfx_worker_thread+0x10/0x10
[    0.317707]  kthread+0xf6/0x130
[    0.317859]  ? __pfx_kthread+0x10/0x10
[    0.318019]  ret_from_fork+0x3d/0x60
[    0.318169]  ? __pfx_kthread+0x10/0x10
[    0.318317]  ret_from_fork_asm+0x1a/0x30
[    0.318464]  </TASK>
[    0.318610] ---[ end trace 0000000000000000 ]---
[    0.318884] hv_vmbus: probe failed for device 58f75a6d-d949-4320-99e1-a2a2576d581c (-19)

I'll do some additional debugging to try to narrow down what's going
wrong. I'm experienced with Linux guests on Hyper-V, but don't have
any existing knowledge of the hid-hyperv.c driver or how it interacts with
the hid-core.c code.  Nonetheless, I should be able to peel the onion a
bit more.

Benjamin -- if you have thoughts on what to look for, I would appreciate
any pointers that could save me some time. It's certainly possible that
there's a latent bug in how the Hyper-V HID driver interacts with the
HID core, so I'll look at both sides of the interaction.

Thanks,

Michael Kelley
Keyboard shortcuts
hback out one level
jnext message in thread
kprevious message in thread
ldrill in
Escclose help / fold thread tree
?toggle this help