speakup-r lockup analysis so far
Okash Khawaja
okash.khawaja at gmail.com
Sat Aug 26 08:27:07 EDT 2017
Hi,
I ran with lockdep and obtained the logs via netconsole. I've pasted it
below. The lockup happens in input_event() while re-taking
dev->event_lock -
http://elixir.free-electrons.com/linux/latest/source/drivers/input/input.c#L435
- as input_event() has been called again recursively.
This is because we simulate key press while we are inside handler of a
key press. Therefore we should not call speakup_fake_down_arrow() from
inside keyboard_notifier_call(), which was analysis before. Hence the
patch to fix this is correct - the first one was too broad, but the
third one avoids calling speakup_fake_down_arrow only when inside
keyboard_notifier_call context. I'll repost it for review here.
Only question that remains is, why does this change cause cursor to end
up further down when control key is hit, that too on serial synth, not
soft synth. Since it doesn't happen on soft synth and since the above
fix (not simulating a key press from key press handler) is _needed_ to
prevent a lock up, I would suggest we treat this cursor position issue
as a separate bug.
Can I ask what was the initial motive for adding fake arrow down?
Thanks,
Okash
[ 1193.565759] console [netcon0] enabled
[ 1193.565790] netconsole: network logging started
[ 1265.307657] speakup: loading out-of-tree module taints kernel.
[ 1265.308913] speakup: module is from the staging directory, the quality is unknown, you have been warned.
[ 1265.311546] input: Speakup as /devices/virtual/input/input31
[ 1265.312638] initialized device: /dev/synth, node (MAJOR 10, MINOR 25)
[ 1265.313567] speakup 3.1.6: initialized
[ 1265.314467] synth name on entry is: (null)
[ 1265.326335] speakup_soft: module is from the staging directory, the quality is unknown, you have been warned.
[ 1265.327403] synth probe
[ 1265.328872] initialized device: /dev/softsynth, node (MAJOR 10, MINOR 26)
[ 1265.329524] initialized device: /dev/softsynthu, node (MAJOR 10, MINOR 27)
[ 1293.802743] in_keyboard_notifier=1
[ 1293.803215]
[ 1293.803242] ============================================
[ 1293.803304] WARNING: possible recursive locking detected
[ 1293.803369] 4.12.2-ARCH+ #7 Tainted: G C O
[ 1293.803442] --------------------------------------------
[ 1293.803504] swapper/0/0 is trying to acquire lock:
[ 1293.803562] (&(&dev->event_lock)->rlock){-.-...}, at: [<ffffffff8153b0ae>] input_event+0x3e/0x80
[ 1293.803671]
[ 1293.803671] but task is already holding lock:
[ 1293.803740] (&(&dev->event_lock)->rlock){-.-...}, at: [<ffffffff8153b0ae>] input_event+0x3e/0x80
[ 1293.803843]
[ 1293.803843] other info that might help us debug this:
[ 1293.803916] Possible unsafe locking scenario:
[ 1293.803916]
[ 1293.803984] CPU0
[ 1293.804021] ----
[ 1293.804054] lock(&(&dev->event_lock)->rlock);
[ 1293.804109] lock(&(&dev->event_lock)->rlock);
[ 1293.804164]
[ 1293.804164] *** DEADLOCK ***
[ 1293.804164]
[ 1293.804233] May be due to missing lock nesting notation
[ 1293.804233]
[ 1293.804311] 6 locks held by swapper/0/0:
[ 1293.804359] #0: (&serio->lock){-.-...}, at: [<ffffffffa0007fea>] serio_interrupt+0x2a/0x90 [serio]
[ 1293.804469] #1: (&(&dev->event_lock)->rlock){-.-...}, at: [<ffffffff8153b0ae>] input_event+0x3e/0x80
[ 1293.804577] #2: (rcu_read_lock){......}, at: [<ffffffff8153a6b5>] input_pass_values.part.1+0x5/0x260
[ 1293.804685] #3: (kbd_event_lock){-.-...}, at: [<ffffffff814a091c>] kbd_event+0x3c/0x710
[ 1293.804781] #4: (rcu_read_lock){......}, at: [<ffffffff810b1135>] __atomic_notifier_call_chain+0x5/0x110
[ 1293.804898] #5: (speakup_info.spinlock){-.-...}, at: [<ffffffffa06690ac>] keyboard_notifier_call+0xfc/0xcc0 [speakup]
[ 1293.805028]
[ 1293.805028] stack backtrace:
[ 1293.805084] CPU: 0 PID: 0 Comm: swapper/0 Tainted: G C O 4.12.2-ARCH+ #7
[ 1293.805168] Hardware name: Dell Inc. Inspiron 7559/0H0CC0, BIOS 1.2.2 01/22/2017
[ 1293.805250] Call Trace:
[ 1293.805284] <IRQ>
[ 1293.805320] dump_stack+0x8e/0xcd
[ 1293.805366] __lock_acquire+0x87d/0x1a20
[ 1293.805423] ? native_apic_wait_icr_idle+0x1f/0x30
[ 1293.805482] ? arch_irq_work_raise+0x34/0x40
[ 1293.805537] lock_acquire+0xa5/0x250
[ 1293.805583] ? lock_acquire+0xa5/0x250
[ 1293.805632] ? input_event+0x3e/0x80
[ 1293.805683] _raw_spin_lock_irqsave+0x4d/0x90
[ 1293.805736] ? input_event+0x3e/0x80
[ 1293.805782] input_event+0x3e/0x80
[ 1293.805833] speakup_fake_down_arrow2+0x57/0xd0 [speakup]
[ 1293.805902] read_all_doc+0xd7/0xe0 [speakup]
[ 1293.805960] ? kbd_fakekey2+0x40/0x40 [speakup]
[ 1293.806020] keyboard_notifier_call+0xbe8/0xcc0 [speakup]
[ 1293.806085] ? lock_acquire+0xa5/0x250
[ 1293.806136] notifier_call_chain+0x4a/0x70
[ 1293.806191] __atomic_notifier_call_chain+0x72/0x110
[ 1293.806254] atomic_notifier_call_chain+0x16/0x20
[ 1293.806311] kbd_event+0x320/0x710
[ 1293.806361] input_to_handler+0xdb/0xf0
[ 1293.806411] input_pass_values.part.1+0x1b3/0x260
[ 1293.806469] input_handle_event+0xe4/0x150
[ 1293.806608] input_event+0x52/0x80
[ 1293.806660] atkbd_interrupt+0x50a/0x7c0 [atkbd]
[ 1293.806719] serio_interrupt+0x46/0x90 [serio]
[ 1293.806778] i8042_interrupt+0x20d/0x3b0 [i8042]
[ 1293.806839] __handle_irq_event_percpu+0x45/0x390
[ 1293.806899] handle_irq_event_percpu+0x32/0x80
[ 1293.806955] handle_irq_event+0x39/0x60
[ 1293.807007] handle_edge_irq+0x78/0x130
[ 1293.808787] handle_irq+0x1a/0x30
[ 1293.809755] do_IRQ+0x58/0x110
[ 1293.810712] common_interrupt+0x93/0x93
[ 1293.811644] RIP: 0010:cpuidle_enter_state+0x143/0x390
[ 1293.812575] RSP: 0018:ffffffff81c03dc0 EFLAGS: 00000202 ORIG_RAX: ffffffffffffffce
[ 1293.813518] RAX: ffffffff81c18500 RBX: 0000012d3ca4a19b RCX: 0000000000000000
[ 1293.814462] RDX: ffffffff81c18500 RSI: 0000000000000001 RDI: ffffffff81c18500
[ 1293.815398] RBP: ffffffff81c03e00 R08: cccccccccccccccd R09: 0000000000000000
[ 1293.816335] R10: 0000000000000000 R11: 0000000000000000 R12: ffff8804707e3100
[ 1293.817261] R13: 0000000000000000 R14: 0000000000000008 R15: ffffffff81cc7898
[ 1293.818179] </IRQ>
[ 1293.819081] cpuidle_enter+0x17/0x20
[ 1293.819986] call_cpuidle+0x23/0x40
[ 1293.820884] do_idle+0x18f/0x1f0
[ 1293.821776] cpu_startup_entry+0x71/0x80
[ 1293.822662] rest_init+0x131/0x140
[ 1293.823547] start_kernel+0x44d/0x46e
[ 1293.824426] ? early_idt_handler_array+0x120/0x120
[ 1293.825326] x86_64_start_reservations+0x2f/0x31
[ 1293.826186] x86_64_start_kernel+0x141/0x164
[ 1293.827045] secondary_startup_64+0x9f/0x9f
More information about the Speakup
mailing list