Project

General

Profile

Bug #3058

xfs: possible circular locking dependency detected

Added by Tamilarasi muthamizhan over 11 years ago. Updated over 8 years ago.

Status:
Won't Fix
Priority:
Normal
Assignee:
-
Category:
-
Target version:
-
% Done:

0%

Source:
Q/A
Tags:
Backport:
Regression:
No
Severity:
Reviewed:
Affected Versions:
ceph-qa-suite:
Crash signature (v1):
Crash signature (v2):

Description

Logs: ubuntu@teuthology:/a/teuthology-2012-08-28_02:00:05-regression-testing-testing-basic/10406

2012-08-28T03:23:52.209167-07:00 plana40 kernel: [23405.556763] =========================================
=============
2012-08-28T03:23:52.209175-07:00 plana40 kernel: [23405.584315] [ INFO: possible circular locking depende
ncy detected ]
2012-08-28T03:23:52.209177-07:00 plana40 kernel: [23405.611861] 3.6.0-rc2-ceph-00143-g995fc06 #1 Not tain
ted
2012-08-28T03:23:52.209179-07:00 plana40 kernel: [23405.638127] -----------------------------------------
--------------
2012-08-28T03:23:52.209180-07:00 plana40 kernel: [23405.638129] fill2/7976 is trying to acquire lock:
2012-08-28T03:23:52.209183-07:00 plana40 kernel: [23405.638139]  ((&mp->m_flush_work)){+.+.+.}, at: [<fff
fffff81072060>] wait_on_work+0x0/0x160
2012-08-28T03:23:52.209184-07:00 plana40 kernel: [23405.638140] 
2012-08-28T03:23:52.209186-07:00 plana40 kernel: [23405.638140] but task is already holding lock:
2012-08-28T03:23:52.209191-07:00 plana40 kernel: [23405.638174]  (sb_internal#2){.+.+.+}, at: [<ffffffffa
03afe5d>] xfs_trans_alloc+0x2d/0x50 [xfs]
2012-08-28T03:23:52.209192-07:00 plana40 kernel: [23405.638175] 
2012-08-28T03:23:52.209194-07:00 plana40 kernel: [23405.638175] which lock already depends on the new loc
k.
2012-08-28T03:23:52.209195-07:00 plana40 kernel: [23405.638175] 
2012-08-28T03:23:52.209196-07:00 plana40 kernel: [23405.638175] 
2012-08-28T03:23:52.209197-07:00 plana40 kernel: [23405.638175] the existing dependency chain (in reverse
 order) is:
2012-08-28T03:23:52.209199-07:00 plana40 kernel: [23405.638179] 
2012-08-28T03:23:52.209200-07:00 plana40 kernel: [23405.638179] -> #1 (sb_internal#2){.+.+.+}:
2012-08-28T03:23:52.209204-07:00 plana40 kernel: [23405.638183]        [<ffffffff810b2c82>] lock_acquire+
0xa2/0x140
2012-08-28T03:23:52.209207-07:00 plana40 kernel: [23405.638186]        [<ffffffff816318eb>] mutex_lock_ne
sted+0x4b/0x320
2012-08-28T03:23:52.209221-07:00 plana40 kernel: [23405.638210]        [<ffffffffa03aee89>] xfs_icsb_modi
fy_counters+0x119/0x1b0 [xfs]
2012-08-28T03:23:52.209224-07:00 plana40 kernel: [23405.638228]        [<ffffffffa0363346>] xfs_reserve_b
locks+0x96/0x170 [xfs]
2012-08-28T03:23:52.209226-07:00 plana40 kernel: [23405.638252]        [<ffffffffa03aec75>] xfs_unmountfs
+0x95/0x190 [xfs]
2012-08-28T03:23:52.209229-07:00 plana40 kernel: [23405.638268]        [<ffffffffa036cd95>] xfs_fs_put_su
per+0x25/0x70 [xfs]
2012-08-28T03:23:52.209231-07:00 plana40 kernel: [23405.638273]        [<ffffffff8117de12>] generic_shutdown_super+0x62/0xf0
2012-08-28T03:23:52.209233-07:00 plana40 kernel: [23405.638276]        [<ffffffff8117ded0>] kill_block_super+0x30/0x80
2012-08-28T03:23:52.209237-07:00 plana40 kernel: [23405.638279]        [<ffffffff8117e1a5>] deactivate_locked_super+0x45/0x70
2012-08-28T03:23:52.209239-07:00 plana40 kernel: [23405.638283]        [<ffffffff8117ee4e>] deactivate_super+0x4e/0x70
2012-08-28T03:23:52.209241-07:00 plana40 kernel: [23405.638287]        [<ffffffff8119b1d6>] mntput_no_expire+0x106/0x160
2012-08-28T03:23:52.209243-07:00 plana40 kernel: [23405.638289]        [<ffffffff8119c1fe>] sys_umount+0x6e/0x3b0
2012-08-28T03:23:52.209245-07:00 plana40 kernel: [23405.638293]        [<ffffffff8163d569>] system_call_fastpath+0x16/0x1b
2012-08-28T03:23:52.209246-07:00 plana40 kernel: [23405.638296] 
2012-08-28T03:23:52.209248-07:00 plana40 kernel: [23405.638296] -> #0 ((&mp->m_flush_work)){+.+.+.}:
2012-08-28T03:23:52.209252-07:00 plana40 kernel: [23405.638298]        [<ffffffff810b25e8>] __lock_acquire+0x1ac8/0x1b90
2012-08-28T03:23:52.209254-07:00 plana40 kernel: [23405.638301]        [<ffffffff810b2c82>] lock_acquire+0xa2/0x140
2012-08-28T03:23:52.209256-07:00 plana40 kernel: [23405.638304]        [<ffffffff810720a1>] wait_on_work+0x41/0x160
2012-08-28T03:23:52.209258-07:00 plana40 kernel: [23405.638307]        [<ffffffff81072203>] flush_work_sync+0x43/0x90
2012-08-28T03:23:52.209260-07:00 plana40 kernel: [23405.638323]        [<ffffffffa036ec7f>] xfs_flush_inodes+0x2f/0x40 [xfs]
2012-08-28T03:23:52.209262-07:00 plana40 kernel: [23405.638341]        [<ffffffffa0371d2e>] xfs_create+0x3be/0x640 [xfs]
2012-08-28T03:23:52.209264-07:00 plana40 kernel: [23405.638357]        [<ffffffffa036888f>] xfs_vn_mknod+0x8f/0x1c0 [xfs]
2012-08-28T03:23:52.209266-07:00 plana40 kernel: [23405.638372]        [<ffffffffa03689f3>] xfs_vn_create+0x13/0x20 [xfs]
2012-08-28T03:23:52.209270-07:00 plana40 kernel: [23405.638375]        [<ffffffff8118aeb5>] vfs_create+0xb5/0x120
2012-08-28T03:23:52.209272-07:00 plana40 kernel: [23405.638378]        [<ffffffff8118bcc0>] do_last+0xda0/0xf00
2012-08-28T03:23:52.209274-07:00 plana40 kernel: [23405.638380]        [<ffffffff8118bed3>] path_openat+0
xb3/0x4c0
2012-08-28T03:23:52.209276-07:00 plana40 kernel: [23405.638383]        [<ffffffff8118c6f2>] do_filp_open+0x42/0xa0
2012-08-28T03:23:52.209278-07:00 plana40 kernel: [23405.638386]        [<ffffffff8117b040>] do_sys_open+0x100/0x1e0
2012-08-28T03:23:52.209279-07:00 plana40 kernel: [23405.638389]        [<ffffffff8117b141>] sys_open+0x21/0x30
2012-08-28T03:23:52.209281-07:00 plana40 kernel: [23405.638391]        [<ffffffff8163d569>] system_call_fastpath+0x16/0x1b
2012-08-28T03:23:52.209285-07:00 plana40 kernel: [23405.638392] 
2012-08-28T03:23:52.209286-07:00 plana40 kernel: [23405.638392] other info that might help us debug this:
2012-08-28T03:23:52.209287-07:00 plana40 kernel: [23405.638392] 
2012-08-28T03:23:52.209289-07:00 plana40 kernel: [23405.638393]  Possible unsafe locking scenario:
2012-08-28T03:23:52.209290-07:00 plana40 kernel: [23405.638393] 
2012-08-28T03:23:52.209292-07:00 plana40 kernel: [23405.638394]        CPU0                    CPU1
2012-08-28T03:23:52.209293-07:00 plana40 kernel: [23405.638394]        ----                    ----
2012-08-28T03:23:52.209294-07:00 plana40 kernel: [23405.638396]   lock(sb_internal#2);
2012-08-28T03:23:52.209298-07:00 plana40 kernel: [23405.638398]                                lock((&mp->m_flush_work));
2012-08-28T03:23:52.209300-07:00 plana40 kernel: [23405.638400]                                lock(sb_internal#2);
2012-08-28T03:23:52.209301-07:00 plana40 kernel: [23405.638402]   lock((&mp->m_flush_work));
2012-08-28T03:23:52.209302-07:00 plana40 kernel: [23405.638402] 
2012-08-28T03:23:52.209304-07:00 plana40 kernel: [23405.638402]  *** DEADLOCK ***
2012-08-28T03:23:52.209305-07:00 plana40 kernel: [23405.638402] 
2012-08-28T03:23:52.209306-07:00 plana40 kernel: [23405.638404] 3 locks held by fill2/7976:
2012-08-28T03:23:52.209310-07:00 plana40 kernel: [23405.638409]  #0:  (sb_writers#14){.+.+.+}, at: [<ffffffff8119b5b4>] mnt_want_write+0x24/0x50
2012-08-28T03:23:52.209313-07:00 plana40 kernel: [23405.638414]  #1:  (&type->i_mutex_dir_key#9){+.+.+.}, at: [<ffffffff8118b22b>] do_last+0x30b/0xf00
2012-08-28T03:23:52.209316-07:00 plana40 kernel: [23405.638440]  #2:  (sb_internal#2){.+.+.+}, at: [<ffffffffa03afe5d>] xfs_trans_alloc+0x2d/0x50 [xfs]
2012-08-28T03:23:52.209317-07:00 plana40 kernel: [23405.638441] 
2012-08-28T03:23:52.209318-07:00 plana40 kernel: [23405.638441] stack backtrace:
2012-08-28T03:23:52.209359-07:00 plana40 kernel: [23405.638443] Pid: 7976, comm: fill2 Not tainted 3.6.0-rc2-ceph-00143-g995fc06 #1
2012-08-28T03:23:52.209360-07:00 plana40 kernel: [23405.638444] Call Trace:
2012-08-28T03:23:52.209364-07:00 plana40 kernel: [23405.638448]  [<ffffffff8162a77c>] print_circular_bug+
0x1fb/0x20c
2012-08-28T03:23:52.209367-07:00 plana40 kernel: [23405.638451]  [<ffffffff810b25e8>] __lock_acquire+0x1ac8/0x1b90
2012-08-28T03:23:52.209369-07:00 plana40 kernel: [23405.638455]  [<ffffffff81050500>] ? __mmdrop+0x60/0x90
2012-08-28T03:23:52.209371-07:00 plana40 kernel: [23405.638459]  [<ffffffff8108494a>] ? finish_task_switch+0x10a/0x110
2012-08-28T03:23:52.209373-07:00 plana40 kernel: [23405.638463]  [<ffffffff81072060>] ? busy_worker_rebind_fn+0x100/0x100
2012-08-28T03:23:52.209374-07:00 plana40 kernel: [23405.638465]  [<ffffffff810b2c82>] lock_acquire+0xa2/0x140
2012-08-28T03:23:52.209376-07:00 plana40 kernel: [23405.638468]  [<ffffffff81072060>] ? busy_worker_rebind_fn+0x100/0x100
2012-08-28T03:23:52.209378-07:00 plana40 kernel: [23405.638472]  [<ffffffff81634c30>] ? _raw_spin_unlock_irq+0x30/0x40
2012-08-28T03:23:52.209382-07:00 plana40 kernel: [23405.638475]  [<ffffffff810720a1>] wait_on_work+0x41/0x160
2012-08-28T03:23:52.209384-07:00 plana40 kernel: [23405.638477]  [<ffffffff81072060>] ? busy_worker_rebind_fn+0x100/0x100
2012-08-28T03:23:52.209386-07:00 plana40 kernel: [23405.638480]  [<ffffffff810710a8>] ? start_flush_work+0x108/0x180
2012-08-28T03:23:52.209388-07:00 plana40 kernel: [23405.638483]  [<ffffffff81634e5f>] ? _raw_spin_unlock_irqrestore+0x3f/0x80
2012-08-28T03:23:52.209391-07:00 plana40 kernel: [23405.638486]  [<ffffffff81072203>] flush_work_sync+0x43/0x90
2012-08-28T03:23:52.209393-07:00 plana40 kernel: [23405.638488]  [<ffffffff810b379d>] ? trace_hardirqs_on+0xd/0x10
2012-08-28T03:23:52.209394-07:00 plana40 kernel: [23405.638491]  [<ffffffff810706c4>] ? __queue_work+0xe4/0x3b0
2012-08-28T03:23:52.209401-07:00 plana40 kernel: [23405.638509]  [<ffffffffa036ec7f>] xfs_flush_inodes+0x2f/0x40 [xfs]
2012-08-28T03:23:52.209403-07:00 plana40 kernel: [23405.638527]  [<ffffffffa0371d2e>] xfs_create+0x3be/0x640 [xfs]
2012-08-28T03:23:52.209405-07:00 plana40 kernel: [23405.638529]  [<ffffffff81192254>] ? d_rehash+0x24/0x40
2012-08-28T03:23:52.209407-07:00 plana40 kernel: [23405.638545]  [<ffffffffa036888f>] xfs_vn_mknod+0x8f/0x1c0 [xfs]
2012-08-28T03:23:52.209409-07:00 plana40 kernel: [23405.638561]  [<ffffffffa03689f3>] xfs_vn_create+0x13/
0x20 [xfs]
2012-08-28T03:23:52.209411-07:00 plana40 kernel: [23405.638564]  [<ffffffff8118aeb5>] vfs_create+0xb5/0x120
2012-08-28T03:23:52.209413-07:00 plana40 kernel: [23405.638567]  [<ffffffff8118bcc0>] do_last+0xda0/0xf00
2012-08-28T03:23:52.209414-07:00 plana40 kernel: [23405.638570]  [<ffffffff8118bed3>] path_openat+0xb3/0x4c0
2012-08-28T03:23:52.209418-07:00 plana40 kernel: [23405.638573]  [<ffffffff8118c6f2>] do_filp_open+0x42/0xa0
2012-08-28T03:23:52.209420-07:00 plana40 kernel: [23405.638577]  [<ffffffff8132babd>] ? do_raw_spin_unlock+0x5d/0xb0
2012-08-28T03:23:52.209422-07:00 plana40 kernel: [23405.638579]  [<ffffffff81634c6b>] ? _raw_spin_unlock+0x2b/0x40
2012-08-28T03:23:52.209424-07:00 plana40 kernel: [23405.638582]  [<ffffffff81199a22>] ? alloc_fd+0xd2/0x120
2012-08-28T03:23:52.209426-07:00 plana40 kernel: [23405.638585]  [<ffffffff8117b040>] do_sys_open+0x100/0x1e0
2012-08-28T03:23:52.209428-07:00 plana40 kernel: [23405.638588]  [<ffffffff8117b141>] sys_open+0x21/0x30
2012-08-28T03:23:52.209429-07:00 plana40 kernel: [23405.638590]  [<ffffffff8163d569>] system_call_fastpath+0x16/0x1b
2012-08-28T03:23:56.017269-07:00 plana40 kernel: [23409.414754] XFS (rbd2): Mounting Filesystem
2012-08-28T03:23:56.322868-07:00 plana40 kernel: [23409.720118] XFS (rbd2): Ending clean mount
2012-08-28T03:24:09.726925-07:00 plana40 kernel: [23423.101047] XFS (rbd2): Mounting Filesystem
2012-08-28T03:24:10.069138-07:00 plana40 kernel: [23423.443036] XFS (rbd2): Ending clean mount
2012-08-28T03:24:25.706773-07:00 plana40 kernel: [23439.053799] XFS (rbd2): Mounting Filesystem
2012-08-28T03:24:25.967883-07:00 plana40 kernel: [23439.314846] XFS (rbd2): Ending clean mount
2012-08-28T03:24:41.274859-07:00 plana40 kernel: [23454.595433] XFS (rbd1): Mounting Filesystem
2012-08-28T03:24:41.581621-07:00 plana40 kernel: [23454.902059] XFS (rbd1): Ending clean mount
2012-08-28T03:24:44.026073-07:00 plana40 kernel: [23457.341122] XFS (rbd2): unknown mount option [foobar].
2012-08-28T03:24:44.333401-07:00 plana40 kernel: [23457.622354] XFS (rbd2): Filesystem has duplicate UUID 53a04ae9-103d-4894-981f-892ad659f533 - can't mount
2012-08-28T03:24:44.859334-07:00 plana40 kernel: [23458.173026] XFS (rbd1): Mounting Filesystem
2012-08-28T03:24:45.142515-07:00 plana40 kernel: [23458.456009] XFS (rbd1): Ending clean mount
2012-08-28T03:24:46.582102-07:00 plana40 kernel: [23459.893012] XFS (rbd2): Mounting Filesystem
2012-08-28T03:24:46.837651-07:00 plana40 kernel: [23460.148478] XFS (rbd2): Ending clean mount

ubuntu@teuthology:/a/teuthology-2012-08-28_02:00:05-regression-testing-testing-basic/10406$ cat config.yaml 
kernel: &id001
  kdb: true
  sha1: 995fc068ddf675260098c60591989bf2ee184338
nuke-on-error: true
overrides:
  ceph:
    fs: btrfs
    log-whitelist:
    - slow request
    sha1: c03ca95d235c9a072dcd8a77ad5274a52e93ae30
  workunit:
    sha1: c03ca95d235c9a072dcd8a77ad5274a52e93ae30
roles:
- - mon.a
  - mon.c
  - osd.0
  - osd.1
  - osd.2
- - mon.b
  - mds.a
  - osd.3
  - osd.4
  - osd.5
- - client.0
targets:
  ubuntu@plana39.front.sepia.ceph.com: ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQDo+Kh24vRxeTQ6/n5PIIGuxrPHPRO/xMQlwoLHi7mR01cIXJMG5wet7mp2om3/5SZSDcLBHduDKrdWL142Sg5fC0zZPUggbxS7nz/UCjYBzMsOtHEUAU5Gs0KFopOCHXNEveK95ezsroMAD5+jS/IEpiooYCkrR3H+NSvUU0Ae352PlXqV0vamkYzyQyEMmhFE50ALhUXbKMve3d2mxJee5sqVZSBmQTbze9RKUA96t9iiwiheflXbN1i9WHlbBOIue5pZ5fM3/vqPWgaShfFpa0pT56QKJfjyFcDeCLOislo23E5qKAJOi5vn5BoYVtG3niNQpt/YbYGfDEHVeqt9
  ubuntu@plana40.front.sepia.ceph.com: ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQDEwyNlwC9Utqf3PCjL2JR4wwDkzpdEJuW93DOW82vYVisYEGod454JwXeNkjqzTUk6tXeRoUM9f/C6sZS3LFgHcMYt6m0sxP8DC4qU+q0YxCw9zLY8bXKe4DDjijM62h/SnyqyOWIh9amGT7wRwZEHBV1BKvZbNxQIJ7ESkuKsk/tJfWKhq7dSw6E/+MZ4yQtXvTyaJ3pK96Hq2uoUkawv+FxXBrzG3FtTTYA8gqA1SIiV3erEIQuBK/WD74i5yK4rwpfGTo7jNc0V6wrwO1BKFj/OGjSC+2LSAkBgf8WLe6UL/dHr3bBEyzm0V4xMf5Iqb8JGvkaXNEfbFqzKC2Wv
  ubuntu@plana80.front.sepia.ceph.com: ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQCjbUncT43IZIcpSlFXnWDaagYNdnaLTfgsN8TKi3J2QYOB1BlMpaSRBByXr5MW2ZGuWrB77USjJLdRW/feuwtAjDbwc7y5woxcxn1u9eqPh4RyQWqyCmKWvi3GpdM4/4vh+L+7X5rNzJPStTjiPXCxHK+stPGCk9pg+J+KKg/GlJ1Lwx1DeWetdForGqEVJrTSSWj8RM+Nyw/V+c+t2d6gW1SzjY2NvaDdVHfduM+8X9F9aTf3KLitnIvNQWXzfqoEDNPSwrrO2uvTDyqpFkW6HLpZDnWm+io8Y9P7XMrEhWCTlQX2SHeQv/BhaA1btYAw7qfLC9n8RbeXLlQnc5yn
tasks:
- internal.lock_machines: 3
- internal.save_config: null
- internal.check_lock: null
- internal.connect: null
- internal.check_conflict: null
- kernel: *id001
- internal.base: null
- internal.archive: null
- internal.coredump: null
- internal.syslog: null
- internal.timer: null
- chef: null
- clock: null
- ceph: null
- rbd.xfstests: null

History

#1 Updated by Tamilarasi muthamizhan over 11 years ago

Logs: ubuntu@teuthology:/a/teuthology-2012-08-29_19:00:06-regression-master-testing-gcov/11363

#2 Updated by Sage Weil over 11 years ago

  • Status changed from New to Won't Fix

#3 Updated by Kefu Chai over 8 years ago

  • Regression set to No

in case others run into the same issue, spotted at /a/ubuntu-2015-07-15_07:52:21-rados:monthrash-wip-kefu-testing---basic-multi/974764/remote/plana82/syslog/kern.log.gz. the tested changes happened on monitor, thus only in user space. i suspect this lockdep issue is in xfs:

2015-07-15T08:12:01.620084-07:00 plana82 kernel: [  557.291591] ======================================================
2015-07-15T08:12:01.620096-07:00 plana82 kernel: [  557.297832] [ INFO: possible circular locking dependency detected ]
2015-07-15T08:12:01.620099-07:00 plana82 kernel: [  557.304162] 3.18.0-rc4-ceph-00015-g388cfdc #1 Tainted: G          I E
2015-07-15T08:12:01.620101-07:00 plana82 kernel: [  557.310751] -------------------------------------------------------
2015-07-15T08:12:01.620104-07:00 plana82 kernel: [  557.317080] ceph-osd/5963 is trying to acquire lock:
2015-07-15T08:12:01.620109-07:00 plana82 kernel: [  557.322103]  (&sb->s_type->i_mutex_key#14){+.+.+.}, at: [<ffffffffa05b96e9>] xfs_file_buffered_aio_write.isra.9+0x79/0x2b0 [xfs]
2015-07-15T08:12:01.620111-07:00 plana82 kernel: [  557.334055]
2015-07-15T08:12:01.620113-07:00 plana82 kernel: [  557.334055] but task is already holding lock:
2015-07-15T08:12:01.620120-07:00 plana82 kernel: [  557.339962]  (&pipe->mutex/1){+.+.+.}, at: [<ffffffff811d73b5>] pipe_lock_nested+0x25/0x30
2015-07-15T08:12:01.620122-07:00 plana82 kernel: [  557.348579]
2015-07-15T08:12:01.620125-07:00 plana82 kernel: [  557.348579] which lock already depends on the new lock.
2015-07-15T08:12:01.620127-07:00 plana82 kernel: [  557.348579]
2015-07-15T08:12:01.620129-07:00 plana82 kernel: [  557.356846]
2015-07-15T08:12:01.620132-07:00 plana82 kernel: [  557.356846] the existing dependency chain (in reverse order) is:
2015-07-15T08:12:01.620134-07:00 plana82 kernel: [  557.364406]
2015-07-15T08:12:01.620136-07:00 plana82 kernel: [  557.364406] -> #2 (&pipe->mutex/1){+.+.+.}:
2015-07-15T08:12:01.620144-07:00 plana82 kernel: [  557.369109]        [<ffffffff810a2ece>] lock_acquire+0x9e/0x140
2015-07-15T08:12:01.620148-07:00 plana82 kernel: [  557.375146]        [<ffffffff817327c6>] mutex_lock_nested+0x66/0x390
2015-07-15T08:12:01.620152-07:00 plana82 kernel: [  557.381686]        [<ffffffff811d73b5>] pipe_lock_nested+0x25/0x30
2015-07-15T08:12:01.620155-07:00 plana82 kernel: [  557.387987]        [<ffffffff811d73d3>] pipe_lock+0x13/0x20
2015-07-15T08:12:01.620159-07:00 plana82 kernel: [  557.393676]        [<ffffffff811fffda>] splice_to_pipe+0x2a/0x290
2015-07-15T08:12:01.620163-07:00 plana82 kernel: [  557.399884]        [<ffffffff81200e58>] __generic_file_splice_read+0x588/0x630
2015-07-15T08:12:01.620167-07:00 plana82 kernel: [  557.407239]        [<ffffffff81200f3e>] generic_file_splice_read+0x3e/0x80
2015-07-15T08:12:01.620175-07:00 plana82 kernel: [  557.414238]        [<ffffffffa05b8dee>] xfs_file_splice_read+0xce/0x190 [xfs]
2015-07-15T08:12:01.620179-07:00 plana82 kernel: [  557.421517]        [<ffffffff811ff37f>] do_splice_to+0x6f/0x90
2015-07-15T08:12:01.620182-07:00 plana82 kernel: [  557.427465]        [<ffffffff8120151f>] SyS_splice+0x2ef/0x7c0
2015-07-15T08:12:01.620186-07:00 plana82 kernel: [  557.433413]        [<ffffffff81736e56>] system_call_fastpath+0x16/0x1b
2015-07-15T08:12:01.620188-07:00 plana82 kernel: [  557.440061]
2015-07-15T08:12:01.620191-07:00 plana82 kernel: [  557.440061] -> #1 (&(&ip->i_iolock)->mr_lock){++++++}:
2015-07-15T08:12:01.620194-07:00 plana82 kernel: [  557.445665]        [<ffffffff810a2ece>] lock_acquire+0x9e/0x140
2015-07-15T08:12:01.620196-07:00 plana82 kernel: [  557.451701]        [<ffffffff8109d41f>] down_write_nested+0x4f/0x80
2015-07-15T08:12:01.620204-07:00 plana82 kernel: [  557.458087]        [<ffffffffa05c4d28>] xfs_ilock+0x118/0x160 [xfs]
2015-07-15T08:12:01.620208-07:00 plana82 kernel: [  557.464494]        [<ffffffffa05c410d>] xfs_vn_setattr+0x4d/0x80 [xfs]
2015-07-15T08:12:01.620210-07:00 plana82 kernel: [  557.471159]        [<ffffffff811ed127>] notify_change+0x1c7/0x3a0
2015-07-15T08:12:01.620214-07:00 plana82 kernel: [  557.477369]        [<ffffffff811ccfb6>] do_truncate+0x66/0xa0
2015-07-15T08:12:01.620217-07:00 plana82 kernel: [  557.483230]        [<ffffffff811cd359>] do_sys_ftruncate.constprop.16+0x109/0x170
2015-07-15T08:12:01.620220-07:00 plana82 kernel: [  557.490844]        [<ffffffff811cd3fe>] SyS_ftruncate+0xe/0x10
2015-07-15T08:12:01.620223-07:00 plana82 kernel: [  557.496795]        [<ffffffff81736e56>] system_call_fastpath+0x16/0x1b
2015-07-15T08:12:01.620270-07:00 plana82 kernel: [  557.563523]
2015-07-15T08:12:01.620273-07:00 plana82 kernel: [  557.563523] other info that might help us debug this:
2015-07-15T08:12:01.620275-07:00 plana82 kernel: [  557.563523]
2015-07-15T08:12:01.620278-07:00 plana82 kernel: [  557.571619] Chain exists of:
2015-07-15T08:12:01.620282-07:00 plana82 kernel: [  557.571619]   &sb->s_type->i_mutex_key#14 --> &(&ip->i_iolock)->mr_lock --> &pipe->mutex/1
2015-07-15T08:12:01.620287-07:00 plana82 kernel: [  557.571619]
2015-07-15T08:12:01.620291-07:00 plana82 kernel: [  557.582149]  Possible unsafe locking scenario:
2015-07-15T08:12:01.620293-07:00 plana82 kernel: [  557.582149]
2015-07-15T08:12:01.620314-07:00 plana82 kernel: [  557.588143]        CPU0                    CPU1
2015-07-15T08:12:01.620318-07:00 plana82 kernel: [  557.592732]        ----                    ----
2015-07-15T08:12:01.620320-07:00 plana82 kernel: [  557.597321]   lock(&pipe->mutex/1);
2015-07-15T08:12:01.620324-07:00 plana82 kernel: [  557.601034]                                lock(&(&ip->i_iolock)->mr_lock);
2015-07-15T08:12:01.620327-07:00 plana82 kernel: [  557.608167]                                lock(&pipe->mutex/1);
2015-07-15T08:12:01.620335-07:00 plana82 kernel: [  557.614397]   lock(&sb->s_type->i_mutex_key#14);
2015-07-15T08:12:01.620337-07:00 plana82 kernel: [  557.619236]
2015-07-15T08:12:01.620340-07:00 plana82 kernel: [  557.619236]  *** DEADLOCK ***
2015-07-15T08:12:01.620342-07:00 plana82 kernel: [  557.619236]
2015-07-15T08:12:01.620344-07:00 plana82 kernel: [  557.625246] 2 locks held by ceph-osd/5963:
2015-07-15T08:12:01.620405-07:00 plana82 kernel: [  557.629400]  #0:  (sb_writers#13){.+.+.+}, at: [<ffffffff8120194a>] SyS_splice+0x71a/0x7c0
2015-07-15T08:12:01.620410-07:00 plana82 kernel: [  557.638072]  #1:  (&pipe->mutex/1){+.+.+.}, at: [<ffffffff811d73b5>] pipe_lock_nested+0x25/0x30
2015-07-15T08:12:01.620417-07:00 plana82 kernel: [  557.647178]
2015-07-15T08:12:01.620420-07:00 plana82 kernel: [  557.647178] stack backtrace:
2015-07-15T08:12:01.620424-07:00 plana82 kernel: [  557.651609] CPU: 1 PID: 5963 Comm: ceph-osd Tainted: G          I E  3.18.0-rc4-ceph-00015-g388cfdc #1
2015-07-15T08:12:01.620428-07:00 plana82 kernel: [  557.660994] Hardware name: Dell Inc. PowerEdge R410/01V648, BIOS 1.6.3 02/07/2011
2015-07-15T08:12:01.620431-07:00 plana82 kernel: [  557.668563]  ffffffff82386430 ffff8800bbeefa48 ffffffff8172d26c 0000000000000007
2015-07-15T08:12:01.620435-07:00 plana82 kernel: [  557.676286]  ffffffff823be7a0 ffff8800bbeefa98 ffffffff817285e3 ffffffffffffc000
2015-07-15T08:12:01.620439-07:00 plana82 kernel: [  557.683996]  ffffffff82110860 ffff8800bbee2a58 ffff8800bbee2a30 ffff8800bbee2a58
2015-07-15T08:12:01.620441-07:00 plana82 kernel: [  557.691689] Call Trace:
2015-07-15T08:12:01.620448-07:00 plana82 kernel: [  557.694204]  [<ffffffff8172d26c>] dump_stack+0x4e/0x68
2015-07-15T08:12:01.620452-07:00 plana82 kernel: [  557.699406]  [<ffffffff817285e3>] print_circular_bug+0x1fb/0x20c
2015-07-15T08:12:01.620456-07:00 plana82 kernel: [  557.705481]  [<ffffffff810a223e>] __lock_acquire+0x162e/0x1c90
2015-07-15T08:12:01.620460-07:00 plana82 kernel: [  557.711380]  [<ffffffff8109ec2f>] ? save_trace+0x3f/0xc0
2015-07-15T08:12:01.620464-07:00 plana82 kernel: [  557.716786]  [<ffffffffa05b96e9>] ? xfs_file_buffered_aio_write.isra.9+0x79/0x2b0 [xfs]
2015-07-15T08:12:01.620467-07:00 plana82 kernel: [  557.724870]  [<ffffffff810a2ece>] lock_acquire+0x9e/0x140
2015-07-15T08:12:01.620472-07:00 plana82 kernel: [  557.730355]  [<ffffffffa05b96e9>] ? xfs_file_buffered_aio_write.isra.9+0x79/0x2b0 [xfs]
2015-07-15T08:12:01.620485-07:00 plana82 kernel: [  557.738439]  [<ffffffff817327c6>] mutex_lock_nested+0x66/0x390
2015-07-15T08:12:01.620490-07:00 plana82 kernel: [  557.744355]  [<ffffffffa05b96e9>] ? xfs_file_buffered_aio_write.isra.9+0x79/0x2b0 [xfs]
2015-07-15T08:12:01.620493-07:00 plana82 kernel: [  557.752440]  [<ffffffff811d73b5>] ? pipe_lock_nested+0x25/0x30
2015-07-15T08:12:01.620497-07:00 plana82 kernel: [  557.758358]  [<ffffffffa05b96e9>] xfs_file_buffered_aio_write.isra.9+0x79/0x2b0 [xfs]
2015-07-15T08:12:01.620501-07:00 plana82 kernel: [  557.766268]  [<ffffffff810a392d>] ? trace_hardirqs_on+0xd/0x10
2015-07-15T08:12:01.620505-07:00 plana82 kernel: [  557.772165]  [<ffffffff811d73b5>] ? pipe_lock_nested+0x25/0x30
2015-07-15T08:12:01.620509-07:00 plana82 kernel: [  557.778084]  [<ffffffffa05b99b7>] xfs_file_write_iter+0x97/0x140 [xfs]
2015-07-15T08:12:01.620512-07:00 plana82 kernel: [  557.784675]  [<ffffffff811ffa8b>] iter_file_splice_write+0x28b/0x460
2015-07-15T08:12:01.620522-07:00 plana82 kernel: [  557.792332]  [<ffffffff8120143a>] SyS_splice+0x20a/0x7c0
2015-07-15T08:12:01.620527-07:00 plana82 kernel: [  557.797708]  [<ffffffff81736e56>] system_call_fastpath+0x16/0x1b
2015-07-15T09:31:28.894083-07:00 plana82 kernel: [ 5327.934404] perf interrupt took too long (2507 > 2500), lowering kernel.perf_event_max_sample_rate to 50000
2015-07-15T09:32:14.516334-07:00 plana82 kernel: [ 5373.584604] tgtd calls setitimer() with new_value NULL pointer. Misfeature support will be removed
2015-07-15T09:32:55.689460-07:00 plana82 kernel: Kernel logging (proc) stopped.

Also available in: Atom PDF