[#LU-78] kiblnd_check_conns can deadlock

[LU-78] kiblnd_check_conns can deadlock Created: 09/Feb/11 Updated: 08/Apr/12 Resolved: 05/Mar/12
Status:	Resolved
Project:	Lustre
Component/s:	None
Affects Version/s:	Lustre 2.0.0, Lustre 1.8.6
Fix Version/s:	Lustre 2.2.0, Lustre 2.1.2

Type:

Bug

Priority:

Major

Reporter:

Oleg Drokin

Assignee:

Liang Zhen (Inactive)

Resolution:

Fixed

Votes:

Labels:

paj

Severity:

Bugzilla ID:

20,288

Rank (Obsolete):

4708

Description

kiblnd_check_conns() called kiblnd_check_sends() with read_lock(&kiblnd_data.kib_global_lock), it's
so wrong because kiblnd_check_sends() could do a lot of things:
1. lnet_finalize(), which is not safe with spinlock
2. kiblnd_close_conn(), which will hold write_lock(&kiblnd_data.kib_global_lock) to be bomb of
deadlock

There is a patch in the bug from Isaac, but it introduced som regressions and was therefore reverted.

Comments

Comment by Bruno Faccini (Inactive) [ 20/Feb/12 ]

Hello,

At TGCC, running Lustre 2.1.0, we have encountered multiple occurences where an OSS was so loaded that a lot of Client were complaining against it and we were unable to logon to it.

A crash-dump was forced and it analysis alway show the same situation were almost all CPUs/cores are stuck running kiblnd_sd_<id> and/or ib_cm/<id> threads all spinning around the "kiblnd_data.kib_global_lock" RW-SpinLock, trying to write-locking it, with Kernel stacks/trace-backs like following :
=====================================================================
PID: 10493 TASK: ffff88087a4ae790 CPU: 6 COMMAND: "kiblnd_sd_23"
#0 [ffff88088e447e90] crash_nmi_callback at ffffffff8101fd06
#1 [ffff88088e447ea0] notifier_call_chain at ffffffff814837f5
#2 [ffff88088e447ee0] atomic_notifier_call_chain at ffffffff8148385a
#3 [ffff88088e447ef0] notify_die at ffffffff8108026e
#4 [ffff88088e447f20] do_nmi at ffffffff81481443
#5 [ffff88088e447f50] nmi at ffffffff81480d50
[exception RIP: __write_lock_failed+9]
RIP: ffffffff81264919 RSP: ffff880874453d68 RFLAGS: 00000087
RAX: 0000000000000246 RBX: ffff880f5a797ad8 RCX: 0000000000000078
RDX: 0000000000000246 RSI: 00000000000000d1 RDI: ffffffffa0572ecc
RBP: ffff880874453d70 R8: ffff880d9a408000 R9: 0000000000000012
R10: dead000000100100 R11: 0000000000000001 R12: ffff880ec7518b80
R13: ffff88087cd4a8c0 R14: 0000000000000000 R15: ffff88087d31ee00
ORIG_RAX: ffffffffffffffff CS: 0010 SS: 0018
— <NMI exception stack> —
#6 [ffff880874453d68] __write_lock_failed at ffffffff81264919
#7 [ffff880874453d68] _write_lock_irqsave at ffffffff814805e8
#8 [ffff880874453d78] kiblnd_rx_complete at ffffffffa056682d [ko2iblnd]
#9 [ffff880874453df8] kiblnd_complete at ffffffffa05669f2 [ko2iblnd]
#10 [ffff880874453e38] kiblnd_scheduler at ffffffffa0566d94 [ko2iblnd]
#11 [ffff880874453f48] kernel_thread at ffffffff810041aa

PID: 9312 TASK: ffff88087cd5c080 CPU: 25 COMMAND: "ib_cm/25"
#0 [ffff88048e587e90] crash_nmi_callback at ffffffff8101fd06
#1 [ffff88048e587ea0] notifier_call_chain at ffffffff814837f5
#2 [ffff88048e587ee0] atomic_notifier_call_chain at ffffffff8148385a
#3 [ffff88048e587ef0] notify_die at ffffffff8108026e
#4 [ffff88048e587f20] do_nmi at ffffffff81481443
#5 [ffff88048e587f50] nmi at ffffffff81480d50
[exception RIP: __write_lock_failed+9]
RIP: ffffffff81264919 RSP: ffff88087a033c58 RFLAGS: 00000087
RAX: 0000000000000282 RBX: ffff8810681b41c0 RCX: 0000000000000002
RDX: 0000000000000282 RSI: 0000000000000000 RDI: ffffffffa0572ecc
RBP: ffff88087a033c60 R8: 0000000000000000 R9: 0000000000000000
R10: 0000000000000000 R11: 0000000000000001 R12: ffff880f2291a000
R13: 0000000000000000 R14: ffff8807a4210200 R15: ffffe8f7ff997988
ORIG_RAX: ffffffffffffffff CS: 0010 SS: 0018
— <NMI exception stack> —
#6 [ffff88087a033c58] __write_lock_failed at ffffffff81264919
#7 [ffff88087a033c58] _write_lock_irqsave at ffffffff814805e8
#8 [ffff88087a033c68] kiblnd_close_conn at ffffffffa055fa4b [ko2iblnd]
#9 [ffff88087a033c98] kiblnd_cm_callback at ffffffffa056a910 [ko2iblnd]
#10 [ffff88087a033d08] cma_ib_handler at ffffffffa03686e9 [rdma_cm]
#11 [ffff88087a033d88] cm_process_work at ffffffffa0346e67 [ib_cm]
#12 [ffff88087a033dd8] cm_work_handler at ffffffffa03493c9 [ib_cm]
#13 [ffff88087a033e38] worker_thread at ffffffff810749a0
#14 [ffff88087a033ee8] kthread at ffffffff81079f36
#15 [ffff88087a033f48] kernel_thread at ffffffff810041aa
=====================================================================

and this because the "kiblnd_data.kib_global_lock" read-locker is awaiting to be scheduled on its CPU/Core sinc a very long time with the following Kernel-stack :
=====================================================================
PID: 10494 TASK: ffff88087a4ae040 CPU: 19 COMMAND: "kiblnd_connd"
#0 [ffff88083b577c10] schedule at ffffffff8147dddc
#1 [ffff88083b577cd8] cfs_schedule at ffffffffa03fd74e [libcfs]
#2 [ffff88083b577ce8] kiblnd_pool_alloc_node at ffffffffa05569b3 [ko2iblnd]
#3 [ffff88083b577d58] kiblnd_get_idle_tx at ffffffffa056063d [ko2iblnd]
#4 [ffff88083b577d88] kiblnd_check_sends at ffffffffa0562ed6 [ko2iblnd]
#5 [ffff88083b577e18] kiblnd_check_conns at ffffffffa0563123 [ko2iblnd]
#6 [ffff88083b577e98] kiblnd_connd at ffffffffa05664f7 [ko2iblnd]
#7 [ffff88083b577f48] kernel_thread at ffffffff810041aa
=====================================================================

and this because the CPU/Core it has been scheduled to is starved by one of its write-lock competitor.

This scenario definitelly seems to be a specific case/consequence of the bug/limitation described in this ~~LU-78~~, but since it now happpens in the "real life" on a customer site running production workload we would like to have its priority to be raised.

Do you agree with both my analysis and request ???

Comment by Bruno Faccini (Inactive) [ 20/Feb/12 ]

Possible ways to fix this problem could be to :

_ avoid re-schedule()/yield CPU in kiblnd_pool_alloc_node(), but wait/spin active.

_ change kiblnd_data.kib_global_lock RW-SpinLock to a Semaphore.

What do you think ??

Comment by Liang Zhen (Inactive) [ 20/Feb/12 ]

I've posted a patch at here:
http://review.whamcloud.com/#change,2166

Comment by Bruno Faccini (Inactive) [ 23/Feb/12 ]

Since it will allow kiblnd_pool_alloc_node() to re-schedule() without keeping a read-lock on kiblnd_data.kib_global_lock, this patch looks good to me.

On the other hand, this problem is very solid/frequent at TGCC, so do you think this patch will be exposed/tested soon ???