Kernel oops when running bonnie++ on btrfs

Kernel oops when running bonnie++ on btrfs

[Lee Trager]

I wanted to see how btrfs compares to other filesystems so I have been
running bonnie++ on it. While the results are good(much faster then
ext2) every once in awhile I get a kernel oops. I am testing on xubuntu
8.10 with the 2.6.27-7-686 kernel using the latest git sources. Most of the
time the oops happens within 20min of running bonnie++ but sometimes it
takes a few hours. This happens with and without compression.

To reproduce this bug you can run

while true; do bonnie++ -s 5120 -n 4:524288:0:512; done

Nov 12 22:39:12 Intrepid-btrfs kernel: [ 2531.781731] allocation failed
flags 1, wanted 4096^M
Nov 12 22:39:13 Intrepid-btrfs kernel: [ 2531.781758] space_info has
3822407680 free, is full^M
Nov 12 22:39:13 Intrepid-btrfs kernel: [ 2531.814789] block group
12582912 has 8388608 bytes, 8388608 used 0 pinned 0 reserved^M
Nov 12 22:39:13 Intrepid-btrfs kernel: [ 2531.814837] 0 blocks of free
space at or bigger than bytes is^M
Nov 12 22:39:13 Intrepid-btrfs kernel: [ 2531.814869] block group
424542208 has 790429696 bytes, 790429696 used 0 pinned 0 reserved^M
Nov 12 22:39:13 Intrepid-btrfs kernel: [ 2531.814890] 1 blocks of free
space at or bigger than bytes is^M
Nov 12 22:39:13 Intrepid-btrfs kernel: [ 2531.814893] block group
1214971904 has 790429696 bytes, 790347776 used 0 pinned 0 reserved^M
Nov 12 22:39:13 Intrepid-btrfs kernel: [ 2531.814896] 1 blocks of free
space at or bigger than bytes is^M
Nov 12 22:39:13 Intrepid-btrfs kernel: [ 2531.814898] block group
2005401600 has 790429696 bytes, 790421504 used 0 pinned 0 reserved^M
Nov 12 22:39:13 Intrepid-btrfs kernel: [ 2531.814901] 1 blocks of free
space at or bigger than bytes is^M
Nov 12 22:39:13 Intrepid-btrfs kernel: [ 2531.814903] block group
2795831296 has 790429696 bytes, 4096 used 0 pinned 0 reserved^M
Nov 12 22:39:13 Intrepid-btrfs kernel: [ 2531.814906] 1 blocks of free
space at or bigger than bytes is^M
Nov 12 22:39:13 Intrepid-btrfs kernel: [ 2531.814909] block group
3586260992 has 790429696 bytes, 1867776 used 0 pinned 0 reserved^M
Nov 12 22:39:13 Intrepid-btrfs kernel: [ 2531.814911] 1 blocks of free
space at or bigger than bytes is^M
Nov 12 22:39:13 Intrepid-btrfs kernel: [ 2531.814950] block group
4376690688 has 790429696 bytes, 0 used 0 pinned 0 reserved^M
Nov 12 22:39:13 Intrepid-btrfs kernel: [ 2531.814952] 0 blocks of free
space at or bigger than bytes is^M
Nov 12 22:39:13 Intrepid-btrfs kernel: [ 2531.814955] block group
5167120384 has 790429696 bytes, 0 used 0 pinned 0 reserved^M
Nov 12 22:39:13 Intrepid-btrfs kernel: [ 2531.814958] 0 blocks of free
space at or bigger than bytes is^M
Nov 12 22:39:13 Intrepid-btrfs kernel: [ 2531.814960] block group
5957550080 has 790429696 bytes, 127959040 used 0 pinned 0 reserved^M
Nov 12 22:39:13 Intrepid-btrfs kernel: [ 2531.814963] 0 blocks of free
space at or bigger than bytes is^M
Nov 12 22:39:13 Intrepid-btrfs kernel: [ 2531.814965] block group
6747979776 has 752943104 bytes, 728870912 used 0 pinned 24072192
reserved^M
Nov 12 22:39:13 Intrepid-btrfs kernel: [ 2531.814968] 0 blocks of free
space at or bigger than bytes is^M
Nov 12 22:39:13 Intrepid-btrfs kernel: [ 2531.815588] ------------[ cut
here ]------------^M
Nov 12 22:39:13 Intrepid-btrfs kernel: [ 2531.815960] kernel BUG at
/home/ltrager/btrfs/btrfs-unstable-standalone/extent-tree.c:2437!^M
Nov 12 22:39:13 Intrepid-btrfs kernel: [ 2531.816012] invalid opcode:
0000 [#1] SMP ^M
Nov 12 22:39:13 Intrepid-btrfsNov 12 22:39:13 Intrepid-btrfs kernel: [
2531.816012] ^M
Nov 12 22:39:13 Intrepid-btrfs kernel: [ 2531.816012] Pid: 5193, comm:
btrfs-delalloc- Not tainted (2.6.27-7-generic #1)^M
Nov 12 22:39:13 Intrepid-btrfs kernel: [ 2531.816012] EIP:
0060:[<e08d2b62>] EFLAGS: 00010257 CPU: 0^M
Nov 12 22:39:13 Intrepid-btrfs kernel: [ 2531.816012] EIP is at
__btrfs_reserve_extent+0x3c2/0x480 [btrfs]^M
Nov 12 22:39:13 Intrepid-btrfs kernel: [ 2531.816012] EAX: df72d284 EBX:
dd27c180 ECX: ffffffff EDX: 00000001^M
Nov 12 22:39:13 Intrepid-btrfs kernel: [ 2531.816012] ESI: dd27c1ac EDI:
df72d278 EBP: d80e7de8 ESP: d80e7d74^M
Nov 12 22:39:13 Intrepid-btrfs kernel: [ 2531.816012]  DS: 007b ES: 007b
FS: 00d8 GS: 0000 SS: 0068^M
Nov 12 22:39:13 Intrepid-btrfs kernel: [ 2531.816012] Process
btrfs-delalloc- (pid: 5193, ti=d80e6000 task=d80bcb60
task.ti=d80e6000)^M
Nov 12 22:39:13 Intrepid-btrfs kernel: [ 2531.816012] Stack: e090d750
92360000 00000001 2ce10000 00000000 2b71b000 00000000 00000000 ^M
Nov 12 22:39:13 Intrepid-btrfs kernel: [ 2531.816012]        00000000
016f5000 00000000 00000000 00000000 00000000 00000000 00000001 ^M
Nov 12 22:39:13 Intrepid-btrfs kernel: [ 2531.816012]        00000000
00000000 00000000 00000000 00001000 00000000 dee450a0 df61c000 ^M
Nov 12 22:39:13 Intrepid-btrfs kernel: [ 2531.816012] Call Trace:^M
Nov 12 22:39:13 Intrepid-btrfs kernel: [ 2531.816012]  [<e08d2ea7>] ?
btrfs_reserve_extent+0x77/0xb0 [btrfs]^M
Nov 12 22:39:13 Intrepid-btrfs kernel: [ 2531.816012]  [<e08de767>] ?
cow_file_range+0x227/0x4d0 [btrfs]^M
Nov 12 22:39:13 Intrepid-btrfs kernel: [ 2531.816012]  [<e08dee68>] ?
submit_compressed_extents+0x458/0x4d0 [btrfs]^M
Nov 12 22:39:13 Intrepid-btrfs kernel: [ 2531.816012]  [<c01284cb>] ?
finish_task_switch+0x2b/0xe0^M
Nov 12 22:39:13 Intrepid-btrfs kernel: [ 2531.816012]  [<e08def6b>] ?
async_cow_submit+0x8b/0xa0 [btrfs]^M
Nov 12 22:39:13 Intrepid-btrfs kernel: [ 2531.816012]  [<e0900634>] ?
run_ordered_completions+0x74/0xd0 [btrfs]^M
Nov 12 22:39:13 Intrepid-btrfs kernel: [ 2531.816012]  [<e0900728>] ?
worker_loop+0x98/0x180 [btrfs]^M
Nov 12 22:39:13 Intrepid-btrfs kernel: [ 2531.816012]  [<e0900690>] ?
worker_loop+0x0/0x180 [btrfs]^M
Nov 12 22:39:13 Intrepid-btrfs kernel: [ 2531.816012]  [<c0147141>] ?
kthread+0x41/0x80^M
Nov 12 22:39:13 Intrepid-btrfs kernel: [ 2531.816012]  [<c0147100>] ?
kthread+0x0/0x80^M
Nov 12 22:39:13 Intrepid-btrfs kernel: [ 2531.816012]  [<c0105297>] ?
kernel_thread_helper+0x7/0x10^M
Nov 12 22:39:13 Intrepid-btrfs kernel: [ 2531.816012]
=======================^M
Nov 12 22:39:13 Intrepid-btrfs kernel: [ 2531.816012] Code: 98 aa df 8d
4b 44 89 c8 89 4d f0 e8 e9 ad aa df 8b 7b 38 8b 07 0f 18 00 90 83 c3 38
39 fb 89 5d ec 75 33 8b 45 f0 e8 ae 8e 87 df <0f> 0b eb fe 66 90 8b 90
90 18 00 00 8b 88 78 18 00 00 8b b0 8c ^M
Nov 12 22:39:13 Intrepid-btrfs kernel: [ 2531.816012] EIP: [<e08d2b62>]
__btrfs_reserve_extent+0x3c2/0x480 [btrfs] SS:ESP 0068:d80e7d74^M
Nov 12 22:39:13 Intrepid-btrfs kernel: [ 2531.832531] ---[ end trace
0a75a78f84ed31b6 ]---

Lee

Re: Kernel oops when running bonnie++ on btrfs

[Josef Bacik]

On Thu, Nov 13, 2008 at 01:49:07PM -0500, Lee Trager wrote:
> I wanted to see how btrfs compares to other filesystems so I have been
> running bonnie++ on it. While the results are good(much faster then
> ext2) every once in awhile I get a kernel oops. I am testing on xubuntu
> 8.10 with the 2.6.27-7-686 kernel using the latest git sources. Most of the
> time the oops happens within 20min of running bonnie++ but sometimes it
> takes a few hours. This happens with and without compression.
> 
> To reproduce this bug you can run
> 
> while true; do bonnie++ -s 5120 -n 4:524288:0:512; done
>

Thanks, still tracking down random places where we ENOSPC too soon.  Have you
updated today?  There was a fix that went in earlier today that may help you.  I
wll run with your command and see if I can replicate here and fix it.

Josef
 

Re: Kernel oops when running bonnie++ on btrfs

[Lee Trager]

I updated today and ran the test again, it seems like its still
there but on a different line. Here is an updated log

Nov 14 16:23:42 Intrepid-btrfsc kernel: [ 1295.947414] space info full 1

Nov 14 16:23:45 Intrepid-btrfsc kernel: [ 1299.123999] allocation failed
flags 1, wanted 4096

Nov 14 16:23:45 Intrepid-btrfsc kernel: [ 1299.124047] space_info has
2789093376 free, is full

Nov 14 16:23:45 Intrepid-btrfsc kernel: [ 1299.134507] block group
12582912 has 8388608 bytes, 8388608 used 0 pinned 0 reserved

Nov 14 16:23:45 Intrepid-btrfsc kernel: [ 1299.134552] 0 blocks of free
space at or bigger than bytes is

Nov 14 16:23:45 Intrepid-btrfsc kernel: [ 1299.134579] block group
424542208 has 790429696 bytes, 790429696 used 0 pinned 0 reserved

Nov 14 16:23:45 Intrepid-btrfsc kernel: [ 1299.134602] 1 blocks of free
space at or bigger than bytes is

Nov 14 16:23:45 Intrepid-btrfsc kernel: [ 1299.134604] block group
1214971904 has 790429696 bytes, 0 used 0 pinned 0 reserved

Nov 14 16:23:45 Intrepid-btrfsc kernel: [ 1299.134607] 0 blocks of free
space at or bigger than bytes is

Nov 14 16:23:45 Intrepid-btrfsc kernel: [ 1299.134610] block group
2005401600 has 790429696 bytes, 0 used 0 pinned 0 reserved

Nov 14 16:23:45 Intrepid-btrfsc kernel: [ 1299.134612] 0 blocks of free
space at or bigger than bytes is

Nov 14 16:23:45 Intrepid-btrfsc kernel: [ 1299.134615] block group
2795831296 has 790429696 bytes, 0 used 0 pinned 0 reserved

Nov 14 16:23:45 Intrepid-btrfsc kernel: [ 1299.134617] 0 blocks of free
space at or bigger than bytes is

Nov 14 16:23:45 Intrepid-btrfsc kernel: [ 1299.134619] block group
3586260992 has 790429696 bytes, 372625408 used 0 pinned 0 reserved

Nov 14 16:23:45 Intrepid-btrfsc kernel: [ 1299.134622] 0 blocks of free
space at or bigger than bytes is

Nov 14 16:23:45 Intrepid-btrfsc kernel: [ 1299.134663] block group
4376690688 has 790429696 bytes, 790429696 used 0 pinned 0 reserved

Nov 14 16:23:45 Intrepid-btrfsc kernel: [ 1299.134666] 0 blocks of free
space at or bigger than bytes is

Nov 14 16:23:45 Intrepid-btrfsc kernel: [ 1299.134668] block group
5167120384 has 790429696 bytes, 790429696 used 0 pinned 0 reserved

Nov 14 16:23:45 Intrepid-btrfsc kernel: [ 1299.134671] 0 blocks of free
space at or bigger than bytes is

Nov 14 16:23:45 Intrepid-btrfsc kernel: [ 1299.134674] block group
5957550080 has 790429696 bytes, 783273984 used 0 pinned 7155712 reserved

Nov 14 16:23:46 Intrepid-btrfsc kernel: [ 1299.134676] 0 blocks of free
space at or bigger than bytes is

Nov 14 16:23:46 Intrepid-btrfsc kernel: [ 1299.134679] block group
6747979776 has 752943104 bytes, 751333376 used 0 pinned 1609728 reserved

Nov 14 16:23:46 Intrepid-btrfsc kernel: [ 1299.134682] 0 blocks of free
space at or bigger than bytes is

Nov 14 16:23:46 Intrepid-btrfsc kernel: [ 1299.135276] ------------[ cut
here ]------------

Nov 14 16:23:46 Intrepid-btrfsc kernel: [ 1299.135759] kernel BUG at
/home/ltrager/btrfs/btrfs-unstable-standalone/extent-tree.c:3077!

Nov 14 16:23:46 Intrepid-btrfsc kernel: [ 1299.135997] invalid opcode:
0000 [#1] SMP 

Nov 14 16:23:46 Intrepid-btrfsc kernel: [ 1299.136203] Modules linked
in: af_packet bridge stp bnep rfcomm sco l2cap bluetooth ppdev
cpufreq_userspace cpufreq_stats cpufreq_powersave cpufreq_ondemand
freq_table cpufreq_conservative wmi video output sbs sbshc pci_slot
battery iptable_filter ip_tables x_tables lp evdev psmouse serio_raw
pcspkr parport_pc parport snd_ens1371 gameport snd_ac97_codec ac97_bus
snd_pcm_oss snd_mixer_oss snd_pcm snd_seq_dummy snd_seq_oss snd_seq_midi
snd_rawmidi snd_seq_midi_event snd_seq snd_timer snd_seq_device snd
soundcore snd_page_alloc container i2c_piix4 ac button intel_agp
i2c_core agpgart shpchp pci_hotplug ext2 mbcache sr_mod cdrom sd_mod
crc_t10dif pata_acpi ata_piix sg uhci_hcd ata_generic ehci_hcd pcnet32
mii mptspi mptscsih usbcore mptbase scsi_transport_spi libata scsi_mod
dock thermal processor fan fbcon tileblit font bitblit softcursor fuse
btrfs libcrc32c zlib_deflate

Nov 14 16:23:46 Intrepid-btrfsc kernel: [ 1299.136203] 

Nov 14 16:23:46 Intrepid-btrfsc kernel: [ 1299.136203] Pid: 5305, comm:
btrfs-delalloc- Not tainted (2.6.27-7-generic #1)

Nov 14 16:23:46 Intrepid-btrfsc kernel: [ 1299.136203] EIP:
0060:[<e08cd712>] EFLAGS: 00010257 CPU: 0

Nov 14 16:23:46 Intrepid-btrfsc kernel: [ 1299.136203] EIP is at
__btrfs_reserve_extent+0x3c2/0x480 [btrfs]

Nov 14 16:23:46 Intrepid-btrfsc kernel: [ 1299.136203] EAX: df7a2c44
EBX: d81936c0 ECX: ffffffff EDX: 00000001

Nov 14 16:23:46 Intrepid-btrfsc kernel: [ 1299.136203] ESI: d81936ec
EDI: df7a2c38 EBP: d82dbde8 ESP: d82dbd74

Nov 14 16:23:46 Intrepid-btrfsc kernel: [ 1299.136203]  DS: 007b ES:
007b FS: 00d8 GS: 0000 SS: 0068

Nov 14 16:23:46 Intrepid-btrfsc kernel: [ 1299.136203] Process
btrfs-delalloc- (pid: 5305, ti=d82da000 task=d81e1920 task.ti=d82da000)

Nov 14 16:23:46 Intrepid-btrfsc kernel: [ 1299.136203] Stack: e090ab84
92360000 00000001 2ce10000 00000000 2cc87000 00000000 00000000 

Nov 14 16:23:46 Intrepid-btrfsc kernel: [ 1299.136203]        00000000
00189000 00000000 00000000 00000000 00000000 00000000 00000001 

Nov 14 16:23:46 Intrepid-btrfsc kernel: [ 1299.136203]        00000000
00000000 00000000 00000000 00001000 00000000 dee44190 df6aa000 

Nov 14 16:23:46 Intrepid-btrfsc kernel: [ 1299.136203] Call Trace:

Nov 14 16:23:46 Intrepid-btrfsc kernel: [ 1299.136203]  [<e08cda57>] ?
btrfs_reserve_extent+0x77/0xb0 [btrfs]

Nov 14 16:23:46 Intrepid-btrfsc kernel: [ 1299.136203]  [<e08dae37>] ?
cow_file_range+0x227/0x4d0 [btrfs]

Nov 14 16:23:46 Intrepid-btrfsc kernel: [ 1299.136203]  [<e08db538>] ?
submit_compressed_extents+0x458/0x4d0 [btrfs]

Nov 14 16:23:46 Intrepid-btrfsc kernel: [ 1299.136203]  [<c01284cb>] ?
finish_task_switch+0x2b/0xe0

Nov 14 16:23:46 Intrepid-btrfsc kernel: [ 1299.136203]  [<e08db63b>] ?
async_cow_submit+0x8b/0xa0 [btrfs]

Nov 14 16:23:46 Intrepid-btrfsc kernel: [ 1299.136203]  [<e08fcd04>] ?
run_ordered_completions+0x74/0xd0 [btrfs]

Nov 14 16:23:46 Intrepid-btrfsc kernel: [ 1299.136203]  [<e08fcdf8>] ?
worker_loop+0x98/0x180 [btrfs]

Nov 14 16:23:46 Intrepid-btrfsc kernel: [ 1299.136203]  [<e08fcd60>] ?
worker_loop+0x0/0x180 [btrfs]

Nov 14 16:23:46 Intrepid-btrfsc kernel: [ 1299.136203]  [<c0147141>] ?
kthread+0x41/0x80

Nov 14 16:23:46 Intrepid-btrfsc kernel: [ 1299.136203]  [<c0147100>] ?
kthread+0x0/0x80

Nov 14 16:23:46 Intrepid-btrfsc kernel: [ 1299.136203]  [<c0105297>] ?
kernel_thread_helper+0x7/0x10

Nov 14 16:23:46 Intrepid-btrfsc kernel: [ 1299.136203]
=======================

Nov 14 16:23:46 Intrepid-btrfsc kernel: [ 1299.136203] Code: ec aa df 8d
4b 44 89 c8 89 4d f0 e8 39 02 ab df 8b 7b 38 8b 07 0f 18 00 90 83 c3 38
39 fb 89 5d ec 75 33 8b 45 f0 e8 fe e2 87 df <0f> 0b eb fe 66 90 8b 90
90 18 00 00 8b 88 78 18 00 00 8b b0 8c 

Nov 14 16:23:46 Intrepid-btrfsc kernel: [ 1299.136203] EIP: [<e08cd712>]
__btrfs_reserve_extent+0x3c2/0x480 [btrfs] SS:ESP 0068:d82dbd74

Nov 14 16:23:46 Intrepid-btrfsc kernel: [ 1299.159252] ---[ end trace
ae4786bfdd8753ad ]---?
On Thu, Nov 13, 2008 at 02:20:05PM -0500, Josef Bacik wrote:
> On Thu, Nov 13, 2008 at 01:49:07PM -0500, Lee Trager wrote:
> > I wanted to see how btrfs compares to other filesystems so I have been
> > running bonnie++ on it. While the results are good(much faster then
> > ext2) every once in awhile I get a kernel oops. I am testing on xubuntu
> > 8.10 with the 2.6.27-7-686 kernel using the latest git sources. Most of the
> > time the oops happens within 20min of running bonnie++ but sometimes it
> > takes a few hours. This happens with and without compression.
> > 
> > To reproduce this bug you can run
> > 
> > while true; do bonnie++ -s 5120 -n 4:524288:0:512; done
> >
> 
> Thanks, still tracking down random places where we ENOSPC too soon.  Have you
> updated today?  There was a fix that went in earlier today that may help you.  I
> wll run with your command and see if I can replicate here and fix it.
> 
> Josef
>  

Re: Kernel oops when running bonnie++ on btrfs

[Martin Bürger]

On Thursday 13 November 2008, Josef Bacik wrote:
> Thanks, still tracking down random places where we ENOSPC too
> soon.
Probably something I've just hit as well [1].

[1] http://rafb.net/p/kvYLj917.html

Best wishes,
--=20
Martin B=FCrger
1024D/27C9019B@www.edu.uni-klu.ac.at/~mbuerger/key.asc
Key fingerprint =3D D10D 97EF 0C32 B337 5A12  0B6C 2D47 7575 27C9 019B
--
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

Re: Kernel oops when running bonnie++ on btrfs

[Chris Mason]

On Fri, 2008-11-14 at 17:47 +0100, Martin B=C3=BCrger wrote:
> On Thursday 13 November 2008, Josef Bacik wrote:
> > Thanks, still tracking down random places where we ENOSPC too
> > soon.
> Probably something I've just hit as well [1].
>=20
> [1] http://rafb.net/p/kvYLj917.html

Thanks, they do look similar.  Did you mount with -o ssd?

-chris


--
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

Re: Kernel oops when running bonnie++ on btrfs

[Martin Bürger]

On Friday 14 November 2008, Chris Mason wrote:
> On Fri, 2008-11-14 at 17:47 +0100, Martin B=C3=BCrger wrote:
> > On Thursday 13 November 2008, Josef Bacik wrote:
> > > Thanks, still tracking down random places where we ENOSPC too
> > > soon.
> >
> > Probably something I've just hit as well [1].
> >
> > [1] http://rafb.net/p/kvYLj917.html
>
> Thanks, they do look similar.  Did you mount with -o ssd?
No, no additional options at all.

--=20
Martin B=C3=BCrger
1024D/27C9019B@www.edu.uni-klu.ac.at/~mbuerger/key.asc
Key fingerprint =3D D10D 97EF 0C32 B337 5A12  0B6C 2D47 7575 27C9 019B
--
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

Re: Kernel oops when running bonnie++ on btrfs

[Josef Bacik]

How big is your fs?  Thanks,

Josef

Re: Kernel oops when running bonnie++ on btrfs

[Lee Trager]

7539M

Lee

On Fri, Nov 14, 2008 at 03:26:37PM -0500, Josef Bacik wrote:
> How big is your fs?  Thanks,
> 
> Josef