Created attachment 131131 [details] Report Description for hid sensors Recent patches in the kernel have caused the hid-sensor-hub to load correctly on the MS Surface tablet. In kernel 3.14 there is also support for generic inclinometer sensor (hid-sensor-incl-3d) over the iio bus. The data from this sensor, or any sensor on the device, can only be read from once. For example a call to: # cat /sys/bus/iio/devices/iio\:device0/in_incli_x_raw 481 ...returns only this number after each call. I can reboot the device and a get different result each time its moved, but would expect to get a new number after each call/read when the device has been tilted. I have tried using generic_buffer.c but that seems to have errors setting up the buffer.It hangs once and then, when re-running after closing hung proccess, read() returns -1. Lockdep complains about a possible circular lock dependency after trying to read from in_incli_x_raw or even writing to buffer/enable in sysfs. [ 157.798348] ====================================================== [ 157.798352] [ INFO: possible circular locking dependency detected ] [ 157.798358] 3.14.0-rc8+ #75 Tainted: GF I [ 157.798362] ------------------------------------------------------- [ 157.798367] swapper/1/0 is trying to acquire lock: [ 157.798372] (&(&sd->lock)->rlock){-.....}, at: [<ffffffffa01ad8ec>] sensor_hub_raw_event+0x8c/0x3a0 [hid_sensor_hub] [ 157.798396] but task is already holding lock: [ 157.798401] (&(&usbhid->lock)->rlock){-.-...}, at: [<ffffffff81612fc6>] hid_ctrl+0x36/0x180 [ 157.798420] which lock already depends on the new lock. [ 157.798427] the existing dependency chain (in reverse order) is: [ 157.798433] -> #1 (&(&usbhid->lock)->rlock){-.-...}: [ 157.798445] [<ffffffff810f37a2>] lock_acquire+0xa2/0x1e0 [ 157.798456] [<ffffffff81793b18>] _raw_spin_lock_irqsave+0x58/0xa0 [ 157.798470] [<ffffffff816127b5>] usbhid_submit_report+0x35/0x3b0 [ 157.798479] [<ffffffff81612b5a>] usbhid_request+0x2a/0x30 [ 157.798487] [<ffffffffa01ad276>] sensor_hub_input_attr_get_raw_value+0x126/0x210 [hid_sensor_hub] [ 157.798499] [<ffffffffa03c71b3>] incl_3d_read_raw+0x73/0xe0 [hid_sensor_incl_3d] [ 157.798510] [<ffffffffa02cdc63>] iio_read_channel_info+0x33/0x60 [industrialio] [ 157.798523] [<ffffffff814cb360>] dev_attr_show+0x20/0x60 [ 157.798534] [<ffffffff812a4d08>] sysfs_kf_seq_show+0x78/0xf0 [ 157.798544] [<ffffffff812a8179>] kernfs_seq_show+0x29/0x30 [ 157.798554] [<ffffffff81249444>] seq_read+0x164/0x3e0 [ 157.798565] [<ffffffff812a8a8d>] kernfs_fop_read+0xfd/0x170 [ 157.798574] [<ffffffff812205be>] vfs_read+0x9e/0x170 [ 157.798585] [<ffffffff812210b9>] SyS_read+0x49/0xb0 [ 157.798594] [<ffffffff8179d6e9>] system_call_fastpath+0x16/0x1b [ 157.798606] -> #0 (&(&sd->lock)->rlock){-.....}: [ 157.798617] [<ffffffff810f2e05>] __lock_acquire+0x19c5/0x1b70 [ 157.798626] [<ffffffff810f37a2>] lock_acquire+0xa2/0x1e0 [ 157.798634] [<ffffffff81793b18>] _raw_spin_lock_irqsave+0x58/0xa0 [ 157.798645] [<ffffffffa01ad8ec>] sensor_hub_raw_event+0x8c/0x3a0 [hid_sensor_hub] [ 157.798656] [<ffffffff81604377>] hid_input_report+0x167/0x1a0 [ 157.798667] [<ffffffff816130f9>] hid_ctrl+0x169/0x180 [ 157.798675] [<ffffffff8154c200>] __usb_hcd_giveback_urb+0x80/0x130 [ 157.798686] [<ffffffff8154c3cf>] usb_hcd_giveback_urb+0x3f/0x120 [ 157.798696] [<ffffffff8158df1f>] xhci_irq+0x77f/0x1cc0 [ 157.798706] [<ffffffff8158f471>] xhci_msi_irq+0x11/0x20 [ 157.798715] [<ffffffff81105d1e>] handle_irq_event_percpu+0x3e/0x3a0 [ 157.798725] [<ffffffff811060bd>] handle_irq_event+0x3d/0x60 [ 157.798733] [<ffffffff81108ae7>] handle_edge_irq+0x77/0x130 [ 157.798743] [<ffffffff8101dd02>] handle_irq+0x102/0x190 [ 157.798754] [<ffffffff8179f94f>] do_IRQ+0x4f/0xf0 [ 157.798763] [<ffffffff81794a72>] ret_from_intr+0x0/0x1a [ 157.798771] [<ffffffff815f9219>] cpuidle_idle_call+0xb9/0x3b0 [ 157.798781] [<ffffffff810261fe>] arch_cpu_idle+0xe/0x40 [ 157.798791] [<ffffffff8110507e>] cpu_startup_entry+0x9e/0x400 [ 157.798800] [<ffffffff8104c138>] start_secondary+0x1d8/0x280 [ 157.798811] other info that might help us debug this: [ 157.798818] Possible unsafe locking scenario: [ 157.798823] CPU0 CPU1 [ 157.798828] ---- ---- [ 157.798831] lock(&(&usbhid->lock)->rlock); [ 157.798839] lock(&(&sd->lock)->rlock); [ 157.798846] lock(&(&usbhid->lock)->rlock); [ 157.798853] lock(&(&sd->lock)->rlock); [ 157.798861] *** DEADLOCK *** [ 157.798870] 1 lock held by swapper/1/0: [ 157.798874] #0: (&(&usbhid->lock)->rlock){-.-...}, at: [<ffffffff81612fc6>] hid_ctrl+0x36/0x180 [ 157.798891] stack backtrace: [ 157.798900] CPU: 1 PID: 0 Comm: swapper/1 Tainted: GF I 3.14.0-rc8+ #75 [ 157.798906] Hardware name: Microsoft Corporation Surface Pro 2/Surface Pro 2, BIOS 2.03.0250 09/06/2013 [ 157.798911] ffffffff82545720 ffff88011ae03ad8 ffffffff8178ab90 ffffffff82545720 [ 157.798925] ffff88011ae03b18 ffffffff817862fe ffff88011ae03b70 ffff880118de2ee8 [ 157.798938] ffff880118de2680 0000000000000000 ffff880118de2eb0 ffff880118de2ee8 [ 157.798952] Call Trace: [ 157.798957] <IRQ> [<ffffffff8178ab90>] dump_stack+0x4e/0x7a [ 157.798976] [<ffffffff817862fe>] print_circular_bug+0x200/0x20e [ 157.798986] [<ffffffff810f2e05>] __lock_acquire+0x19c5/0x1b70 [ 157.799003] [<ffffffff813d0851>] ? dynamic_emit_prefix+0x121/0x180 [ 157.799014] [<ffffffff810f37a2>] lock_acquire+0xa2/0x1e0 [ 157.799029] [<ffffffffa01ad8ec>] ? sensor_hub_raw_event+0x8c/0x3a0 [hid_sensor_hub] [ 157.799041] [<ffffffff81793b18>] _raw_spin_lock_irqsave+0x58/0xa0 [ 157.799055] [<ffffffffa01ad8ec>] ? sensor_hub_raw_event+0x8c/0x3a0 [hid_sensor_hub] [ 157.799069] [<ffffffffa01ad8ec>] sensor_hub_raw_event+0x8c/0x3a0 [hid_sensor_hub] [ 157.799081] [<ffffffff81793cca>] ? _raw_spin_unlock_irqrestore+0x4a/0x80 [ 157.799092] [<ffffffff81604377>] hid_input_report+0x167/0x1a0 [ 157.799105] [<ffffffff816130f9>] hid_ctrl+0x169/0x180 [ 157.799116] [<ffffffff8154c200>] __usb_hcd_giveback_urb+0x80/0x130 [ 157.799127] [<ffffffff8154c3cf>] usb_hcd_giveback_urb+0x3f/0x120 [ 157.799138] [<ffffffff8158df1f>] xhci_irq+0x77f/0x1cc0 [ 157.799149] [<ffffffff8158f471>] xhci_msi_irq+0x11/0x20 [ 157.799159] [<ffffffff81105d1e>] handle_irq_event_percpu+0x3e/0x3a0 [ 157.799169] [<ffffffff811060bd>] handle_irq_event+0x3d/0x60 [ 157.799179] [<ffffffff81108ae7>] handle_edge_irq+0x77/0x130 [ 157.799190] [<ffffffff8101dd02>] handle_irq+0x102/0x190 [ 157.799201] [<ffffffff81798ac0>] ? atomic_notifier_call_chain+0xa0/0x110 [ 157.799210] [<ffffffff81798a25>] ? atomic_notifier_call_chain+0x5/0x110 [ 157.799220] [<ffffffff8179f94f>] do_IRQ+0x4f/0xf0 [ 157.799230] [<ffffffff81794a72>] common_interrupt+0x72/0x72 [ 157.799235] <EOI> [<ffffffff815f90e7>] ? cpuidle_enter_state+0x57/0xd0 [ 157.799255] [<ffffffff815f9219>] cpuidle_idle_call+0xb9/0x3b0 [ 157.799265] [<ffffffff810261fe>] arch_cpu_idle+0xe/0x40 [ 157.799275] [<ffffffff8110507e>] cpu_startup_entry+0x9e/0x400 [ 157.799286] [<ffffffff8104c138>] start_secondary+0x1d8/0x280 [ 157.799297] hid_sensor_hub:sensor_hub_raw_event:432: hid-sensor-hub 0003:045E:07A9.0001: 0 collection_index:30 hid:200800 sz:1 [ 157.799305] hid_sensor_hub:sensor_hub_raw_event:448: hid-sensor-hub 0003:045E:07A9.0001: collection->usage 200201 [ 157.799314] hid_sensor_hub:sensor_hub_raw_event:432: hid-sensor-hub 0003:045E:07A9.0001: 1 collection_index:2b hid:200541 sz:4 Here is the dmesg output when the device is started: [ 15.284690] hid_sensor_iio_common:hid_sensor_parse_common_attributes:241: hid-sensor-hub 0003:045E:07A9.0001: common attributes: 1:7, 3:7, 4:7 ffffffff:ffffffff [ 15.284733] hid_sensor_incl_3d:incl_3d_parse_report:280: hid_sensor_incl_3d HID-SENSOR-200086.6.auto: incl_3d 2:7, 3:7, 4:7 [ 15.284738] hid_sensor_incl_3d:incl_3d_parse_report:291: hid_sensor_incl_3d HID-SENSOR-200086.6.auto: Sensitivity index:report -1:-1 I'm guessing the -1 that it cant find the Sensitivity index report as its value never gets set. I'll attach the report description for the device and a full dmesg with lots of debug output.
Created attachment 131141 [details] DMESG 3.14
I should note that I have tried enabling both ENUM_QUIRK and NO_INIT_REPORT quirks on the hid device and hid-sensor-hub.
Here is the lockdep message when using genric_buffer.c, on the hid-incli-3d, bytes per datum is 0 and I think that's why the buffer not started error occurs. Scan mask is also zero but not too sure what that's suppose to be the mask of. I'm still reading through the code. [ 1458.857436] Buffer not started: buffer parameter update failed (-22) [ 1472.137975] iio-buffer: Scan Mask: 0 Scan Timestamp: 0 Bytes per datum 0 [ 1472.144031] hid_sensor_hub:sensor_hub_raw_event:417: hid-sensor-hub 0003:045E:07A9.0001: sensor_hub_raw_event report id:0x7 size:13 type:0 [ 1472.144040] hid_sensor_hub:sensor_hub_raw_event:418: hid-sensor-hub 0003:045E:07A9.0001: maxfield:6 [ 1472.144149] hid_sensor_hub:sensor_hub_raw_event:432: hid-sensor-hub 0003:045E:07A9.0001: 0 collection_index:30 hid:200800 sz:1 [ 1472.144155] hid_sensor_hub:sensor_hub_raw_event:448: hid-sensor-hub 0003:045E:07A9.0001: collection->usage 200201 [ 1472.144182] ================================= [ 1472.144185] [ INFO: inconsistent lock state ] [ 1472.144189] 3.14.0-rc8+ #75 Tainted: GF I [ 1472.144193] --------------------------------- [ 1472.144196] inconsistent {HARDIRQ-ON-W} -> {IN-HARDIRQ-W} usage. [ 1472.144201] gnome-terminal-/2137 [HC1[1]:SC0[0]:HE0:SE1] takes: [ 1472.144205] (&(&sd->dyn_callback_lock)->rlock){?.+...}, at: [<ffffffffa025999b>] sensor_hub_raw_event+0x13b/0x3a0 [hid_sensor_hub] [ 1472.144223] {HARDIRQ-ON-W} state was registered at: [ 1472.144225] [<ffffffff810f19f0>] __lock_acquire+0x5b0/0x1b70 [ 1472.144235] [<ffffffff810f37a2>] lock_acquire+0xa2/0x1e0 [ 1472.144241] [<ffffffff81793900>] _raw_spin_lock+0x40/0x80 [ 1472.144251] [<ffffffffa025a3f0>] sensor_hub_register_callback+0x40/0xe4 [hid_sensor_hub] [ 1472.144259] [<ffffffffa03e7590>] hid_incl_3d_probe+0x2d0/0x3f8 [hid_sensor_incl_3d] [ 1472.144267] [<ffffffff814d17c5>] platform_drv_probe+0x45/0xb0 [ 1472.144274] [<ffffffff814cf775>] driver_probe_device+0x125/0x3a0 [ 1472.144282] [<ffffffff814cfac3>] __driver_attach+0x93/0xa0 [ 1472.144289] [<ffffffff814cd60b>] bus_for_each_dev+0x6b/0xb0 [ 1472.144295] [<ffffffff814cf0fe>] driver_attach+0x1e/0x20 [ 1472.144302] [<ffffffff814cecd8>] bus_add_driver+0x188/0x260 [ 1472.144308] [<ffffffff814d0134>] driver_register+0x64/0xf0 [ 1472.144315] [<ffffffff814d16ea>] __platform_driver_register+0x4a/0x50 [ 1472.144321] [<ffffffffa01b5017>] 0xffffffffa01b5017 [ 1472.144329] [<ffffffff81002142>] do_one_initcall+0xd2/0x180 [ 1472.144337] [<ffffffff81128cc7>] load_module+0x1e97/0x26d0 [ 1472.144344] [<ffffffff81129696>] SyS_finit_module+0x86/0xb0 [ 1472.144350] [<ffffffff8179d6e9>] system_call_fastpath+0x16/0x1b [ 1472.144359] irq event stamp: 1468028 [ 1472.144363] hardirqs last enabled at (1468027): [<ffffffff81794b1c>] retint_swapgs+0x13/0x1b [ 1472.144369] hardirqs last disabled at (1468028): [<ffffffff81794a6d>] common_interrupt+0x6d/0x72 [ 1472.144375] softirqs last enabled at (1468024): [<ffffffff81095c0e>] __do_softirq+0x1ee/0x4b0 [ 1472.144383] softirqs last disabled at (1468011): [<ffffffff81096215>] irq_exit+0xc5/0xd0 [ 1472.144388] other info that might help us debug this: [ 1472.144392] Possible unsafe locking scenario: [ 1472.144395] CPU0 [ 1472.144398] ---- [ 1472.144400] lock(&(&sd->dyn_callback_lock)->rlock); [ 1472.144405] <Interrupt> [ 1472.144407] lock(&(&sd->dyn_callback_lock)->rlock); [ 1472.144412] *** DEADLOCK *** [ 1472.144416] 1 lock held by gnome-terminal-/2137: [ 1472.144419] #0: (&(&sd->lock)->rlock){-.....}, at: [<ffffffffa02598ec>] sensor_hub_raw_event+0x8c/0x3a0 [hid_sensor_hub] [ 1472.144431] stack backtrace: [ 1472.144438] CPU: 1 PID: 2137 Comm: gnome-terminal- Tainted: GF I 3.14.0-rc8+ #75 [ 1472.144441] Hardware name: Microsoft Corporation Surface Pro 2/Surface Pro 2, BIOS 2.03.0250 09/06/2013 [ 1472.144445] ffffffff82515400 ffff88011ae03a90 ffffffff8178ab90 ffff88008d598000 [ 1472.144455] ffff88011ae03ae0 ffffffff817866b7 0000000000000000 ffff880000000000 [ 1472.144464] ffff880100000001 0000000000000002 ffff88008d598000 ffffffff810f0350 [ 1472.144473] Call Trace: [ 1472.144476] <IRQ> [<ffffffff8178ab90>] dump_stack+0x4e/0x7a [ 1472.144491] [<ffffffff817866b7>] print_usage_bug+0x1f3/0x204 [ 1472.144498] [<ffffffff810f0350>] ? check_usage_backwards+0x140/0x140 [ 1472.144505] [<ffffffff810f0d52>] mark_lock+0x222/0x2b0 [ 1472.144512] [<ffffffff810f1c94>] __lock_acquire+0x854/0x1b70 [ 1472.144523] [<ffffffff814cb30e>] ? dev_printk_emit+0x3e/0x40 [ 1472.144532] [<ffffffff813d0851>] ? dynamic_emit_prefix+0x121/0x180 [ 1472.144541] [<ffffffff813d09ea>] ? __dynamic_dev_dbg+0xba/0xf0 [ 1472.144548] [<ffffffff810f37a2>] lock_acquire+0xa2/0x1e0 [ 1472.144559] [<ffffffffa025999b>] ? sensor_hub_raw_event+0x13b/0x3a0 [hid_sensor_hub] [ 1472.144567] [<ffffffff81793900>] _raw_spin_lock+0x40/0x80 [ 1472.144577] [<ffffffffa025999b>] ? sensor_hub_raw_event+0x13b/0x3a0 [hid_sensor_hub] [ 1472.144587] [<ffffffffa025999b>] sensor_hub_raw_event+0x13b/0x3a0 [hid_sensor_hub] [ 1472.144598] [<ffffffff81604377>] hid_input_report+0x167/0x1a0 [ 1472.144606] [<ffffffff81611e0c>] hid_irq_in+0x8c/0x210 [ 1472.144616] [<ffffffff8154c200>] __usb_hcd_giveback_urb+0x80/0x130 [ 1472.144623] [<ffffffff8154c3cf>] usb_hcd_giveback_urb+0x3f/0x120 [ 1472.144633] [<ffffffff8158df1f>] xhci_irq+0x77f/0x1cc0 [ 1472.144641] [<ffffffff8158f471>] xhci_msi_irq+0x11/0x20 [ 1472.144651] [<ffffffff81105d1e>] handle_irq_event_percpu+0x3e/0x3a0 [ 1472.144658] [<ffffffff811060bd>] handle_irq_event+0x3d/0x60 [ 1472.144665] [<ffffffff81108ae7>] handle_edge_irq+0x77/0x130 [ 1472.144675] [<ffffffff8101dd02>] handle_irq+0x102/0x190 [ 1472.144682] [<ffffffff810ed7ad>] ? trace_hardirqs_off+0xd/0x10 [ 1472.144690] [<ffffffff810d389d>] ? irqtime_account_irq+0xbd/0xc0 [ 1472.144698] [<ffffffff8179f94f>] do_IRQ+0x4f/0xf0 [ 1472.144705] [<ffffffff81794a72>] common_interrupt+0x72/0x72 [ 1472.144708] <EOI> [<ffffffff81794b1c>] ? retint_swapgs+0x13/0x1b [ 1472.144722] hid_sensor_hub:sensor_hub_raw_event:432: hid-sensor-hub 0003:045E:07A9.0001: 1 collection_index:2b hid:200541 sz:4 [ 1472.144728] hid_sensor_hub:sensor_hub_raw_event:448: hid-sensor-hub 0003:045E:07A9.0001: collection->usage 200086 [ 1472.144735] hid_sensor_hub:sensor_hub_raw_event:432: hid-sensor-hub 0003:045E:07A9.0001: 2 collection_index:2b hid:20047f sz:2 [ 1472.144741] hid_sensor_hub:sensor_hub_raw_event:448: hid-sensor-hub 0003:045E:07A9.0001: collection->usage 200086 [ 1472.144748] hid_sensor_hub:sensor_hub_raw_event:432: hid-sensor-hub 0003:045E:07A9.0001: 3 collection_index:2b hid:200480 sz:2 [ 1472.144753] hid_sensor_hub:sensor_hub_raw_event:448: hid-sensor-hub 0003:045E:07A9.0001: collection->usage 200086 [ 1472.144760] hid_sensor_hub:sensor_hub_raw_event:432: hid-sensor-hub 0003:045E:07A9.0001: 4 collection_index:2b hid:200481 sz:2 [ 1472.144766] hid_sensor_hub:sensor_hub_raw_event:448: hid-sensor-hub 0003:045E:07A9.0001: collection->usage 200086 [ 1472.144773] hid_sensor_hub:sensor_hub_raw_event:432: hid-sensor-hub 0003:045E:07A9.0001: 5 collection_index:31 hid:200810 sz:1 [ 1472.144778] hid_sensor_hub:sensor_hub_raw_event:448: hid-sensor-hub 0003:045E:07A9.0001: collection->usage 200202 [ 1472.144786] hid_sensor_incl_3d:incl_3d_proc_event:200: iio iio:device0: incl_3d_proc_event [1] [ 1472.144792] hid_sensor_incl_3d:hid_sensor_push_data:187: iio iio:device0: hid_sensor_push_data
Probably worth emailing a copy of this to srinivas.pandruvada@linux.intel.com
I contacted Srinivas and was told of this patch: https://git.kernel.org/cgit/linux/kernel/git/torvalds/linux.git/commit/drivers/hid/hid-sensor-hub.c?id=f74346a04b79c9a5e50a2ee5e923b94195975d17 fixed the lockdep. I have tested the newest kernel which has this patch applied and the sensors do work. I still get a locdep warning under certain configurations, usually with dynamic debugging turned on. It is the same lockdep warning that I copied into comment 3. The warning is about the case in which hid-sensor-hub locks the dyn_callback lock in sensor_hub_register_callbacks. If that function is interrupted while the lock is being held this might cuase a deadlock if another function, like sensor_hub_raw_event, tries to obtain dyn_callback lock. I will upload the patch that I used in kernel 3.15-rc4 that changes all calls to lock dyn_callbacks, in hid_sensor_hub, to spin locks that disable interrupts.
Created attachment 135471 [details] [PATCH] Disable interrupts when dyn_callback_lock gets locked
Created attachment 136031 [details] Report Description for hid sensors with labels Added labels to report description
Created attachment 136041 [details] [Patch] HID: hid-sensor-hub: Add Surface ID's to hid-sensor-hub to enable report quirks.
The only sensor that doesn't work, that has a driver, is hid-magn-3d. This is because the sensor doesn't have any axis usage attributes. It only has a True North usage attribute which is not handled by this driver.
I'm interested in getting access to this sensor data on my Surface Pro2, but with 3.16rc4 I'm not seeing the hid-sensor-hub loading correctly. I consistently get the following at boot or if I rmmod/modprobe hid-sensor-hub: Jul 09 13:46:12 kea-tablet kernel: hid-sensor-hub 0003:045E:07A9.0001: usb_submit_urb(ctrl) failed: -1 Jul 09 13:46:12 kea-tablet kernel: hid-sensor-hub 0003:045E:07A9.0001: timeout initializing reports I'm wondering if others are seeing this error as well.
Hello Keith Amidon, I believe this error occurs because the kernel is trying to send some initial reports that the usb device never responds too. I think this only happens on newer firmwares. I cannot test this as I'd have to run windows update to get the newer firmware. To fix this you need to not send these initial reports by setting a quirk HID_QUIRK_NO_INIT_REPORTS. I'll post a patch if you'd like to test it. Thanks, Reyad Attiyat
Created attachment 142631 [details] [PATCH] Add quirk to not send inital reports
That did work. I don't see messages about hid-sensor-hub in dmesg anymore and I get data from /sys/bus/iio. As an added bonus the machine boots faster. Now if I could just solve my Marvell wireless issues similar #69661...
Is this going to be included in the mainstream kernel?
This should be in mainline now. I have sent patches for the quirk that is needed too.