I'm seeing the same behavior here after an update to the kernel version in question. I get about 30 seconds after booting, and then the crash occurs, and anything that tries to touch the root partition (the only thing I have btrfs on) hangs.

Luckily, I was able to type fast enough to set grub back to booting 2.6.38.8-35 (probably helps that /boot is on a separate partition, too), and everything works fine with that kernel.

The line number mentioned in the trace seems to vary, but it's always been tree-log.c in the few trace I've seen, I think.

BTW:

it seems that only BTRFS have problems

running this build on two physical machines with different hardware up to a system with RAID1 for /boot and RAID10 for / and /data all seems to work perfectly including VMware-Workstation after patching the source to compile  the modules

AFAIK a great build if using ext4

+1

I have two SSDs in RAID0 as my / (btrfs). I had to revert to 2.6.38.

There is something wrong with the log tree.  You have 2 options here

1) Help me debug the problem.  I can give you patches to build and then capture the output of what happens so I can figure out where this is coming from and try and fix it for real

or

2) You can clear the log.  You will need to clone the official btrfs-progs git repository and build it from src, I'd give you a link to the git tree but it seems git.kernel.org is down, but when it comes back up you are looking for Chris Mason's btrfs-progs-unstable tree.  Build this and then run

btrfs-zero-log /dev/whatever

on your device with the fs not mounted.  If you are running / on btrfs you will need to run btrfs-zero-log from rescue mode.  This should make it so you can boot.


Let me know if you want to help me debug this, I will provide debug patches.  If you do want to help you cannot zero your log.

Ah it's back, this is the git tree you need

git://git.kernel.org/pub/scm/linux/kernel/git/mason/btrfs-progs-unstable.git


/me goes to update fedora's btrfs-progs

(In reply to comment #4)
> There is something wrong with the log tree.  You have 2 options here
> 
> 1) Help me debug the problem.  I can give you patches to build and then capture
> the output of what happens so I can figure out where this is coming from and
> try and fix it for real

I would be willing to try option 1. Please attach the patch here and I'll make a scratch kernel build. These would be patches against 3.0 (2.6.40) correct?

Argh actually there is no reason to debug, I just looked and I know what's wrong.  I'll put a patch in here for you to test to verify it fixes the problem.

Created attachment 516735 [details]
Patch to fix the problem

Ok please test this patch and verify it fixes the problem.

(In reply to comment #8)
> Created attachment 516735 [details]
> Patch to fix the problem
> 
> Ok please test this patch and verify it fixes the problem.

Great job! It seems to have fixed the problem.

Scratch build: http://koji.fedoraproject.org/koji/taskinfo?taskID=3252386

Hm - The same with "2.6.40.1-0.fc15.x86_64"

btrfs-progs-0.19-14.fc15.x86_64
btrfs-zero-log /dev/sdh1 -> command not found!



------------[ cut here ]------------
kernel BUG at fs/btrfs/tree-log.c:1742!
invalid opcode: 0000 [#1] SMP 
CPU 0 
Modules linked in: usb_storage xt_limit xt_state xt_multiport iptable_nat nf_nat nf_conntrack_ipv4 nf_conntrack nf_defrag_ipv4 snd_ens1371 gameport snd_rawmidi snd_ac97_codec ac97_bus snd_seq snd_seq_device snd_pcm snd_timer snd shpchp soundcore vmxnet3 snd_page_alloc vmw_balloon btrfs zlib_deflate libcrc32c raid10 vmw_pvscsi [last unloaded: scsi_wait_scan]

Pid: 761, comm: btrfs-transacti Not tainted 2.6.40.1-0.fc15.x86_64 #1 VMware, Inc. VMware Virtual Platform/440BX Desktop Reference Platform
RIP: 0010:[<ffffffffa0065f08>]  [<ffffffffa0065f08>] walk_down_log_tree+0x1ce/0x2c1 [btrfs]
RSP: 0018:ffff880045667bc0  EFLAGS: 00010282
RAX: 00000000ffffffa1 RBX: ffff880045667c5c RCX: 0000000000000001
RDX: 0000000000000100 RSI: 0000000000001000 RDI: ffff880037967ad0
RBP: ffff880045667c20 R08: ffffffffa006b784 R09: 0100000000000000
R10: 0100000000000000 R11: 000000000000000b R12: ffff880046c7d120
R13: ffff880047822000 R14: ffff8800461ef500 R15: ffff880045667ca0
FS:  0000000000000000(0000) GS:ffff88004ac00000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
CR2: 00007f5bf1917970 CR3: 0000000047f97000 CR4: 00000000000006f0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
Process btrfs-transacti (pid: 761, threadinfo ffff880045666000, task ffff880047a90000)
Stack:
 ffff880045667c10 ffff880046d9d000 fffffffffffffffa 00000000a1fb8000
 0000100045871800 0000000000006b3a ffff880047822000 ffff880046c7d120
 ffff880047822000 0000000000000000 0000000000000000 ffff880045667ca0
Call Trace:
 [<ffffffffa006607a>] walk_log_tree+0x7f/0x19e [btrfs]
 [<ffffffffa0068021>] free_log_tree+0x3e/0x9d [btrfs]
 [<ffffffffa0068249>] ? wait_for_writer+0xc5/0xc5 [btrfs]
 [<ffffffffa0068804>] btrfs_free_log+0x1d/0x2c [btrfs]
 [<ffffffffa003b5ee>] commit_fs_roots+0x8b/0x14b [btrfs]
 [<ffffffff81041325>] ? should_resched+0xe/0x2d
 [<ffffffff814b497c>] ? _cond_resched+0xe/0x22
 [<ffffffffa003c9d9>] btrfs_commit_transaction+0x3e0/0x706 [btrfs]
 [<ffffffff810703fa>] ? remove_wait_queue+0x3a/0x3a
 [<ffffffffa003d180>] ? start_transaction+0x20a/0x262 [btrfs]
 [<ffffffff81041325>] ? should_resched+0xe/0x2d
 [<ffffffffa003725c>] transaction_kthread+0x167/0x21e [btrfs]
 [<ffffffffa00370f5>] ? btrfs_congested_fn+0x86/0x86 [btrfs]
 [<ffffffff8106fd0b>] kthread+0x84/0x8c
 [<ffffffff814bd7a4>] kernel_thread_helper+0x4/0x10
 [<ffffffff8106fc87>] ? kthread_worker_fn+0x148/0x148
 [<ffffffff814bd7a0>] ? gs_change+0x13/0x13
Code: 48 83 7d b0 fa 74 11 be cb 06 00 00 48 c7 c7 7f 2b 08 a0 e8 b1 ed fe e0 8b 55 c4 48 8b 75 b8 4c 89 ef e8 99 a4 fc ff 85 c0 74 02 <0f> 0b 4c 89 f7 e8 9b 3d ff ff eb 70 48 8b 75 c8 48 89 c7 e8 91 
RIP  [<ffffffffa0065f08>] walk_down_log_tree+0x1ce/0x2c1 [btrfs]
 RSP <ffff880045667bc0>
---[ end trace 299564d5dd414705 ]---

Please try the scratch build in c#9, it should work.

sorry - i am enduser and this is not what the comment in changelog says

* Thu Aug 04 2011 Josef Bacik <josef> 0.19-14 
- bring btrfs-progs uptodate with upstream

Yeah I screwed up, I didn't make it so it actually build btrfs-zero-log, I'm fixing that now.

well, http://koji.fedoraproject.org/koji/buildinfo?buildID=257315 has no binary and a "rpmbuild --rebuild" of the src.rpm will also not spit out one :-)

Prüfe auf nicht gepackte Datei(en): /usr/lib/rpm/check-files /home/builduser/rpmbuild/BUILDROOT/btrfs-progs-0.19-15.fc15.x86_64
Ausführung(%clean): /bin/sh -e /var/tmp/rpm-tmp.0SHJNl
+ umask 022
+ cd /home/builduser/rpmbuild/BUILD
+ cd btrfs-progs-0.19
+ /bin/rm -rf /home/builduser/rpmbuild/BUILDROOT/btrfs-progs-0.19-15.fc15.x86_64
+ exit 0
Ausführung(--clean): /bin/sh -e /var/tmp/rpm-tmp.cKZX4O
+ umask 022
+ cd /home/builduser/rpmbuild/BUILD
+ rm -rf btrfs-progs-0.19
+ exit 0

Harald, if you use the kernel scratch build in comment 9 you do not need to zero your log and you do not need the latest btrfs-progs. Using just the scratch build should work for you.

this "scratch-build" whatever this is is oldr than the latest from koji
kernel-2.6.40.1-1.fc15 has the same problem
so why is this not fixed in 2.6.40.1-1

btrfs-zero-log does NOT help 
* booted with 2.6.38
* stopped all services
* unmounted 
* btrfs-zero-log
* reboot with 2.6.40.1-1.fc15
* crash -> see below

------------[ cut here ]------------
kernel BUG at fs/btrfs/tree-log.c:1742!
invalid opcode: 0000 [#1] SMP 
CPU 1 
Modules linked in: usb_storage xt_limit xt_state xt_multiport iptable_nat nf_nat nf_conntrack_ipv4 nf_conntrack nf_defrag_ipv4 snd_ens1371 gameport snd_rawmidi snd_ac97_codec ac97_bus snd_seq snd_seq_device snd_pcm snd_timer vmw_balloon snd soundcore snd_page_alloc shpchp vmxnet3 raid10 btrfs zlib_deflate libcrc32c vmw_pvscsi [last unloaded: ipv6]

Pid: 792, comm: btrfs-transacti Not tainted 2.6.40.1-1.fc15.x86_64 #1 VMware, Inc. VMware Virtual Platform/440BX Desktop Reference Platform
RIP: 0010:[<ffffffffa005cf08>]  [<ffffffffa005cf08>] walk_down_log_tree+0x1ce/0x2c1 [btrfs]
RSP: 0018:ffff880047633bc0  EFLAGS: 00010282
RAX: 00000000ffffffa1 RBX: ffff880047633c5c RCX: 0000000000000001
RDX: 0000000000000000 RSI: 0000000000001000 RDI: ffff880037b948d0
RBP: ffff880047633c20 R08: ffffffffa0062784 R09: 0000000000020000
R10: 0000000000020000 R11: 0000000000000001 R12: ffff880046c7c240
R13: ffff8800476e3000 R14: ffff880046e6d400 R15: ffff880047633ca0
FS:  0000000000000000(0000) GS:ffff88004ad00000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
CR2: 00000000014e4ffc CR3: 0000000047af5000 CR4: 00000000000006e0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
Process btrfs-transacti (pid: 792, threadinfo ffff880047632000, task ffff880037a09730)
Stack:
 ffff880047633c10 ffff880046ddf048 fffffffffffffffa 00000001e1d11000
 0000100045942000 0000000000006be1 ffff8800476e3000 ffff880046c7c240
 ffff8800476e3000 0000000000000000 0000000000000000 ffff880047633ca0
Call Trace:
 [<ffffffffa005d07a>] walk_log_tree+0x7f/0x19e [btrfs]
 [<ffffffffa005f021>] free_log_tree+0x3e/0x9d [btrfs]
 [<ffffffffa005f249>] ? wait_for_writer+0xc5/0xc5 [btrfs]
 [<ffffffffa005f804>] btrfs_free_log+0x1d/0x2c [btrfs]
 [<ffffffffa00325ee>] commit_fs_roots+0x8b/0x14b [btrfs]
 [<ffffffff81041325>] ? should_resched+0xe/0x2d
 [<ffffffff8148669c>] ? _cond_resched+0xe/0x22
 [<ffffffffa00339d9>] btrfs_commit_transaction+0x3e0/0x706 [btrfs]
 [<ffffffff810703fa>] ? remove_wait_queue+0x3a/0x3a
 [<ffffffffa0034180>] ? start_transaction+0x20a/0x262 [btrfs]
 [<ffffffff81041325>] ? should_resched+0xe/0x2d
 [<ffffffffa002e25c>] transaction_kthread+0x167/0x21e [btrfs]
 [<ffffffffa002e0f5>] ? btrfs_congested_fn+0x86/0x86 [btrfs]
 [<ffffffff8106fd0b>] kthread+0x84/0x8c
 [<ffffffff8148f4e4>] kernel_thread_helper+0x4/0x10
 [<ffffffff8106fc87>] ? kthread_worker_fn+0x148/0x148
 [<ffffffff8148f4e0>] ? gs_change+0x13/0x13
Code: 48 83 7d b0 fa 74 11 be cb 06 00 00 48 c7 c7 7f 9b 07 a0 e8 b1 7d ff e0 8b 55 c4 48 8b 75 b8 4c 89 ef e8 99 a4 fc ff 85 c0 74 02 <0f> 0b 4c 89 f7 e8 9b 3d ff ff eb 70 48 8b 75 c8 48 89 c7 e8 91 
RIP  [<ffffffffa005cf08>] walk_down_log_tree+0x1ce/0x2c1 [btrfs]
 RSP <ffff880047633bc0>
---[ end trace 73d323aca6525080 ]---

this problem has NOTHING to do with btfrs-log

* rebootet with 2.6.38
* rsync of all data to the host
* uncommented the disk and all bind-mounts in /etc/fstab
* rebooted the machine
* mkfs.btrfs aka create a new filesystem
* rsync adta back, seems all work fine
* reboot 2.6.40.1-1.fc15.x86_64
* 30 seconds later crash

i will go back to ext4 and hope such things do not affect users of F16 after they was forced with a btrfs-fs as default without knowing that they better should select ext4 manually and are beta-testers

------------[ cut here ]------------
kernel BUG at fs/btrfs/tree-log.c:1742!
invalid opcode: 0000 [#1] SMP 
CPU 0 
Modules linked in: usb_storage xt_limit xt_state xt_multiport iptable_nat nf_nat nf_conntrack_ipv4 nf_conntrack nf_defrag_ipv4 snd_ens1371 gameport snd_rawmidi snd_ac97_codec ac97_bus snd_seq snd_seq_device snd_pcm vmw_balloon snd_timer snd soundcore snd_page_alloc vmxnet3 shpchp btrfs raid10 zlib_deflate libcrc32c vmw_pvscsi [last unloaded: ipv6]

Pid: 774, comm: btrfs-transacti Not tainted 2.6.40.1-1.fc15.x86_64 #1 VMware, Inc. VMware Virtual Platform/440BX Desktop Reference Platform
RIP: 0010:[<ffffffffa0065f08>]  [<ffffffffa0065f08>] walk_down_log_tree+0x1ce/0x2c1 [btrfs]
RSP: 0018:ffff880047b0bbc0  EFLAGS: 00010282
RAX: 00000000ffffffa1 RBX: ffff880047b0bc5c RCX: 0000000000000001
RDX: 0000000000000100 RSI: 0000000000001000 RDI: ffff8800375b13d0
RBP: ffff880047b0bc20 R08: ffffffffa006b784 R09: 0000000200000000
R10: 0000000200000000 R11: 000000000000000a R12: ffff880046c41090
R13: ffff88004591f800 R14: ffff880046c58b80 R15: ffff880047b0bca0
FS:  0000000000000000(0000) GS:ffff88004ac00000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
CR2: 00000000009c5408 CR3: 0000000045dc2000 CR4: 00000000000006f0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
Process btrfs-transacti (pid: 774, threadinfo ffff880047b0a000, task ffff880047f82e60)
Stack:
 ffff880047b0bc10 ffff880046eae000 fffffffffffffffa 0000000001ca1000
 0000100047b0bc00 000000000000001c ffff88004591f800 ffff880046c41090
 ffff88004591f800 0000000000000000 0000000000000000 ffff880047b0bca0
Call Trace:
 [<ffffffffa006607a>] walk_log_tree+0x7f/0x19e [btrfs]
 [<ffffffffa0068021>] free_log_tree+0x3e/0x9d [btrfs]
 [<ffffffffa0068249>] ? wait_for_writer+0xc5/0xc5 [btrfs]
 [<ffffffffa0068804>] btrfs_free_log+0x1d/0x2c [btrfs]
 [<ffffffffa003b5ee>] commit_fs_roots+0x8b/0x14b [btrfs]
 [<ffffffff81041325>] ? should_resched+0xe/0x2d
 [<ffffffff8148669c>] ? _cond_resched+0xe/0x22
 [<ffffffffa003c9d9>] btrfs_commit_transaction+0x3e0/0x706 [btrfs]
 [<ffffffff810703fa>] ? remove_wait_queue+0x3a/0x3a
 [<ffffffffa003d180>] ? start_transaction+0x20a/0x262 [btrfs]
 [<ffffffff81041325>] ? should_resched+0xe/0x2d
 [<ffffffffa003725c>] transaction_kthread+0x167/0x21e [btrfs]
 [<ffffffffa00370f5>] ? btrfs_congested_fn+0x86/0x86 [btrfs]
 [<ffffffff8106fd0b>] kthread+0x84/0x8c
 [<ffffffff8148f4e4>] kernel_thread_helper+0x4/0x10
 [<ffffffff8106fc87>] ? kthread_worker_fn+0x148/0x148
 [<ffffffff8148f4e0>] ? gs_change+0x13/0x13
Code: 48 83 7d b0 fa 74 11 be cb 06 00 00 48 c7 c7 7f 2b 08 a0 e8 b1 ed fe e0 8b 55 c4 48 8b 75 b8 4c 89 ef e8 99 a4 fc ff 85 c0 74 02 <0f> 0b 4c 89 f7 e8 9b 3d ff ff eb 70 48 8b 75 c8 48 89 c7 e8 91 
RIP  [<ffffffffa0065f08>] walk_down_log_tree+0x1ce/0x2c1 [btrfs]
 RSP <ffff880047b0bbc0>
---[ end trace da37f3b8d2e0050d ]---

(In reply to comment #16)
> this "scratch-build" whatever this is is oldr than the latest from koji
> kernel-2.6.40.1-1.fc15 has the same problem
> so why is this not fixed in 2.6.40.1-1

Harald, this is my last comment to you since you choose to ignore my help.

The latest kernel build in koji *DOES NOT HAVE THE FIX* because I am not a kernel developer. Only *MY SCRATCH BUILD* in *COMMENT 9* has the fix. PLEASE USE THE COMMENT 9 SCRATCH BUILD.

Do not make any more comments until you install the SCRATCH BUILD FROM COMMENT 9.

> The latest kernel build in koji *DOES NOT HAVE THE FIX* 
> because I am not a kernel developer

so YOUR build is NOT relevant for a bug reported for a fedora-kernel pushed to uptaes-testing - why do you not say this at the begin? anyways - my testing time of btrfs has finished today and i am happy with ext4

BTW

> Do not make any more comments until you install the SCRATCH BUILD 
> FROM COMMENT 9

you should stop to explain the reporter of a bug in which conditions you "allow" him to comment the bugreport!

Since the scratch build works I'm going to push it into the official fedora kernel, thanks for testing.  Harald, can I see the output of btrfs-zero-log?  It should have worked.

And I don't understand your comment about f16.  The alpha deadline has passed and we still don't have a working fsck so there is going to be no switch, ext4 will continue to be the default.  Let's try to use bugzilla for dealing with bugs and fedora-devel list for being hostile and unhelpful.

Was this fix not included in the 2.6.40.3-0.fc15.x86_64 kernel update?

If it was, I'm still seeing the same crash.

> Harald, can I see the output of btrfs-zero-log? 
> It should have worked

There was no output, but btrfs-zero-log can not solve this porblem if you look at my comment above - Trahsing the partiton and format in again with btrfs has the same problem after the next reboot, so something in 2.6.40 is badly broken

as said i switched back to ext4 because this time my testserver is defacto my stable buildserver für F15 packages as long F15 is not stable anough for production use and only on my workstations where i can live with some bad things better

Dan, I just pushed the patches to -stable so they should show up soon, sorry about that.  Let me know when it comes back right and I will close this bug.  Thanks.

It's no problem. However, do you have a version number I could look out for that has the patch?

As far as I can tell, Fedora only keeps the 3 most recent versions of the kernel around by default, so if I upgrade without doing some manual intervention, and the next kernel upgrade isn't the fixed version, I won't have any versions that do work left to boot from. So it'd be nice to know that the next one I upgrade to can be expected to work.

kernel-2.6.40.4-5.fc15 has been submitted as an update for Fedora 15.
https://admin.fedoraproject.org/updates/kernel-2.6.40.4-5.fc15

kernel-2.6.40.4-5.fc15 has been pushed to the Fedora 15 stable repository.  If problems still persist, please make note of it in this bug report.