Bug 788064 - reproducible kernel BUG at fs/btrfs/inode.c:1668!
Summary: reproducible kernel BUG at fs/btrfs/inode.c:1668!
Keywords:
Status: CLOSED INSUFFICIENT_DATA
Alias: None
Product: Fedora
Classification: Fedora
Component: kernel
Version: 19
Hardware: Unspecified
OS: Unspecified
unspecified
unspecified
Target Milestone: ---
Assignee: Zach Brown
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2012-02-07 11:20 UTC by Tomasz Torcz
Modified: 2015-05-18 01:40 UTC (History)
6 users (show)

Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed: 2013-05-15 19:18:00 UTC
Type: ---
Embargoed:


Attachments (Terms of Use)

Description Tomasz Torcz 2012-02-07 11:20:27 UTC
Description of problem:
I have 4 1TB disk in raid10. Everytime I run following fio load, after few hours I got BUG() like below. Btrfs mounted with compress=lzo,space_cache

#v+
[write-test]                                                                                                                                                                            
rw=randwrite                                        
ioengine=libaio                                                                                                                                                                         
blocksize=4k                                                                                                                                                                            
iodepth=32                                                                                                                                                                              
size=1512G   
#v-

[64354.305737] ------------[ cut here ]------------
[64354.306009] kernel BUG at fs/btrfs/inode.c:1668!
[64354.306009] invalid opcode: 0000 [#1] SMP 
[64354.306009] CPU 1 
[64354.306009] Modules linked in: lockd bnep bluetooth rfkill snd_intel8x0 snd_ac97_codec ac97_bus snd_seq snd_seq_device ppdev snd_pcm snd_timer snd soundcore iTCO_wdt tg3 parport_pc iTCO_vendor_support parport snd_page_alloc dcdbas serio_raw i2c_i801 microcode sunrpc uinput aoe btrfs zlib_deflate libcrc32c sata_promise i915 drm_kms_helper drm i2c_algo_bit i2c_core video [last unloaded: scsi_wait_scan]
[64354.330470] 
[64354.330470] Pid: 5149, comm: btrfs-endio-wri Tainted: G        W    3.3.0-0.rc2.git3.2.fc17.x86_64 #1 Dell Inc.                 OptiPlex GX620               /0FH884
[64354.330470] RIP: 0010:[<ffffffffa0125751>]  [<ffffffffa0125751>] insert_reserved_file_extent.constprop.50+0x251/0x260 [btrfs]
[64354.330470] RSP: 0018:ffff8800757ffbd0  EFLAGS: 00010286
[64354.330470] RDX: 0000000000000000 RSI: ffffea00033c3700 RDI: 0000000000000246
[64354.330470] RBP: ffff8800757ffc60 R08: ffff8800cf0dc760 R09: 0000000100110002
[64354.330470] R10: ffff8800cf0dc7f0 R11: 0000000000000000 R12: ffff8800a453a290
[64354.330470] R13: ffff8800cf0dc1d8 R14: ffff8800a3a69868 R15: 0000002e8f0b2000
[64354.330470] FS:  0000000000000000(0000) GS:ffff8800db000000(0000) knlGS:0000000000000000
[64354.330470] CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
[64354.330470] CR2: 0000003238285240 CR3: 0000000023ba8000 CR4: 00000000000006e0
[64354.330470] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[64354.330470] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
[64354.330470] Process btrfs-endio-wri (pid: 5149, threadinfo ffff8800757fe000, task ffff880097978000)
[64354.330470] Stack:
[64354.330470]  00ff8800757ffc00 0000000000001000 0000001d7ab1f000 ffff8800a453a290
[64354.330470]  0000000000001000 ffff8800cf207a90 ffff8800757ffc50 ffffffffa0123455
[64354.330470]  ffff8800757ffc30 0000000000000000 00000000000000cc ffff8800a3a69868
[64354.330470] Call Trace:
[64354.330470]  [<ffffffffa0123455>] ? start_transaction+0x85/0x3b0 [btrfs]
[64354.330470]  [<ffffffffa0128ef2>] btrfs_finish_ordered_io+0x232/0x350 [btrfs]
[64354.330470]  [<ffffffffa012905c>] btrfs_writepage_end_io_hook+0x4c/0x150 [btrfs]
[64354.330470]  [<ffffffffa013eea2>] end_bio_extent_writepage+0x122/0x170 [btrfs]
[64354.330470]  [<ffffffff811f3c5d>] bio_endio+0x1d/0x40
[64354.330470]  [<ffffffffa011ab44>] end_workqueue_fn+0x64/0x150 [btrfs]
[64354.330470]  [<ffffffffa014f5a9>] worker_loop+0x149/0x5d0 [btrfs]
[64354.330470]  [<ffffffffa014f460>] ? btrfs_queue_worker+0x310/0x310 [btrfs]
[64354.330470]  [<ffffffff81089ad7>] kthread+0xb7/0xc0
[64354.330470]  [<ffffffff810cd07d>] ? trace_hardirqs_on+0xd/0x10
[64354.330470]  [<ffffffff816a77b4>] kernel_thread_helper+0x4/0x10
[64354.330470]  [<ffffffff8169d6b0>] ? _raw_spin_unlock_irq+0x30/0x50
[64354.330470]  [<ffffffff8169dbb4>] ? retint_restore_args+0x13/0x13
[64354.330470]  [<ffffffff81089a20>] ? kthread_worker_fn+0x1a0/0x1a0
[64354.330470]  [<ffffffff816a77b0>] ? gs_change+0x13/0x13
[64354.330470] Code: ff 84 0f 85 67 fe ff ff e9 5e fe ff ff 0f 1f 44 00 00 41 80 be 78 fb ff ff 84 75 9a eb 94 0f 1f 40 00 b8 f4 ff ff ff eb b9 0f 0b <0f> 0b 0f 0b 66 66 2e 0f 1f 84 00 00 00 00 00 55 48 89 e5 48 83 
[64354.330470] RIP  [<ffffffffa0125751>] insert_reserved_file_extent.constprop.50+0x251/0x260 [btrfs]
[64354.330470]  RSP <ffff8800757ffbd0>
[64354.557410] ---[ end trace 6288379729f3c564 ]---
[64354.650352] ------------[ cut here ]------------
[64354.651007] kernel BUG at fs/btrfs/inode.c:1668!
[64354.651007] invalid opcode: 0000 [#2] SMP 
[64354.651007] CPU 0 
[64354.651007] Modules linked in: lockd bnep bluetooth rfkill snd_intel8x0 snd_ac97_codec ac97_bus snd_seq snd_seq_device ppdev snd_pcm snd_timer snd soundcore iTCO_wdt tg3 parport_pc iTCO_vendor_support parport snd_page_alloc dcdbas serio_raw i2c_i801 microcode sunrpc uinput aoe btrfs zlib_deflate libcrc32c sata_promise i915 drm_kms_helper drm i2c_algo_bit i2c_core video [last unloaded: scsi_wait_scan]
[64354.651007] 
[64354.651007] Pid: 5054, comm: btrfs-endio-wri Tainted: G      D W    3.3.0-0.rc2.git3.2.fc17.x86_64 #1 Dell Inc.                 OptiPlex GX620               /0FH884
[64354.651007] RIP: 0010:[<ffffffffa0125751>]  [<ffffffffa0125751>] insert_reserved_file_extent.constprop.50+0x251/0x260 [btrfs]
[64354.651007] RSP: 0000:ffff88008a601bd0  EFLAGS: 00010286
[64354.651007] RDX: 0000000000000000 RSI: ffffea00033c3700 RDI: 0000000000000246
[64354.651007] RBP: ffff88008a601c60 R08: ffff8800cf0dc760 R09: 0000000100110003
[64354.651007] R10: ffff8800cf0dc7f0 R11: 0000000000000000 R12: ffff8800a453a290
[64354.651007] R13: ffff8800cf0dc3b0 R14: ffff8800a3a69868 R15: 0000002ea0ad9000
[64354.651007] FS:  0000000000000000(0000) GS:ffff8800dae00000(0000) knlGS:0000000000000000
[64354.651007] CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
[64354.651007] CR2: 0000003238a5d1d0 CR3: 00000000abeaf000 CR4: 00000000000006f0
[64354.651007] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[64354.651007] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
[64354.651007] Process btrfs-endio-wri (pid: 5054, threadinfo ffff88008a600000, task ffff88008a852680)
[64354.651007] Stack:
[64354.651007]  00ff88008a601c00 0000000000001000 0000001d7ab2f000 ffff8800a453a290
[64354.651007]  0000000000001000 ffff8800cf207450 ffff88008a601c50 ffffffffa0123455
[64354.651007]  ffff88008a601c30 0000000000000000 00000000000000cc ffff8800a3a69868
[64354.651007] Call Trace:
[64354.651007]  [<ffffffffa0123455>] ? start_transaction+0x85/0x3b0 [btrfs]
[64354.651007]  [<ffffffffa0128ef2>] btrfs_finish_ordered_io+0x232/0x350 [btrfs]
[64354.651007]  [<ffffffffa012905c>] btrfs_writepage_end_io_hook+0x4c/0x150 [btrfs]
[64354.651007]  [<ffffffffa013eea2>] end_bio_extent_writepage+0x122/0x170 [btrfs]
[64354.651007]  [<ffffffff811f3c5d>] bio_endio+0x1d/0x40
[64354.651007]  [<ffffffffa011ab44>] end_workqueue_fn+0x64/0x150 [btrfs]
[64354.651007]  [<ffffffffa014f5a9>] worker_loop+0x149/0x5d0 [btrfs]
[64354.651007]  [<ffffffffa014f460>] ? btrfs_queue_worker+0x310/0x310 [btrfs]
[64354.651007]  [<ffffffff81089ad7>] kthread+0xb7/0xc0
[64354.651007]  [<ffffffff810cd07d>] ? trace_hardirqs_on+0xd/0x10
[64354.651007]  [<ffffffff816a77b4>] kernel_thread_helper+0x4/0x10
[64354.651007]  [<ffffffff8169d6b0>] ? _raw_spin_unlock_irq+0x30/0x50
[64354.651007]  [<ffffffff8169dbb4>] ? retint_restore_args+0x13/0x13
[64354.651007]  [<ffffffff81089a20>] ? kthread_worker_fn+0x1a0/0x1a0
[64354.651007]  [<ffffffff816a77b0>] ? gs_change+0x13/0x13
[64354.651007] Code: ff 84 0f 85 67 fe ff ff e9 5e fe ff ff 0f 1f 44 00 00 41 80 be 78 fb ff ff 84 75 9a eb 94 0f 1f 40 00 b8 f4 ff ff ff eb b9 0f 0b <0f> 0b 0f 0b 66 66 2e 0f 1f 84 00 00 00 00 00 55 48 89 e5 48 83 
[64354.651007] RIP  [<ffffffffa0125751>] insert_reserved_file_extent.constprop.50+0x251/0x260 [btrfs]
[64354.651007]  RSP <ffff88008a601bd0>
[64354.820765] ---[ end trace 6288379729f3c565 ]---
[64354.930890] ------------[ cut here ]------------
[64354.931006] kernel BUG at fs/btrfs/inode.c:1668!
[64354.931006] invalid opcode: 0000 [#3] SMP 
[64354.931006] CPU 0 
[64354.931006] Modules linked in: lockd bnep bluetooth rfkill snd_intel8x0 snd_ac97_codec ac97_bus snd_seq snd_seq_device ppdev snd_pcm snd_timer snd soundcore iTCO_wdt tg3 parport_pc iTCO_vendor_support parport snd_page_alloc dcdbas serio_raw i2c_i801 microcode sunrpc uinput aoe btrfs zlib_deflate libcrc32c sata_promise i915 drm_kms_helper drm i2c_algo_bit i2c_core video [last unloaded: scsi_wait_scan]
[64354.931006] 
[64354.931006] Pid: 31070, comm: btrfs-endio-wri Tainted: G      D W    3.3.0-0.rc2.git3.2.fc17.x86_64 #1 Dell Inc.                 OptiPlex GX620               /0FH884
[64354.931006] RIP: 0010:[<ffffffffa0125751>]  [<ffffffffa0125751>] insert_reserved_file_extent.constprop.50+0x251/0x260 [btrfs]
[64354.931006] RSP: 0000:ffff88005e5c1bd0  EFLAGS: 00010286
[64354.931006] RDX: 0000000000000000 RSI: ffffea00033c3700 RDI: 0000000000000246
[64354.931006] RBP: ffff88005e5c1c60 R08: ffff8800cf0dcb10 R09: 0000000100110004
[64354.931006] R10: ffff8800cf0dcba0 R11: 0000000000000000 R12: ffff8800a453a290
[64354.931006] R13: ffff8800cf0dd620 R14: ffff8800a3a69868 R15: 0000002ed4e12000
[64354.931006] FS:  0000000000000000(0000) GS:ffff8800dae00000(0000) knlGS:0000000000000000
[64354.931006] CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
[64354.931006] CR2: 0000003238a5d1d0 CR3: 00000000abeaf000 CR4: 00000000000006f0
[64354.931006] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[64354.931006] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
[64354.931006] Process btrfs-endio-wri (pid: 31070, threadinfo ffff88005e5c0000, task ffff880000198000)
[64354.931006] Stack:
[64354.931006]  00ff88005e5c1c00 0000000000001000 000000129838f000 ffff8800a453a290
[64354.931006]  0000000000001000 ffff8800cf2064b0 ffff88005e5c1c50 ffffffffa0123455
[64354.931006]  ffff88005e5c1c30 0000000000000000 00000000000000cc ffff8800a3a69868
[64354.931006] Call Trace:
[64354.931006]  [<ffffffffa0123455>] ? start_transaction+0x85/0x3b0 [btrfs]
[64354.931006]  [<ffffffffa0128ef2>] btrfs_finish_ordered_io+0x232/0x350 [btrfs]
[64354.931006]  [<ffffffffa012905c>] btrfs_writepage_end_io_hook+0x4c/0x150 [btrfs]
[64354.931006]  [<ffffffffa013eea2>] end_bio_extent_writepage+0x122/0x170 [btrfs]
[64354.931006]  [<ffffffff811f3c5d>] bio_endio+0x1d/0x40
[64354.931006]  [<ffffffffa011ab44>] end_workqueue_fn+0x64/0x150 [btrfs]
[64354.931006]  [<ffffffffa014f5a9>] worker_loop+0x149/0x5d0 [btrfs]
[64354.931006]  [<ffffffffa014f460>] ? btrfs_queue_worker+0x310/0x310 [btrfs]
[64354.931006]  [<ffffffff81089ad7>] kthread+0xb7/0xc0
[64354.931006]  [<ffffffff810cd07d>] ? trace_hardirqs_on+0xd/0x10
[64354.931006]  [<ffffffff816a77b4>] kernel_thread_helper+0x4/0x10
[64354.931006]  [<ffffffff8169d6b0>] ? _raw_spin_unlock_irq+0x30/0x50
[64354.931006]  [<ffffffff8169dbb4>] ? retint_restore_args+0x13/0x13
[64354.931006]  [<ffffffff81089a20>] ? kthread_worker_fn+0x1a0/0x1a0
[64354.931006]  [<ffffffff816a77b0>] ? gs_change+0x13/0x13
[64354.931006] Code: ff 84 0f 85 67 fe ff ff e9 5e fe ff ff 0f 1f 44 00 00 41 80 be 78 fb ff ff 84 75 9a eb 94 0f 1f 40 00 b8 f4 ff ff ff eb b9 0f 0b <0f> 0b 0f 0b 66 66 2e 0f 1f 84 00 00 00 00 00 55 48 89 e5 48 83 
[64354.931006] RIP  [<ffffffffa0125751>] insert_reserved_file_extent.constprop.50+0x251/0x260 [btrfs]
[64354.931006]  RSP <ffff88005e5c1bd0>
[64355.103531] ---[ end trace 6288379729f3c566 ]---
[64355.214974] ------------[ cut here ]------------
[64355.215006] kernel BUG at fs/btrfs/inode.c:1668!
[64355.215006] invalid opcode: 0000 [#4] SMP 
[64355.215006] CPU 0 
[64355.215006] Modules linked in: lockd bnep bluetooth rfkill snd_intel8x0 snd_ac97_codec ac97_bus snd_seq snd_seq_device ppdev snd_pcm snd_timer snd soundcore iTCO_wdt tg3 parport_pc iTCO_vendor_support parport snd_page_alloc dcdbas serio_raw i2c_i801 microcode sunrpc uinput aoe btrfs zlib_deflate libcrc32c sata_promise i915 drm_kms_helper drm i2c_algo_bit i2c_core video [last unloaded: scsi_wait_scan]
[64355.215006] 
[64355.215006] Pid: 31073, comm: btrfs-endio-wri Tainted: G      D W    3.3.0-0.rc2.git3.2.fc17.x86_64 #1 Dell Inc.                 OptiPlex GX620               /0FH884
[64355.215006] RIP: 0010:[<ffffffffa0125751>]  [<ffffffffa0125751>] insert_reserved_file_extent.constprop.50+0x251/0x260 [btrfs]
[64355.215006] RSP: 0000:ffff88002b969bd0  EFLAGS: 00010286
[64355.215006] RDX: 0000000000000000 RSI: ffffea00033c3700 RDI: 0000000000000246
[64355.215006] RBP: ffff88002b969c60 R08: ffff8800cf0dc938 R09: 0000000100110005
[64355.215006] R10: ffff8800cf0dc9c8 R11: 0000000000000000 R12: ffff8800a453a290
[64355.215006] R13: ffff8800cf0dcb10 R14: ffff8800a3a69868 R15: 0000002eeafd6000
[64355.215006] FS:  0000000000000000(0000) GS:ffff8800dae00000(0000) knlGS:0000000000000000
[64355.215006] CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
[64355.215006] CR2: 0000003238a5d1d0 CR3: 00000000abeaf000 CR4: 00000000000006f0
[64355.215006] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[64355.215006] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
[64355.215006] Process btrfs-endio-wri (pid: 31073, threadinfo ffff88002b968000, task ffff880097044d00)
[64355.215006] Stack:
[64355.215006]  00ff88002b969c00 0000000000001000 0000001d7ab3f000 ffff8800a453a290
[64355.215006]  0000000000001000 ffff8800cf206190 ffff88002b969c50 ffffffffa0123455
[64355.215006]  ffff88002b969c30 0000000000000000 00000000000000cc ffff8800a3a69868
[64355.215006] Call Trace:
[64355.215006]  [<ffffffffa0123455>] ? start_transaction+0x85/0x3b0 [btrfs]
[64355.215006]  [<ffffffffa0128ef2>] btrfs_finish_ordered_io+0x232/0x350 [btrfs]
[64355.215006]  [<ffffffffa012905c>] btrfs_writepage_end_io_hook+0x4c/0x150 [btrfs]
[64355.215006]  [<ffffffffa013eea2>] end_bio_extent_writepage+0x122/0x170 [btrfs]
[64355.215006]  [<ffffffff811f3c5d>] bio_endio+0x1d/0x40
[64355.215006]  [<ffffffffa011ab44>] end_workqueue_fn+0x64/0x150 [btrfs]
[64355.215006]  [<ffffffffa014f5a9>] worker_loop+0x149/0x5d0 [btrfs]
[64355.215006]  [<ffffffffa014f460>] ? btrfs_queue_worker+0x310/0x310 [btrfs]
[64355.215006]  [<ffffffff81089ad7>] kthread+0xb7/0xc0
[64355.215006]  [<ffffffff810cd07d>] ? trace_hardirqs_on+0xd/0x10
[64355.215006]  [<ffffffff816a77b4>] kernel_thread_helper+0x4/0x10
[64355.215006]  [<ffffffff8169d6b0>] ? _raw_spin_unlock_irq+0x30/0x50
[64355.215006]  [<ffffffff8169dbb4>] ? retint_restore_args+0x13/0x13
[64355.215006]  [<ffffffff81089a20>] ? kthread_worker_fn+0x1a0/0x1a0
[64355.215006]  [<ffffffff816a77b0>] ? gs_change+0x13/0x13
[64355.215006] Code: ff 84 0f 85 67 fe ff ff e9 5e fe ff ff 0f 1f 44 00 00 41 80 be 78 fb ff ff 84 75 9a eb 94 0f 1f 40 00 b8 f4 ff ff ff eb b9 0f 0b <0f> 0b 0f 0b 66 66 2e 0f 1f 84 00 00 00 00 00 55 48 89 e5 48 83 
[64355.215006] RIP  [<ffffffffa0125751>] insert_reserved_file_extent.constprop.50+0x251/0x260 [btrfs]
[64355.215006]  RSP <ffff88002b969bd0>
[64355.390309] ---[ end trace 6288379729f3c567 ]---
[64355.390512] btrfs-endio-wri used greatest stack depth: 1848 bytes left


Version-Release number of selected component (if applicable):
It's fedora16 with F17's latest kernel, currently 3.3.0-0.rc2.git3.2.fc17.x86_64

How reproducible:
Always after few hours.

Label: 'duo'  uuid: 94b52e73-92a0-481f-a809-4acd24f83d93
	Total devices 4 FS bytes used 1.50TB
	devid    1 size 931.51GB used 931.51GB path /dev/sdb
	devid    2 size 931.51GB used 806.02GB path /dev/sdc
	devid    3 size 931.51GB used 931.51GB path /dev/sdd
	devid    4 size 931.51GB used 931.51GB path /dev/sde


btrfs f df /mnt/raid10test/
Data, RAID1: total=1.75TB, used=1.50TB
System, RAID1: total=16.00MB, used=260.00KB
System: total=4.00MB, used=0.00
Metadata, RAID1: total=3.50GB, used=3.25GB

# LANG=C ls -lh /mnt/raid10test/; LANG=C df -h /mnt/raid10test/
total 1.5T
-rw-r--r--. 1 root root 1.5T Feb  7 03:49 write-test.1.0

Filesystem      Size  Used Avail Use% Mounted on
/dev/sdb        3.7T  3.1T  517G  86% /mnt/raid10test

Comment 1 Fedora End Of Life 2013-04-03 18:05:35 UTC
This bug appears to have been reported against 'rawhide' during the Fedora 19 development cycle.
Changing version to '19'.

(As we did not run this process for some time, it could affect also pre-Fedora 19 development
cycle bugs. We are very sorry. It will help us with cleanup during Fedora 19 End Of Life. Thank you.)

More information and reason for this action is here:
https://fedoraproject.org/wiki/BugZappers/HouseKeeping/Fedora19

Comment 2 Dave Jones 2013-05-15 18:52:34 UTC
over a year with no progress..

Tomasz, is this still reproducible for you ?

Comment 3 Tomasz Torcz 2013-05-15 19:18:00 UTC
Nope, I no longer have access to system in question. Let's clean this up.


Note You need to log in before you can comment on or make changes to this bug.