xfs
[Top] [All Lists]

[INFO: possible circular locking dependency detected ] this is false ala

To: "xfs@xxxxxxxxxxx" <xfs@xxxxxxxxxxx>
Subject: [INFO: possible circular locking dependency detected ] this is false alarm or not?
From: mikhail <mikhail.v.gavrilov@xxxxxxxxx>
Date: Fri, 19 Aug 2016 00:40:54 +0500
Delivered-to: xfs@xxxxxxxxxxx
Dkim-signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=20120113; h=message-id:subject:from:to:date:mime-version; bh=IReyGEdenyViDEL4B5s/z8DrY4zhGbHqPKkoJiBXK68=; b=FSVBrl2eHh+gtUv2dVrJMACIf6HSLy24bnUEcY60HK0D0It3JBm7bwlm+FffYytmSc LtG6GmKFalNux2DtG0+cwGqPbMu4Ac4mlXswe6ptzMr6x1igoMnqPnVfGl8HOMpNLex3 jjbUcjX0cpAxHwMqxvW4Pbs1zS1PvxignQqRWCTCSX/b8FSMlsPvrLd0e0pMhl7m3FtN iMjpztFhSa1MTA18orQTefqeNtkKUfsK/P+jR18pIm/FEHovbNAfRFSxnc5QsONowWrZ p1lcE4RHrQcp1fpUFBKxN9e/J6NDglooqbzU5G0CuGkddnlJ/tveovLz+Y5A8d4BuH9H u+Dw==
After each boot in dmesg log appear messages see below:

[ 7322.502515] ======================================================
[ 7322.502517] [ INFO: possible circular locking dependency detected ]
[ 7322.502519] 4.6.6-300.fc24.x86_64+debug #1 Not tainted
[ 7322.502520] -------------------------------------------------------
[ 7322.502521] DOM Worker/23663 is trying to acquire lock:
[ 7322.502522]ÂÂ(&sb->s_type->i_mutex_key#20){+.+.+.}, at:
[<ffffffffc0b6dc8d>] xfs_file_buffered_aio_write+0x6d/0x350 [xfs]
[ 7322.502613]Â
ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂbut task is already holding lock:
[ 7322.502614]ÂÂ(&pipe->mutex/1){+.+.+.}, at: [<ffffffff812a161e>]
pipe_lock+0x1e/0x20
[ 7322.502622]Â
ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂwhich lock already depends on the new lock.

[ 7322.502625]Â
ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂthe existing dependency chain (in reverse order) is:
[ 7322.502626]Â
ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ-> #2 (&pipe->mutex/1){+.+.+.}:
[ 7322.502631]ÂÂÂÂÂÂÂÂ[<ffffffff81113abe>] lock_acquire+0xfe/0x1f0
[ 7322.502636]ÂÂÂÂÂÂÂÂ[<ffffffff818cd096>] mutex_lock_nested+0x86/0x400
[ 7322.502641]ÂÂÂÂÂÂÂÂ[<ffffffff812a161e>] pipe_lock+0x1e/0x20
[ 7322.502644]ÂÂÂÂÂÂÂÂ[<ffffffff812d1400>] splice_to_pipe+0x40/0x260
[ 7322.502650]ÂÂÂÂÂÂÂÂ[<ffffffff812d2dd3>]
__generic_file_splice_read+0x633/0x710
[ 7322.502653]ÂÂÂÂÂÂÂÂ[<ffffffff812d3285>]
generic_file_splice_read+0x45/0x90
[ 7322.502656]ÂÂÂÂÂÂÂÂ[<ffffffffc0b6b3fc>]
xfs_file_splice_read+0x11c/0x2a0 [xfs]
[ 7322.502725]ÂÂÂÂÂÂÂÂ[<ffffffff812d1779>] do_splice_to+0x79/0x90
[ 7322.502728]ÂÂÂÂÂÂÂÂ[<ffffffff812d4114>] SyS_splice+0x7f4/0x830
[ 7322.502731]ÂÂÂÂÂÂÂÂ[<ffffffff818d097c>]
entry_SYSCALL_64_fastpath+0x1f/0xbd
[ 7322.502735]Â
ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ-> #1 (&(&ip->i_iolock)->mr_lock){++++++}:
[ 7322.502738]ÂÂÂÂÂÂÂÂ[<ffffffff81113abe>] lock_acquire+0xfe/0x1f0
[ 7322.502741]ÂÂÂÂÂÂÂÂ[<ffffffff8110c0ee>] down_write_nested+0x5e/0xc0
[ 7322.502744]ÂÂÂÂÂÂÂÂ[<ffffffffc0b7c3c5>] xfs_ilock+0x215/0x2c0 [xfs]
[ 7322.502792]ÂÂÂÂÂÂÂÂ[<ffffffffc0b6dc9a>]
xfs_file_buffered_aio_write+0x7a/0x350 [xfs]
[ 7322.502823]ÂÂÂÂÂÂÂÂ[<ffffffffc0b6e0b1>]
xfs_file_write_iter+0x141/0x160 [xfs]
[ 7322.502850]ÂÂÂÂÂÂÂÂ[<ffffffff81297bde>] __vfs_write+0xce/0x120
[ 7322.502853]ÂÂÂÂÂÂÂÂ[<ffffffff81298495>] vfs_write+0xa5/0x190
[ 7322.502855]ÂÂÂÂÂÂÂÂ[<ffffffff81299968>] SyS_write+0x58/0xd0
[ 7322.502857]ÂÂÂÂÂÂÂÂ[<ffffffff818d097c>]
entry_SYSCALL_64_fastpath+0x1f/0xbd
[ 7322.502860]Â
ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ-> #0 (&sb->s_type->i_mutex_key#20){+.+.+.}:
[ 7322.502864]ÂÂÂÂÂÂÂÂ[<ffffffff81112f55>] __lock_acquire+0x1775/0x18e0
[ 7322.502868]ÂÂÂÂÂÂÂÂ[<ffffffff81113abe>] lock_acquire+0xfe/0x1f0
[ 7322.502870]ÂÂÂÂÂÂÂÂ[<ffffffff818cd096>] mutex_lock_nested+0x86/0x400
[ 7322.502873]ÂÂÂÂÂÂÂÂ[<ffffffffc0b6dc8d>]
xfs_file_buffered_aio_write+0x6d/0x350 [xfs]
[ 7322.502900]ÂÂÂÂÂÂÂÂ[<ffffffffc0b6e0b1>]
xfs_file_write_iter+0x141/0x160 [xfs]
[ 7322.502923]ÂÂÂÂÂÂÂÂ[<ffffffff812979eb>] vfs_iter_write+0x7b/0xd0
[ 7322.502926]ÂÂÂÂÂÂÂÂ[<ffffffff812d2300>]
iter_file_splice_write+0x270/0x3c0
[ 7322.502929]ÂÂÂÂÂÂÂÂ[<ffffffff812d3c89>] SyS_splice+0x369/0x830
[ 7322.502931]ÂÂÂÂÂÂÂÂ[<ffffffff818d097c>]
entry_SYSCALL_64_fastpath+0x1f/0xbd
[ 7322.502934]Â
ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂother info that might help us debug this:

[ 7322.502936] Chain exists of:
ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ&sb->s_type->i_mutex_key#20 --> &(&ip->i_iolock)-
>mr_lock --> &pipe->mutex/1

[ 7322.502941]ÂÂPossible unsafe locking scenario:

[ 7322.502943]ÂÂÂÂÂÂÂÂCPU0ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂCPU1
[ 7322.502944]ÂÂÂÂÂÂÂÂ----ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ----
[ 7322.502945]ÂÂÂlock(&pipe->mutex/1);
[ 7322.502948]ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂlock(&(&ip->i_iolock)-
>mr_lock);
[ 7322.502949]ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂlock(&pipe->mutex/1);
[ 7322.502952]ÂÂÂlock(&sb->s_type->i_mutex_key#20);
[ 7322.502954]Â
ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ*** DEADLOCK ***

[ 7322.502957] 2 locks held by DOM Worker/23663:
[ 7322.502958]ÂÂ#0:ÂÂ(sb_writers#16){.+.+.+}, at: [<ffffffff8129b9f4>]
__sb_start_write+0xb4/0xf0
[ 7322.502963]ÂÂ#1:ÂÂ(&pipe->mutex/1){+.+.+.}, at: [<ffffffff812a161e>]
pipe_lock+0x1e/0x20
[ 7322.502968]Â
ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂstack backtrace:
[ 7322.502971] CPU: 1 PID: 23663 Comm: DOM Worker Not tainted 4.6.6-
300.fc24.x86_64+debug #1
[ 7322.502973] Hardware name: Gigabyte Technology Co., Ltd. Z87M-
D3H/Z87M-D3H, BIOS F11 08/12/2014
[ 7322.502974]ÂÂ0000000000000086 00000000f800081a ffff880095f0ba90
ffffffff81458cb5
[ 7322.502978]ÂÂffffffff82b0e9a0 ffffffff82b1a590 ffff880095f0bad0
ffffffff8110ff4e
[ 7322.502981]ÂÂ0000000000000002 ffff8807dd994000 0000000000000002
ffff8807dd994958
[ 7322.502984] Call Trace:
[ 7322.502988]ÂÂ[<ffffffff81458cb5>] dump_stack+0x86/0xc1
[ 7322.502992]ÂÂ[<ffffffff8110ff4e>] print_circular_bug+0x1be/0x210
[ 7322.502994]ÂÂ[<ffffffff81112f55>] __lock_acquire+0x1775/0x18e0
[ 7322.502997]ÂÂ[<ffffffff81113abe>] lock_acquire+0xfe/0x1f0
[ 7322.503021]ÂÂ[<ffffffffc0b6dc8d>] ?
xfs_file_buffered_aio_write+0x6d/0x350 [xfs]
[ 7322.503025]ÂÂ[<ffffffff818cd096>] mutex_lock_nested+0x86/0x400
[ 7322.503049]ÂÂ[<ffffffffc0b6dc8d>] ?
xfs_file_buffered_aio_write+0x6d/0x350 [xfs]
[ 7322.503071]ÂÂ[<ffffffffc0b6dc8d>] ?
xfs_file_buffered_aio_write+0x6d/0x350 [xfs]
[ 7322.503092]ÂÂ[<ffffffffc0b6dc8d>]
xfs_file_buffered_aio_write+0x6d/0x350 [xfs]
[ 7322.503095]ÂÂ[<ffffffff811112a6>] ? mark_held_locks+0x76/0xa0
[ 7322.503099]ÂÂ[<ffffffff818cd298>] ? mutex_lock_nested+0x288/0x400
[ 7322.503102]ÂÂ[<ffffffff811113c5>] ?
trace_hardirqs_on_caller+0xf5/0x1b0
[ 7322.503122]ÂÂ[<ffffffffc0b6e0b1>] xfs_file_write_iter+0x141/0x160
[xfs]
[ 7322.503125]ÂÂ[<ffffffff812979eb>] vfs_iter_write+0x7b/0xd0
[ 7322.503128]ÂÂ[<ffffffff812d2300>] iter_file_splice_write+0x270/0x3c0
[ 7322.503131]ÂÂ[<ffffffff812d3c89>] SyS_splice+0x369/0x830
[ 7322.503134]ÂÂ[<ffffffff811113c5>] ?
trace_hardirqs_on_caller+0xf5/0x1b0
[ 7322.503136]ÂÂ[<ffffffff818d097c>]
entry_SYSCALL_64_fastpath+0x1f/0xbd

And system freeze for while time.
It possible find who is culprit from my log?

Best regards,
Mikhail Gavrilov

Attachment: dmesg.txt
Description: Text document

<Prev in Thread] Current Thread [Next in Thread>
  • [INFO: possible circular locking dependency detected ] this is false alarm or not?, mikhail <=