Re: speakup-r lockup analysis so far

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

 



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
_______________________________________________
Speakup mailing list
Speakup@xxxxxxxxxxxxxxxxx
http://linux-speakup.org/cgi-bin/mailman/listinfo/speakup




[Index of Archives]     [Linux for the Blind]     [Fedora Discussioin]     [Linux Kernel]     [Yosemite News]     [Big List of Linux Books]
  Powered by Linux