bcache bug / fs freeze on heavy IO

bcache bug / fs freeze on heavy IO

[Thomas Klaube]

Hi,

(I have sent this also to linux-kernel by mistake)

while testing/benchmarking with fio on a bcache backed ext4 fs I see
this dmesg output. System is ubuntu 14.04.1 but with vanilla Kernel 3.16.1:

Aug 22 00:57:01 ubuntu kernel: [19115.694955] ------------[ cut here ]------------
Aug 22 00:57:01 ubuntu kernel: [19115.695519] kernel BUG at drivers/md/bcache/btree.c:2053!
Aug 22 00:57:01 ubuntu kernel: [19115.696066] invalid opcode: 0000 [#1] SMP 
Aug 22 00:57:01 ubuntu kernel: [19115.696619] Modules linked in: xfs libcrc32c usb_storage x86_pkg_temp_thermal intel_powerclamp coretemp kvm_intel kvm crct10dif_pclmul crc32_pclmul ast ghash_clmulni_intel aesni_intel aes_x86_64 syscopyarea sysfillrect sysimgblt glue_helper mei_me mei drm_kms_helper bonding ttm lpc_ich lrw gf128mul ipmi_si ablk_helper drm video shpchp cryptd acpi_pad hid_generic usbhid hid btrfs xor raid6_pq bcache ses enclosure megaraid_sas e1000e igb i2c_algo_bit dca ptp pps_core [last unloaded: usb_storage]
Aug 22 00:57:01 ubuntu kernel: [19115.699123] CPU: 3 PID: 274 Comm: bcache_gc Not tainted 3.16.1 #4
Aug 22 00:57:01 ubuntu kernel: [19115.699756] Hardware name: Supermicro X10SLM-F/X10SLM-F, BIOS 2.0 04/24/2014
Aug 22 00:57:01 ubuntu kernel: [19115.700387] task: ffff880404d59920 ti: ffff8803cd320000 task.ti: ffff8803cd320000
Aug 22 00:57:01 ubuntu kernel: [19115.701022] RIP: 0010:[<ffffffffa01be195>]  [<ffffffffa01be195>] btree_split+0x4d5/0x6c0 [bcache]
Aug 22 00:57:01 ubuntu kernel: [19115.701670] RSP: 0018:ffff8803cd3238d8  EFLAGS: 00010283
Aug 22 00:57:01 ubuntu kernel: [19115.702305] RAX: ffff8803cd323970 RBX: ffff88030e82e400 RCX: ffffffffa01d6660
Aug 22 00:57:01 ubuntu kernel: [19115.702942] RDX: 0000000000000000 RSI: 0000000000000200 RDI: ffff8803cd323870
Aug 22 00:57:01 ubuntu kernel: [19115.703577] RBP: ffff8803cd3239e8 R08: 0000000000000000 R09: 0000000000000003
Aug 22 00:57:01 ubuntu kernel: [19115.704205] R10: 0000000000000004 R11: 0000000000000005 R12: ffff8800d7584400
Aug 22 00:57:01 ubuntu kernel: [19115.704829] R13: 0000000000000000 R14: ffff88030e82e4d0 R15: ffff8803cd323e28
Aug 22 00:57:01 ubuntu kernel: [19115.705469] FS:  0000000000000000(0000) GS:ffff88041fd80000(0000) knlGS:0000000000000000
Aug 22 00:57:01 ubuntu kernel: [19115.706085] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
Aug 22 00:57:01 ubuntu kernel: [19115.706697] CR2: 00007f3b3938c000 CR3: 0000000001c13000 CR4: 00000000001407e0
Aug 22 00:57:01 ubuntu kernel: [19115.707310] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
Aug 22 00:57:01 ubuntu kernel: [19115.707915] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Aug 22 00:57:01 ubuntu kernel: [19115.708510] Stack:
Aug 22 00:57:01 ubuntu kernel: [19115.709107]  ffff8803cd3238f0 ffff8800d7584498 0000000000000000 ffff8803cd323b20
Aug 22 00:57:01 ubuntu kernel: [19115.709705]  00001162b81ec3bd 0000000000000000 ffff880404d59920 0000000000000000
Aug 22 00:57:01 ubuntu kernel: [19115.710303]  0000000000000000 0000000000000000 00000000a0000001 ffff8803cd323940
Aug 22 00:57:01 ubuntu kernel: [19115.710894] Call Trace:
Aug 22 00:57:01 ubuntu kernel: [19115.711474]  [<ffffffff810a3a94>] ? arch_vtime_task_switch+0x94/0xa0
Aug 22 00:57:01 ubuntu kernel: [19115.712061]  [<ffffffff810a3add>] ? vtime_common_task_switch+0x3d/0x40
Aug 22 00:57:01 ubuntu kernel: [19115.712643]  [<ffffffff8109c528>] ? finish_task_switch+0x128/0x180
Aug 22 00:57:01 ubuntu kernel: [19115.713217]  [<ffffffffa01be62a>] bch_btree_insert_node+0x2aa/0x3b0 [bcache]
Aug 22 00:57:01 ubuntu kernel: [19115.713791]  [<ffffffffa01bee14>] btree_gc_coalesce.isra.28+0x6e4/0x870 [bcache]
Aug 22 00:57:01 ubuntu kernel: [19115.714363]  [<ffffffffa01bf2b1>] btree_gc_recurse+0x1b1/0x300 [bcache]
Aug 22 00:57:01 ubuntu kernel: [19115.714927]  [<ffffffffa01bf19e>] btree_gc_recurse+0x9e/0x300 [bcache]
Aug 22 00:57:01 ubuntu kernel: [19115.715516]  [<ffffffffa01bf9fb>] bch_btree_gc+0x42b/0x5b0 [bcache]
Aug 22 00:57:01 ubuntu kernel: [19115.716063]  [<ffffffff810b34e0>] ? prepare_to_wait_event+0x100/0x100
Aug 22 00:57:01 ubuntu kernel: [19115.716605]  [<ffffffffa01bfbb8>] bch_gc_thread+0x38/0x120 [bcache]
Aug 22 00:57:01 ubuntu kernel: [19115.717155]  [<ffffffffa01bfb80>] ? bch_btree_gc+0x5b0/0x5b0 [bcache]
Aug 22 00:57:01 ubuntu kernel: [19115.717706]  [<ffffffff8108fb92>] kthread+0xd2/0xf0
Aug 22 00:57:01 ubuntu kernel: [19115.718257]  [<ffffffff8108fac0>] ? kthread_create_on_node+0x180/0x180
Aug 22 00:57:01 ubuntu kernel: [19115.718818]  [<ffffffff8168c7fc>] ret_from_fork+0x7c/0xb0
Aug 22 00:57:01 ubuntu kernel: [19115.719383]  [<ffffffff8108fac0>] ? kthread_create_on_node+0x180/0x180
Aug 22 00:57:01 ubuntu kernel: [19115.719952] Code: 8d 44 c2 10 48 8d 95 48 ff ff ff 48 89 85 50 ff ff ff e8 ff 01 00 00 48 8b 85 50 ff ff ff 48 39 85 48 ff ff ff 0f 84 6c fd ff ff <0f> 0b 66 0f 1f 84 00 00 00 00 00 4c 8b 35 e9 0e 02 00 4d 85 f6 
Aug 22 00:57:01 ubuntu kernel: [19115.721195] RIP  [<ffffffffa01be195>] btree_split+0x4d5/0x6c0 [bcache]
Aug 22 00:57:01 ubuntu kernel: [19115.721815]  RSP <ffff8803cd3238d8>
Aug 22 00:57:01 ubuntu kernel: [19115.724499] ------------[ cut here ]------------
Aug 22 00:57:01 ubuntu kernel: [19115.725160] kernel BUG at arch/x86/mm/pageattr.c:216!
Aug 22 00:57:01 ubuntu kernel: [19115.725819] invalid opcode: 0000 [#2] SMP 
Aug 22 00:57:01 ubuntu kernel: [19115.726475] Modules linked in: xfs libcrc32c usb_storage x86_pkg_temp_thermal intel_powerclamp coretemp kvm_intel kvm crct10dif_pclmul crc32_pclmul ast ghash_clmulni_intel aesni_intel aes_x86_64 syscopyarea sysfillrect sysimgblt glue_helper mei_me mei drm_kms_helper bonding ttm lpc_ich lrw gf128mul ipmi_si ablk_helper drm video shpchp cryptd acpi_pad hid_generic usbhid hid btrfs xor raid6_pq bcache ses enclosure megaraid_sas e1000e igb i2c_algo_bit dca ptp pps_core [last unloaded: usb_storage]
Aug 22 00:57:01 ubuntu kernel: [19115.729293] CPU: 3 PID: 274 Comm: bcache_gc Not tainted 3.16.1 #4
Aug 22 00:57:01 ubuntu kernel: [19115.729962] Hardware name: Supermicro X10SLM-F/X10SLM-F, BIOS 2.0 04/24/2014
Aug 22 00:57:01 ubuntu kernel: [19115.730628] task: ffff880404d59920 ti: ffff8803cd320000 task.ti: ffff8803cd320000
Aug 22 00:57:01 ubuntu kernel: [19115.731292] RIP: 0010:[<ffffffff8105db53>]  [<ffffffff8105db53>] change_page_attr_set_clr+0x433/0x440
Aug 22 00:57:01 ubuntu kernel: [19115.731968] RSP: 0018:ffff8803cd322cc8  EFLAGS: 00010046
Aug 22 00:57:01 ubuntu kernel: [19115.732631] RAX: 0000000000000046 RBX: 0000000000000000 RCX: 0000000000000010
Aug 22 00:57:01 ubuntu kernel: [19115.733292] RDX: 0000000000002000 RSI: 0000000000000000 RDI: 0000000080000000
Aug 22 00:57:01 ubuntu kernel: [19115.733943] RBP: ffff8803cd322d58 R08: 0000000000000001 R09: 0000000000000004
Aug 22 00:57:01 ubuntu kernel: [19115.734591] R10: ffff88041fd94e48 R11: 0000000000000000 R12: 0000000000000000
Aug 22 00:57:01 ubuntu kernel: [19115.735233] R13: 0000000000000010 R14: 0000000000000004 R15: 0000000000000005
Aug 22 00:57:01 ubuntu kernel: [19115.735872] FS:  0000000000000000(0000) GS:ffff88041fd80000(0000) knlGS:0000000000000000
Aug 22 00:57:01 ubuntu kernel: [19115.736518] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
Aug 22 00:57:01 ubuntu kernel: [19115.737159] CR2: 00007f3b3938c000 CR3: 0000000001c13000 CR4: 00000000001407e0
Aug 22 00:57:01 ubuntu kernel: [19115.737803] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
Aug 22 00:57:01 ubuntu kernel: [19115.738441] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Aug 22 00:57:01 ubuntu kernel: [19115.739075] Stack:
Aug 22 00:57:01 ubuntu kernel: [19115.739708]  ffff8803cd322d08 0000000000000000 0000000000000000 0000000000000200
Aug 22 00:57:01 ubuntu kernel: [19115.740360]  0000000000000008 0000000000000000 0000000000000000 0000000000000010
Aug 22 00:57:01 ubuntu kernel: [19115.741000]  0000000000000000 0000000500000001 00000000000ccb18 0000020000000000
Aug 22 00:57:01 ubuntu kernel: [19115.741631] Call Trace:
Aug 22 00:57:01 ubuntu kernel: [19115.742253]  [<ffffffff8105dea6>] _set_pages_array+0xe6/0x130
Aug 22 00:57:01 ubuntu kernel: [19115.742879]  [<ffffffff8105df23>] set_pages_array_wc+0x13/0x20
Aug 22 00:57:01 ubuntu kernel: [19115.743501]  [<ffffffffa017627f>] ttm_set_pages_caching+0x2f/0x70 [ttm]
Aug 22 00:57:01 ubuntu kernel: [19115.744125]  [<ffffffffa017637c>] ttm_alloc_new_pages.isra.6+0xbc/0x190 [ttm]
Aug 22 00:57:01 ubuntu kernel: [19115.744757]  [<ffffffffa0176c73>] ttm_pool_populate+0x3c3/0x4d0 [ttm]
Aug 22 00:57:01 ubuntu kernel: [19115.745379]  [<ffffffffa035bcbe>] ast_ttm_tt_populate+0xe/0x10 [ast]
Aug 22 00:57:01 ubuntu kernel: [19115.746000]  [<ffffffffa0173781>] ttm_bo_move_memcpy+0x5d1/0x680 [ttm]
Aug 22 00:57:01 ubuntu kernel: [19115.746585]  [<ffffffffa035bc68>] ast_bo_move+0x18/0x20 [ast]
Aug 22 00:57:01 ubuntu kernel: [19115.747173]  [<ffffffffa0170e75>] ttm_bo_handle_move_mem+0x265/0x5b0 [ttm]
Aug 22 00:57:01 ubuntu kernel: [19115.747762]  [<ffffffffa0171836>] ? ttm_bo_mem_space+0x116/0x340 [ttm]
Aug 22 00:57:01 ubuntu kernel: [19115.748353]  [<ffffffffa0171f2f>] ttm_bo_validate+0x21f/0x230 [ttm]
Aug 22 00:57:01 ubuntu kernel: [19115.748940]  [<ffffffffa035c4a2>] ast_bo_push_sysram+0x82/0xe0 [ast]
Aug 22 00:57:01 ubuntu kernel: [19115.749527]  [<ffffffffa0359f25>] ast_crtc_do_set_base.isra.14.constprop.24+0x75/0x350 [ast]
Aug 22 00:57:01 ubuntu kernel: [19115.750134]  [<ffffffffa035acf4>] ast_crtc_mode_set+0xaf4/0xc50 [ast]
Aug 22 00:57:01 ubuntu kernel: [19115.750728]  [<ffffffffa03288c9>] drm_crtc_helper_set_mode+0x2b9/0x4f0 [drm_kms_helper]
Aug 22 00:57:01 ubuntu kernel: [19115.751328]  [<ffffffffa032964f>] drm_crtc_helper_set_config+0x87f/0xaa0 [drm_kms_helper]
Aug 22 00:57:01 ubuntu kernel: [19115.751929]  [<ffffffff8168a31b>] ? __ww_mutex_lock+0x1b/0x97
Aug 22 00:57:01 ubuntu kernel: [19115.752521]  [<ffffffffa01143b1>] drm_mode_set_config_internal+0x61/0xe0 [drm]
Aug 22 00:57:01 ubuntu kernel: [19115.753100]  [<ffffffffa032c354>] drm_fb_helper_pan_display+0x94/0xf0 [drm_kms_helper]
Aug 22 00:57:01 ubuntu kernel: [19115.753675]  [<ffffffff813d87f9>] fb_pan_display+0xc9/0x190
Aug 22 00:57:01 ubuntu kernel: [19115.754245]  [<ffffffff813d2950>] bit_update_start+0x20/0x50
Aug 22 00:57:01 ubuntu kernel: [19115.754815]  [<ffffffff813d2402>] fbcon_switch+0x3a2/0x550
Aug 22 00:57:01 ubuntu kernel: [19115.755382]  [<ffffffff8145fcf9>] redraw_screen+0x189/0x240
Aug 22 00:57:01 ubuntu kernel: [19115.755987]  [<ffffffff813d89ee>] ? fb_blank+0x9e/0xc0
Aug 22 00:57:01 ubuntu kernel: [19115.756551]  [<ffffffff813cf99a>] fbcon_blank+0x20a/0x2d0
Aug 22 00:57:01 ubuntu kernel: [19115.757097]  [<ffffffff810c6af4>] ? wake_up_klogd+0x34/0x50
Aug 22 00:57:01 ubuntu kernel: [19115.757625]  [<ffffffff810c6d08>] ? console_unlock+0x1f8/0x440
Aug 22 00:57:01 ubuntu kernel: [19115.758140]  [<ffffffff8107902b>] ? lock_timer_base.isra.34+0x2b/0x50
Aug 22 00:57:01 ubuntu kernel: [19115.758637]  [<ffffffff810787ff>] ? internal_add_timer+0x2f/0x70
Aug 22 00:57:01 ubuntu kernel: [19115.759128]  [<ffffffff8107acea>] ? mod_timer+0x12a/0x1e0
Aug 22 00:57:01 ubuntu kernel: [19115.759610]  [<ffffffff81460818>] do_unblank_screen+0xb8/0x1f0
Aug 22 00:57:01 ubuntu kernel: [19115.760082]  [<ffffffff81460960>] unblank_screen+0x10/0x20
Aug 22 00:57:01 ubuntu kernel: [19115.760544]  [<ffffffff813798d9>] bust_spinlocks+0x19/0x40
Aug 22 00:57:01 ubuntu kernel: [19115.761000]  [<ffffffff81016918>] oops_end+0x38/0x150
Aug 22 00:57:01 ubuntu kernel: [19115.761462]  [<ffffffff81016d3b>] die+0x4b/0x70
Aug 22 00:57:01 ubuntu kernel: [19115.761917]  [<ffffffff81013300>] do_trap+0xb0/0x150
Aug 22 00:57:01 ubuntu kernel: [19115.762374]  [<ffffffff81013967>] do_error_trap+0x97/0x150
Aug 22 00:57:01 ubuntu kernel: [19115.762835]  [<ffffffffa01be195>] ? btree_split+0x4d5/0x6c0 [bcache]
Aug 22 00:57:01 ubuntu kernel: [19115.763299]  [<ffffffff8101c1a5>] ? native_sched_clock+0x35/0x90
Aug 22 00:57:01 ubuntu kernel: [19115.763755]  [<ffffffff8101c209>] ? sched_clock+0x9/0x10
Aug 22 00:57:01 ubuntu kernel: [19115.764200]  [<ffffffff810a2ec5>] ? sched_clock_cpu+0x85/0xc0
Aug 22 00:57:01 ubuntu kernel: [19115.764645]  [<ffffffffa01bb312>] ? bch_btree_insert_keys+0x72/0x200 [bcache]
Aug 22 00:57:01 ubuntu kernel: [19115.765098]  [<ffffffff81013fe0>] do_invalid_op+0x20/0x30
Aug 22 00:57:01 ubuntu kernel: [19115.765552]  [<ffffffff8168e35e>] invalid_op+0x1e/0x30
Aug 22 00:57:01 ubuntu kernel: [19115.766023]  [<ffffffffa01be195>] ? btree_split+0x4d5/0x6c0 [bcache]
Aug 22 00:57:01 ubuntu kernel: [19115.766475]  [<ffffffffa01be181>] ? btree_split+0x4c1/0x6c0 [bcache]
Aug 22 00:57:01 ubuntu kernel: [19115.766919]  [<ffffffff810a3a94>] ? arch_vtime_task_switch+0x94/0xa0
Aug 22 00:57:01 ubuntu kernel: [19115.767384]  [<ffffffff810a3add>] ? vtime_common_task_switch+0x3d/0x40
Aug 22 00:57:01 ubuntu kernel: [19115.767870]  [<ffffffff8109c528>] ? finish_task_switch+0x128/0x180
Aug 22 00:57:01 ubuntu kernel: [19115.768342]  [<ffffffffa01be62a>] bch_btree_insert_node+0x2aa/0x3b0 [bcache]
Aug 22 00:57:01 ubuntu kernel: [19115.768771]  [<ffffffffa01bee14>] btree_gc_coalesce.isra.28+0x6e4/0x870 [bcache]
Aug 22 00:57:01 ubuntu kernel: [19115.769212]  [<ffffffffa01bf2b1>] btree_gc_recurse+0x1b1/0x300 [bcache]
Aug 22 00:57:01 ubuntu kernel: [19115.769659]  [<ffffffffa01bf19e>] btree_gc_recurse+0x9e/0x300 [bcache]
Aug 22 00:57:01 ubuntu kernel: [19115.770099]  [<ffffffffa01bf9fb>] bch_btree_gc+0x42b/0x5b0 [bcache]
Aug 22 00:57:01 ubuntu kernel: [19115.770533]  [<ffffffff810b34e0>] ? prepare_to_wait_event+0x100/0x100
Aug 22 00:57:01 ubuntu kernel: [19115.770971]  [<ffffffffa01bfbb8>] bch_gc_thread+0x38/0x120 [bcache]
Aug 22 00:57:01 ubuntu kernel: [19115.771441]  [<ffffffffa01bfb80>] ? bch_btree_gc+0x5b0/0x5b0 [bcache]
Aug 22 00:57:01 ubuntu kernel: [19115.771919]  [<ffffffff8108fb92>] kthread+0xd2/0xf0
Aug 22 00:57:01 ubuntu kernel: [19115.772380]  [<ffffffff8108fac0>] ? kthread_create_on_node+0x180/0x180
Aug 22 00:57:01 ubuntu kernel: [19115.772806]  [<ffffffff8168c7fc>] ret_from_fork+0x7c/0xb0
Aug 22 00:57:01 ubuntu kernel: [19115.773225]  [<ffffffff8108fac0>] ? kthread_create_on_node+0x180/0x180
Aug 22 00:57:01 ubuntu kernel: [19115.773645] Code: ff ff 48 8b 4d 80 e9 9f fc ff ff 0f 0b 0f 0b be ba 00 00 00 48 c7 c7 09 99 a2 81 89 4d 80 e8 95 ed 00 00 8b 4d 80 e9 04 ff ff ff <0f> 0b 66 66 2e 0f 1f 84 00 00 00 00 00 0f 1f 44 00 00 55 48 89 
Aug 22 00:57:01 ubuntu kernel: [19115.774598] RIP  [<ffffffff8105db53>] change_page_attr_set_clr+0x433/0x440
Aug 22 00:57:01 ubuntu kernel: [19115.775044]  RSP <ffff8803cd322cc8>
Aug 22 00:57:01 ubuntu kernel: [19115.775494] ---[ end trace 658339f61e40f6ce ]---

Is bcache considered stable in 3.16 kernel? Is there anything I
could do to debug? I had also problems with xfs on top of bcache. 


Thanx and Regards
Thomas Klaube

Re: bcache bug / fs freeze on heavy IO

[Kent Overstreet]

ouch.

Is there anything more in the log before it hit that BUG_ON()?

On Fri, Aug 22, 2014 at 12:56 AM, Thomas Klaube <thomas@klaube.net> wrote:
> Hi,
>
> (I have sent this also to linux-kernel by mistake)
>
> while testing/benchmarking with fio on a bcache backed ext4 fs I see
> this dmesg output. System is ubuntu 14.04.1 but with vanilla Kernel 3.16.1:
>
> Aug 22 00:57:01 ubuntu kernel: [19115.694955] ------------[ cut here ]------------
> Aug 22 00:57:01 ubuntu kernel: [19115.695519] kernel BUG at drivers/md/bcache/btree.c:2053!
> Aug 22 00:57:01 ubuntu kernel: [19115.696066] invalid opcode: 0000 [#1] SMP
> Aug 22 00:57:01 ubuntu kernel: [19115.696619] Modules linked in: xfs libcrc32c usb_storage x86_pkg_temp_thermal intel_powerclamp coretemp kvm_intel kvm crct10dif_pclmul crc32_pclmul ast ghash_clmulni_intel aesni_intel aes_x86_64 syscopyarea sysfillrect sysimgblt glue_helper mei_me mei drm_kms_helper bonding ttm lpc_ich lrw gf128mul ipmi_si ablk_helper drm video shpchp cryptd acpi_pad hid_generic usbhid hid btrfs xor raid6_pq bcache ses enclosure megaraid_sas e1000e igb i2c_algo_bit dca ptp pps_core [last unloaded: usb_storage]
> Aug 22 00:57:01 ubuntu kernel: [19115.699123] CPU: 3 PID: 274 Comm: bcache_gc Not tainted 3.16.1 #4
> Aug 22 00:57:01 ubuntu kernel: [19115.699756] Hardware name: Supermicro X10SLM-F/X10SLM-F, BIOS 2.0 04/24/2014
> Aug 22 00:57:01 ubuntu kernel: [19115.700387] task: ffff880404d59920 ti: ffff8803cd320000 task.ti: ffff8803cd320000
> Aug 22 00:57:01 ubuntu kernel: [19115.701022] RIP: 0010:[<ffffffffa01be195>]  [<ffffffffa01be195>] btree_split+0x4d5/0x6c0 [bcache]
> Aug 22 00:57:01 ubuntu kernel: [19115.701670] RSP: 0018:ffff8803cd3238d8  EFLAGS: 00010283
> Aug 22 00:57:01 ubuntu kernel: [19115.702305] RAX: ffff8803cd323970 RBX: ffff88030e82e400 RCX: ffffffffa01d6660
> Aug 22 00:57:01 ubuntu kernel: [19115.702942] RDX: 0000000000000000 RSI: 0000000000000200 RDI: ffff8803cd323870
> Aug 22 00:57:01 ubuntu kernel: [19115.703577] RBP: ffff8803cd3239e8 R08: 0000000000000000 R09: 0000000000000003
> Aug 22 00:57:01 ubuntu kernel: [19115.704205] R10: 0000000000000004 R11: 0000000000000005 R12: ffff8800d7584400
> Aug 22 00:57:01 ubuntu kernel: [19115.704829] R13: 0000000000000000 R14: ffff88030e82e4d0 R15: ffff8803cd323e28
> Aug 22 00:57:01 ubuntu kernel: [19115.705469] FS:  0000000000000000(0000) GS:ffff88041fd80000(0000) knlGS:0000000000000000
> Aug 22 00:57:01 ubuntu kernel: [19115.706085] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> Aug 22 00:57:01 ubuntu kernel: [19115.706697] CR2: 00007f3b3938c000 CR3: 0000000001c13000 CR4: 00000000001407e0
> Aug 22 00:57:01 ubuntu kernel: [19115.707310] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
> Aug 22 00:57:01 ubuntu kernel: [19115.707915] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
> Aug 22 00:57:01 ubuntu kernel: [19115.708510] Stack:
> Aug 22 00:57:01 ubuntu kernel: [19115.709107]  ffff8803cd3238f0 ffff8800d7584498 0000000000000000 ffff8803cd323b20
> Aug 22 00:57:01 ubuntu kernel: [19115.709705]  00001162b81ec3bd 0000000000000000 ffff880404d59920 0000000000000000
> Aug 22 00:57:01 ubuntu kernel: [19115.710303]  0000000000000000 0000000000000000 00000000a0000001 ffff8803cd323940
> Aug 22 00:57:01 ubuntu kernel: [19115.710894] Call Trace:
> Aug 22 00:57:01 ubuntu kernel: [19115.711474]  [<ffffffff810a3a94>] ? arch_vtime_task_switch+0x94/0xa0
> Aug 22 00:57:01 ubuntu kernel: [19115.712061]  [<ffffffff810a3add>] ? vtime_common_task_switch+0x3d/0x40
> Aug 22 00:57:01 ubuntu kernel: [19115.712643]  [<ffffffff8109c528>] ? finish_task_switch+0x128/0x180
> Aug 22 00:57:01 ubuntu kernel: [19115.713217]  [<ffffffffa01be62a>] bch_btree_insert_node+0x2aa/0x3b0 [bcache]
> Aug 22 00:57:01 ubuntu kernel: [19115.713791]  [<ffffffffa01bee14>] btree_gc_coalesce.isra.28+0x6e4/0x870 [bcache]
> Aug 22 00:57:01 ubuntu kernel: [19115.714363]  [<ffffffffa01bf2b1>] btree_gc_recurse+0x1b1/0x300 [bcache]
> Aug 22 00:57:01 ubuntu kernel: [19115.714927]  [<ffffffffa01bf19e>] btree_gc_recurse+0x9e/0x300 [bcache]
> Aug 22 00:57:01 ubuntu kernel: [19115.715516]  [<ffffffffa01bf9fb>] bch_btree_gc+0x42b/0x5b0 [bcache]
> Aug 22 00:57:01 ubuntu kernel: [19115.716063]  [<ffffffff810b34e0>] ? prepare_to_wait_event+0x100/0x100
> Aug 22 00:57:01 ubuntu kernel: [19115.716605]  [<ffffffffa01bfbb8>] bch_gc_thread+0x38/0x120 [bcache]
> Aug 22 00:57:01 ubuntu kernel: [19115.717155]  [<ffffffffa01bfb80>] ? bch_btree_gc+0x5b0/0x5b0 [bcache]
> Aug 22 00:57:01 ubuntu kernel: [19115.717706]  [<ffffffff8108fb92>] kthread+0xd2/0xf0
> Aug 22 00:57:01 ubuntu kernel: [19115.718257]  [<ffffffff8108fac0>] ? kthread_create_on_node+0x180/0x180
> Aug 22 00:57:01 ubuntu kernel: [19115.718818]  [<ffffffff8168c7fc>] ret_from_fork+0x7c/0xb0
> Aug 22 00:57:01 ubuntu kernel: [19115.719383]  [<ffffffff8108fac0>] ? kthread_create_on_node+0x180/0x180
> Aug 22 00:57:01 ubuntu kernel: [19115.719952] Code: 8d 44 c2 10 48 8d 95 48 ff ff ff 48 89 85 50 ff ff ff e8 ff 01 00 00 48 8b 85 50 ff ff ff 48 39 85 48 ff ff ff 0f 84 6c fd ff ff <0f> 0b 66 0f 1f 84 00 00 00 00 00 4c 8b 35 e9 0e 02 00 4d 85 f6
> Aug 22 00:57:01 ubuntu kernel: [19115.721195] RIP  [<ffffffffa01be195>] btree_split+0x4d5/0x6c0 [bcache]
> Aug 22 00:57:01 ubuntu kernel: [19115.721815]  RSP <ffff8803cd3238d8>
> Aug 22 00:57:01 ubuntu kernel: [19115.724499] ------------[ cut here ]------------
> Aug 22 00:57:01 ubuntu kernel: [19115.725160] kernel BUG at arch/x86/mm/pageattr.c:216!
> Aug 22 00:57:01 ubuntu kernel: [19115.725819] invalid opcode: 0000 [#2] SMP
> Aug 22 00:57:01 ubuntu kernel: [19115.726475] Modules linked in: xfs libcrc32c usb_storage x86_pkg_temp_thermal intel_powerclamp coretemp kvm_intel kvm crct10dif_pclmul crc32_pclmul ast ghash_clmulni_intel aesni_intel aes_x86_64 syscopyarea sysfillrect sysimgblt glue_helper mei_me mei drm_kms_helper bonding ttm lpc_ich lrw gf128mul ipmi_si ablk_helper drm video shpchp cryptd acpi_pad hid_generic usbhid hid btrfs xor raid6_pq bcache ses enclosure megaraid_sas e1000e igb i2c_algo_bit dca ptp pps_core [last unloaded: usb_storage]
> Aug 22 00:57:01 ubuntu kernel: [19115.729293] CPU: 3 PID: 274 Comm: bcache_gc Not tainted 3.16.1 #4
> Aug 22 00:57:01 ubuntu kernel: [19115.729962] Hardware name: Supermicro X10SLM-F/X10SLM-F, BIOS 2.0 04/24/2014
> Aug 22 00:57:01 ubuntu kernel: [19115.730628] task: ffff880404d59920 ti: ffff8803cd320000 task.ti: ffff8803cd320000
> Aug 22 00:57:01 ubuntu kernel: [19115.731292] RIP: 0010:[<ffffffff8105db53>]  [<ffffffff8105db53>] change_page_attr_set_clr+0x433/0x440
> Aug 22 00:57:01 ubuntu kernel: [19115.731968] RSP: 0018:ffff8803cd322cc8  EFLAGS: 00010046
> Aug 22 00:57:01 ubuntu kernel: [19115.732631] RAX: 0000000000000046 RBX: 0000000000000000 RCX: 0000000000000010
> Aug 22 00:57:01 ubuntu kernel: [19115.733292] RDX: 0000000000002000 RSI: 0000000000000000 RDI: 0000000080000000
> Aug 22 00:57:01 ubuntu kernel: [19115.733943] RBP: ffff8803cd322d58 R08: 0000000000000001 R09: 0000000000000004
> Aug 22 00:57:01 ubuntu kernel: [19115.734591] R10: ffff88041fd94e48 R11: 0000000000000000 R12: 0000000000000000
> Aug 22 00:57:01 ubuntu kernel: [19115.735233] R13: 0000000000000010 R14: 0000000000000004 R15: 0000000000000005
> Aug 22 00:57:01 ubuntu kernel: [19115.735872] FS:  0000000000000000(0000) GS:ffff88041fd80000(0000) knlGS:0000000000000000
> Aug 22 00:57:01 ubuntu kernel: [19115.736518] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> Aug 22 00:57:01 ubuntu kernel: [19115.737159] CR2: 00007f3b3938c000 CR3: 0000000001c13000 CR4: 00000000001407e0
> Aug 22 00:57:01 ubuntu kernel: [19115.737803] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
> Aug 22 00:57:01 ubuntu kernel: [19115.738441] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
> Aug 22 00:57:01 ubuntu kernel: [19115.739075] Stack:
> Aug 22 00:57:01 ubuntu kernel: [19115.739708]  ffff8803cd322d08 0000000000000000 0000000000000000 0000000000000200
> Aug 22 00:57:01 ubuntu kernel: [19115.740360]  0000000000000008 0000000000000000 0000000000000000 0000000000000010
> Aug 22 00:57:01 ubuntu kernel: [19115.741000]  0000000000000000 0000000500000001 00000000000ccb18 0000020000000000
> Aug 22 00:57:01 ubuntu kernel: [19115.741631] Call Trace:
> Aug 22 00:57:01 ubuntu kernel: [19115.742253]  [<ffffffff8105dea6>] _set_pages_array+0xe6/0x130
> Aug 22 00:57:01 ubuntu kernel: [19115.742879]  [<ffffffff8105df23>] set_pages_array_wc+0x13/0x20
> Aug 22 00:57:01 ubuntu kernel: [19115.743501]  [<ffffffffa017627f>] ttm_set_pages_caching+0x2f/0x70 [ttm]
> Aug 22 00:57:01 ubuntu kernel: [19115.744125]  [<ffffffffa017637c>] ttm_alloc_new_pages.isra.6+0xbc/0x190 [ttm]
> Aug 22 00:57:01 ubuntu kernel: [19115.744757]  [<ffffffffa0176c73>] ttm_pool_populate+0x3c3/0x4d0 [ttm]
> Aug 22 00:57:01 ubuntu kernel: [19115.745379]  [<ffffffffa035bcbe>] ast_ttm_tt_populate+0xe/0x10 [ast]
> Aug 22 00:57:01 ubuntu kernel: [19115.746000]  [<ffffffffa0173781>] ttm_bo_move_memcpy+0x5d1/0x680 [ttm]
> Aug 22 00:57:01 ubuntu kernel: [19115.746585]  [<ffffffffa035bc68>] ast_bo_move+0x18/0x20 [ast]
> Aug 22 00:57:01 ubuntu kernel: [19115.747173]  [<ffffffffa0170e75>] ttm_bo_handle_move_mem+0x265/0x5b0 [ttm]
> Aug 22 00:57:01 ubuntu kernel: [19115.747762]  [<ffffffffa0171836>] ? ttm_bo_mem_space+0x116/0x340 [ttm]
> Aug 22 00:57:01 ubuntu kernel: [19115.748353]  [<ffffffffa0171f2f>] ttm_bo_validate+0x21f/0x230 [ttm]
> Aug 22 00:57:01 ubuntu kernel: [19115.748940]  [<ffffffffa035c4a2>] ast_bo_push_sysram+0x82/0xe0 [ast]
> Aug 22 00:57:01 ubuntu kernel: [19115.749527]  [<ffffffffa0359f25>] ast_crtc_do_set_base.isra.14.constprop.24+0x75/0x350 [ast]
> Aug 22 00:57:01 ubuntu kernel: [19115.750134]  [<ffffffffa035acf4>] ast_crtc_mode_set+0xaf4/0xc50 [ast]
> Aug 22 00:57:01 ubuntu kernel: [19115.750728]  [<ffffffffa03288c9>] drm_crtc_helper_set_mode+0x2b9/0x4f0 [drm_kms_helper]
> Aug 22 00:57:01 ubuntu kernel: [19115.751328]  [<ffffffffa032964f>] drm_crtc_helper_set_config+0x87f/0xaa0 [drm_kms_helper]
> Aug 22 00:57:01 ubuntu kernel: [19115.751929]  [<ffffffff8168a31b>] ? __ww_mutex_lock+0x1b/0x97
> Aug 22 00:57:01 ubuntu kernel: [19115.752521]  [<ffffffffa01143b1>] drm_mode_set_config_internal+0x61/0xe0 [drm]
> Aug 22 00:57:01 ubuntu kernel: [19115.753100]  [<ffffffffa032c354>] drm_fb_helper_pan_display+0x94/0xf0 [drm_kms_helper]
> Aug 22 00:57:01 ubuntu kernel: [19115.753675]  [<ffffffff813d87f9>] fb_pan_display+0xc9/0x190
> Aug 22 00:57:01 ubuntu kernel: [19115.754245]  [<ffffffff813d2950>] bit_update_start+0x20/0x50
> Aug 22 00:57:01 ubuntu kernel: [19115.754815]  [<ffffffff813d2402>] fbcon_switch+0x3a2/0x550
> Aug 22 00:57:01 ubuntu kernel: [19115.755382]  [<ffffffff8145fcf9>] redraw_screen+0x189/0x240
> Aug 22 00:57:01 ubuntu kernel: [19115.755987]  [<ffffffff813d89ee>] ? fb_blank+0x9e/0xc0
> Aug 22 00:57:01 ubuntu kernel: [19115.756551]  [<ffffffff813cf99a>] fbcon_blank+0x20a/0x2d0
> Aug 22 00:57:01 ubuntu kernel: [19115.757097]  [<ffffffff810c6af4>] ? wake_up_klogd+0x34/0x50
> Aug 22 00:57:01 ubuntu kernel: [19115.757625]  [<ffffffff810c6d08>] ? console_unlock+0x1f8/0x440
> Aug 22 00:57:01 ubuntu kernel: [19115.758140]  [<ffffffff8107902b>] ? lock_timer_base.isra.34+0x2b/0x50
> Aug 22 00:57:01 ubuntu kernel: [19115.758637]  [<ffffffff810787ff>] ? internal_add_timer+0x2f/0x70
> Aug 22 00:57:01 ubuntu kernel: [19115.759128]  [<ffffffff8107acea>] ? mod_timer+0x12a/0x1e0
> Aug 22 00:57:01 ubuntu kernel: [19115.759610]  [<ffffffff81460818>] do_unblank_screen+0xb8/0x1f0
> Aug 22 00:57:01 ubuntu kernel: [19115.760082]  [<ffffffff81460960>] unblank_screen+0x10/0x20
> Aug 22 00:57:01 ubuntu kernel: [19115.760544]  [<ffffffff813798d9>] bust_spinlocks+0x19/0x40
> Aug 22 00:57:01 ubuntu kernel: [19115.761000]  [<ffffffff81016918>] oops_end+0x38/0x150
> Aug 22 00:57:01 ubuntu kernel: [19115.761462]  [<ffffffff81016d3b>] die+0x4b/0x70
> Aug 22 00:57:01 ubuntu kernel: [19115.761917]  [<ffffffff81013300>] do_trap+0xb0/0x150
> Aug 22 00:57:01 ubuntu kernel: [19115.762374]  [<ffffffff81013967>] do_error_trap+0x97/0x150
> Aug 22 00:57:01 ubuntu kernel: [19115.762835]  [<ffffffffa01be195>] ? btree_split+0x4d5/0x6c0 [bcache]
> Aug 22 00:57:01 ubuntu kernel: [19115.763299]  [<ffffffff8101c1a5>] ? native_sched_clock+0x35/0x90
> Aug 22 00:57:01 ubuntu kernel: [19115.763755]  [<ffffffff8101c209>] ? sched_clock+0x9/0x10
> Aug 22 00:57:01 ubuntu kernel: [19115.764200]  [<ffffffff810a2ec5>] ? sched_clock_cpu+0x85/0xc0
> Aug 22 00:57:01 ubuntu kernel: [19115.764645]  [<ffffffffa01bb312>] ? bch_btree_insert_keys+0x72/0x200 [bcache]
> Aug 22 00:57:01 ubuntu kernel: [19115.765098]  [<ffffffff81013fe0>] do_invalid_op+0x20/0x30
> Aug 22 00:57:01 ubuntu kernel: [19115.765552]  [<ffffffff8168e35e>] invalid_op+0x1e/0x30
> Aug 22 00:57:01 ubuntu kernel: [19115.766023]  [<ffffffffa01be195>] ? btree_split+0x4d5/0x6c0 [bcache]
> Aug 22 00:57:01 ubuntu kernel: [19115.766475]  [<ffffffffa01be181>] ? btree_split+0x4c1/0x6c0 [bcache]
> Aug 22 00:57:01 ubuntu kernel: [19115.766919]  [<ffffffff810a3a94>] ? arch_vtime_task_switch+0x94/0xa0
> Aug 22 00:57:01 ubuntu kernel: [19115.767384]  [<ffffffff810a3add>] ? vtime_common_task_switch+0x3d/0x40
> Aug 22 00:57:01 ubuntu kernel: [19115.767870]  [<ffffffff8109c528>] ? finish_task_switch+0x128/0x180
> Aug 22 00:57:01 ubuntu kernel: [19115.768342]  [<ffffffffa01be62a>] bch_btree_insert_node+0x2aa/0x3b0 [bcache]
> Aug 22 00:57:01 ubuntu kernel: [19115.768771]  [<ffffffffa01bee14>] btree_gc_coalesce.isra.28+0x6e4/0x870 [bcache]
> Aug 22 00:57:01 ubuntu kernel: [19115.769212]  [<ffffffffa01bf2b1>] btree_gc_recurse+0x1b1/0x300 [bcache]
> Aug 22 00:57:01 ubuntu kernel: [19115.769659]  [<ffffffffa01bf19e>] btree_gc_recurse+0x9e/0x300 [bcache]
> Aug 22 00:57:01 ubuntu kernel: [19115.770099]  [<ffffffffa01bf9fb>] bch_btree_gc+0x42b/0x5b0 [bcache]
> Aug 22 00:57:01 ubuntu kernel: [19115.770533]  [<ffffffff810b34e0>] ? prepare_to_wait_event+0x100/0x100
> Aug 22 00:57:01 ubuntu kernel: [19115.770971]  [<ffffffffa01bfbb8>] bch_gc_thread+0x38/0x120 [bcache]
> Aug 22 00:57:01 ubuntu kernel: [19115.771441]  [<ffffffffa01bfb80>] ? bch_btree_gc+0x5b0/0x5b0 [bcache]
> Aug 22 00:57:01 ubuntu kernel: [19115.771919]  [<ffffffff8108fb92>] kthread+0xd2/0xf0
> Aug 22 00:57:01 ubuntu kernel: [19115.772380]  [<ffffffff8108fac0>] ? kthread_create_on_node+0x180/0x180
> Aug 22 00:57:01 ubuntu kernel: [19115.772806]  [<ffffffff8168c7fc>] ret_from_fork+0x7c/0xb0
> Aug 22 00:57:01 ubuntu kernel: [19115.773225]  [<ffffffff8108fac0>] ? kthread_create_on_node+0x180/0x180
> Aug 22 00:57:01 ubuntu kernel: [19115.773645] Code: ff ff 48 8b 4d 80 e9 9f fc ff ff 0f 0b 0f 0b be ba 00 00 00 48 c7 c7 09 99 a2 81 89 4d 80 e8 95 ed 00 00 8b 4d 80 e9 04 ff ff ff <0f> 0b 66 66 2e 0f 1f 84 00 00 00 00 00 0f 1f 44 00 00 55 48 89
> Aug 22 00:57:01 ubuntu kernel: [19115.774598] RIP  [<ffffffff8105db53>] change_page_attr_set_clr+0x433/0x440
> Aug 22 00:57:01 ubuntu kernel: [19115.775044]  RSP <ffff8803cd322cc8>
> Aug 22 00:57:01 ubuntu kernel: [19115.775494] ---[ end trace 658339f61e40f6ce ]---
>
> Is bcache considered stable in 3.16 kernel? Is there anything I
> could do to debug? I had also problems with xfs on top of bcache.
>
>
> Thanx and Regards
> Thomas Klaube
> --
> To unsubscribe from this list: send the line "unsubscribe linux-bcache" in
> the body of a message to majordomo@vger.kernel.org
> More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: bcache bug / fs freeze on heavy IO

[Kent Overstreet]

there weren't any bcache changes in 3.16 from 3.15, so unless you hit
this again or someone else reports it I would think you just got
unlucky.

there's a bunch of fixes queued up for 3.17 though, and more I need to
backport and push out...

On Fri, Aug 22, 2014 at 2:34 AM, Kent Overstreet <kmo@daterainc.com> wrote:
> ouch.
>
> Is there anything more in the log before it hit that BUG_ON()?
>
> On Fri, Aug 22, 2014 at 12:56 AM, Thomas Klaube <thomas@klaube.net> wrote:
>> Hi,
>>
>> (I have sent this also to linux-kernel by mistake)
>>
>> while testing/benchmarking with fio on a bcache backed ext4 fs I see
>> this dmesg output. System is ubuntu 14.04.1 but with vanilla Kernel 3.16.1:
>>
>> Aug 22 00:57:01 ubuntu kernel: [19115.694955] ------------[ cut here ]------------
>> Aug 22 00:57:01 ubuntu kernel: [19115.695519] kernel BUG at drivers/md/bcache/btree.c:2053!
>> Aug 22 00:57:01 ubuntu kernel: [19115.696066] invalid opcode: 0000 [#1] SMP
>> Aug 22 00:57:01 ubuntu kernel: [19115.696619] Modules linked in: xfs libcrc32c usb_storage x86_pkg_temp_thermal intel_powerclamp coretemp kvm_intel kvm crct10dif_pclmul crc32_pclmul ast ghash_clmulni_intel aesni_intel aes_x86_64 syscopyarea sysfillrect sysimgblt glue_helper mei_me mei drm_kms_helper bonding ttm lpc_ich lrw gf128mul ipmi_si ablk_helper drm video shpchp cryptd acpi_pad hid_generic usbhid hid btrfs xor raid6_pq bcache ses enclosure megaraid_sas e1000e igb i2c_algo_bit dca ptp pps_core [last unloaded: usb_storage]
>> Aug 22 00:57:01 ubuntu kernel: [19115.699123] CPU: 3 PID: 274 Comm: bcache_gc Not tainted 3.16.1 #4
>> Aug 22 00:57:01 ubuntu kernel: [19115.699756] Hardware name: Supermicro X10SLM-F/X10SLM-F, BIOS 2.0 04/24/2014
>> Aug 22 00:57:01 ubuntu kernel: [19115.700387] task: ffff880404d59920 ti: ffff8803cd320000 task.ti: ffff8803cd320000
>> Aug 22 00:57:01 ubuntu kernel: [19115.701022] RIP: 0010:[<ffffffffa01be195>]  [<ffffffffa01be195>] btree_split+0x4d5/0x6c0 [bcache]
>> Aug 22 00:57:01 ubuntu kernel: [19115.701670] RSP: 0018:ffff8803cd3238d8  EFLAGS: 00010283
>> Aug 22 00:57:01 ubuntu kernel: [19115.702305] RAX: ffff8803cd323970 RBX: ffff88030e82e400 RCX: ffffffffa01d6660
>> Aug 22 00:57:01 ubuntu kernel: [19115.702942] RDX: 0000000000000000 RSI: 0000000000000200 RDI: ffff8803cd323870
>> Aug 22 00:57:01 ubuntu kernel: [19115.703577] RBP: ffff8803cd3239e8 R08: 0000000000000000 R09: 0000000000000003
>> Aug 22 00:57:01 ubuntu kernel: [19115.704205] R10: 0000000000000004 R11: 0000000000000005 R12: ffff8800d7584400
>> Aug 22 00:57:01 ubuntu kernel: [19115.704829] R13: 0000000000000000 R14: ffff88030e82e4d0 R15: ffff8803cd323e28
>> Aug 22 00:57:01 ubuntu kernel: [19115.705469] FS:  0000000000000000(0000) GS:ffff88041fd80000(0000) knlGS:0000000000000000
>> Aug 22 00:57:01 ubuntu kernel: [19115.706085] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
>> Aug 22 00:57:01 ubuntu kernel: [19115.706697] CR2: 00007f3b3938c000 CR3: 0000000001c13000 CR4: 00000000001407e0
>> Aug 22 00:57:01 ubuntu kernel: [19115.707310] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
>> Aug 22 00:57:01 ubuntu kernel: [19115.707915] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
>> Aug 22 00:57:01 ubuntu kernel: [19115.708510] Stack:
>> Aug 22 00:57:01 ubuntu kernel: [19115.709107]  ffff8803cd3238f0 ffff8800d7584498 0000000000000000 ffff8803cd323b20
>> Aug 22 00:57:01 ubuntu kernel: [19115.709705]  00001162b81ec3bd 0000000000000000 ffff880404d59920 0000000000000000
>> Aug 22 00:57:01 ubuntu kernel: [19115.710303]  0000000000000000 0000000000000000 00000000a0000001 ffff8803cd323940
>> Aug 22 00:57:01 ubuntu kernel: [19115.710894] Call Trace:
>> Aug 22 00:57:01 ubuntu kernel: [19115.711474]  [<ffffffff810a3a94>] ? arch_vtime_task_switch+0x94/0xa0
>> Aug 22 00:57:01 ubuntu kernel: [19115.712061]  [<ffffffff810a3add>] ? vtime_common_task_switch+0x3d/0x40
>> Aug 22 00:57:01 ubuntu kernel: [19115.712643]  [<ffffffff8109c528>] ? finish_task_switch+0x128/0x180
>> Aug 22 00:57:01 ubuntu kernel: [19115.713217]  [<ffffffffa01be62a>] bch_btree_insert_node+0x2aa/0x3b0 [bcache]
>> Aug 22 00:57:01 ubuntu kernel: [19115.713791]  [<ffffffffa01bee14>] btree_gc_coalesce.isra.28+0x6e4/0x870 [bcache]
>> Aug 22 00:57:01 ubuntu kernel: [19115.714363]  [<ffffffffa01bf2b1>] btree_gc_recurse+0x1b1/0x300 [bcache]
>> Aug 22 00:57:01 ubuntu kernel: [19115.714927]  [<ffffffffa01bf19e>] btree_gc_recurse+0x9e/0x300 [bcache]
>> Aug 22 00:57:01 ubuntu kernel: [19115.715516]  [<ffffffffa01bf9fb>] bch_btree_gc+0x42b/0x5b0 [bcache]
>> Aug 22 00:57:01 ubuntu kernel: [19115.716063]  [<ffffffff810b34e0>] ? prepare_to_wait_event+0x100/0x100
>> Aug 22 00:57:01 ubuntu kernel: [19115.716605]  [<ffffffffa01bfbb8>] bch_gc_thread+0x38/0x120 [bcache]
>> Aug 22 00:57:01 ubuntu kernel: [19115.717155]  [<ffffffffa01bfb80>] ? bch_btree_gc+0x5b0/0x5b0 [bcache]
>> Aug 22 00:57:01 ubuntu kernel: [19115.717706]  [<ffffffff8108fb92>] kthread+0xd2/0xf0
>> Aug 22 00:57:01 ubuntu kernel: [19115.718257]  [<ffffffff8108fac0>] ? kthread_create_on_node+0x180/0x180
>> Aug 22 00:57:01 ubuntu kernel: [19115.718818]  [<ffffffff8168c7fc>] ret_from_fork+0x7c/0xb0
>> Aug 22 00:57:01 ubuntu kernel: [19115.719383]  [<ffffffff8108fac0>] ? kthread_create_on_node+0x180/0x180
>> Aug 22 00:57:01 ubuntu kernel: [19115.719952] Code: 8d 44 c2 10 48 8d 95 48 ff ff ff 48 89 85 50 ff ff ff e8 ff 01 00 00 48 8b 85 50 ff ff ff 48 39 85 48 ff ff ff 0f 84 6c fd ff ff <0f> 0b 66 0f 1f 84 00 00 00 00 00 4c 8b 35 e9 0e 02 00 4d 85 f6
>> Aug 22 00:57:01 ubuntu kernel: [19115.721195] RIP  [<ffffffffa01be195>] btree_split+0x4d5/0x6c0 [bcache]
>> Aug 22 00:57:01 ubuntu kernel: [19115.721815]  RSP <ffff8803cd3238d8>
>> Aug 22 00:57:01 ubuntu kernel: [19115.724499] ------------[ cut here ]------------
>> Aug 22 00:57:01 ubuntu kernel: [19115.725160] kernel BUG at arch/x86/mm/pageattr.c:216!
>> Aug 22 00:57:01 ubuntu kernel: [19115.725819] invalid opcode: 0000 [#2] SMP
>> Aug 22 00:57:01 ubuntu kernel: [19115.726475] Modules linked in: xfs libcrc32c usb_storage x86_pkg_temp_thermal intel_powerclamp coretemp kvm_intel kvm crct10dif_pclmul crc32_pclmul ast ghash_clmulni_intel aesni_intel aes_x86_64 syscopyarea sysfillrect sysimgblt glue_helper mei_me mei drm_kms_helper bonding ttm lpc_ich lrw gf128mul ipmi_si ablk_helper drm video shpchp cryptd acpi_pad hid_generic usbhid hid btrfs xor raid6_pq bcache ses enclosure megaraid_sas e1000e igb i2c_algo_bit dca ptp pps_core [last unloaded: usb_storage]
>> Aug 22 00:57:01 ubuntu kernel: [19115.729293] CPU: 3 PID: 274 Comm: bcache_gc Not tainted 3.16.1 #4
>> Aug 22 00:57:01 ubuntu kernel: [19115.729962] Hardware name: Supermicro X10SLM-F/X10SLM-F, BIOS 2.0 04/24/2014
>> Aug 22 00:57:01 ubuntu kernel: [19115.730628] task: ffff880404d59920 ti: ffff8803cd320000 task.ti: ffff8803cd320000
>> Aug 22 00:57:01 ubuntu kernel: [19115.731292] RIP: 0010:[<ffffffff8105db53>]  [<ffffffff8105db53>] change_page_attr_set_clr+0x433/0x440
>> Aug 22 00:57:01 ubuntu kernel: [19115.731968] RSP: 0018:ffff8803cd322cc8  EFLAGS: 00010046
>> Aug 22 00:57:01 ubuntu kernel: [19115.732631] RAX: 0000000000000046 RBX: 0000000000000000 RCX: 0000000000000010
>> Aug 22 00:57:01 ubuntu kernel: [19115.733292] RDX: 0000000000002000 RSI: 0000000000000000 RDI: 0000000080000000
>> Aug 22 00:57:01 ubuntu kernel: [19115.733943] RBP: ffff8803cd322d58 R08: 0000000000000001 R09: 0000000000000004
>> Aug 22 00:57:01 ubuntu kernel: [19115.734591] R10: ffff88041fd94e48 R11: 0000000000000000 R12: 0000000000000000
>> Aug 22 00:57:01 ubuntu kernel: [19115.735233] R13: 0000000000000010 R14: 0000000000000004 R15: 0000000000000005
>> Aug 22 00:57:01 ubuntu kernel: [19115.735872] FS:  0000000000000000(0000) GS:ffff88041fd80000(0000) knlGS:0000000000000000
>> Aug 22 00:57:01 ubuntu kernel: [19115.736518] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
>> Aug 22 00:57:01 ubuntu kernel: [19115.737159] CR2: 00007f3b3938c000 CR3: 0000000001c13000 CR4: 00000000001407e0
>> Aug 22 00:57:01 ubuntu kernel: [19115.737803] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
>> Aug 22 00:57:01 ubuntu kernel: [19115.738441] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
>> Aug 22 00:57:01 ubuntu kernel: [19115.739075] Stack:
>> Aug 22 00:57:01 ubuntu kernel: [19115.739708]  ffff8803cd322d08 0000000000000000 0000000000000000 0000000000000200
>> Aug 22 00:57:01 ubuntu kernel: [19115.740360]  0000000000000008 0000000000000000 0000000000000000 0000000000000010
>> Aug 22 00:57:01 ubuntu kernel: [19115.741000]  0000000000000000 0000000500000001 00000000000ccb18 0000020000000000
>> Aug 22 00:57:01 ubuntu kernel: [19115.741631] Call Trace:
>> Aug 22 00:57:01 ubuntu kernel: [19115.742253]  [<ffffffff8105dea6>] _set_pages_array+0xe6/0x130
>> Aug 22 00:57:01 ubuntu kernel: [19115.742879]  [<ffffffff8105df23>] set_pages_array_wc+0x13/0x20
>> Aug 22 00:57:01 ubuntu kernel: [19115.743501]  [<ffffffffa017627f>] ttm_set_pages_caching+0x2f/0x70 [ttm]
>> Aug 22 00:57:01 ubuntu kernel: [19115.744125]  [<ffffffffa017637c>] ttm_alloc_new_pages.isra.6+0xbc/0x190 [ttm]
>> Aug 22 00:57:01 ubuntu kernel: [19115.744757]  [<ffffffffa0176c73>] ttm_pool_populate+0x3c3/0x4d0 [ttm]
>> Aug 22 00:57:01 ubuntu kernel: [19115.745379]  [<ffffffffa035bcbe>] ast_ttm_tt_populate+0xe/0x10 [ast]
>> Aug 22 00:57:01 ubuntu kernel: [19115.746000]  [<ffffffffa0173781>] ttm_bo_move_memcpy+0x5d1/0x680 [ttm]
>> Aug 22 00:57:01 ubuntu kernel: [19115.746585]  [<ffffffffa035bc68>] ast_bo_move+0x18/0x20 [ast]
>> Aug 22 00:57:01 ubuntu kernel: [19115.747173]  [<ffffffffa0170e75>] ttm_bo_handle_move_mem+0x265/0x5b0 [ttm]
>> Aug 22 00:57:01 ubuntu kernel: [19115.747762]  [<ffffffffa0171836>] ? ttm_bo_mem_space+0x116/0x340 [ttm]
>> Aug 22 00:57:01 ubuntu kernel: [19115.748353]  [<ffffffffa0171f2f>] ttm_bo_validate+0x21f/0x230 [ttm]
>> Aug 22 00:57:01 ubuntu kernel: [19115.748940]  [<ffffffffa035c4a2>] ast_bo_push_sysram+0x82/0xe0 [ast]
>> Aug 22 00:57:01 ubuntu kernel: [19115.749527]  [<ffffffffa0359f25>] ast_crtc_do_set_base.isra.14.constprop.24+0x75/0x350 [ast]
>> Aug 22 00:57:01 ubuntu kernel: [19115.750134]  [<ffffffffa035acf4>] ast_crtc_mode_set+0xaf4/0xc50 [ast]
>> Aug 22 00:57:01 ubuntu kernel: [19115.750728]  [<ffffffffa03288c9>] drm_crtc_helper_set_mode+0x2b9/0x4f0 [drm_kms_helper]
>> Aug 22 00:57:01 ubuntu kernel: [19115.751328]  [<ffffffffa032964f>] drm_crtc_helper_set_config+0x87f/0xaa0 [drm_kms_helper]
>> Aug 22 00:57:01 ubuntu kernel: [19115.751929]  [<ffffffff8168a31b>] ? __ww_mutex_lock+0x1b/0x97
>> Aug 22 00:57:01 ubuntu kernel: [19115.752521]  [<ffffffffa01143b1>] drm_mode_set_config_internal+0x61/0xe0 [drm]
>> Aug 22 00:57:01 ubuntu kernel: [19115.753100]  [<ffffffffa032c354>] drm_fb_helper_pan_display+0x94/0xf0 [drm_kms_helper]
>> Aug 22 00:57:01 ubuntu kernel: [19115.753675]  [<ffffffff813d87f9>] fb_pan_display+0xc9/0x190
>> Aug 22 00:57:01 ubuntu kernel: [19115.754245]  [<ffffffff813d2950>] bit_update_start+0x20/0x50
>> Aug 22 00:57:01 ubuntu kernel: [19115.754815]  [<ffffffff813d2402>] fbcon_switch+0x3a2/0x550
>> Aug 22 00:57:01 ubuntu kernel: [19115.755382]  [<ffffffff8145fcf9>] redraw_screen+0x189/0x240
>> Aug 22 00:57:01 ubuntu kernel: [19115.755987]  [<ffffffff813d89ee>] ? fb_blank+0x9e/0xc0
>> Aug 22 00:57:01 ubuntu kernel: [19115.756551]  [<ffffffff813cf99a>] fbcon_blank+0x20a/0x2d0
>> Aug 22 00:57:01 ubuntu kernel: [19115.757097]  [<ffffffff810c6af4>] ? wake_up_klogd+0x34/0x50
>> Aug 22 00:57:01 ubuntu kernel: [19115.757625]  [<ffffffff810c6d08>] ? console_unlock+0x1f8/0x440
>> Aug 22 00:57:01 ubuntu kernel: [19115.758140]  [<ffffffff8107902b>] ? lock_timer_base.isra.34+0x2b/0x50
>> Aug 22 00:57:01 ubuntu kernel: [19115.758637]  [<ffffffff810787ff>] ? internal_add_timer+0x2f/0x70
>> Aug 22 00:57:01 ubuntu kernel: [19115.759128]  [<ffffffff8107acea>] ? mod_timer+0x12a/0x1e0
>> Aug 22 00:57:01 ubuntu kernel: [19115.759610]  [<ffffffff81460818>] do_unblank_screen+0xb8/0x1f0
>> Aug 22 00:57:01 ubuntu kernel: [19115.760082]  [<ffffffff81460960>] unblank_screen+0x10/0x20
>> Aug 22 00:57:01 ubuntu kernel: [19115.760544]  [<ffffffff813798d9>] bust_spinlocks+0x19/0x40
>> Aug 22 00:57:01 ubuntu kernel: [19115.761000]  [<ffffffff81016918>] oops_end+0x38/0x150
>> Aug 22 00:57:01 ubuntu kernel: [19115.761462]  [<ffffffff81016d3b>] die+0x4b/0x70
>> Aug 22 00:57:01 ubuntu kernel: [19115.761917]  [<ffffffff81013300>] do_trap+0xb0/0x150
>> Aug 22 00:57:01 ubuntu kernel: [19115.762374]  [<ffffffff81013967>] do_error_trap+0x97/0x150
>> Aug 22 00:57:01 ubuntu kernel: [19115.762835]  [<ffffffffa01be195>] ? btree_split+0x4d5/0x6c0 [bcache]
>> Aug 22 00:57:01 ubuntu kernel: [19115.763299]  [<ffffffff8101c1a5>] ? native_sched_clock+0x35/0x90
>> Aug 22 00:57:01 ubuntu kernel: [19115.763755]  [<ffffffff8101c209>] ? sched_clock+0x9/0x10
>> Aug 22 00:57:01 ubuntu kernel: [19115.764200]  [<ffffffff810a2ec5>] ? sched_clock_cpu+0x85/0xc0
>> Aug 22 00:57:01 ubuntu kernel: [19115.764645]  [<ffffffffa01bb312>] ? bch_btree_insert_keys+0x72/0x200 [bcache]
>> Aug 22 00:57:01 ubuntu kernel: [19115.765098]  [<ffffffff81013fe0>] do_invalid_op+0x20/0x30
>> Aug 22 00:57:01 ubuntu kernel: [19115.765552]  [<ffffffff8168e35e>] invalid_op+0x1e/0x30
>> Aug 22 00:57:01 ubuntu kernel: [19115.766023]  [<ffffffffa01be195>] ? btree_split+0x4d5/0x6c0 [bcache]
>> Aug 22 00:57:01 ubuntu kernel: [19115.766475]  [<ffffffffa01be181>] ? btree_split+0x4c1/0x6c0 [bcache]
>> Aug 22 00:57:01 ubuntu kernel: [19115.766919]  [<ffffffff810a3a94>] ? arch_vtime_task_switch+0x94/0xa0
>> Aug 22 00:57:01 ubuntu kernel: [19115.767384]  [<ffffffff810a3add>] ? vtime_common_task_switch+0x3d/0x40
>> Aug 22 00:57:01 ubuntu kernel: [19115.767870]  [<ffffffff8109c528>] ? finish_task_switch+0x128/0x180
>> Aug 22 00:57:01 ubuntu kernel: [19115.768342]  [<ffffffffa01be62a>] bch_btree_insert_node+0x2aa/0x3b0 [bcache]
>> Aug 22 00:57:01 ubuntu kernel: [19115.768771]  [<ffffffffa01bee14>] btree_gc_coalesce.isra.28+0x6e4/0x870 [bcache]
>> Aug 22 00:57:01 ubuntu kernel: [19115.769212]  [<ffffffffa01bf2b1>] btree_gc_recurse+0x1b1/0x300 [bcache]
>> Aug 22 00:57:01 ubuntu kernel: [19115.769659]  [<ffffffffa01bf19e>] btree_gc_recurse+0x9e/0x300 [bcache]
>> Aug 22 00:57:01 ubuntu kernel: [19115.770099]  [<ffffffffa01bf9fb>] bch_btree_gc+0x42b/0x5b0 [bcache]
>> Aug 22 00:57:01 ubuntu kernel: [19115.770533]  [<ffffffff810b34e0>] ? prepare_to_wait_event+0x100/0x100
>> Aug 22 00:57:01 ubuntu kernel: [19115.770971]  [<ffffffffa01bfbb8>] bch_gc_thread+0x38/0x120 [bcache]
>> Aug 22 00:57:01 ubuntu kernel: [19115.771441]  [<ffffffffa01bfb80>] ? bch_btree_gc+0x5b0/0x5b0 [bcache]
>> Aug 22 00:57:01 ubuntu kernel: [19115.771919]  [<ffffffff8108fb92>] kthread+0xd2/0xf0
>> Aug 22 00:57:01 ubuntu kernel: [19115.772380]  [<ffffffff8108fac0>] ? kthread_create_on_node+0x180/0x180
>> Aug 22 00:57:01 ubuntu kernel: [19115.772806]  [<ffffffff8168c7fc>] ret_from_fork+0x7c/0xb0
>> Aug 22 00:57:01 ubuntu kernel: [19115.773225]  [<ffffffff8108fac0>] ? kthread_create_on_node+0x180/0x180
>> Aug 22 00:57:01 ubuntu kernel: [19115.773645] Code: ff ff 48 8b 4d 80 e9 9f fc ff ff 0f 0b 0f 0b be ba 00 00 00 48 c7 c7 09 99 a2 81 89 4d 80 e8 95 ed 00 00 8b 4d 80 e9 04 ff ff ff <0f> 0b 66 66 2e 0f 1f 84 00 00 00 00 00 0f 1f 44 00 00 55 48 89
>> Aug 22 00:57:01 ubuntu kernel: [19115.774598] RIP  [<ffffffff8105db53>] change_page_attr_set_clr+0x433/0x440
>> Aug 22 00:57:01 ubuntu kernel: [19115.775044]  RSP <ffff8803cd322cc8>
>> Aug 22 00:57:01 ubuntu kernel: [19115.775494] ---[ end trace 658339f61e40f6ce ]---
>>
>> Is bcache considered stable in 3.16 kernel? Is there anything I
>> could do to debug? I had also problems with xfs on top of bcache.
>>
>>
>> Thanx and Regards
>> Thomas Klaube
>> --
>> To unsubscribe from this list: send the line "unsubscribe linux-bcache" in
>> the body of a message to majordomo@vger.kernel.org
>> More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: bcache bug / fs freeze on heavy IO

[Kent Overstreet]

how large of an SSD/what bucket size were you using?

it's possible you tripped over a bug I recently fixed in the dev
branch when the btree grew to depth 2 - that had lurked for awhile
because with ~1 mb buckets you need around a terabyte or so SSD to get
a depth 2 btree in normal usage...

On Fri, Aug 22, 2014 at 2:38 AM, Kent Overstreet <kmo@daterainc.com> wrote:
> there weren't any bcache changes in 3.16 from 3.15, so unless you hit
> this again or someone else reports it I would think you just got
> unlucky.
>
> there's a bunch of fixes queued up for 3.17 though, and more I need to
> backport and push out...
>
> On Fri, Aug 22, 2014 at 2:34 AM, Kent Overstreet <kmo@daterainc.com> wrote:
>> ouch.
>>
>> Is there anything more in the log before it hit that BUG_ON()?
>>
>> On Fri, Aug 22, 2014 at 12:56 AM, Thomas Klaube <thomas@klaube.net> wrote:
>>> Hi,
>>>
>>> (I have sent this also to linux-kernel by mistake)
>>>
>>> while testing/benchmarking with fio on a bcache backed ext4 fs I see
>>> this dmesg output. System is ubuntu 14.04.1 but with vanilla Kernel 3.16.1:
>>>
>>> Aug 22 00:57:01 ubuntu kernel: [19115.694955] ------------[ cut here ]------------
>>> Aug 22 00:57:01 ubuntu kernel: [19115.695519] kernel BUG at drivers/md/bcache/btree.c:2053!
>>> Aug 22 00:57:01 ubuntu kernel: [19115.696066] invalid opcode: 0000 [#1] SMP
>>> Aug 22 00:57:01 ubuntu kernel: [19115.696619] Modules linked in: xfs libcrc32c usb_storage x86_pkg_temp_thermal intel_powerclamp coretemp kvm_intel kvm crct10dif_pclmul crc32_pclmul ast ghash_clmulni_intel aesni_intel aes_x86_64 syscopyarea sysfillrect sysimgblt glue_helper mei_me mei drm_kms_helper bonding ttm lpc_ich lrw gf128mul ipmi_si ablk_helper drm video shpchp cryptd acpi_pad hid_generic usbhid hid btrfs xor raid6_pq bcache ses enclosure megaraid_sas e1000e igb i2c_algo_bit dca ptp pps_core [last unloaded: usb_storage]
>>> Aug 22 00:57:01 ubuntu kernel: [19115.699123] CPU: 3 PID: 274 Comm: bcache_gc Not tainted 3.16.1 #4
>>> Aug 22 00:57:01 ubuntu kernel: [19115.699756] Hardware name: Supermicro X10SLM-F/X10SLM-F, BIOS 2.0 04/24/2014
>>> Aug 22 00:57:01 ubuntu kernel: [19115.700387] task: ffff880404d59920 ti: ffff8803cd320000 task.ti: ffff8803cd320000
>>> Aug 22 00:57:01 ubuntu kernel: [19115.701022] RIP: 0010:[<ffffffffa01be195>]  [<ffffffffa01be195>] btree_split+0x4d5/0x6c0 [bcache]
>>> Aug 22 00:57:01 ubuntu kernel: [19115.701670] RSP: 0018:ffff8803cd3238d8  EFLAGS: 00010283
>>> Aug 22 00:57:01 ubuntu kernel: [19115.702305] RAX: ffff8803cd323970 RBX: ffff88030e82e400 RCX: ffffffffa01d6660
>>> Aug 22 00:57:01 ubuntu kernel: [19115.702942] RDX: 0000000000000000 RSI: 0000000000000200 RDI: ffff8803cd323870
>>> Aug 22 00:57:01 ubuntu kernel: [19115.703577] RBP: ffff8803cd3239e8 R08: 0000000000000000 R09: 0000000000000003
>>> Aug 22 00:57:01 ubuntu kernel: [19115.704205] R10: 0000000000000004 R11: 0000000000000005 R12: ffff8800d7584400
>>> Aug 22 00:57:01 ubuntu kernel: [19115.704829] R13: 0000000000000000 R14: ffff88030e82e4d0 R15: ffff8803cd323e28
>>> Aug 22 00:57:01 ubuntu kernel: [19115.705469] FS:  0000000000000000(0000) GS:ffff88041fd80000(0000) knlGS:0000000000000000
>>> Aug 22 00:57:01 ubuntu kernel: [19115.706085] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
>>> Aug 22 00:57:01 ubuntu kernel: [19115.706697] CR2: 00007f3b3938c000 CR3: 0000000001c13000 CR4: 00000000001407e0
>>> Aug 22 00:57:01 ubuntu kernel: [19115.707310] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
>>> Aug 22 00:57:01 ubuntu kernel: [19115.707915] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
>>> Aug 22 00:57:01 ubuntu kernel: [19115.708510] Stack:
>>> Aug 22 00:57:01 ubuntu kernel: [19115.709107]  ffff8803cd3238f0 ffff8800d7584498 0000000000000000 ffff8803cd323b20
>>> Aug 22 00:57:01 ubuntu kernel: [19115.709705]  00001162b81ec3bd 0000000000000000 ffff880404d59920 0000000000000000
>>> Aug 22 00:57:01 ubuntu kernel: [19115.710303]  0000000000000000 0000000000000000 00000000a0000001 ffff8803cd323940
>>> Aug 22 00:57:01 ubuntu kernel: [19115.710894] Call Trace:
>>> Aug 22 00:57:01 ubuntu kernel: [19115.711474]  [<ffffffff810a3a94>] ? arch_vtime_task_switch+0x94/0xa0
>>> Aug 22 00:57:01 ubuntu kernel: [19115.712061]  [<ffffffff810a3add>] ? vtime_common_task_switch+0x3d/0x40
>>> Aug 22 00:57:01 ubuntu kernel: [19115.712643]  [<ffffffff8109c528>] ? finish_task_switch+0x128/0x180
>>> Aug 22 00:57:01 ubuntu kernel: [19115.713217]  [<ffffffffa01be62a>] bch_btree_insert_node+0x2aa/0x3b0 [bcache]
>>> Aug 22 00:57:01 ubuntu kernel: [19115.713791]  [<ffffffffa01bee14>] btree_gc_coalesce.isra.28+0x6e4/0x870 [bcache]
>>> Aug 22 00:57:01 ubuntu kernel: [19115.714363]  [<ffffffffa01bf2b1>] btree_gc_recurse+0x1b1/0x300 [bcache]
>>> Aug 22 00:57:01 ubuntu kernel: [19115.714927]  [<ffffffffa01bf19e>] btree_gc_recurse+0x9e/0x300 [bcache]
>>> Aug 22 00:57:01 ubuntu kernel: [19115.715516]  [<ffffffffa01bf9fb>] bch_btree_gc+0x42b/0x5b0 [bcache]
>>> Aug 22 00:57:01 ubuntu kernel: [19115.716063]  [<ffffffff810b34e0>] ? prepare_to_wait_event+0x100/0x100
>>> Aug 22 00:57:01 ubuntu kernel: [19115.716605]  [<ffffffffa01bfbb8>] bch_gc_thread+0x38/0x120 [bcache]
>>> Aug 22 00:57:01 ubuntu kernel: [19115.717155]  [<ffffffffa01bfb80>] ? bch_btree_gc+0x5b0/0x5b0 [bcache]
>>> Aug 22 00:57:01 ubuntu kernel: [19115.717706]  [<ffffffff8108fb92>] kthread+0xd2/0xf0
>>> Aug 22 00:57:01 ubuntu kernel: [19115.718257]  [<ffffffff8108fac0>] ? kthread_create_on_node+0x180/0x180
>>> Aug 22 00:57:01 ubuntu kernel: [19115.718818]  [<ffffffff8168c7fc>] ret_from_fork+0x7c/0xb0
>>> Aug 22 00:57:01 ubuntu kernel: [19115.719383]  [<ffffffff8108fac0>] ? kthread_create_on_node+0x180/0x180
>>> Aug 22 00:57:01 ubuntu kernel: [19115.719952] Code: 8d 44 c2 10 48 8d 95 48 ff ff ff 48 89 85 50 ff ff ff e8 ff 01 00 00 48 8b 85 50 ff ff ff 48 39 85 48 ff ff ff 0f 84 6c fd ff ff <0f> 0b 66 0f 1f 84 00 00 00 00 00 4c 8b 35 e9 0e 02 00 4d 85 f6
>>> Aug 22 00:57:01 ubuntu kernel: [19115.721195] RIP  [<ffffffffa01be195>] btree_split+0x4d5/0x6c0 [bcache]
>>> Aug 22 00:57:01 ubuntu kernel: [19115.721815]  RSP <ffff8803cd3238d8>
>>> Aug 22 00:57:01 ubuntu kernel: [19115.724499] ------------[ cut here ]------------
>>> Aug 22 00:57:01 ubuntu kernel: [19115.725160] kernel BUG at arch/x86/mm/pageattr.c:216!
>>> Aug 22 00:57:01 ubuntu kernel: [19115.725819] invalid opcode: 0000 [#2] SMP
>>> Aug 22 00:57:01 ubuntu kernel: [19115.726475] Modules linked in: xfs libcrc32c usb_storage x86_pkg_temp_thermal intel_powerclamp coretemp kvm_intel kvm crct10dif_pclmul crc32_pclmul ast ghash_clmulni_intel aesni_intel aes_x86_64 syscopyarea sysfillrect sysimgblt glue_helper mei_me mei drm_kms_helper bonding ttm lpc_ich lrw gf128mul ipmi_si ablk_helper drm video shpchp cryptd acpi_pad hid_generic usbhid hid btrfs xor raid6_pq bcache ses enclosure megaraid_sas e1000e igb i2c_algo_bit dca ptp pps_core [last unloaded: usb_storage]
>>> Aug 22 00:57:01 ubuntu kernel: [19115.729293] CPU: 3 PID: 274 Comm: bcache_gc Not tainted 3.16.1 #4
>>> Aug 22 00:57:01 ubuntu kernel: [19115.729962] Hardware name: Supermicro X10SLM-F/X10SLM-F, BIOS 2.0 04/24/2014
>>> Aug 22 00:57:01 ubuntu kernel: [19115.730628] task: ffff880404d59920 ti: ffff8803cd320000 task.ti: ffff8803cd320000
>>> Aug 22 00:57:01 ubuntu kernel: [19115.731292] RIP: 0010:[<ffffffff8105db53>]  [<ffffffff8105db53>] change_page_attr_set_clr+0x433/0x440
>>> Aug 22 00:57:01 ubuntu kernel: [19115.731968] RSP: 0018:ffff8803cd322cc8  EFLAGS: 00010046
>>> Aug 22 00:57:01 ubuntu kernel: [19115.732631] RAX: 0000000000000046 RBX: 0000000000000000 RCX: 0000000000000010
>>> Aug 22 00:57:01 ubuntu kernel: [19115.733292] RDX: 0000000000002000 RSI: 0000000000000000 RDI: 0000000080000000
>>> Aug 22 00:57:01 ubuntu kernel: [19115.733943] RBP: ffff8803cd322d58 R08: 0000000000000001 R09: 0000000000000004
>>> Aug 22 00:57:01 ubuntu kernel: [19115.734591] R10: ffff88041fd94e48 R11: 0000000000000000 R12: 0000000000000000
>>> Aug 22 00:57:01 ubuntu kernel: [19115.735233] R13: 0000000000000010 R14: 0000000000000004 R15: 0000000000000005
>>> Aug 22 00:57:01 ubuntu kernel: [19115.735872] FS:  0000000000000000(0000) GS:ffff88041fd80000(0000) knlGS:0000000000000000
>>> Aug 22 00:57:01 ubuntu kernel: [19115.736518] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
>>> Aug 22 00:57:01 ubuntu kernel: [19115.737159] CR2: 00007f3b3938c000 CR3: 0000000001c13000 CR4: 00000000001407e0
>>> Aug 22 00:57:01 ubuntu kernel: [19115.737803] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
>>> Aug 22 00:57:01 ubuntu kernel: [19115.738441] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
>>> Aug 22 00:57:01 ubuntu kernel: [19115.739075] Stack:
>>> Aug 22 00:57:01 ubuntu kernel: [19115.739708]  ffff8803cd322d08 0000000000000000 0000000000000000 0000000000000200
>>> Aug 22 00:57:01 ubuntu kernel: [19115.740360]  0000000000000008 0000000000000000 0000000000000000 0000000000000010
>>> Aug 22 00:57:01 ubuntu kernel: [19115.741000]  0000000000000000 0000000500000001 00000000000ccb18 0000020000000000
>>> Aug 22 00:57:01 ubuntu kernel: [19115.741631] Call Trace:
>>> Aug 22 00:57:01 ubuntu kernel: [19115.742253]  [<ffffffff8105dea6>] _set_pages_array+0xe6/0x130
>>> Aug 22 00:57:01 ubuntu kernel: [19115.742879]  [<ffffffff8105df23>] set_pages_array_wc+0x13/0x20
>>> Aug 22 00:57:01 ubuntu kernel: [19115.743501]  [<ffffffffa017627f>] ttm_set_pages_caching+0x2f/0x70 [ttm]
>>> Aug 22 00:57:01 ubuntu kernel: [19115.744125]  [<ffffffffa017637c>] ttm_alloc_new_pages.isra.6+0xbc/0x190 [ttm]
>>> Aug 22 00:57:01 ubuntu kernel: [19115.744757]  [<ffffffffa0176c73>] ttm_pool_populate+0x3c3/0x4d0 [ttm]
>>> Aug 22 00:57:01 ubuntu kernel: [19115.745379]  [<ffffffffa035bcbe>] ast_ttm_tt_populate+0xe/0x10 [ast]
>>> Aug 22 00:57:01 ubuntu kernel: [19115.746000]  [<ffffffffa0173781>] ttm_bo_move_memcpy+0x5d1/0x680 [ttm]
>>> Aug 22 00:57:01 ubuntu kernel: [19115.746585]  [<ffffffffa035bc68>] ast_bo_move+0x18/0x20 [ast]
>>> Aug 22 00:57:01 ubuntu kernel: [19115.747173]  [<ffffffffa0170e75>] ttm_bo_handle_move_mem+0x265/0x5b0 [ttm]
>>> Aug 22 00:57:01 ubuntu kernel: [19115.747762]  [<ffffffffa0171836>] ? ttm_bo_mem_space+0x116/0x340 [ttm]
>>> Aug 22 00:57:01 ubuntu kernel: [19115.748353]  [<ffffffffa0171f2f>] ttm_bo_validate+0x21f/0x230 [ttm]
>>> Aug 22 00:57:01 ubuntu kernel: [19115.748940]  [<ffffffffa035c4a2>] ast_bo_push_sysram+0x82/0xe0 [ast]
>>> Aug 22 00:57:01 ubuntu kernel: [19115.749527]  [<ffffffffa0359f25>] ast_crtc_do_set_base.isra.14.constprop.24+0x75/0x350 [ast]
>>> Aug 22 00:57:01 ubuntu kernel: [19115.750134]  [<ffffffffa035acf4>] ast_crtc_mode_set+0xaf4/0xc50 [ast]
>>> Aug 22 00:57:01 ubuntu kernel: [19115.750728]  [<ffffffffa03288c9>] drm_crtc_helper_set_mode+0x2b9/0x4f0 [drm_kms_helper]
>>> Aug 22 00:57:01 ubuntu kernel: [19115.751328]  [<ffffffffa032964f>] drm_crtc_helper_set_config+0x87f/0xaa0 [drm_kms_helper]
>>> Aug 22 00:57:01 ubuntu kernel: [19115.751929]  [<ffffffff8168a31b>] ? __ww_mutex_lock+0x1b/0x97
>>> Aug 22 00:57:01 ubuntu kernel: [19115.752521]  [<ffffffffa01143b1>] drm_mode_set_config_internal+0x61/0xe0 [drm]
>>> Aug 22 00:57:01 ubuntu kernel: [19115.753100]  [<ffffffffa032c354>] drm_fb_helper_pan_display+0x94/0xf0 [drm_kms_helper]
>>> Aug 22 00:57:01 ubuntu kernel: [19115.753675]  [<ffffffff813d87f9>] fb_pan_display+0xc9/0x190
>>> Aug 22 00:57:01 ubuntu kernel: [19115.754245]  [<ffffffff813d2950>] bit_update_start+0x20/0x50
>>> Aug 22 00:57:01 ubuntu kernel: [19115.754815]  [<ffffffff813d2402>] fbcon_switch+0x3a2/0x550
>>> Aug 22 00:57:01 ubuntu kernel: [19115.755382]  [<ffffffff8145fcf9>] redraw_screen+0x189/0x240
>>> Aug 22 00:57:01 ubuntu kernel: [19115.755987]  [<ffffffff813d89ee>] ? fb_blank+0x9e/0xc0
>>> Aug 22 00:57:01 ubuntu kernel: [19115.756551]  [<ffffffff813cf99a>] fbcon_blank+0x20a/0x2d0
>>> Aug 22 00:57:01 ubuntu kernel: [19115.757097]  [<ffffffff810c6af4>] ? wake_up_klogd+0x34/0x50
>>> Aug 22 00:57:01 ubuntu kernel: [19115.757625]  [<ffffffff810c6d08>] ? console_unlock+0x1f8/0x440
>>> Aug 22 00:57:01 ubuntu kernel: [19115.758140]  [<ffffffff8107902b>] ? lock_timer_base.isra.34+0x2b/0x50
>>> Aug 22 00:57:01 ubuntu kernel: [19115.758637]  [<ffffffff810787ff>] ? internal_add_timer+0x2f/0x70
>>> Aug 22 00:57:01 ubuntu kernel: [19115.759128]  [<ffffffff8107acea>] ? mod_timer+0x12a/0x1e0
>>> Aug 22 00:57:01 ubuntu kernel: [19115.759610]  [<ffffffff81460818>] do_unblank_screen+0xb8/0x1f0
>>> Aug 22 00:57:01 ubuntu kernel: [19115.760082]  [<ffffffff81460960>] unblank_screen+0x10/0x20
>>> Aug 22 00:57:01 ubuntu kernel: [19115.760544]  [<ffffffff813798d9>] bust_spinlocks+0x19/0x40
>>> Aug 22 00:57:01 ubuntu kernel: [19115.761000]  [<ffffffff81016918>] oops_end+0x38/0x150
>>> Aug 22 00:57:01 ubuntu kernel: [19115.761462]  [<ffffffff81016d3b>] die+0x4b/0x70
>>> Aug 22 00:57:01 ubuntu kernel: [19115.761917]  [<ffffffff81013300>] do_trap+0xb0/0x150
>>> Aug 22 00:57:01 ubuntu kernel: [19115.762374]  [<ffffffff81013967>] do_error_trap+0x97/0x150
>>> Aug 22 00:57:01 ubuntu kernel: [19115.762835]  [<ffffffffa01be195>] ? btree_split+0x4d5/0x6c0 [bcache]
>>> Aug 22 00:57:01 ubuntu kernel: [19115.763299]  [<ffffffff8101c1a5>] ? native_sched_clock+0x35/0x90
>>> Aug 22 00:57:01 ubuntu kernel: [19115.763755]  [<ffffffff8101c209>] ? sched_clock+0x9/0x10
>>> Aug 22 00:57:01 ubuntu kernel: [19115.764200]  [<ffffffff810a2ec5>] ? sched_clock_cpu+0x85/0xc0
>>> Aug 22 00:57:01 ubuntu kernel: [19115.764645]  [<ffffffffa01bb312>] ? bch_btree_insert_keys+0x72/0x200 [bcache]
>>> Aug 22 00:57:01 ubuntu kernel: [19115.765098]  [<ffffffff81013fe0>] do_invalid_op+0x20/0x30
>>> Aug 22 00:57:01 ubuntu kernel: [19115.765552]  [<ffffffff8168e35e>] invalid_op+0x1e/0x30
>>> Aug 22 00:57:01 ubuntu kernel: [19115.766023]  [<ffffffffa01be195>] ? btree_split+0x4d5/0x6c0 [bcache]
>>> Aug 22 00:57:01 ubuntu kernel: [19115.766475]  [<ffffffffa01be181>] ? btree_split+0x4c1/0x6c0 [bcache]
>>> Aug 22 00:57:01 ubuntu kernel: [19115.766919]  [<ffffffff810a3a94>] ? arch_vtime_task_switch+0x94/0xa0
>>> Aug 22 00:57:01 ubuntu kernel: [19115.767384]  [<ffffffff810a3add>] ? vtime_common_task_switch+0x3d/0x40
>>> Aug 22 00:57:01 ubuntu kernel: [19115.767870]  [<ffffffff8109c528>] ? finish_task_switch+0x128/0x180
>>> Aug 22 00:57:01 ubuntu kernel: [19115.768342]  [<ffffffffa01be62a>] bch_btree_insert_node+0x2aa/0x3b0 [bcache]
>>> Aug 22 00:57:01 ubuntu kernel: [19115.768771]  [<ffffffffa01bee14>] btree_gc_coalesce.isra.28+0x6e4/0x870 [bcache]
>>> Aug 22 00:57:01 ubuntu kernel: [19115.769212]  [<ffffffffa01bf2b1>] btree_gc_recurse+0x1b1/0x300 [bcache]
>>> Aug 22 00:57:01 ubuntu kernel: [19115.769659]  [<ffffffffa01bf19e>] btree_gc_recurse+0x9e/0x300 [bcache]
>>> Aug 22 00:57:01 ubuntu kernel: [19115.770099]  [<ffffffffa01bf9fb>] bch_btree_gc+0x42b/0x5b0 [bcache]
>>> Aug 22 00:57:01 ubuntu kernel: [19115.770533]  [<ffffffff810b34e0>] ? prepare_to_wait_event+0x100/0x100
>>> Aug 22 00:57:01 ubuntu kernel: [19115.770971]  [<ffffffffa01bfbb8>] bch_gc_thread+0x38/0x120 [bcache]
>>> Aug 22 00:57:01 ubuntu kernel: [19115.771441]  [<ffffffffa01bfb80>] ? bch_btree_gc+0x5b0/0x5b0 [bcache]
>>> Aug 22 00:57:01 ubuntu kernel: [19115.771919]  [<ffffffff8108fb92>] kthread+0xd2/0xf0
>>> Aug 22 00:57:01 ubuntu kernel: [19115.772380]  [<ffffffff8108fac0>] ? kthread_create_on_node+0x180/0x180
>>> Aug 22 00:57:01 ubuntu kernel: [19115.772806]  [<ffffffff8168c7fc>] ret_from_fork+0x7c/0xb0
>>> Aug 22 00:57:01 ubuntu kernel: [19115.773225]  [<ffffffff8108fac0>] ? kthread_create_on_node+0x180/0x180
>>> Aug 22 00:57:01 ubuntu kernel: [19115.773645] Code: ff ff 48 8b 4d 80 e9 9f fc ff ff 0f 0b 0f 0b be ba 00 00 00 48 c7 c7 09 99 a2 81 89 4d 80 e8 95 ed 00 00 8b 4d 80 e9 04 ff ff ff <0f> 0b 66 66 2e 0f 1f 84 00 00 00 00 00 0f 1f 44 00 00 55 48 89
>>> Aug 22 00:57:01 ubuntu kernel: [19115.774598] RIP  [<ffffffff8105db53>] change_page_attr_set_clr+0x433/0x440
>>> Aug 22 00:57:01 ubuntu kernel: [19115.775044]  RSP <ffff8803cd322cc8>
>>> Aug 22 00:57:01 ubuntu kernel: [19115.775494] ---[ end trace 658339f61e40f6ce ]---
>>>
>>> Is bcache considered stable in 3.16 kernel? Is there anything I
>>> could do to debug? I had also problems with xfs on top of bcache.
>>>
>>>
>>> Thanx and Regards
>>> Thomas Klaube
>>> --
>>> To unsubscribe from this list: send the line "unsubscribe linux-bcache" in
>>> the body of a message to majordomo@vger.kernel.org
>>> More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: bcache bug / fs freeze on heavy IO

[Thomas Klaube]

----- Ursprüngliche Mail -----
> Von: "Kent Overstreet" <kmo@daterainc.com>
> An: "Thomas Klaube" <thomas@klaube.net>
> CC: linux-bcache@vger.kernel.org
> Gesendet: Freitag, 22. August 2014 11:42:09
> Betreff: Re: bcache bug / fs freeze on heavy IO

Hi Kent,

> how large of an SSD/what bucket size were you using?

The SSD is 900GB (HW Raid 1 over 2 Samsung SSDs). Bucket size is 512k 
(thats what cat /sys/fs/bcache/3a26850d-c5a3-4919-93c3-51cdb99bec65/bucket_size
says). 

> it's possible you tripped over a bug I recently fixed in the dev
> branch when the btree grew to depth 2 - that had lurked for awhile
> because with ~1 mb buckets you need around a terabyte or so SSD to get
> a depth 2 btree in normal usage...

Is the fix already in the 3.17-rc1 kernel? Then I would setup a testrun
with 3.17-rc1. I could also setup a testrun on the Ubuntu 3.13.0-34 kernel
if that is helpful...

There was nothing else in the Log before the BUG_ON(). 

Regards
Thomas

> 
> On Fri, Aug 22, 2014 at 2:38 AM, Kent Overstreet <kmo@daterainc.com> wrote:
> > there weren't any bcache changes in 3.16 from 3.15, so unless you hit
> > this again or someone else reports it I would think you just got
> > unlucky.
> >
> > there's a bunch of fixes queued up for 3.17 though, and more I need to
> > backport and push out...
> >
> > On Fri, Aug 22, 2014 at 2:34 AM, Kent Overstreet <kmo@daterainc.com> wrote:
> >> ouch.
> >>
> >> Is there anything more in the log before it hit that BUG_ON()?
> >>
> >> On Fri, Aug 22, 2014 at 12:56 AM, Thomas Klaube <thomas@klaube.net> wrote:
> >>> Hi,
> >>>
> >>> (I have sent this also to linux-kernel by mistake)
> >>>
> >>> while testing/benchmarking with fio on a bcache backed ext4 fs I see
> >>> this dmesg output. System is ubuntu 14.04.1 but with vanilla Kernel
> >>> 3.16.1:
> >>>
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.694955] ------------[ cut here
> >>> ]------------
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.695519] kernel BUG at
> >>> drivers/md/bcache/btree.c:2053!
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.696066] invalid opcode: 0000 [#1]
> >>> SMP
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.696619] Modules linked in: xfs
> >>> libcrc32c usb_storage x86_pkg_temp_thermal intel_powerclamp coretemp
> >>> kvm_intel kvm crct10dif_pclmul crc32_pclmul ast ghash_clmulni_intel
> >>> aesni_intel aes_x86_64 syscopyarea sysfillrect sysimgblt glue_helper
> >>> mei_me mei drm_kms_helper bonding ttm lpc_ich lrw gf128mul ipmi_si
> >>> ablk_helper drm video shpchp cryptd acpi_pad hid_generic usbhid hid
> >>> btrfs xor raid6_pq bcache ses enclosure megaraid_sas e1000e igb
> >>> i2c_algo_bit dca ptp pps_core [last unloaded: usb_storage]
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.699123] CPU: 3 PID: 274 Comm:
> >>> bcache_gc Not tainted 3.16.1 #4
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.699756] Hardware name: Supermicro
> >>> X10SLM-F/X10SLM-F, BIOS 2.0 04/24/2014
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.700387] task: ffff880404d59920 ti:
> >>> ffff8803cd320000 task.ti: ffff8803cd320000
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.701022] RIP:
> >>> 0010:[<ffffffffa01be195>]  [<ffffffffa01be195>] btree_split+0x4d5/0x6c0
> >>> [bcache]
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.701670] RSP: 0018:ffff8803cd3238d8
> >>> EFLAGS: 00010283
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.702305] RAX: ffff8803cd323970 RBX:
> >>> ffff88030e82e400 RCX: ffffffffa01d6660
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.702942] RDX: 0000000000000000 RSI:
> >>> 0000000000000200 RDI: ffff8803cd323870
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.703577] RBP: ffff8803cd3239e8 R08:
> >>> 0000000000000000 R09: 0000000000000003
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.704205] R10: 0000000000000004 R11:
> >>> 0000000000000005 R12: ffff8800d7584400
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.704829] R13: 0000000000000000 R14:
> >>> ffff88030e82e4d0 R15: ffff8803cd323e28
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.705469] FS:  0000000000000000(0000)
> >>> GS:ffff88041fd80000(0000) knlGS:0000000000000000
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.706085] CS:  0010 DS: 0000 ES: 0000
> >>> CR0: 0000000080050033
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.706697] CR2: 00007f3b3938c000 CR3:
> >>> 0000000001c13000 CR4: 00000000001407e0
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.707310] DR0: 0000000000000000 DR1:
> >>> 0000000000000000 DR2: 0000000000000000
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.707915] DR3: 0000000000000000 DR6:
> >>> 00000000fffe0ff0 DR7: 0000000000000400
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.708510] Stack:
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.709107]  ffff8803cd3238f0
> >>> ffff8800d7584498 0000000000000000 ffff8803cd323b20
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.709705]  00001162b81ec3bd
> >>> 0000000000000000 ffff880404d59920 0000000000000000
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.710303]  0000000000000000
> >>> 0000000000000000 00000000a0000001 ffff8803cd323940
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.710894] Call Trace:
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.711474]  [<ffffffff810a3a94>] ?
> >>> arch_vtime_task_switch+0x94/0xa0
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.712061]  [<ffffffff810a3add>] ?
> >>> vtime_common_task_switch+0x3d/0x40
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.712643]  [<ffffffff8109c528>] ?
> >>> finish_task_switch+0x128/0x180
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.713217]  [<ffffffffa01be62a>]
> >>> bch_btree_insert_node+0x2aa/0x3b0 [bcache]
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.713791]  [<ffffffffa01bee14>]
> >>> btree_gc_coalesce.isra.28+0x6e4/0x870 [bcache]
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.714363]  [<ffffffffa01bf2b1>]
> >>> btree_gc_recurse+0x1b1/0x300 [bcache]
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.714927]  [<ffffffffa01bf19e>]
> >>> btree_gc_recurse+0x9e/0x300 [bcache]
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.715516]  [<ffffffffa01bf9fb>]
> >>> bch_btree_gc+0x42b/0x5b0 [bcache]
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.716063]  [<ffffffff810b34e0>] ?
> >>> prepare_to_wait_event+0x100/0x100
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.716605]  [<ffffffffa01bfbb8>]
> >>> bch_gc_thread+0x38/0x120 [bcache]
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.717155]  [<ffffffffa01bfb80>] ?
> >>> bch_btree_gc+0x5b0/0x5b0 [bcache]
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.717706]  [<ffffffff8108fb92>]
> >>> kthread+0xd2/0xf0
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.718257]  [<ffffffff8108fac0>] ?
> >>> kthread_create_on_node+0x180/0x180
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.718818]  [<ffffffff8168c7fc>]
> >>> ret_from_fork+0x7c/0xb0
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.719383]  [<ffffffff8108fac0>] ?
> >>> kthread_create_on_node+0x180/0x180
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.719952] Code: 8d 44 c2 10 48 8d 95
> >>> 48 ff ff ff 48 89 85 50 ff ff ff e8 ff 01 00 00 48 8b 85 50 ff ff ff 48
> >>> 39 85 48 ff ff ff 0f 84 6c fd ff ff <0f> 0b 66 0f 1f 84 00 00 00 00 00
> >>> 4c 8b 35 e9 0e 02 00 4d 85 f6
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.721195] RIP  [<ffffffffa01be195>]
> >>> btree_split+0x4d5/0x6c0 [bcache]
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.721815]  RSP <ffff8803cd3238d8>
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.724499] ------------[ cut here
> >>> ]------------
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.725160] kernel BUG at
> >>> arch/x86/mm/pageattr.c:216!
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.725819] invalid opcode: 0000 [#2]
> >>> SMP
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.726475] Modules linked in: xfs
> >>> libcrc32c usb_storage x86_pkg_temp_thermal intel_powerclamp coretemp
> >>> kvm_intel kvm crct10dif_pclmul crc32_pclmul ast ghash_clmulni_intel
> >>> aesni_intel aes_x86_64 syscopyarea sysfillrect sysimgblt glue_helper
> >>> mei_me mei drm_kms_helper bonding ttm lpc_ich lrw gf128mul ipmi_si
> >>> ablk_helper drm video shpchp cryptd acpi_pad hid_generic usbhid hid
> >>> btrfs xor raid6_pq bcache ses enclosure megaraid_sas e1000e igb
> >>> i2c_algo_bit dca ptp pps_core [last unloaded: usb_storage]
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.729293] CPU: 3 PID: 274 Comm:
> >>> bcache_gc Not tainted 3.16.1 #4
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.729962] Hardware name: Supermicro
> >>> X10SLM-F/X10SLM-F, BIOS 2.0 04/24/2014
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.730628] task: ffff880404d59920 ti:
> >>> ffff8803cd320000 task.ti: ffff8803cd320000
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.731292] RIP:
> >>> 0010:[<ffffffff8105db53>]  [<ffffffff8105db53>]
> >>> change_page_attr_set_clr+0x433/0x440
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.731968] RSP: 0018:ffff8803cd322cc8
> >>> EFLAGS: 00010046
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.732631] RAX: 0000000000000046 RBX:
> >>> 0000000000000000 RCX: 0000000000000010
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.733292] RDX: 0000000000002000 RSI:
> >>> 0000000000000000 RDI: 0000000080000000
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.733943] RBP: ffff8803cd322d58 R08:
> >>> 0000000000000001 R09: 0000000000000004
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.734591] R10: ffff88041fd94e48 R11:
> >>> 0000000000000000 R12: 0000000000000000
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.735233] R13: 0000000000000010 R14:
> >>> 0000000000000004 R15: 0000000000000005
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.735872] FS:  0000000000000000(0000)
> >>> GS:ffff88041fd80000(0000) knlGS:0000000000000000
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.736518] CS:  0010 DS: 0000 ES: 0000
> >>> CR0: 0000000080050033
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.737159] CR2: 00007f3b3938c000 CR3:
> >>> 0000000001c13000 CR4: 00000000001407e0
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.737803] DR0: 0000000000000000 DR1:
> >>> 0000000000000000 DR2: 0000000000000000
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.738441] DR3: 0000000000000000 DR6:
> >>> 00000000fffe0ff0 DR7: 0000000000000400
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.739075] Stack:
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.739708]  ffff8803cd322d08
> >>> 0000000000000000 0000000000000000 0000000000000200
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.740360]  0000000000000008
> >>> 0000000000000000 0000000000000000 0000000000000010
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.741000]  0000000000000000
> >>> 0000000500000001 00000000000ccb18 0000020000000000
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.741631] Call Trace:
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.742253]  [<ffffffff8105dea6>]
> >>> _set_pages_array+0xe6/0x130
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.742879]  [<ffffffff8105df23>]
> >>> set_pages_array_wc+0x13/0x20
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.743501]  [<ffffffffa017627f>]
> >>> ttm_set_pages_caching+0x2f/0x70 [ttm]
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.744125]  [<ffffffffa017637c>]
> >>> ttm_alloc_new_pages.isra.6+0xbc/0x190 [ttm]
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.744757]  [<ffffffffa0176c73>]
> >>> ttm_pool_populate+0x3c3/0x4d0 [ttm]
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.745379]  [<ffffffffa035bcbe>]
> >>> ast_ttm_tt_populate+0xe/0x10 [ast]
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.746000]  [<ffffffffa0173781>]
> >>> ttm_bo_move_memcpy+0x5d1/0x680 [ttm]
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.746585]  [<ffffffffa035bc68>]
> >>> ast_bo_move+0x18/0x20 [ast]
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.747173]  [<ffffffffa0170e75>]
> >>> ttm_bo_handle_move_mem+0x265/0x5b0 [ttm]
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.747762]  [<ffffffffa0171836>] ?
> >>> ttm_bo_mem_space+0x116/0x340 [ttm]
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.748353]  [<ffffffffa0171f2f>]
> >>> ttm_bo_validate+0x21f/0x230 [ttm]
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.748940]  [<ffffffffa035c4a2>]
> >>> ast_bo_push_sysram+0x82/0xe0 [ast]
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.749527]  [<ffffffffa0359f25>]
> >>> ast_crtc_do_set_base.isra.14.constprop.24+0x75/0x350 [ast]
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.750134]  [<ffffffffa035acf4>]
> >>> ast_crtc_mode_set+0xaf4/0xc50 [ast]
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.750728]  [<ffffffffa03288c9>]
> >>> drm_crtc_helper_set_mode+0x2b9/0x4f0 [drm_kms_helper]
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.751328]  [<ffffffffa032964f>]
> >>> drm_crtc_helper_set_config+0x87f/0xaa0 [drm_kms_helper]
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.751929]  [<ffffffff8168a31b>] ?
> >>> __ww_mutex_lock+0x1b/0x97
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.752521]  [<ffffffffa01143b1>]
> >>> drm_mode_set_config_internal+0x61/0xe0 [drm]
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.753100]  [<ffffffffa032c354>]
> >>> drm_fb_helper_pan_display+0x94/0xf0 [drm_kms_helper]
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.753675]  [<ffffffff813d87f9>]
> >>> fb_pan_display+0xc9/0x190
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.754245]  [<ffffffff813d2950>]
> >>> bit_update_start+0x20/0x50
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.754815]  [<ffffffff813d2402>]
> >>> fbcon_switch+0x3a2/0x550
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.755382]  [<ffffffff8145fcf9>]
> >>> redraw_screen+0x189/0x240
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.755987]  [<ffffffff813d89ee>] ?
> >>> fb_blank+0x9e/0xc0
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.756551]  [<ffffffff813cf99a>]
> >>> fbcon_blank+0x20a/0x2d0
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.757097]  [<ffffffff810c6af4>] ?
> >>> wake_up_klogd+0x34/0x50
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.757625]  [<ffffffff810c6d08>] ?
> >>> console_unlock+0x1f8/0x440
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.758140]  [<ffffffff8107902b>] ?
> >>> lock_timer_base.isra.34+0x2b/0x50
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.758637]  [<ffffffff810787ff>] ?
> >>> internal_add_timer+0x2f/0x70
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.759128]  [<ffffffff8107acea>] ?
> >>> mod_timer+0x12a/0x1e0
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.759610]  [<ffffffff81460818>]
> >>> do_unblank_screen+0xb8/0x1f0
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.760082]  [<ffffffff81460960>]
> >>> unblank_screen+0x10/0x20
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.760544]  [<ffffffff813798d9>]
> >>> bust_spinlocks+0x19/0x40
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.761000]  [<ffffffff81016918>]
> >>> oops_end+0x38/0x150
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.761462]  [<ffffffff81016d3b>]
> >>> die+0x4b/0x70
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.761917]  [<ffffffff81013300>]
> >>> do_trap+0xb0/0x150
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.762374]  [<ffffffff81013967>]
> >>> do_error_trap+0x97/0x150
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.762835]  [<ffffffffa01be195>] ?
> >>> btree_split+0x4d5/0x6c0 [bcache]
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.763299]  [<ffffffff8101c1a5>] ?
> >>> native_sched_clock+0x35/0x90
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.763755]  [<ffffffff8101c209>] ?
> >>> sched_clock+0x9/0x10
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.764200]  [<ffffffff810a2ec5>] ?
> >>> sched_clock_cpu+0x85/0xc0
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.764645]  [<ffffffffa01bb312>] ?
> >>> bch_btree_insert_keys+0x72/0x200 [bcache]
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.765098]  [<ffffffff81013fe0>]
> >>> do_invalid_op+0x20/0x30
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.765552]  [<ffffffff8168e35e>]
> >>> invalid_op+0x1e/0x30
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.766023]  [<ffffffffa01be195>] ?
> >>> btree_split+0x4d5/0x6c0 [bcache]
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.766475]  [<ffffffffa01be181>] ?
> >>> btree_split+0x4c1/0x6c0 [bcache]
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.766919]  [<ffffffff810a3a94>] ?
> >>> arch_vtime_task_switch+0x94/0xa0
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.767384]  [<ffffffff810a3add>] ?
> >>> vtime_common_task_switch+0x3d/0x40
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.767870]  [<ffffffff8109c528>] ?
> >>> finish_task_switch+0x128/0x180
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.768342]  [<ffffffffa01be62a>]
> >>> bch_btree_insert_node+0x2aa/0x3b0 [bcache]
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.768771]  [<ffffffffa01bee14>]
> >>> btree_gc_coalesce.isra.28+0x6e4/0x870 [bcache]
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.769212]  [<ffffffffa01bf2b1>]
> >>> btree_gc_recurse+0x1b1/0x300 [bcache]
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.769659]  [<ffffffffa01bf19e>]
> >>> btree_gc_recurse+0x9e/0x300 [bcache]
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.770099]  [<ffffffffa01bf9fb>]
> >>> bch_btree_gc+0x42b/0x5b0 [bcache]
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.770533]  [<ffffffff810b34e0>] ?
> >>> prepare_to_wait_event+0x100/0x100
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.770971]  [<ffffffffa01bfbb8>]
> >>> bch_gc_thread+0x38/0x120 [bcache]
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.771441]  [<ffffffffa01bfb80>] ?
> >>> bch_btree_gc+0x5b0/0x5b0 [bcache]
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.771919]  [<ffffffff8108fb92>]
> >>> kthread+0xd2/0xf0
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.772380]  [<ffffffff8108fac0>] ?
> >>> kthread_create_on_node+0x180/0x180
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.772806]  [<ffffffff8168c7fc>]
> >>> ret_from_fork+0x7c/0xb0
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.773225]  [<ffffffff8108fac0>] ?
> >>> kthread_create_on_node+0x180/0x180
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.773645] Code: ff ff 48 8b 4d 80 e9
> >>> 9f fc ff ff 0f 0b 0f 0b be ba 00 00 00 48 c7 c7 09 99 a2 81 89 4d 80 e8
> >>> 95 ed 00 00 8b 4d 80 e9 04 ff ff ff <0f> 0b 66 66 2e 0f 1f 84 00 00 00
> >>> 00 00 0f 1f 44 00 00 55 48 89
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.774598] RIP  [<ffffffff8105db53>]
> >>> change_page_attr_set_clr+0x433/0x440
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.775044]  RSP <ffff8803cd322cc8>
> >>> Aug 22 00:57:01 ubuntu kernel: [19115.775494] ---[ end trace
> >>> 658339f61e40f6ce ]---
> >>>
> >>> Is bcache considered stable in 3.16 kernel? Is there anything I
> >>> could do to debug? I had also problems with xfs on top of bcache.
> >>>
> >>>
> >>> Thanx and Regards
> >>> Thomas Klaube
> >>> --
> >>> To unsubscribe from this list: send the line "unsubscribe linux-bcache"
> >>> in
> >>> the body of a message to majordomo@vger.kernel.org
> >>> More majordomo info at  http://vger.kernel.org/majordomo-info.html
>

Re: bcache bug / fs freeze on heavy IO

[Thomas Klaube]

----- Ursprüngliche Mail -----
> Von: "Kent Overstreet" <kmo@daterainc.com>
> An: "Thomas Klaube" <thomas@klaube.net>
> CC: linux-bcache@vger.kernel.org
> Gesendet: Freitag, 22. August 2014 11:38:05
> Betreff: Re: bcache bug / fs freeze on heavy IO
> 
> there weren't any bcache changes in 3.16 from 3.15, so unless you hit
> this again or someone else reports it I would think you just got
> unlucky.

Hi,

I have similar issue again. This is with kernel 3.13.0-34 (ubuntu
server 14.04.1 LTS). This also happend during a fio benchmark on a
bcache device:

Aug 26 01:52:06 ubuntu kernel: [18378.656038] BUG: unable to handle kernel NULL pointer dereference at 0000000000000099
Aug 26 01:52:06 ubuntu kernel: [18378.656067] IP: [<ffffffffa0306bb6>] bch_btree_insert_node+0x16/0x2b0 [bcache]
Aug 26 01:52:06 ubuntu kernel: [18378.656093] PGD 0 
Aug 26 01:52:06 ubuntu kernel: [18378.656101] Oops: 0000 [#1] SMP 
Aug 26 01:52:06 ubuntu kernel: [18378.656113] Modules linked in: bcache binfmt_misc x86_pkg_temp_thermal intel_powerclamp coretemp kvm_intel kvm crct10dif_pclmul ast ttm crc32_pclmul ghash_clmulni_intel drm_kms_helper aesni_intel aes_x86_64 drm lrw gf128mul glue_helper ablk_helper syscopyarea cryptd sysfillrect sysimgblt lpc_ich shpchp mei_me mei bonding lp parport ipmi_si video mac_hid acpi_pad hid_generic usbhid ses hid enclosure usb_storage megaraid_sas ahci libahci igb e1000e i2c_algo_bit dca ptp pps_core
Aug 26 01:52:06 ubuntu kernel: [18378.656277] CPU: 3 PID: 1770 Comm: bcache_gc Not tainted 3.13.0-34-generic #60-Ubuntu
Aug 26 01:52:06 ubuntu kernel: [18378.656299] Hardware name: Supermicro X10SLM-F/X10SLM-F, BIOS 2.0 04/24/2014
Aug 26 01:52:06 ubuntu kernel: [18378.656319] task: ffff8804045fc7d0 ti: ffff880405b28000 task.ti: ffff880405b28000
Aug 26 01:52:06 ubuntu kernel: [18378.656340] RIP: 0010:[<ffffffffa0306bb6>]  [<ffffffffa0306bb6>] bch_btree_insert_node+0x16/0x2b0 [bcache]
Aug 26 01:52:06 ubuntu kernel: [18378.656370] RSP: 0018:ffff880405b297d8  EFLAGS: 00010246
Aug 26 01:52:06 ubuntu kernel: [18378.656385] RAX: ffff8803fe5c0000 RBX: ffff8802f5824400 RCX: 0000000000000000
Aug 26 01:52:06 ubuntu kernel: [18378.656405] RDX: ffff880405b29858 RSI: ffff880405b29dd4 RDI: ffffffffffffffff
Aug 26 01:52:06 ubuntu kernel: [18378.656424] RBP: ffff880405b297f8 R08: 0000000000000000 R09: ffff880405b29880
Aug 26 01:52:06 ubuntu kernel: [18378.656444] R10: 0000000000000001 R11: 000007ffffffffff R12: 0000000000000000
Aug 26 01:52:06 ubuntu kernel: [18378.656464] R13: ffff880405b29858 R14: ffff880405b29828 R15: 0000000000004587
Aug 26 01:52:06 ubuntu kernel: [18378.656484] FS:  0000000000000000(0000) GS:ffff88041fd80000(0000) knlGS:0000000000000000
Aug 26 01:52:06 ubuntu kernel: [18378.656507] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
Aug 26 01:52:06 ubuntu kernel: [18378.656524] CR2: 0000000000000099 CR3: 0000000001c0e000 CR4: 00000000001407e0
Aug 26 01:52:06 ubuntu kernel: [18378.656544] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
Aug 26 01:52:06 ubuntu kernel: [18378.656564] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Aug 26 01:52:06 ubuntu kernel: [18378.656584] Stack:
Aug 26 01:52:06 ubuntu kernel: [18378.656590]  ffff8802f5824400 ffff880039161800 0000000000000000 ffff880405b29828
Aug 26 01:52:06 ubuntu kernel: [18378.656614]  ffff880405b29910 ffffffffa0306a71 0000000000000000 ffff880405b29ab0
Aug 26 01:52:06 ubuntu kernel: [18378.656638]  000010b71d30b6be ffff880405b29dd4 0000000000000000 ffff8804045fc7d0
Aug 26 01:52:06 ubuntu kernel: [18378.656661] Call Trace:
Aug 26 01:52:06 ubuntu kernel: [18378.656672]  [<ffffffffa0306a71>] btree_split+0x441/0x570 [bcache]
Aug 26 01:52:06 ubuntu kernel: [18378.656692]  [<ffffffff810753d5>] ? del_timer+0x55/0x70
Aug 26 01:52:06 ubuntu kernel: [18378.656709]  [<ffffffff81081f89>] ? try_to_grab_pending+0xa9/0x160
Aug 26 01:52:06 ubuntu kernel: [18378.656728]  [<ffffffffa0306cc1>] bch_btree_insert_node+0x121/0x2b0 [bcache]
Aug 26 01:52:06 ubuntu kernel: [18378.656750]  [<ffffffffa030787e>] btree_gc_recurse+0xa2e/0xbb0 [bcache]
Aug 26 01:52:06 ubuntu kernel: [18378.656771]  [<ffffffffa0309755>] ? bch_btree_ptr_invalid+0xa5/0xd0 [bcache]
Aug 26 01:52:06 ubuntu kernel: [18378.656793]  [<ffffffffa03072d6>] btree_gc_recurse+0x486/0xbb0 [bcache]
Aug 26 01:52:06 ubuntu kernel: [18378.656813]  [<ffffffff810a7145>] ? load_balance+0x185/0x890
Aug 26 01:52:06 ubuntu kernel: [18378.656831]  [<ffffffffa0309755>] ? bch_btree_ptr_invalid+0xa5/0xd0 [bcache]
Aug 26 01:52:06 ubuntu kernel: [18378.656852]  [<ffffffff8101b7e9>] ? sched_clock+0x9/0x10
Aug 26 01:52:06 ubuntu kernel: [18378.656869]  [<ffffffffa0302380>] ? btree_node_free+0x1d0/0x1d0 [bcache]
Aug 26 01:52:06 ubuntu kernel: [18378.656889]  [<ffffffffa0305803>] ? btree_gc_mark_node+0x63/0x210 [bcache]
Aug 26 01:52:06 ubuntu kernel: [18378.656910]  [<ffffffffa0307feb>] bch_btree_gc+0x41b/0x5a0 [bcache]
Aug 26 01:52:06 ubuntu kernel: [18378.656930]  [<ffffffff8171fd41>] ? __schedule+0x381/0x7d0
Aug 26 01:52:06 ubuntu kernel: [18378.656948]  [<ffffffffa03081a8>] bch_gc_thread+0x38/0x120 [bcache]
Aug 26 01:52:06 ubuntu kernel: [18378.656967]  [<ffffffffa0308170>] ? bch_btree_gc+0x5a0/0x5a0 [bcache]
Aug 26 01:52:06 ubuntu kernel: [18378.656986]  [<ffffffff8108b3d2>] kthread+0xd2/0xf0
Aug 26 01:52:06 ubuntu kernel: [18378.657608]  [<ffffffff8108b300>] ? kthread_create_on_node+0x1d0/0x1d0
Aug 26 01:52:06 ubuntu kernel: [18378.658237]  [<ffffffff8172c6bc>] ret_from_fork+0x7c/0xb0
Aug 26 01:52:06 ubuntu kernel: [18378.658845]  [<ffffffff8108b300>] ? kthread_create_on_node+0x1d0/0x1d0
Aug 26 01:52:06 ubuntu kernel: [18378.659445] Code: 24 60 e8 5e a1 da e0 eb 8a 66 66 66 2e 0f 1f 84 00 00 00 00 00 0f 1f 44 00 00 55 48 89 e5 41 56 41 55 49 89 d5 41 54 49 89 cc 53 <80> bf 9a 00 00 00 00 48 89 fb 0f 85 6c 02 00 00 4c 8b 8b 80 00 
Aug 26 01:52:06 ubuntu kernel: [18378.660709] RIP  [<ffffffffa0306bb6>] bch_btree_insert_node+0x16/0x2b0 [bcache]
Aug 26 01:52:06 ubuntu kernel: [18378.661333]  RSP <ffff880405b297d8>
Aug 26 01:52:06 ubuntu kernel: [18378.661938] CR2: 0000000000000099
Aug 26 01:52:06 ubuntu kernel: [18378.685807] ---[ end trace c759c6ac8f543aa1 ]---

There are several fio processes hanging in d state and kill -9 does
not work. Elevator is cfq, here is the fio setup:

[rnd]
rw=randrw
ramp_time=30
runtime=36600
time_based
rwmixread=30
size=100g
refill_buffers=1
directory=.
iodepth=64
direct=1
blocksize=4k
numjobs=16
group_reporting
ioengine=libaio
loops=1

the fio job reads/writes to preallocated files and this fio job is
run in parallel with a similar fio job (same setup) on a non-bcached
device. There is no error on the fio job that runs on the non-bcache
device (job is successfully finishing after 36600 sec with reasonable
results). There are no errors in the controller logs and there are no
other errors in dmesg.

Any ideas? Probably I can reproduce this. 

Regards
Thomas Klaube

Re: bcache bug / fs freeze on heavy IO

[Slava Pestov]

Hi Thomas,

On Mon, Aug 25, 2014 at 11:38 PM, Thomas Klaube <thomas@klaube.net> wrote:
> ----- Ursprüngliche Mail -----
>> Von: "Kent Overstreet" <kmo@daterainc.com>
>> An: "Thomas Klaube" <thomas@klaube.net>
>> CC: linux-bcache@vger.kernel.org
>> Gesendet: Freitag, 22. August 2014 11:38:05
>> Betreff: Re: bcache bug / fs freeze on heavy IO
>>
>> there weren't any bcache changes in 3.16 from 3.15, so unless you hit
>> this again or someone else reports it I would think you just got
>> unlucky.
>
> Hi,
>
> I have similar issue again. This is with kernel 3.13.0-34 (ubuntu
> server 14.04.1 LTS). This also happend during a fio benchmark on a
> bcache device:
>
> Aug 26 01:52:06 ubuntu kernel: [18378.656038] BUG: unable to handle kernel NULL pointer dereference at 0000000000000099

I believe this is fixed in 3.17:

http://evilpiepirate.org/git/linux-bcache.git/commit/?h=bcache-dev&id=2452cc89063a2a6890368f185c4b6d7d8802179e

Can you either try upgrading your kernel, or as a workaround try
increasing your bucket size. This will lower the btree depth (depth 2
trees won't hit this problem).

> Aug 26 01:52:06 ubuntu kernel: [18378.656067] IP: [<ffffffffa0306bb6>] bch_btree_insert_node+0x16/0x2b0 [bcache]
> Aug 26 01:52:06 ubuntu kernel: [18378.656093] PGD 0
> Aug 26 01:52:06 ubuntu kernel: [18378.656101] Oops: 0000 [#1] SMP
> Aug 26 01:52:06 ubuntu kernel: [18378.656113] Modules linked in: bcache binfmt_misc x86_pkg_temp_thermal intel_powerclamp coretemp kvm_intel kvm crct10dif_pclmul ast ttm crc32_pclmul ghash_clmulni_intel drm_kms_helper aesni_intel aes_x86_64 drm lrw gf128mul glue_helper ablk_helper syscopyarea cryptd sysfillrect sysimgblt lpc_ich shpchp mei_me mei bonding lp parport ipmi_si video mac_hid acpi_pad hid_generic usbhid ses hid enclosure usb_storage megaraid_sas ahci libahci igb e1000e i2c_algo_bit dca ptp pps_core
> Aug 26 01:52:06 ubuntu kernel: [18378.656277] CPU: 3 PID: 1770 Comm: bcache_gc Not tainted 3.13.0-34-generic #60-Ubuntu
> Aug 26 01:52:06 ubuntu kernel: [18378.656299] Hardware name: Supermicro X10SLM-F/X10SLM-F, BIOS 2.0 04/24/2014
> Aug 26 01:52:06 ubuntu kernel: [18378.656319] task: ffff8804045fc7d0 ti: ffff880405b28000 task.ti: ffff880405b28000
> Aug 26 01:52:06 ubuntu kernel: [18378.656340] RIP: 0010:[<ffffffffa0306bb6>]  [<ffffffffa0306bb6>] bch_btree_insert_node+0x16/0x2b0 [bcache]
> Aug 26 01:52:06 ubuntu kernel: [18378.656370] RSP: 0018:ffff880405b297d8  EFLAGS: 00010246
> Aug 26 01:52:06 ubuntu kernel: [18378.656385] RAX: ffff8803fe5c0000 RBX: ffff8802f5824400 RCX: 0000000000000000
> Aug 26 01:52:06 ubuntu kernel: [18378.656405] RDX: ffff880405b29858 RSI: ffff880405b29dd4 RDI: ffffffffffffffff
> Aug 26 01:52:06 ubuntu kernel: [18378.656424] RBP: ffff880405b297f8 R08: 0000000000000000 R09: ffff880405b29880
> Aug 26 01:52:06 ubuntu kernel: [18378.656444] R10: 0000000000000001 R11: 000007ffffffffff R12: 0000000000000000
> Aug 26 01:52:06 ubuntu kernel: [18378.656464] R13: ffff880405b29858 R14: ffff880405b29828 R15: 0000000000004587
> Aug 26 01:52:06 ubuntu kernel: [18378.656484] FS:  0000000000000000(0000) GS:ffff88041fd80000(0000) knlGS:0000000000000000
> Aug 26 01:52:06 ubuntu kernel: [18378.656507] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> Aug 26 01:52:06 ubuntu kernel: [18378.656524] CR2: 0000000000000099 CR3: 0000000001c0e000 CR4: 00000000001407e0
> Aug 26 01:52:06 ubuntu kernel: [18378.656544] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
> Aug 26 01:52:06 ubuntu kernel: [18378.656564] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
> Aug 26 01:52:06 ubuntu kernel: [18378.656584] Stack:
> Aug 26 01:52:06 ubuntu kernel: [18378.656590]  ffff8802f5824400 ffff880039161800 0000000000000000 ffff880405b29828
> Aug 26 01:52:06 ubuntu kernel: [18378.656614]  ffff880405b29910 ffffffffa0306a71 0000000000000000 ffff880405b29ab0
> Aug 26 01:52:06 ubuntu kernel: [18378.656638]  000010b71d30b6be ffff880405b29dd4 0000000000000000 ffff8804045fc7d0
> Aug 26 01:52:06 ubuntu kernel: [18378.656661] Call Trace:
> Aug 26 01:52:06 ubuntu kernel: [18378.656672]  [<ffffffffa0306a71>] btree_split+0x441/0x570 [bcache]
> Aug 26 01:52:06 ubuntu kernel: [18378.656692]  [<ffffffff810753d5>] ? del_timer+0x55/0x70
> Aug 26 01:52:06 ubuntu kernel: [18378.656709]  [<ffffffff81081f89>] ? try_to_grab_pending+0xa9/0x160
> Aug 26 01:52:06 ubuntu kernel: [18378.656728]  [<ffffffffa0306cc1>] bch_btree_insert_node+0x121/0x2b0 [bcache]
> Aug 26 01:52:06 ubuntu kernel: [18378.656750]  [<ffffffffa030787e>] btree_gc_recurse+0xa2e/0xbb0 [bcache]
> Aug 26 01:52:06 ubuntu kernel: [18378.656771]  [<ffffffffa0309755>] ? bch_btree_ptr_invalid+0xa5/0xd0 [bcache]
> Aug 26 01:52:06 ubuntu kernel: [18378.656793]  [<ffffffffa03072d6>] btree_gc_recurse+0x486/0xbb0 [bcache]
> Aug 26 01:52:06 ubuntu kernel: [18378.656813]  [<ffffffff810a7145>] ? load_balance+0x185/0x890
> Aug 26 01:52:06 ubuntu kernel: [18378.656831]  [<ffffffffa0309755>] ? bch_btree_ptr_invalid+0xa5/0xd0 [bcache]
> Aug 26 01:52:06 ubuntu kernel: [18378.656852]  [<ffffffff8101b7e9>] ? sched_clock+0x9/0x10
> Aug 26 01:52:06 ubuntu kernel: [18378.656869]  [<ffffffffa0302380>] ? btree_node_free+0x1d0/0x1d0 [bcache]
> Aug 26 01:52:06 ubuntu kernel: [18378.656889]  [<ffffffffa0305803>] ? btree_gc_mark_node+0x63/0x210 [bcache]
> Aug 26 01:52:06 ubuntu kernel: [18378.656910]  [<ffffffffa0307feb>] bch_btree_gc+0x41b/0x5a0 [bcache]
> Aug 26 01:52:06 ubuntu kernel: [18378.656930]  [<ffffffff8171fd41>] ? __schedule+0x381/0x7d0
> Aug 26 01:52:06 ubuntu kernel: [18378.656948]  [<ffffffffa03081a8>] bch_gc_thread+0x38/0x120 [bcache]
> Aug 26 01:52:06 ubuntu kernel: [18378.656967]  [<ffffffffa0308170>] ? bch_btree_gc+0x5a0/0x5a0 [bcache]
> Aug 26 01:52:06 ubuntu kernel: [18378.656986]  [<ffffffff8108b3d2>] kthread+0xd2/0xf0
> Aug 26 01:52:06 ubuntu kernel: [18378.657608]  [<ffffffff8108b300>] ? kthread_create_on_node+0x1d0/0x1d0
> Aug 26 01:52:06 ubuntu kernel: [18378.658237]  [<ffffffff8172c6bc>] ret_from_fork+0x7c/0xb0
> Aug 26 01:52:06 ubuntu kernel: [18378.658845]  [<ffffffff8108b300>] ? kthread_create_on_node+0x1d0/0x1d0
> Aug 26 01:52:06 ubuntu kernel: [18378.659445] Code: 24 60 e8 5e a1 da e0 eb 8a 66 66 66 2e 0f 1f 84 00 00 00 00 00 0f 1f 44 00 00 55 48 89 e5 41 56 41 55 49 89 d5 41 54 49 89 cc 53 <80> bf 9a 00 00 00 00 48 89 fb 0f 85 6c 02 00 00 4c 8b 8b 80 00
> Aug 26 01:52:06 ubuntu kernel: [18378.660709] RIP  [<ffffffffa0306bb6>] bch_btree_insert_node+0x16/0x2b0 [bcache]
> Aug 26 01:52:06 ubuntu kernel: [18378.661333]  RSP <ffff880405b297d8>
> Aug 26 01:52:06 ubuntu kernel: [18378.661938] CR2: 0000000000000099
> Aug 26 01:52:06 ubuntu kernel: [18378.685807] ---[ end trace c759c6ac8f543aa1 ]---
>
> There are several fio processes hanging in d state and kill -9 does
> not work. Elevator is cfq, here is the fio setup:
>
> [rnd]
> rw=randrw
> ramp_time=30
> runtime=36600
> time_based
> rwmixread=30
> size=100g
> refill_buffers=1
> directory=.
> iodepth=64
> direct=1
> blocksize=4k
> numjobs=16
> group_reporting
> ioengine=libaio
> loops=1
>
> the fio job reads/writes to preallocated files and this fio job is
> run in parallel with a similar fio job (same setup) on a non-bcached
> device. There is no error on the fio job that runs on the non-bcache
> device (job is successfully finishing after 36600 sec with reasonable
> results). There are no errors in the controller logs and there are no
> other errors in dmesg.
>
> Any ideas? Probably I can reproduce this.
>
> Regards
> Thomas Klaube
> --
> To unsubscribe from this list: send the line "unsubscribe linux-bcache" in
> the body of a message to majordomo@vger.kernel.org
> More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: bcache bug / fs freeze on heavy IO

[Thomas Klaube]

----- Ursprüngliche Mail -----
> Von: "Slava Pestov" <sp@datera.io>
> An: "Thomas Klaube" <thomas@klaube.net>
> CC: "Kent Overstreet" <kmo@daterainc.com>, linux-bcache@vger.kernel.org
> Gesendet: Sonntag, 31. August 2014 22:34:52
> Betreff: Re: bcache bug / fs freeze on heavy IO
> 
> Hi Thomas,

Hi Slava,

> > Aug 26 01:52:06 ubuntu kernel: [18378.656038] BUG: unable to handle kernel
> > NULL pointer dereference at 0000000000000099
> 
> I believe this is fixed in 3.17:
> 
> http://evilpiepirate.org/git/linux-bcache.git/commit/?h=bcache-dev&id=2452cc89063a2a6890368f185c4b6d7d8802179e
> 
> Can you either try upgrading your kernel, or as a workaround try
> increasing your bucket size. This will lower the btree depth (depth 2
> trees won't hit this problem).

I upgraded to 3.17.0-rc3 and rerun the fio tests for 10 hours without any 
problems (no suspect messages in dmesg, no fs errors and no hanging tasks 
or other problems). So it seems I am unable to trigger the problem in 
3.17.0-rc3 but I will perform some more tests....

Thanx and regards
Thomas Klaube