2010-01-02 10:33:13

by Carlos Mafra

[permalink] [raw]
Subject: 2.6.33-rc2+ bug in fs/btrfs/ordered-data.c:672

I started testing btrfs for my /home a few days ago and yesterday
I hit a kernel bug, using 2.6.33-rc2-00187-g08d869a.

I wasn't doing any stress test with it, I was simply watching a
DVD with xine while chrome was open in another workspace.

I noticed the kernel bug when the movie was over and I typed
'echo mem > /sys/power/state' to go to sleep but it got stuck,
so I checked what was happening in dmesg and I saw the bug in there.
By looking at the printk timings the bug was there for ~16 minutes, so
that last suspend to RAM atempt was not guilty in this bug. However,
the laptop was turned on for some hours already and had already passed
through a few suspend to RAM in this period.

I tried to save the dmesg but it failed writing, so I took a picture
of the bug trace

http://www.aei.mpg.de/~crmafra/btrfs_bug.jpg

Some info about my laptop is in this dmesg from this morning

http://www.aei.mpg.de/~crmafra/dmesg-2.6.33-rc2.txt

I hope this helps.


2010-01-02 22:35:17

by Carlos Mafra

[permalink] [raw]
Subject: Re: 2.6.33-rc2+ bug in fs/btrfs/ordered-data.c:672

On Sa 2.Jan'10 at 11:32:27 +0100, Carlos R. Mafra wrote:
> I started testing btrfs for my /home a few days ago and yesterday
> I hit a kernel bug, using 2.6.33-rc2-00187-g08d869a.
>
> I wasn't doing any stress test with it, I was simply watching a
> DVD with xine while chrome was open in another workspace.

Today I hit the bug twice, and it was always with chrome. I've
seen the other two reports in kerneloops.org involving
btrfs_ordered_update_i_size() and chrome was there too.

And now I saved the dmesg in the ext3 partition, so now there
is no need for the photo,


[13450.613952] ------------[ cut here ]------------
[13450.613957] kernel BUG at fs/btrfs/ordered-data.c:672!
[13450.613960] invalid opcode: 0000 [#1] SMP
[13450.613963] last sysfs file: /sys/devices/system/cpu/cpu0/cpufreq/scaling_cur_freq
[13450.613966] CPU 1
[13450.613970] Pid: 3372, comm: chrome Not tainted 2.6.33-rc2-fs-00187-g08d869a #293 VAIO/VGN-FZ240E
[13450.613973] RIP: 0010:[<ffffffff811d9537>] [<ffffffff811d9537>] btrfs_ordered_update_i_size+0x237/0x3d0
[13450.613982] RSP: 0018:ffff880071355da8 EFLAGS: 00010287
[13450.613984] RAX: ffff88007f0c0728 RBX: 0000000000000000 RCX: ffff880077c0c6a8
[13450.613986] RDX: 00000000002b5000 RSI: 0000000000000000 RDI: ffff880077c0c6b8
[13450.613989] RBP: ffff880071355e18 R08: 0000000000000000 R09: 0000000000000000
[13450.613991] R10: 0000000000000000 R11: 0000000000000000 R12: ffff8800729dd260
[13450.613993] R13: 00000000002b4b24 R14: 0000000000000000 R15: 00000000002b4b24
[13450.613996] FS: 00007f2b3db68910(0000) GS:ffff880001b00000(0000) knlGS:0000000000000000
[13450.613999] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[13450.614001] CR2: 00007f2b3c2a4000 CR3: 0000000071167000 CR4: 00000000000006e0
[13450.614003] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[13450.614005] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
[13450.614008] Process chrome (pid: 3372, threadinfo ffff880071354000, task ffff88007d380640)
[13450.614010] Stack:
[13450.614011] ffff8800729dd0c0 0000000000000000 fffffffffffff000 0000000000000fff
[13450.614015] <0> ffff8800729dd0f0 ffff88007c7cc000 ffff8800729dd0c0 ffff8800729dd170
[13450.614019] <0> ffff880071355e18 ffff880071355ee8 ffff8800729dd260 0000000000000000
[13450.614023] Call Trace:
[13450.614028] [<ffffffff811c915d>] btrfs_setattr+0x17d/0x270
[13450.614033] [<ffffffff810e5fe4>] notify_change+0x104/0x2e0
[13450.614037] [<ffffffff810ce84f>] do_truncate+0x5f/0x90
[13450.614041] [<ffffffff810d0002>] ? vfs_write+0x132/0x180
[13450.614044] [<ffffffff810cef79>] sys_ftruncate+0xe9/0x130
[13450.614049] [<ffffffff81002dab>] system_call_fastpath+0x16/0x1b
[13450.614050] Code: 0f 1f 40 00 eb 88 66 0f 1f 44 00 00 49 8b 84 24 38 ff ff ff 48 85 c0 74 1b 48 8b 50 98 49 39 d5 72 12 48 03 50 a8 49 39 d5 73 09 <0f> 0b eb fe 0f 1f 44 00 00 49 8b 94 24 30 ff ff ff 48 89 55 b8
[13450.614082] RIP [<ffffffff811d9537>] btrfs_ordered_update_i_size+0x237/0x3d0
[13450.614087] RSP <ffff880071355da8>
[13450.614090] ---[ end trace 74172209f4d15206 ]---

2010-01-04 00:22:45

by Johannes Hirte

[permalink] [raw]
Subject: Re: 2.6.33-rc2+ bug in fs/btrfs/ordered-data.c:672

Am Samstag 02 Januar 2010 23:34:17 schrieb Carlos R. Mafra:
> On Sa 2.Jan'10 at 11:32:27 +0100, Carlos R. Mafra wrote:
> > I started testing btrfs for my /home a few days ago and yesterday
> > I hit a kernel bug, using 2.6.33-rc2-00187-g08d869a.
> >
> > I wasn't doing any stress test with it, I was simply watching a
> > DVD with xine while chrome was open in another workspace.
>
> Today I hit the bug twice, and it was always with chrome. I've
> seen the other two reports in kerneloops.org involving
> btrfs_ordered_update_i_size() and chrome was there too.
>
> And now I saved the dmesg in the ext3 partition, so now there
> is no need for the photo,
>
>
> [13450.613952] ------------[ cut here ]------------
> [13450.613957] kernel BUG at fs/btrfs/ordered-data.c:672!
> [13450.613960] invalid opcode: 0000 [#1] SMP
> [13450.613963] last sysfs file:
> /sys/devices/system/cpu/cpu0/cpufreq/scaling_cur_freq [13450.613966] CPU 1
> [13450.613970] Pid: 3372, comm: chrome Not tainted
> 2.6.33-rc2-fs-00187-g08d869a #293 VAIO/VGN-FZ240E [13450.613973] RIP:
> 0010:[<ffffffff811d9537>] [<ffffffff811d9537>]
> btrfs_ordered_update_i_size+0x237/0x3d0 [13450.613982] RSP:
> 0018:ffff880071355da8 EFLAGS: 00010287
> [13450.613984] RAX: ffff88007f0c0728 RBX: 0000000000000000 RCX:
> ffff880077c0c6a8 [13450.613986] RDX: 00000000002b5000 RSI:
> 0000000000000000 RDI: ffff880077c0c6b8 [13450.613989] RBP:
> ffff880071355e18 R08: 0000000000000000 R09: 0000000000000000
> [13450.613991] R10: 0000000000000000 R11: 0000000000000000 R12:
> ffff8800729dd260 [13450.613993] R13: 00000000002b4b24 R14:
> 0000000000000000 R15: 00000000002b4b24 [13450.613996] FS:
> 00007f2b3db68910(0000) GS:ffff880001b00000(0000) knlGS:0000000000000000
> [13450.613999] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> [13450.614001] CR2: 00007f2b3c2a4000 CR3: 0000000071167000 CR4:
> 00000000000006e0 [13450.614003] DR0: 0000000000000000 DR1:
> 0000000000000000 DR2: 0000000000000000 [13450.614005] DR3:
> 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
> [13450.614008] Process chrome (pid: 3372, threadinfo ffff880071354000,
> task ffff88007d380640) [13450.614010] Stack:
> [13450.614011] ffff8800729dd0c0 0000000000000000 fffffffffffff000
> 0000000000000fff [13450.614015] <0> ffff8800729dd0f0 ffff88007c7cc000
> ffff8800729dd0c0 ffff8800729dd170 [13450.614019] <0> ffff880071355e18
> ffff880071355ee8 ffff8800729dd260 0000000000000000 [13450.614023] Call
> Trace:
> [13450.614028] [<ffffffff811c915d>] btrfs_setattr+0x17d/0x270
> [13450.614033] [<ffffffff810e5fe4>] notify_change+0x104/0x2e0
> [13450.614037] [<ffffffff810ce84f>] do_truncate+0x5f/0x90
> [13450.614041] [<ffffffff810d0002>] ? vfs_write+0x132/0x180
> [13450.614044] [<ffffffff810cef79>] sys_ftruncate+0xe9/0x130
> [13450.614049] [<ffffffff81002dab>] system_call_fastpath+0x16/0x1b
> [13450.614050] Code: 0f 1f 40 00 eb 88 66 0f 1f 44 00 00 49 8b 84 24 38 ff
> ff ff 48 85 c0 74 1b 48 8b 50 98 49 39 d5 72 12 48 03 50 a8 49 39 d5 73 09
> <0f> 0b eb fe 0f 1f 44 00 00 49 8b 94 24 30 ff ff ff 48 89 55 b8
> [13450.614082] RIP [<ffffffff811d9537>]
> btrfs_ordered_update_i_size+0x237/0x3d0 [13450.614087] RSP
> <ffff880071355da8>
> [13450.614090] ---[ end trace 74172209f4d15206 ]---

Sounds like the bug reported here: http://article.gmane.org/gmane.comp.file-
systems.btrfs/4332/match=btrfs+fails+randomly. Can you try the patch provided
in that thread?

regards,
Johannes

2010-01-04 04:20:21

by Yan Zheng

[permalink] [raw]
Subject: Re: 2.6.33-rc2+ bug in fs/btrfs/ordered-data.c:672

On Mon, Jan 4, 2010 at 8:22 AM, Johannes Hirte
<[email protected]> wrote:
> Am Samstag 02 Januar 2010 23:34:17 schrieb Carlos R. Mafra:
>> On Sa ?2.Jan'10 at 11:32:27 +0100, Carlos R. Mafra wrote:
>> > I started testing btrfs for my /home a few days ago and yesterday
>> > I hit a kernel bug, using 2.6.33-rc2-00187-g08d869a.
>> >
>> > I wasn't doing any stress test with it, I was simply watching a
>> > DVD with xine while chrome was open in another workspace.
>>
>> Today I hit the bug twice, and it was always with chrome. I've
>> seen the other two reports in kerneloops.org involving
>> btrfs_ordered_update_i_size() and chrome was there too.
>>
>> And now I saved the dmesg in the ext3 partition, so now there
>> is no need for the photo,
>>
>>
>> [13450.613952] ------------[ cut here ]------------
>> [13450.613957] kernel BUG at fs/btrfs/ordered-data.c:672!
>> [13450.613960] invalid opcode: 0000 [#1] SMP
>> [13450.613963] last sysfs file:
>> ?/sys/devices/system/cpu/cpu0/cpufreq/scaling_cur_freq [13450.613966] CPU 1
>> [13450.613970] Pid: 3372, comm: chrome Not tainted
>> ?2.6.33-rc2-fs-00187-g08d869a #293 VAIO/VGN-FZ240E [13450.613973] RIP:
>> ?0010:[<ffffffff811d9537>] ?[<ffffffff811d9537>]
>> ?btrfs_ordered_update_i_size+0x237/0x3d0 [13450.613982] RSP:
>> ?0018:ffff880071355da8 ?EFLAGS: 00010287
>> [13450.613984] RAX: ffff88007f0c0728 RBX: 0000000000000000 RCX:
>> ?ffff880077c0c6a8 [13450.613986] RDX: 00000000002b5000 RSI:
>> ?0000000000000000 RDI: ffff880077c0c6b8 [13450.613989] RBP:
>> ?ffff880071355e18 R08: 0000000000000000 R09: 0000000000000000
>> ?[13450.613991] R10: 0000000000000000 R11: 0000000000000000 R12:
>> ?ffff8800729dd260 [13450.613993] R13: 00000000002b4b24 R14:
>> ?0000000000000000 R15: 00000000002b4b24 [13450.613996] FS:
>> ?00007f2b3db68910(0000) GS:ffff880001b00000(0000) knlGS:0000000000000000
>> ?[13450.613999] CS: ?0010 DS: 0000 ES: 0000 CR0: 0000000080050033
>> [13450.614001] CR2: 00007f2b3c2a4000 CR3: 0000000071167000 CR4:
>> ?00000000000006e0 [13450.614003] DR0: 0000000000000000 DR1:
>> ?0000000000000000 DR2: 0000000000000000 [13450.614005] DR3:
>> ?0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
>> ?[13450.614008] Process chrome (pid: 3372, threadinfo ffff880071354000,
>> ?task ffff88007d380640) [13450.614010] Stack:
>> [13450.614011] ?ffff8800729dd0c0 0000000000000000 fffffffffffff000
>> ?0000000000000fff [13450.614015] <0> ffff8800729dd0f0 ffff88007c7cc000
>> ?ffff8800729dd0c0 ffff8800729dd170 [13450.614019] <0> ffff880071355e18
>> ?ffff880071355ee8 ffff8800729dd260 0000000000000000 [13450.614023] Call
>> ?Trace:
>> [13450.614028] ?[<ffffffff811c915d>] btrfs_setattr+0x17d/0x270
>> [13450.614033] ?[<ffffffff810e5fe4>] notify_change+0x104/0x2e0
>> [13450.614037] ?[<ffffffff810ce84f>] do_truncate+0x5f/0x90
>> [13450.614041] ?[<ffffffff810d0002>] ? vfs_write+0x132/0x180
>> [13450.614044] ?[<ffffffff810cef79>] sys_ftruncate+0xe9/0x130
>> [13450.614049] ?[<ffffffff81002dab>] system_call_fastpath+0x16/0x1b
>> [13450.614050] Code: 0f 1f 40 00 eb 88 66 0f 1f 44 00 00 49 8b 84 24 38 ff
>> ?ff ff 48 85 c0 74 1b 48 8b 50 98 49 39 d5 72 12 48 03 50 a8 49 39 d5 73 09
>> ?<0f> 0b eb fe 0f 1f 44 00 00 49 8b 94 24 30 ff ff ff 48 89 55 b8
>> ?[13450.614082] RIP ?[<ffffffff811d9537>]
>> ?btrfs_ordered_update_i_size+0x237/0x3d0 [13450.614087] ?RSP
>> ?<ffff880071355da8>
>> [13450.614090] ---[ end trace 74172209f4d15206 ]---
>
> Sounds like the bug reported here: http://article.gmane.org/gmane.comp.file-
> systems.btrfs/4332/match=btrfs+fails+randomly. Can you try the patch provided
> in that thread?
>
I have sent a patch for this.
http://www.mail-archive.com/[email protected]/msg03686.html

Regards
Yan, Zheng

2010-01-04 09:36:38

by Carlos Mafra

[permalink] [raw]
Subject: Re: 2.6.33-rc2+ bug in fs/btrfs/ordered-data.c:672

On Mo 4.Jan'10 at 12:20:18 +0800, Yan, Zheng wrote:

> > Sounds like the bug reported here: http://article.gmane.org/gmane.comp.file-
> > systems.btrfs/4332/match=btrfs+fails+randomly. Can you try the patch provided
> > in that thread?
> >
> I have sent a patch for this.
> http://www.mail-archive.com/[email protected]/msg03686.html

Thanks for pointing it out, my google search missed that report.

I am already testing that patch, and if you don't hear back from
me than all is fine.

Thanks again.