diff mbox

kernel BUG at fs/btrfs/inode.c:2271!

Message ID 4DDAB207.6060500@redhat.com (mailing list archive)
State New, archived
Headers show

Commit Message

Josef Bacik May 23, 2011, 7:14 p.m. UTC 
On 05/22/2011 07:13 AM, Marco Neubauer wrote:
> 
> Am 03.05.2011 um 16:54 schrieb Josef Bacik:
> 
>> On 04/27/2011 02:52 PM, Marco Neubauer wrote:
>>> Hi,
>>>
>>> this is happening mostly every night. I can't reproduce it right now.
>>> vanilla kernel 2.6.38.4
>>>
>>
>> Can you update to a newer kernel, this should be fixed there.  Thanks,
> 
> It's happening again.
> 
> ------------[ cut here ]------------
> WARNING: at fs/btrfs/inode.c:2394 btrfs_orphan_cleanup+0x1fe/0x3b0()
> Hardware name: System Product Name
> Modules linked in: w83627ehf hwmon_vid coretemp md4 cifs vboxnetadp vboxnetflt vboxdrv firewire_ohci firewire_core i915 asus_atk0110 hwmon drm_kms_helper video backlight
> Pid: 12355, comm: updatedb Not tainted 2.6.39 #1
> Call Trace:
> [<ffffffff8103f16b>] ? warn_slowpath_common+0x7b/0xc0
> [<ffffffff81250fee>] ? btrfs_orphan_cleanup+0x1fe/0x3b0
> [<ffffffff812509a3>] ? btrfs_iget+0x53/0x4a0
> [<ffffffff812515b8>] ? btrfs_lookup_dentry+0x418/0x490
> [<ffffffff81251639>] ? btrfs_lookup+0x9/0x20
> [<ffffffff810f7e3c>] ? d_alloc_and_lookup+0x3c/0x90
> [<ffffffff81102a6e>] ? d_lookup+0x2e/0x60
> [<ffffffff810f98db>] ? do_lookup+0xcb/0x2b0
> [<ffffffff810f9c0b>] ? path_init+0x14b/0x3d0
> [<ffffffff810fbf74>] ? path_lookupat+0x154/0x750
> [<ffffffff810f99f0>] ? do_lookup+0x1e0/0x2b0
> [<ffffffff810fc59c>] ? do_path_lookup+0x2c/0xd0
> [<ffffffff810f8776>] ? getname_flags+0x126/0x260
> [<ffffffff810fd31c>] ? user_path_at+0x5c/0xc0
> [<ffffffff810fc59c>] ? do_path_lookup+0x2c/0xd0
> [<ffffffff810f1f50>] ? cp_new_stat+0xe0/0x100
> [<ffffffff810f2053>] ? vfs_fstatat+0x43/0x80
> [<ffffffff810f211f>] ? sys_newlstat+0x1f/0x50
> [<ffffffff8169e47b>] ? system_call_fastpath+0x16/0x1b
> ---[ end trace dfa7e3e0b20f3e13 ]---
> ------------[ cut here ]------------
> kernel BUG at fs/btrfs/inode.c:2285!
> invalid opcode: 0000 [#1] PREEMPT SMP 
> last sysfs file: /sys/devices/system/cpu/cpu0/cpufreq/scaling_cur_freq
> CPU 0 
> Modules linked in: w83627ehf hwmon_vid coretemp md4 cifs vboxnetadp vboxnetflt vboxdrv firewire_ohci firewire_core i915 asus_atk0110 hwmon drm_kms_helper video backlight
> 
> Pid: 12355, comm: updatedb Tainted: G        W   2.6.39 #1 System manufacturer System Product Name/V-P5G45
> RIP: 0010:[<ffffffff8124b8e6>]  [<ffffffff8124b8e6>] btrfs_orphan_del+0xe6/0xf0
> RSP: 0018:ffff880186b81ab8  EFLAGS: 00010282
> RAX: 00000000fffffffe RBX: ffff88007e72ed40 RCX: 0000000000d14404
> RDX: 0000000000d14400 RSI: 00000000000199b0 RDI: ffffea0007a2c310
> RBP: 0000000000000000 R08: ffffffff8127b4b8 R09: 000000000000021f
> R10: 0000000000000047 R11: 0000000000000000 R12: ffff8801eae47640
> R13: ffff88022dee5800 R14: ffff88022dee5b30 R15: 0000000000000001
> FS:  00007feb837fe700(0000) GS:ffff88022fc00000(0000) knlGS:0000000000000000
> CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
> CR2: 000000000310b011 CR3: 0000000183fb6000 CR4: 00000000000406f0
> DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
> DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
> Process updatedb (pid: 12355, threadinfo ffff880186b80000, task ffff88021537c060)
> Stack:
> ffff880100da2158 ffff88022dee5800 ffff88022e80e900 ffff88022dee5b30
> ffff88022dee5b38 ffff880186b81b58 ffff880186b81b18 ffffffff8125104b
> ffff880186b80010 ffff88007e72ed40 ffff8801eae47640 00000000159e523f
> Call Trace:
> [<ffffffff8125104b>] ? btrfs_orphan_cleanup+0x25b/0x3b0
> [<ffffffff812509a3>] ? btrfs_iget+0x53/0x4a0
> [<ffffffff812515b8>] ? btrfs_lookup_dentry+0x418/0x490
> [<ffffffff81251639>] ? btrfs_lookup+0x9/0x20
> [<ffffffff810f7e3c>] ? d_alloc_and_lookup+0x3c/0x90
> [<ffffffff81102a6e>] ? d_lookup+0x2e/0x60
> [<ffffffff810f98db>] ? do_lookup+0xcb/0x2b0
> [<ffffffff810f9c0b>] ? path_init+0x14b/0x3d0
> [<ffffffff810fbf74>] ? path_lookupat+0x154/0x750
> [<ffffffff810f99f0>] ? do_lookup+0x1e0/0x2b0
> [<ffffffff810fc59c>] ? do_path_lookup+0x2c/0xd0
> [<ffffffff810f8776>] ? getname_flags+0x126/0x260
> [<ffffffff810fd31c>] ? user_path_at+0x5c/0xc0
> [<ffffffff810fc59c>] ? do_path_lookup+0x2c/0xd0
> [<ffffffff810f1f50>] ? cp_new_stat+0xe0/0x100
> [<ffffffff810f2053>] ? vfs_fstatat+0x43/0x80
> [<ffffffff810f211f>] ? sys_newlstat+0x1f/0x50
> [<ffffffff8169e47b>] ? system_call_fastpath+0x16/0x1b
> Code: 4c 8b 6c 24 20 4c 8b 74 24 28 4c 8b 7c 24 30 48 83 c4 38 c3 90 48 8b 93 a8 00 00 00 4c 89 ee 4c 89 e7 e8 5e fb 02 00 85 c0 74 b8 <0f> 0b eb fe 66 0f 1f 44 00 00 53 48 8d 86 38 03 00 00 48 89 f3 
> RIP  [<ffffffff8124b8e6>] btrfs_orphan_del+0xe6/0xf0
> RSP <ffff880186b81ab8>
> ---[ end trace dfa7e3e0b20f3e14 ]---
> 
> # btrfs fi show
> Label: 'ROOT'  uuid: 0292b87e-84b3-457f-abae-c2eb03e9d08e
> 	Total devices 1 FS bytes used 15.73GB
> 	devid    1 size 111.67GB used 49.79GB path /dev/sdc2
> 
> Label: 'DATA'  uuid: 07f62881-5cc4-4f8f-b304-7e7a3aae4adc
> 	Total devices 1 FS bytes used 572.87GB
> 	devid    1 size 592.25GB used 592.25GB path /dev/md1
> 
> Btrfs Btrfs v0.19
> 
> 
> # btrfs sub list /
> ID 267 top level 5 path subvol/home
> 
> # btrfs sub list /var/
> ID 643 top level 5 path subvol/tmp
> ID 644 top level 5 path subvol/var
> ID 730 top level 5 path subvol/homedata
> 
> # mount
> /dev/root on / type btrfs (rw,relatime,compress=zlib,ssd,discard,space_cache)
> /dev/sdc2 on /home type btrfs (rw,subvolid=267,compress,space_cache,ssd,discard)
> /dev/md1 on /homedata type btrfs (rw,subvolid=730,compress,space_cache)
> /dev/md1 on /tmp type btrfs (rw,subvolid=643,compress,space_cache)
> /dev/md1 on /var type btrfs (rw,subvolid=644,compress,space_cache)
> 

Can you apply this patch and reproduce and send me the output so I can
figure
out whats going wrong?  Thanks,

Josef


--
To unsubscribe from this list: send the line "unsubscribe linux-btrfs" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Comments

Marco Neubauer May 24, 2011, 6:55 p.m. UTC | #1 
Am 23.05.2011 um 21:14 schrieb Josef Bacik:

> On 05/22/2011 07:13 AM, Marco Neubauer wrote:
>> 
>> Am 03.05.2011 um 16:54 schrieb Josef Bacik:
>> 
>>> On 04/27/2011 02:52 PM, Marco Neubauer wrote:
>>>> Hi,
>>>> 
>>>> this is happening mostly every night. I can't reproduce it right now.
>>>> vanilla kernel 2.6.38.4
>>>> 
>>> 
>>> Can you update to a newer kernel, this should be fixed there.  Thanks,
>> 
>> It's happening again.
>> 
>> ------------[ cut here ]------------
> 
> Can you apply this patch and reproduce and send me the output so I can
> figure
> out whats going wrong?  Thanks,


May 24 03:10:01 mainframe cron[13013]: (root) CMD (test -x /usr/sbin/run-crons && /usr/sbin/run-crons )
May 24 03:10:11 mainframe kernel: found orphan item for 899452 on 267
May 24 03:10:11 mainframe kernel: lookup of inode was from disk
May 24 03:10:11 mainframe kernel: found orphan item for 899452 on 267
May 24 03:10:11 mainframe kernel: lookup of inode was from disk
May 24 03:10:11 mainframe kernel: found orphan item for 899452 on 267
May 24 03:10:11 mainframe kernel: lookup of inode was from disk
May 24 03:10:11 mainframe kernel: found orphan item for 899452 on 267
May 24 03:10:11 mainframe kernel: lookup of inode was from disk
May 24 03:10:11 mainframe kernel: found orphan item for 899452 on 267
May 24 03:10:11 mainframe kernel: lookup of inode was from disk
May 24 03:10:11 mainframe kernel: found orphan item for 899452 on 267
May 24 03:10:11 mainframe kernel: lookup of inode was from disk
May 24 03:10:11 mainframe kernel: found orphan item for 899452 on 267
May 24 03:10:11 mainframe kernel: lookup of inode was from disk
May 24 03:10:11 mainframe kernel: found orphan item for 899452 on 267
May 24 03:10:11 mainframe kernel: lookup of inode was from disk
May 24 03:10:11 mainframe kernel: found orphan item for 899452 on 267
May 24 03:10:11 mainframe kernel: lookup of inode was from disk
May 24 03:10:11 mainframe kernel: found orphan item for 899452 on 267
May 24 03:10:11 mainframe kernel: lookup of inode was from disk
May 24 03:10:11 mainframe kernel: found orphan item for 899452 on 267
May 24 03:10:11 mainframe kernel: lookup of inode was from disk
May 24 03:10:11 mainframe kernel: found orphan item for 899452 on 267
May 24 03:10:11 mainframe kernel: lookup of inode was from disk
May 24 03:10:11 mainframe kernel: found orphan item for 899452 on 267
May 24 03:10:11 mainframe kernel: lookup of inode was from disk
May 24 03:10:11 mainframe kernel: found orphan item for 899452 on 267
May 24 03:10:11 mainframe kernel: lookup of inode was from disk
May 24 03:10:11 mainframe kernel: found orphan item for 899452 on 267
May 24 03:10:11 mainframe kernel: lookup of inode was from disk
May 24 03:10:11 mainframe kernel: found orphan item for 899452 on 267


<- cut -> A lot more messages. The entire file is 5.19 GB.


May 24 03:51:47 mainframe kernel: found orphan item for 899452 on 267
May 24 03:51:47 mainframe kernel: lookup of inode was from disk
May 24 03:51:47 mainframe kernel: found orphan item for 899452 on 267
May 24 03:51:47 mainframe kernel: lookup of inode was from disk
May 24 03:51:47 mainframe kernel: found orphan item for 909358 on 267
May 24 03:51:47 mainframe kernel: lookup of inode was from disk
May 24 03:51:47 mainframe kernel: 909358 is a bad inode
May 24 03:51:47 mainframe kernel: ------------[ cut here ]------------
May 24 03:51:47 mainframe kernel: kernel BUG at fs/btrfs/inode.c:2285!
May 24 03:51:47 mainframe kernel: invalid opcode: 0000 [#1] PREEMPT SMP 
May 24 03:51:47 mainframe kernel: last sysfs file: /sys/devices/pci0000:00/0000:00:1f.2/host2/target2:0:0/2:0:0:0/block/sdc/sdc2/stat
May 24 03:51:47 mainframe kernel: CPU 0 
May 24 03:51:47 mainframe kernel: Modules linked in: w83627ehf hwmon_vid coretemp md4 cifs vboxnetadp vboxnetflt vboxdrv firewire_ohci firewire_core i915 asus_atk0110 hwmon drm_kms_helper video backlight
May 24 03:51:47 mainframe kernel: 
May 24 03:51:47 mainframe kernel: Pid: 13541, comm: updatedb Tainted: G        W   2.6.39 #2 System manufacturer System Product Name/V-P5G45
May 24 03:51:47 mainframe kernel: RIP: 0010:[<ffffffff8124b8e6>]  [<ffffffff8124b8e6>] btrfs_orphan_del+0xe6/0xf0
May 24 03:51:47 mainframe kernel: RSP: 0018:ffff88011be55ab8  EFLAGS: 00010282
May 24 03:51:47 mainframe kernel: RAX: 00000000fffffffe RBX: ffff880023fa8988 RCX: 000000000ab00490
May 24 03:51:47 mainframe kernel: RDX: 000000000ab0048c RSI: 00000000000199b0 RDI: ffffea0007a2c268
May 24 03:51:47 mainframe kernel: RBP: 0000000000000000 R08: ffffffff8127b558 R09: 0000000000000238
May 24 03:51:47 mainframe kernel: R10: 0000000000000042 R11: 0000000000000000 R12: ffff8800c352d740
May 24 03:51:47 mainframe kernel: R13: ffff88022b470000 R14: ffff88022b470330 R15: 0000000000000001
May 24 03:51:47 mainframe kernel: FS:  00007f86a60d3700(0000) GS:ffff88022fc00000(0000) knlGS:0000000000000000
May 24 03:51:47 mainframe kernel: CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
May 24 03:51:47 mainframe kernel: CR2: 00007f38a80c1000 CR3: 000000011bf21000 CR4: 00000000000406f0
May 24 03:51:47 mainframe kernel: DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
May 24 03:51:47 mainframe kernel: DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
May 24 03:51:47 mainframe kernel: Process updatedb (pid: 13541, threadinfo ffff88011be54000, task ffff88020ef24d40)
May 24 03:51:47 mainframe kernel: Stack:
May 24 03:51:47 mainframe kernel: ffff880203811d60 ffff88022b470000 ffff88022e82ce10 0000000032f72582
May 24 03:51:47 mainframe kernel: 0000000000000000 ffff88011be55b58 ffff88011be55b18 ffffffff812511cd
May 24 03:51:47 mainframe kernel: ffff8800c352d740 ffff880023fa8988 ffff88022b470330 ffff88022b470338
May 24 03:51:47 mainframe kernel: Call Trace:
May 24 03:51:47 mainframe kernel: [<ffffffff812511cd>] ? btrfs_orphan_cleanup+0x3dd/0x450
May 24 03:51:47 mainframe kernel: [<ffffffff812509a3>] ? btrfs_iget+0x53/0x4a0
May 24 03:51:47 mainframe kernel: [<ffffffff81251658>] ? btrfs_lookup_dentry+0x418/0x490
May 24 03:51:47 mainframe kernel: [<ffffffff812516d9>] ? btrfs_lookup+0x9/0x20
May 24 03:51:47 mainframe kernel: [<ffffffff810f7e3c>] ? d_alloc_and_lookup+0x3c/0x90
May 24 03:51:47 mainframe kernel: [<ffffffff81102a6e>] ? d_lookup+0x2e/0x60
May 24 03:51:47 mainframe kernel: [<ffffffff810f98db>] ? do_lookup+0xcb/0x2b0
May 24 03:51:47 mainframe kernel: [<ffffffff810f9c0b>] ? path_init+0x14b/0x3d0
May 24 03:51:47 mainframe kernel: [<ffffffff810fbf74>] ? path_lookupat+0x154/0x750
May 24 03:51:47 mainframe kernel: [<ffffffff810f99f0>] ? do_lookup+0x1e0/0x2b0
May 24 03:51:47 mainframe kernel: [<ffffffff810fc59c>] ? do_path_lookup+0x2c/0xd0
May 24 03:51:47 mainframe kernel: [<ffffffff810f8776>] ? getname_flags+0x126/0x260
May 24 03:51:47 mainframe kernel: [<ffffffff810fd31c>] ? user_path_at+0x5c/0xc0
May 24 03:51:47 mainframe kernel: [<ffffffff810fc59c>] ? do_path_lookup+0x2c/0xd0
May 24 03:51:47 mainframe kernel: [<ffffffff810f1f50>] ? cp_new_stat+0xe0/0x100
May 24 03:51:47 mainframe kernel: [<ffffffff810f2053>] ? vfs_fstatat+0x43/0x80
May 24 03:51:47 mainframe kernel: [<ffffffff810f211f>] ? sys_newlstat+0x1f/0x50
May 24 03:51:47 mainframe kernel: [<ffffffff8169e4fb>] ? system_call_fastpath+0x16/0x1b
May 24 03:51:47 mainframe kernel: Code: 4c 8b 6c 24 20 4c 8b 74 24 28 4c 8b 7c 24 30 48 83 c4 38 c3 90 48 8b 93 a8 00 00 00 4c 89 ee 4c 89 e7 e8 fe fb 02 00 85 c0 74 b8 <0f> 0b eb fe 66 0f 1f 44 00 00 53 48 8d 86 38 03 00 00 48 89 f3 
May 24 03:51:47 mainframe kernel: RIP  [<ffffffff8124b8e6>] btrfs_orphan_del+0xe6/0xf0
May 24 03:51:47 mainframe kernel: RSP <ffff88011be55ab8>
May 24 03:51:47 mainframe kernel: ---[ end trace 3413969c6e2d3603 ]---



-marco



--
To unsubscribe from this list: send the line "unsubscribe linux-btrfs" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
diff mbox

Patch

diff --git a/fs/btrfs/inode.c b/fs/btrfs/inode.c
index dc8fb2b..319728b 100644
--- a/fs/btrfs/inode.c
+++ b/fs/btrfs/inode.c
@@ -2314,6 +2314,8 @@  int btrfs_orphan_cleanup(struct btrfs_root *root)
 	key.offset = (u64)-1;

 	while (1) {
+		int new;
+
 		ret = btrfs_search_slot(NULL, root, &key, path, 0, 0);
 		if (ret < 0)
 			goto out;
@@ -2340,6 +2342,9 @@  int btrfs_orphan_cleanup(struct btrfs_root *root)
 		if (btrfs_key_type(&found_key) != BTRFS_ORPHAN_ITEM_KEY)
 			break;

+		printk(KERN_ERR "found orphan item for %llu on %llu\n",
+		       found_key.offset, root->root_key.objectid);
+
 		/* release the path since we're done with it */
 		btrfs_release_path(root, path);

@@ -2351,11 +2356,13 @@  int btrfs_orphan_cleanup(struct btrfs_root *root)
 		found_key.objectid = found_key.offset;
 		found_key.type = BTRFS_INODE_ITEM_KEY;
 		found_key.offset = 0;
-		inode = btrfs_iget(root->fs_info->sb, &found_key, root, NULL);
+		inode = btrfs_iget(root->fs_info->sb, &found_key, root, &new);
 		if (IS_ERR(inode)) {
 			ret = PTR_ERR(inode);
 			goto out;
 		}
+		printk(KERN_ERR "lookup of inode was%s from disk",
+		       new ? "" : " not");

 		/*
 		 * add this inode to the orphan list so btrfs_orphan_del does
@@ -2372,6 +2379,7 @@  int btrfs_orphan_cleanup(struct btrfs_root *root)
 		 * do a destroy_inode
 		 */
 		if (is_bad_inode(inode)) {
+			printk(KERN_ERR "%llu is a bad inode\n", inode->i_ino);
 			trans = btrfs_start_transaction(root, 0);
 			if (IS_ERR(trans)) {
 				ret = PTR_ERR(trans);
@@ -2386,6 +2394,8 @@  int btrfs_orphan_cleanup(struct btrfs_root *root)
 		/* if we have links, this was a truncate, lets do that */
 		if (inode->i_nlink) {
 			if (!S_ISREG(inode->i_mode)) {
+				printk(KERN_ERR "file mode is %lu, nlink is "
+				       "%lu\n", inode->i_mode, inode->i_nlink);
 				WARN_ON(1);
 				iput(inode);
 				continue;