Project

General

Profile

Actions
Copy link

Bug #2302

closed

xfs: warning at mutex_remove_waiter

Added by Sage Weil about 12 years ago. Updated almost 12 years ago.

Status:
Can't reproduce
Priority:
Normal
Assignee:
-
Category:
xfs
Target version:
-
% Done:

0%

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

Description

2012-04-14T14:05:08.845301-07:00 plana37 kernel: [43901.127960] ------------[ cut here ]------------
2012-04-14T14:05:08.845325-07:00 plana37 kernel: [43901.172631] WARNING: at /srv/autobuild-ceph/gitbuilder.git/build/kernel/mutex-debug.c:65 mutex_remove_waiter+0x93/0x130()
2012-04-14T14:05:08.845329-07:00 plana37 kernel: [43901.264274] Hardware name: PowerEdge R410
2012-04-14T14:05:08.845339-07:00 plana37 kernel: [43901.264276] Modules linked in: rbd libceph aesni_intel cryptd aes_x86_64 aes_generic ufs qnx4 hfsplus hfs minix ntfs vfat msdos fat jfs xfs exportfs reiserfs ipmi_devintf ipmi_si ipmi_msghandler i7core_edac edac_core joydev hed serio_raw dcdbas lp parport usbhid hid mptsas ixgbe mptscsih mptbase dca mdio scsi_transport_sas bnx2 btrfs zlib_deflate crc32c libcrc32c [last unloaded: libceph]
2012-04-14T14:05:08.845343-07:00 plana37 kernel: [43901.264312] Pid: 5947, comm: kworker/0:4 Not tainted 3.3.0-ceph-00067-gafede88 #1
2012-04-14T14:05:08.845345-07:00 plana37 kernel: [43901.264315] Call Trace:
2012-04-14T14:05:08.845350-07:00 plana37 kernel: [43901.264322]  [<ffffffff8104e42f>] warn_slowpath_common+0x7f/0xc0
2012-04-14T14:05:08.845353-07:00 plana37 kernel: [43901.264326]  [<ffffffff8104e48a>] warn_slowpath_null+0x1a/0x20
2012-04-14T14:05:08.845357-07:00 plana37 kernel: [43901.264330]  [<ffffffff810a59f3>] mutex_remove_waiter+0x93/0x130
2012-04-14T14:05:08.845360-07:00 plana37 kernel: [43901.264336]  [<ffffffff8161309c>] __mutex_lock_common+0x24c/0x3d0
2012-04-14T14:05:08.845364-07:00 plana37 kernel: [43901.264372]  [<ffffffffa0293a4f>] ? xfs_trans_dqlockedjoin+0x5f/0x70 [xfs]
2012-04-14T14:05:08.845367-07:00 plana37 kernel: [43901.264402]  [<ffffffffa0293a4f>] ? xfs_trans_dqlockedjoin+0x5f/0x70 [xfs]
2012-04-14T14:05:08.845378-07:00 plana37 kernel: [43901.264406]  [<ffffffff81613347>] mutex_lock_nested+0x37/0x50
2012-04-14T14:05:08.845381-07:00 plana37 kernel: [43901.264436]  [<ffffffffa0293a4f>] xfs_trans_dqlockedjoin+0x5f/0x70 [xfs]
2012-04-14T14:05:08.845385-07:00 plana37 kernel: [43901.264465]  [<ffffffffa0293aa5>] xfs_trans_apply_dquot_deltas+0x45/0x290 [xfs]
2012-04-14T14:05:08.845389-07:00 plana37 kernel: [43901.264494]  [<ffffffffa0287257>] xfs_trans_commit+0x67/0x270 [xfs]
2012-04-14T14:05:08.845393-07:00 plana37 kernel: [43901.264516]  [<ffffffffa023e52b>] xfs_iomap_write_allocate+0x16b/0x380 [xfs]
2012-04-14T14:05:08.845399-07:00 plana37 kernel: [43901.264534]  [<ffffffffa0232575>] xfs_map_blocks+0x165/0x240 [xfs]
2012-04-14T14:05:08.845404-07:00 plana37 kernel: [43901.264551]  [<ffffffffa02327ef>] xfs_vm_writepage+0x19f/0x500 [xfs]
2012-04-14T14:05:08.845411-07:00 plana37 kernel: [43901.264557]  [<ffffffff8112990a>] __writepage+0x1a/0x50
2012-04-14T14:05:08.845415-07:00 plana37 kernel: [43901.264561]  [<ffffffff8112b66e>] write_cache_pages+0x24e/0x4e0
2012-04-14T14:05:08.845419-07:00 plana37 kernel: [43901.264566]  [<ffffffff8130e01f>] ? cfq_dispatch_requests+0x18f/0xc10
2012-04-14T14:05:08.845422-07:00 plana37 kernel: [43901.264570]  [<ffffffff811298f0>] ? set_page_dirty+0x70/0x70
2012-04-14T14:05:08.845426-07:00 plana37 kernel: [43901.264574]  [<ffffffff8112b954>] generic_writepages+0x54/0x80
2012-04-14T14:05:08.845429-07:00 plana37 kernel: [43901.264591]  [<ffffffffa02311bc>] xfs_vm_writepages+0x5c/0x80 [xfs]
2012-04-14T14:05:08.845433-07:00 plana37 kernel: [43901.264596]  [<ffffffff8112b9a4>] do_writepages+0x24/0x40
2012-04-14T14:05:08.845440-07:00 plana37 kernel: [43901.264600]  [<ffffffff81120b4b>] __filemap_fdatawrite_range+0x5b/0x60
2012-04-14T14:05:08.845443-07:00 plana37 kernel: [43901.264605]  [<ffffffff81120e23>] filemap_fdatawrite_range+0x13/0x20
2012-04-14T14:05:08.845447-07:00 plana37 kernel: [43901.264624]  [<ffffffffa023a818>] xfs_flush_pages+0x78/0xc0 [xfs]
2012-04-14T14:05:08.845450-07:00 plana37 kernel: [43901.264646]  [<ffffffffa0245416>] xfs_sync_inode_data+0x86/0xb0 [xfs]
2012-04-14T14:05:08.845454-07:00 plana37 kernel: [43901.264669]  [<ffffffffa0245a7e>] xfs_inode_ag_walk+0x20e/0x370 [xfs]
2012-04-14T14:05:08.845458-07:00 plana37 kernel: [43901.264692]  [<ffffffffa0245b5b>] ? xfs_inode_ag_walk+0x2eb/0x370 [xfs]
2012-04-14T14:05:08.845461-07:00 plana37 kernel: [43901.264714]  [<ffffffffa0245390>] ? xfs_sync_worker+0x90/0x90 [xfs]
2012-04-14T14:05:08.845465-07:00 plana37 kernel: [43901.264735]  [<ffffffffa0245390>] ? xfs_sync_worker+0x90/0x90 [xfs]
2012-04-14T14:05:08.845472-07:00 plana37 kernel: [43901.264757]  [<ffffffffa0245c25>] xfs_inode_ag_iterator+0x45/0xa0 [xfs]
2012-04-14T14:05:08.845476-07:00 plana37 kernel: [43901.264780]  [<ffffffffa0245ca9>] xfs_sync_data+0x29/0x50 [xfs]
2012-04-14T14:05:08.845479-07:00 plana37 kernel: [43901.264802]  [<ffffffffa0245cf2>] xfs_flush_worker+0x22/0x40 [xfs]
2012-04-14T14:05:08.845483-07:00 plana37 kernel: [43901.264808]  [<ffffffff8106b256>] process_one_work+0x1a6/0x520
2012-04-14T14:05:08.845486-07:00 plana37 kernel: [43901.264812]  [<ffffffff8106b1e7>] ? process_one_work+0x137/0x520
2012-04-14T14:05:08.845490-07:00 plana37 kernel: [43901.264833]  [<ffffffffa0245cd0>] ? xfs_sync_data+0x50/0x50 [xfs]
2012-04-14T14:05:08.845493-07:00 plana37 kernel: [43901.264838]  [<ffffffff8106d71e>] worker_thread+0x2fe/0x400
2012-04-14T14:05:08.845496-07:00 plana37 kernel: [43901.264841]  [<ffffffff8106d420>] ? manage_workers+0x210/0x210
2012-04-14T14:05:08.845503-07:00 plana37 kernel: [43901.264846]  [<ffffffff8107280e>] kthread+0xbe/0xd0
2012-04-14T14:05:08.845507-07:00 plana37 kernel: [43901.264851]  [<ffffffff8161f5f4>] kernel_thread_helper+0x4/0x10
2012-04-14T14:05:08.845510-07:00 plana37 kernel: [43901.264855]  [<ffffffff81616134>] ? retint_restore_args+0x13/0x13
2012-04-14T14:05:08.845514-07:00 plana37 kernel: [43901.264860]  [<ffffffff81072750>] ? __init_kthread_worker+0x70/0x70
2012-04-14T14:05:08.845516-07:00 plana37 kernel: [43901.264864]  [<ffffffff8161f5f0>] ? gs_change+0x13/0x13
2012-04-14T14:05:08.845519-07:00 plana37 kernel: [43901.264866] ---[ end trace d27597ce9ccb8690 ]---
Actions
Copy link
 #1

Updated by Alex Elder about 12 years ago

I sent a report to the XFS mailing list about the warning. I have to try
to narrow down which test was running when the warning occurred--it was
only a warning, and all the xfstests passed, so it's not immediately clear
which it was.

Actions
Copy link
 #2

Updated by Alex Elder about 12 years ago

Looking at the list of tests that indicate they include quota testing,
the ones that are currently being run by the rdb.xfstests task are:
052 054 116 118 196 219 220 232 234 244 262

So it is most likely that these are the only possible tests that could
have produced the warning. I will start doing some runs to reproduce
the problem, and if I do, I'll divide-and-conquer to identify the culprit.

Actions
Copy link
 #3

Updated by Alex Elder about 12 years ago

I ran subsets of that list at least three times and never
reproduced it. I tried again after a reboot, and again,
nothing. I tried with the whole list again and I finally
got it to show up again. Subsetting again, a little less
aggressively (dropping out one or two tests at a time).

Actions
Copy link
 #4

Updated by Alex Elder about 12 years ago

After a lot of repetitions, I've narrowed it down to test 232 or 234.

Actions
Copy link
 #5

Updated by Alex Elder about 12 years ago

Should have waited. It have reproduced the problem by running test 232.

Actions
Copy link
 #6

Updated by Alex Elder about 12 years ago

I have updated the run_xfstests.sh script so that it simply no longer
runs test 232. That way we can still benefit from the xfstests runs
without having to live with this problem, which is almost certainly
something that needs to be fixed in XFS (not RBD).

Test 232 can be added back just like the other tests that have been
excluded from the xfstests suite for this initial checkin. This
bug will stay open to track getting this problem fixed.

I will likely have to be involved in this bug for XFS, since I am
able to reproduce it, but I feel like doing so is less urgent now.

Actions
Copy link
 #7

Updated by Alex Elder about 12 years ago

Interesting... The warning showed up again despite test 232 being
removed from the list. Based on the time stamp of the message in
the log it looks like it occurred during test 013 ("fsstress")--not
even on my original candidate list.

I think we really just want to invest in getting the XFS problem fixed
rather than pulling out more tests.

From syslog:
2012-04-17T13:07:32.203067-07:00 plana59 kernel: [ 2964.265818] ------------[ cu
t here ]------------
2012-04-17T13:07:32.203088-07:00 plana59 kernel: [ 2964.304506] WARNING: at /srv
/autobuild-ceph/gitbuilder.git/build/kernel/mutex-debug.c:65 mutex_remove_waiter
+0x93/0x130()
...

And from teuthology.log:
2012-04-17T13:06:37.044 INFO:teuthology.orchestra.run.out:012 2s
problem report occurred here, while test 13 was running
2012-04-17T13:09:14.810 INFO:teuthology.orchestra.run.out:013 156s
2012-04-17T13:12:02.924 INFO:teuthology.orchestra.run.out:014 167s

And now that I know to look at the date stamps, I see in the original
report that test 232 was in fact the one that was running:

2012-04-14T14:04:08.344 INFO:teuthology.orchestra.run.out:226 82s
2012-04-14T14:05:51.235 INFO:teuthology.orchestra.run.out:232 102s

Actions
Copy link
 #8

Updated by Sage Weil almost 12 years ago

  • Status changed from New to Can't reproduce
Actions
Copy link

Also available in: Atom PDF