Kernel Bug at fs/btrfs/volumes.c:3638

Hello,

While working with 'fsfuzz - file system fuzzing tool' on 'btrfs' encountered the following kernel bug.

Environment:
Kernel Version: 3.3.0-rc4
Architecture: s390, x86

Providing the kernel trace from 's390' arch.

Btrfs loaded
device fsid 346683e8-0fcc-4440-b421-4535e73d60d6 devid 1 transid 4 /dev/loop0
btrfs: disk space caching is enabled
unable to find logical 131072 len 4096

------------[ cut here ]------------
kernel BUG at fs/btrfs/volumes.c:3638!
illegal operation: 0001 [#1] SMP
Modules linked in: btrfs zlib_deflate crc32c libcrc32c loop dm_multipath dm_mod qeth_l3 ipv6 vmur dasd_eckd_mod dasd_mod scsi_dh_hp_sw scsi_dh_alua scsi_dh_rdac scsi_dh_emc scsi_dh scsi_mod qeth qdio ccwgroup ext3 mbcache jbd
CPU: 0 Not tainted 3.3.0-rc4-0.27-default #1
Process mount (pid: 2396, task: 000000003f176738, ksp: 0000000002ab7648)
Krnl PSW : 0704300180000000 000003e004c10e08 (__btrfs_map_block+0x794/0x8cc [btrfs])
           R:0 T:1 IO:1 EX:1 Key:0 M:1 W:0 P:0 AS:0 CC:3 PM:0 EA:3
Krnl GPRS: 0000000000010000 0700000000000008 000000000000002d 0400000000000000
           00000000004d3f26 00000000004e21a8 0000000002ab7828 
0000000002130d00
           000000003ee5ed90 000000003e962108 0000000000020000 
000000003e962110
           000003e004bb0000 000003e004c4c990 000003e004c10e04 
0000000002ab7620
Krnl Code: 000003e004c10df8: e34050000004       lg      %r4,0(%r5)
           000003e004c10dfe: c0e5fffcfb87       brasl   %r14,3e004bb050c
          #000003e004c10e04: a7f40001           brc     15,3e004c10e06

           000003e004c10e0c: 12bb               ltr     %r11,%r11
           000003e004c10e0e: a7c4ffb7           brc     12,3e004c10d7c
           000003e004c10e12: e31090200004       lg      %r1,32(%r9)
           000003e004c10e18: d507d0001078       clc     0(8,%r13),120(%r1)
Call Trace:
([<000003e004c10e04>] __btrfs_map_block+0x790/0x8cc [btrfs])
 [<000003e004c10f6e>] btrfs_map_block+0x2e/0x3c [btrfs]
 [<000003e004c11db4>] btrfs_map_bio+0x74/0x2ac [btrfs]
 [<000003e004be13c6>] btree_submit_bio_hook+0xd6/0xf0 [btrfs]
 [<000003e004c06b4c>] submit_one_bio+0xb4/0xf8 [btrfs]
 [<000003e004c0e292>] read_extent_buffer_pages+0x292/0x630 [btrfs]
 [<000003e004bddd0c>] btree_read_extent_buffer_pages+0xc8/0xfc [btrfs]
 [<000003e004bdf488>] read_tree_block+0x48/0x7c [btrfs]
 [<000003e004be30d6>] open_ctree+0xec6/0x15f8 [btrfs]
 [<000003e004bbb7d8>] btrfs_fill_super+0x90/0x170 [btrfs]
 [<000003e004bbbefa>] btrfs_mount+0x3ea/0x3f8 [btrfs]
 [<0000000000260b96>] mount_fs+0x5a/0x188
 [<00000000002852e6>] vfs_kern_mount+0x6e/0x11c
 [<0000000000285442>] do_kern_mount+0x52/0x114
 [<000000000028573c>] do_mount+0x238/0x288
 [<000000000028584e>] SyS_mount+0xc2/0xf0
 [<00000000004d7d88>] sysc_noemu+0x22/0x28
 [<000003fffd1fab1e>] 0x3fffd1fab1e
Last Breaking-Event-Address:
 [<000003e004c10e04>] __btrfs_map_block+0x790/0x8cc [btrfs]

---[ end trace 1e786b24696895a8 ]---

Steps to reproduce:

# mount <mangled file system image> <mount point> -t btrfs -o loop

Please let me know if you need more information. Thanks in advance.

Regards
R.Nageswara Sastry

Hi,

I guess you're mounting a quite small partition.

Given that this oops is in such an early stage,
could you please show 1) your mkfs.btrfs options and 2) the log of "btrfs-debug-tree /dev/loop0"?

thanks,
liubo

Here are the steps with options,

1. dd if=3D/dev/zero of=3D<filename.img> bs=3D1M count=3D16

2. mkfs.btrfs <filename.img>

3. Corrupt the <filename.img> using 'mangle'

4. mount -t btrfs -o loop <filename.img> <mount point>

5. # btrfs-debug-tree <filename.img>
Couldn't map the block 3221392384
Couldn't read chunk root
unable to open <filename.img>

# btrfs-debug-tree /dev/loop0
Couldn't map the block 3221392384
Couldn't read chunk root
unable to open /dev/loop0

Regards,
R.Nageswara Sastry

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

I inquired about robustness a while ago and it seems it's at some point on the horizon, but not now. My concern was about hot-unplugged disk drives, but btrfs also doesn't appreciate meta-data corruption. btrfs-raid users could be concerned, because contrarily to on a real RAID, the btrfs meta-data is a potential weak link.

At some point, I would appreciate some kind of thorough evaluation using a fuzzer on small disk images.
The btrfs developers could for instance:
- provide a script to create a filesystem image with a known layout (known corpus)
- provide .config and reference to kernel sources to build the kernel
- provide a minimal root filesystem to be run under qemu, it would run a procedure on the other disk image at boot
crashes wouldn't affect the host, which is good.
- provide a way to retrieve the test parameters and results for every test case
in case of bug, the test can be reproduced by the developers since the configuration is known
- expect volunteers to run the scenarios (I know I would)
The tricky part is of course the potentially super-costly procedure...
Simplest case: flipping every bit / writing blocks with pseudo-random data, even on meta-data only, as the outcome on data is supposed to be known.
Smarter: flipping bits on every btrfs meta-data structure type at every possible logical location.

The kind of stuff that would help all this could be something like Python bindings for a *btrfs library*. Helpful even for prototyping fsck stuff, making illustrations, etc.

As of today, how are btrfs developers testing the filesystem implementation (except with xfstests) ?

Best regards,

cJ

PS: don't be mistaken, I'm not asking for all that, just suggesting.
My time goes to something else, but I do have sleepy computers at home, and they could help.

ing a fuzzer on small disk images.

known corpus)

n a procedure on the other disk image at boot

test case

the configuration is known

=2E

data, even on meta-data only, as the outcome on data is supposed to be= known.

ry possible logical location.

There is a dangerdonteveruse(tm) utility btrfs-corrupt-block able to target at specific metadata structure and corrupt it, with the fsck counterpart for the rescue. I believe we'll see more updates in that area.

The block checksums are supposed to catch bitflips after they were written down to device (provided the data were correct up to the checksum point).

If you're talking about random bitflips in metadata structures during processing, that's very likely to crash in many ways of course. I think some logic needs to be added to those corruptions and accompanied by th= e
fsck part.

thon bindings for a *btrfs library*.

We could see btrfsprogs turn into a library + tool, someday. Added to project page.

tation (except with xfstests) ?

If there is a patch fixing particular bug, I try to set up environment stressing exactly that bug (and sometimes finding another one ...). The xfstests suite is a must before any testing. There are common loads raising the chances to hit a bug like repeated snapshots (and deletions= ),
exhausting data/metadata space, 'fi defrag', 'fi sync', 'fi balance'.

Sometimes it's enough to run a specific xfstest in a loop. I have set o= f
hackish scripts doing just these tasks or wrappers around xfstests to create filesystem with desired raid levels (where applicable) and let the suite run on top of it.

Another dimension of testing are mount options, there are some combinations likely to execrise specific parts of code, or create files in a way that may confuse different mount options (like nodatasum).

We've seen btrfs-specific tests added to xfstests, so it's mostly changing the outer environment for the testsuite.

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

I just noticed that there's a bugreport from opensuse user tripping over the same BUG() during log replay (and his problem was solved by btrfs-zero-log), probably after some crash. The kernel version was 3.1 ie. without the corruption fixes, so while it happened during normal use (and not via a crafted fs image), I'm not sure if this is still the case with recent kernels.

Turning the BUG in __btrfs_map_block to return needs checking the value in not-so-few callers and from various callpaths, it's not straightforward to do eg. a quick return during mount, as in your case.

Good that Jeff Mahoney's error handling series reduce the number of callers to update.

david

------------[ cut here ]------------
WARNING: at /home/abuild/rpmbuild/BUILD/kernel-desktop-3.1.0/linux-3.1/fs/btrfs/tree-log.c:1729 walk_down_log_tree+0x
15a/0x3e0 [btrfs]()
Pid: 8978, comm: mount Not tainted 3.1.0-1.2-desktop #1
Call Trace:
 [<ffffffff810043fa>] dump_trace+0xaa/0x2b0
 [<ffffffff81582a4a>] dump_stack+0x69/0x6f
 [<ffffffff8105386b>] warn_slowpath_common+0x7b/0xc0
 [<ffffffffa0573cba>] walk_down_log_tree+0x15a/0x3e0 [btrfs]
 [<ffffffffa0574267>] walk_log_tree+0xc7/0x1f0 [btrfs]
 [<ffffffffa057803c>] btrfs_recover_log_trees+0x1ec/0x2d0 [btrfs]
 [<ffffffffa0544303>] open_ctree+0x13c3/0x1740 [btrfs]
 [<ffffffffa0522733>] btrfs_fill_super.isra.36+0x73/0x150 [btrfs]
 [<ffffffffa0523b29>] btrfs_mount+0x359/0x3e0 [btrfs]
 [<ffffffff81156465>] mount_fs+0x45/0x1d0
 [<ffffffff8116fdb6>] vfs_kern_mount+0x66/0xd0
 [<ffffffff81171383>] do_kern_mount+0x53/0x120
 [<ffffffff81172e35>] do_mount+0x1a5/0x260
 [<ffffffff811732da>] sys_mount+0x9a/0xf0
 [<ffffffff815a3292>] system_call_fastpath+0x16/0x1b
 [<00007fc524137daa>] 0x7fc524137da9
---[ end trace 2bf4520d35da960f ]---
unable to find logical 5493736079360 len 4096
------------[ cut here ]------------

1728 if (btrfs_header_level(cur) != *level)
1729 WARN_ON(1);

kernel BUG at /home/abuild/rpmbuild/BUILD/kernel-desktop-3.1.0/linux-3.1/fs/btrfs/volumes.c:2891! invalid opcode: 0000 [#1] PREEMPT SMP
CPU 1

Pid: 8978, comm: mount Tainted: G W 3.1.0-1.2-desktop #1

RIP: 0010:[<ffffffffa0568e28>]  [<ffffffffa0568e28>] __btrfs_map_block+0x7c8/0x890 [btrfs]
RSP: 0018:ffff8801b7507798  EFLAGS: 00010296
RAX: 0000000000000043 RBX: 000004ff1c300000 RCX: 0000000000002a82
RDX: 000000000000723a RSI: 0000000000000046 RDI: 0000000000000202
RBP: ffff8801b7507860 R08: 000000000000000a R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000001 R12: ffff8801dcd10cc0
R13: 0000000000000001 R14: 0000000000000000 R15: 0000000000000001
FS:  00007fc524c587e0(0000) GS:ffff88021fd00000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 00007faea5cb8000 CR3: 00000001b74f4000 CR4: 00000000000006e0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
Process mount (pid: 8978, threadinfo ffff8801b7506000, task ffff8801b0d9c740)
Call Trace:
 [<ffffffffa056baa7>] btrfs_map_bio+0x57/0x210 [btrfs]
 [<ffffffffa05600d4>] submit_one_bio+0x64/0xa0 [btrfs]
 [<ffffffffa05653c7>] read_extent_buffer_pages+0x367/0x4a0 [btrfs]
 [<ffffffffa053fd10>] btree_read_extent_buffer_pages.isra.63+0x80/0xc0 [btrfs]
 [<ffffffffa0542b3a>] btrfs_read_buffer+0x2a/0x40 [btrfs]
 [<ffffffffa0576d56>] replay_one_buffer+0x46/0x360 [btrfs]
 [<ffffffffa0573d6d>] walk_down_log_tree+0x20d/0x3e0 [btrfs]
 [<ffffffffa0574267>] walk_log_tree+0xc7/0x1f0 [btrfs]
 [<ffffffffa057803c>] btrfs_recover_log_trees+0x1ec/0x2d0 [btrfs]
 [<ffffffffa0544303>] open_ctree+0x13c3/0x1740 [btrfs]
 [<ffffffffa0522733>] btrfs_fill_super.isra.36+0x73/0x150 [btrfs]
 [<ffffffffa0523b29>] btrfs_mount+0x359/0x3e0 [btrfs]
 [<ffffffff81156465>] mount_fs+0x45/0x1d0
 [<ffffffff8116fdb6>] vfs_kern_mount+0x66/0xd0
 [<ffffffff81171383>] do_kern_mount+0x53/0x120
 [<ffffffff81172e35>] do_mount+0x1a5/0x260
 [<ffffffff811732da>] sys_mount+0x9a/0xf0
 [<ffffffff815a3292>] system_call_fastpath+0x16/0x1b
 [<00007fc524137daa>] 0x7fc524137da9