mm: swap: hang in lru_add_drain_all

[Sasha Levin <sasha.levin@oracle.com>]

[-- Attachment #1: Type: text/plain, Size: 3181 bytes --]

Hi all,

While fuzzing with trinity inside a KVM tools guest running the latest -next
kernel I've stumbled on the following spew:

[  729.682257] INFO: task trinity-c158:13508 blocked for more than 120 seconds.
[  729.683191]       Not tainted 3.16.0-rc5-next-20140718-sasha-00052-g4d34feb #902
[  729.683843] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[  729.684633] trinity-c158    D ffff880d32169000 12520 13508   8729 0x00000000
[  729.685323]  ffff880de6d3fe38 0000000000000002 0000000000000006 ffff880c6c33b000
[  729.686039]  000000785eb36cd1 ffff880de6d3c010 ffff880de6d3c000 ffff880e2b270000
[  729.686761]  ffff880c6c33b000 0000000000000000 ffffffffb070b908 0000000026e426e2
[  729.687483] Call Trace:
[  729.687736] schedule_preempt_disabled (kernel/sched/core.c:2874)
[  729.688544] mutex_lock_nested (kernel/locking/mutex.c:532 kernel/locking/mutex.c:584)
[  729.689127] ? lru_add_drain_all (mm/swap.c:867)
[  729.689666] ? lru_add_drain_all (mm/swap.c:867)
[  729.690334] lru_add_drain_all (mm/swap.c:867)
[  729.690946] SyS_mlockall (./arch/x86/include/asm/current.h:14 include/linux/sched.h:2978 mm/mlock.c:813 mm/mlock.c:798)
[  729.691437] tracesys (arch/x86/kernel/entry_64.S:541)
[  729.691883] 1 lock held by trinity-c158/13508:
[  729.692333] #0: (lock#3){+.+...}, at: lru_add_drain_all (mm/swap.c:867)

There are quite a few tasks with the same stacktrace. Since the lock we're blocking
on is static local to the function it's easy to figure out which task actually has it:

[  739.587839] trinity-c135    D ffff880e1318c000 13096 21051   8729 0x00000000
[  739.589080]  ffff880bf659fcc0 0000000000000002 ffff880c74223cf0 ffff880c74223000
[  739.590544]  000000781c3378ed ffff880bf659c010 ffff880bf659c000 ffff880e2b153000
[  739.591815]  ffff880c74223000 0000000000000000 7fffffffffffffff ffff880bf659fe80
[  739.593165] Call Trace:
[  739.593588] schedule (kernel/sched/core.c:2847)
[  739.594396] schedule_timeout (kernel/time/timer.c:1476)
[  739.595354] ? mark_lock (kernel/locking/lockdep.c:2894)
[  739.596229] ? __this_cpu_preempt_check (lib/smp_processor_id.c:63)
[  739.597297] ? get_parent_ip (kernel/sched/core.c:2561)
[  739.598185] wait_for_completion (include/linux/spinlock.h:328 kernel/sched/completion.c:76 kernel/sched/completion.c:93 kernel/sched/completion.c:101 kernel/sched/completion.c:122)
[  739.599191] ? wake_up_state (kernel/sched/core.c:2942)
[  739.600246] flush_work (kernel/workqueue.c:503 kernel/workqueue.c:2762)
[  739.601171] ? flush_work (kernel/workqueue.c:2733 kernel/workqueue.c:2760)
[  739.602084] ? destroy_worker (kernel/workqueue.c:2348)
[  739.603035] ? wait_for_completion (kernel/sched/completion.c:64 kernel/sched/completion.c:93 kernel/sched/completion.c:101 kernel/sched/completion.c:122)
[  739.604043] lru_add_drain_all (include/linux/cpumask.h:180 mm/swap.c:883)
[  739.605076] SyS_mlockall (./arch/x86/include/asm/current.h:14 include/linux/sched.h:2978 mm/mlock.c:813 mm/mlock.c:798)
[  739.605943] tracesys (arch/x86/kernel/entry_64.S:541)

Now, you'd expect to see lru_add_drain_per_cpu in one of the tasks, but
that's not the case.

Full log attched.


Thanks,
Sasha

[-- Attachment #2: log.txt.xz --]
[-- Type: application/x-xz, Size: 479700 bytes --]