Am 09.08.2013 00:11, schrieb Andrew Morton:
On Thu, 1 Aug 2013 20:39:02 +0200 Alexander Holler <hol...@ahsoftware.de>
wrote:
Enable the processing of HID input records before the RTC will be registered,
in order to allow the RTC register function to read clock. Without doing
that the clock can only be read after the probe function has finished.
Signed-off-by: Alexander Holler <hol...@ahsoftware.de>
---
drivers/rtc/rtc-hid-sensor-time.c | 7 +++++++
1 file changed, 7 insertions(+)
diff --git a/drivers/rtc/rtc-hid-sensor-time.c
b/drivers/rtc/rtc-hid-sensor-time.c
index 1ab3d13..1006a62 100644
--- a/drivers/rtc/rtc-hid-sensor-time.c
+++ b/drivers/rtc/rtc-hid-sensor-time.c
@@ -279,11 +279,18 @@ static int hid_time_probe(struct platform_device *pdev)
return ret;
}
+ /*
+ * Enable HID input processing early in order to be able to read the
+ * clock already in devm_rtc_device_register().
+ */
+ hid_device_io_start(hsdev->hdev);
+
time_state->rtc = devm_rtc_device_register(&pdev->dev,
"hid-sensor-time", &hid_time_rtc_ops,
THIS_MODULE);
if (IS_ERR_OR_NULL(time_state->rtc)) {
+ hid_device_io_stop(hsdev->hdev);
ret = time_state->rtc ? PTR_ERR(time_state->rtc) : -ENODEV;
time_state->rtc = NULL;
sensor_hub_remove_callback(hsdev, HID_USAGE_SENSOR_TIME);
Shouldn't now there be a hid_device_io_stop() in hid_time_remove()?
That isn't how I understood the commit message to commit
c849a6143bec520aff2a6646518b0d041402428b which introduced that
functionality in 3.10. But maybe I'm wrong. I haven't looked at the
underlying code and haven't tested that (very unlikely) error path with
the new change I made.
Also, hid_device_io_start() does a weird up() on a
downed-by-someone-else semaphore. Where was that down() performed in
this case?
Uh, don't know, as already said, I haven't looked at the underlying
code. But I will now do and will enable all mutex/semaphore debug
options I find. I have to admit, I didn't have tested the change with
debug options enabled, so if the kernel doesn't cry on wierd uo()'s
without debug options enabled, I would have missed that.
Also, your changelog implies that the kernel is already doing this
hid_device_io_start(), only it does it too late. If that is the case
then will the existing-before-this-patch call to hid_device_io_start()
generate the "io already started" warning?
No, hid_device_io_start() was introduced especially for such cases. I
need it because devm_rtc_device_register() might want to read the clock,
but without hid_device_io_start() that only is possible after probe
finished (therefor not during devm_rtc_device_register()).
Some time later ...
With several debug options enabled I've got (once) the below backtrace
with the error path enabled (time_state->rtc = NULL instead of
time_state->rtc = rtc_device_register()).
[ 8.007975] rtc_hid_sensor_time HID-SENSOR-2000a0.0: milliseconds
supported
[ 8.015499] rtc_hid_sensor_time HID-SENSOR-2000a0.0: rtc device
register failed!
(...)
[ 65.551939] =================================
[ 65.556343] [ INFO: inconsistent lock state ]
To add some more explanations for the trace (below in full without
times): The device I use does send the time around once every minute as
an hid input report and this just might have happened here, causing the
lock warning. What makes me wonder here is that hid-sensor-hub seems to
receive the input report even after hid_device_io_stop() was called and
the probe function for the hid device in question (rtc-hid-sensor-time)
failed with a rc of -ENODEV.
I've added the HID maintainer and the author of the above mentioned
commit to cc.
I will need some time (hopefully this weekend) to have a deeper look at
what goes wrong there. Unfortunatley rtc-hid-sensor-time currently seems
to be the only user of hid_device_io_stop(), so I might have hit a bug
or did use it wrong.
But nevertheless, the non-error-path does work as expected, at least I
haven't seen a problem until now.
Regards,
Alexander Holler
----------
=================================
[ INFO: inconsistent lock state ]
3.10.5-dockstar-00038-g03242d1-dirty #408 Not tainted
---------------------------------
inconsistent {HARDIRQ-ON-W} -> {IN-HARDIRQ-W} usage.
swapper/0 [HC1[1]:SC0[0]:HE0:SE1] takes:
(&(&sd->dyn_callback_lock)->rlock){?.+...}, at: [<c02af9f8>]
sensor_hub_raw_event+0x10c/0x204
{HARDIRQ-ON-W} state was registered at:
[<c004dba0>] __lock_acquire+0x630/0x18f0
[<c004f31c>] lock_acquire+0x64/0x78
[<c039c960>] _raw_spin_lock+0x40/0x50
[<c02af854>] sensor_hub_register_callback+0x2c/0xc4
[<c029ce1c>] hid_time_probe+0x2f8/0x36c
[<c0234c98>] platform_drv_probe+0x14/0x18
[<c0233d48>] driver_probe_device+0xb4/0x210
[<c023243c>] bus_for_each_drv+0x48/0x8c
[<c0233c50>] device_attach+0x68/0x8c
[<c02332a8>] bus_probe_device+0x28/0xa0
[<c0231a84>] device_add+0x3d8/0x594
[<c0235064>] platform_device_add+0x130/0x1c0
[<c023ca50>] mfd_add_device+0x1d0/0x23c
[<c023cc38>] mfd_add_devices+0x7c/0xac
[<c02afeec>] sensor_hub_probe+0x2a0/0x364
[<c02aa614>] hid_device_probe+0x90/0x128
[<c0233d48>] driver_probe_device+0xb4/0x210
[<c023243c>] bus_for_each_drv+0x48/0x8c
[<c0233c50>] device_attach+0x68/0x8c
[<c02332a8>] bus_probe_device+0x28/0xa0
[<c0231a84>] device_add+0x3d8/0x594
[<c02aa28c>] hid_add_device+0x244/0x29c
[<c02b1f10>] usbhid_probe+0x368/0x448
[<c027bc14>] usb_probe_interface+0x13c/0x1e0
[<c0233d48>] driver_probe_device+0xb4/0x210
[<c023243c>] bus_for_each_drv+0x48/0x8c
[<c0233c50>] device_attach+0x68/0x8c
[<c02332a8>] bus_probe_device+0x28/0xa0
[<c0231a84>] device_add+0x3d8/0x594
[<c027a45c>] usb_set_configuration+0x610/0x6bc
[<c02821d4>] generic_probe+0x3c/0x74
[<c027bcdc>] usb_probe_device+0x24/0x3c
[<c0233d48>] driver_probe_device+0xb4/0x210
[<c023243c>] bus_for_each_drv+0x48/0x8c
[<c0233c50>] device_attach+0x68/0x8c
[<c02332a8>] bus_probe_device+0x28/0xa0
[<c0231a84>] device_add+0x3d8/0x594
[<c0272c04>] usb_new_device+0x1dc/0x304
[<c0274050>] hub_thread+0x9c4/0xf70
[<c0034600>] kthread+0xa0/0xb0
[<c00090a0>] ret_from_fork+0x14/0x34
irq event stamp: 139814
hardirqs last enabled at (139811): [<c02a24e8>]
cpuidle_enter_state+0x50/0x100
hardirqs last disabled at (139812): [<c0008b74>] __irq_svc+0x34/0xa0
softirqs last enabled at (139814): [<c001d9c8>] irq_enter+0x44/0x64
softirqs last disabled at (139813): [<c001d9bc>] irq_enter+0x38/0x64
might help us debug this:
Possible unsafe locking scenario:
CPU0
----
lock(&(&sd->dyn_callback_lock)->rlock);
<Interrupt>
lock(&(&sd->dyn_callback_lock)->rlock);
**
1 lock held by swapper/0:
#0: (&(&sd->lock)->rlock){-.....}, at: [<c02af92c>]
sensor_hub_raw_event+0x40/0x204
:
CPU: 0 PID: 0 Comm: swapper Not tainted
3.10.5-dockstar-00038-g03242d1-dirty #408
[<c000d670>] (unwind_backtrace+0x0/0xe0) from [<c000b2bc>]
(show_stack+0x10/0x14)
[<c000b2bc>] (show_stack+0x10/0x14) from [<c0396884>]
(print_usage_bug.part.25+0x21c/0x284)
[<c0396884>] (print_usage_bug.part.25+0x21c/0x284) from [<c004d34c>]
(mark_lock+0x438/0x65c)
[<c004d34c>] (mark_lock+0x438/0x65c) from [<c004db24>]
(__lock_acquire+0x5b4/0x18f0)
[<c004db24>] (__lock_acquire+0x5b4/0x18f0) from [<c004f31c>]
(lock_acquire+0x64/0x78)
[<c004f31c>] (lock_acquire+0x64/0x78) from [<c039c960>]
(_raw_spin_lock+0x40/0x50)
[<c039c960>] (_raw_spin_lock+0x40/0x50) from [<c02af9f8>]
(sensor_hub_raw_event+0x10c/0x204)
[<c02af9f8>] (sensor_hub_raw_event+0x10c/0x204) from [<c02a9a80>]
(hid_input_report+0x148/0x170)
[<c02a9a80>] (hid_input_report+0x148/0x170) from [<c02b1a18>]
(hid_irq_in+0x98/0x228)
[<c02b1a18>] (hid_irq_in+0x98/0x228) from [<c0275fa0>]
(usb_hcd_giveback_urb+0x94/0xf0)
[<c0275fa0>] (usb_hcd_giveback_urb+0x94/0xf0) from [<c0284c7c>]
(ehci_urb_done+0x6c/0x78)
[<c0284c7c>] (ehci_urb_done+0x6c/0x78) from [<c0287254>]
(qh_completions+0x310/0x394)
[<c0287254>] (qh_completions+0x310/0x394) from [<c0289550>]
(ehci_work+0x14c/0x780)
[<c0289550>] (ehci_work+0x14c/0x780) from [<c028a4cc>]
(ehci_irq+0x21c/0x248)
[<c028a4cc>] (ehci_irq+0x21c/0x248) from [<c0275958>]
(usb_hcd_irq+0x38/0x6c)
[<c0275958>] (usb_hcd_irq+0x38/0x6c) from [<c00621bc>]
(handle_irq_event_percpu+0x2c/0x1a4)
[<c00621bc>] (handle_irq_event_percpu+0x2c/0x1a4) from [<c0062370>]
(handle_irq_event+0x3c/0x5c)
[<c0062370>] (handle_irq_event+0x3c/0x5c) from [<c0064864>]
(handle_level_irq+0xd0/0xe8)
[<c0064864>] (handle_level_irq+0xd0/0xe8) from [<c0061c40>]
(generic_handle_irq+0x20/0x30)
[<c0061c40>] (generic_handle_irq+0x20/0x30) from [<c00098e8>]
(handle_IRQ+0x60/0x84)
[<c00098e8>] (handle_IRQ+0x60/0x84) from [<c0008b78>] (__irq_svc+0x38/0xa0)
[<c0008b78>] (__irq_svc+0x38/0xa0) from [<c02a24f8>]
(cpuidle_enter_state+0x60/0x100)
[<c02a24f8>] (cpuidle_enter_state+0x60/0x100) from [<c02a2674>]
(cpuidle_idle_call+0xdc/0x144)
[<c02a2674>] (cpuidle_idle_call+0xdc/0x144) from [<c0009a2c>]
(arch_cpu_idle+0x8/0x44)
[<c0009a2c>] (arch_cpu_idle+0x8/0x44) from [<c0042ebc>]
(cpu_startup_entry+0x80/0xec)
[<c0042ebc>] (cpu_startup_entry+0x80/0xec) from [<c050a750>]
(start_kernel+0x29c/0x2e4)
----------
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majord...@vger.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/
