Bug 71441

Summary: bcache CPU stalls and IO hangs
Product: IO/Storage Reporter: devsk (funtoos)
Component: OtherAssignee: Michael Lyle (mlyle)
Status: NEW ---    
Severity: normal CC: alan, bugzilla.kernel.org, colyli, szg00000
Priority: P1    
Hardware: All   
OS: Linux   
Kernel Version: 3.13.5 Subsystem:
Regression: No Bisected commit-id:
Attachments: The dmesg in a file.

Description devsk 2014-03-02 22:19:48 UTC
I am trying to use bcache underneath ZFS (using ZoL). I successfully format the cache and the backing device. I replace the existing device in the RAIDZ2 with the new device (/dev/bcache0) and resilvering starts. But after about 10GB of data having passed through bcache, it stalls. The IO wait goes up, the avg load goes up and machine is practically locked up. I can sysrq out of it. The following is repeated in the dmesg.

Mar  2 09:05:19 localhost kernel: [  136.720000] bio: create slab <bio-2> at 2
Mar  2 09:05:19 localhost kernel: [  136.720000] bcache: run_cache_set() invalidating existing data
Mar  2 09:05:19 localhost kernel: [  136.733000] bcache: register_cache() registered cache device sda5
Mar  2 09:05:19 localhost kernel: [  136.868000] bcache: register_bdev() registered backing device sdg1
Mar  2 09:05:19 localhost kernel: [  136.869000] bcache: bch_cached_dev_attach() Caching sdg1 as bcache0 on set 22813878-408c-49a2-9159-5d7c6686a69b
Mar  2 09:15:15 localhost kernel: [  732.175000] INFO: rcu_sched self-detected stall on CPU { 0}  (t=60000 jiffies g=18908 c=18907 q=64325)
Mar  2 09:15:15 localhost kernel: [  732.175000] sending NMI to all CPUs:
Mar  2 09:15:15 localhost kernel: [  732.175000] NMI backtrace for cpu 0
Mar  2 09:15:15 localhost kernel: [  732.175000] CPU: 0 PID: 10519 Comm: bcache_gc Tainted: P         C O 3.13.5 #1
Mar  2 09:15:15 localhost kernel: [  732.175000] Hardware name: OEM OEM/132-BL-E758, BIOS 6.00 PG 04/20/2011
Mar  2 09:15:15 localhost kernel: [  732.175000] task: ffff8802e80372c0 ti: ffff8802c506c000 task.ti: ffff8802c506c000
Mar  2 09:15:15 localhost kernel: [  732.175000] RIP: 0010:[<ffffffff812674eb>]  [<ffffffff812674eb>] __const_udelay+0x9/0x23
Mar  2 09:15:15 localhost kernel: [  732.175000] RSP: 0018:ffff88035fc03e00  EFLAGS: 00000002
Mar  2 09:15:15 localhost kernel: [  732.175000] RAX: 0000000000001400 RBX: 00000000000003e9 RCX: 0000000000000030
Mar  2 09:15:15 localhost kernel: [  732.175000] RDX: 00000000001a7000 RSI: 0000000000000002 RDI: 0000000000068dbc
Mar  2 09:15:15 localhost kernel: [  732.175000] RBP: 0000000000001000 R08: ffffffff817daa10 R09: 0000000000000000
Mar  2 09:15:15 localhost kernel: [  732.175000] R10: 0000000000000000 R11: 0000000000000002 R12: 000000000000b022
Mar  2 09:15:15 localhost kernel: [  732.175000] R13: ffffffff817daa10 R14: 0000000000000002 R15: ffff88035fc0de60
Mar  2 09:15:15 localhost kernel: [  732.175000] FS:  0000000000000000(0000) GS:ffff88035fc00000(0000) knlGS:0000000000000000
Mar  2 09:15:15 localhost kernel: [  732.175000] CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
Mar  2 09:15:15 localhost kernel: [  732.175000] CR2: 00000000f6371000 CR3: 000000000175f000 CR4: 00000000000007f0
Mar  2 09:15:15 localhost kernel: [  732.175000] Stack:
Mar  2 09:15:15 localhost kernel: [  732.175000]  ffffffff8102a6d9 0000000000000002 0000000000000002 0000000000000002
Mar  2 09:15:15 localhost kernel: [  732.175000]  ffffffff8102b3ba 00000000000000fe 0000000000000001 0000000000000086
Mar  2 09:15:15 localhost kernel: [  732.175000]  ffffffff8102b42b 0000000000002710 ffff88035fc0e3b0 0000000000000000
Mar  2 09:15:15 localhost kernel: [  732.175000] Call Trace:
Mar  2 09:15:15 localhost kernel: [  732.175000]  <IRQ>                                                                                                                                                                  
Mar  2 09:15:15 localhost kernel: [  732.175000]  [<ffffffff8102a6d9>] ? native_safe_apic_wait_icr_idle+0x2e/0x39                                                                                                        
Mar  2 09:15:15 localhost kernel: [  732.175000]  [<ffffffff8102b3ba>] ? __default_send_IPI_dest_field.constprop.0+0x19/0x4d                                                                                             
Mar  2 09:15:15 localhost kernel: [  732.175000]  [<ffffffff8102b42b>] ? default_send_IPI_mask_sequence_phys+0x3d/0x6d                                                                                                   
Mar  2 09:15:15 localhost kernel: [  732.175000]  [<ffffffff8102b590>] ? arch_trigger_all_cpu_backtrace+0x42/0x6a                                                                                                        
Mar  2 09:15:15 localhost kernel: [  732.175000]  [<ffffffff8108429d>] ? rcu_check_callbacks+0x1b9/0x4d5                                                                                                                 
Mar  2 09:15:15 localhost kernel: [  732.175000]  [<ffffffff8108b21d>] ? tick_sched_do_timer+0x25/0x25                                                                                                                   
Mar  2 09:15:15 localhost kernel: [  732.175000]  [<ffffffff8105416f>] ? update_process_times+0x31/0x56                                                                                                                  
Mar  2 09:15:15 localhost kernel: [  732.175000]  [<ffffffff8108b24d>] ? tick_sched_timer+0x30/0x4c                                                                                                                      
Mar  2 09:15:15 localhost kernel: [  732.175000]  [<ffffffff81063b72>] ? __run_hrtimer.isra.23+0x75/0xce                                                                                                                 
Mar  2 09:15:15 localhost kernel: [  732.175000]  [<ffffffff8106420a>] ? hrtimer_interrupt+0xbe/0x1a9                                                                                                                    
Mar  2 09:15:15 localhost kernel: [  732.175000]  [<ffffffff8102a90b>] ? smp_apic_timer_interrupt+0x27/0x37                                                                                                              
Mar  2 09:15:15 localhost kernel: [  732.175000]  [<ffffffff8152820a>] ? apic_timer_interrupt+0x6a/0x70                                                                                                                  
Mar  2 09:15:15 localhost kernel: [  732.175000]  <EOI>                                                                                                                                                                  
Mar  2 09:15:15 localhost kernel: [  732.175000]  [<ffffffff8140fa47>] ? btree_iter_cmp.isra.4+0x1a/0x59                                                                                                                 
Mar  2 09:15:15 localhost kernel: [  732.175000]  [<ffffffff81411212>] ? bch_btree_iter_next+0x187/0x1d5                                                                                                                 
Mar  2 09:15:15 localhost kernel: [  732.175000]  [<ffffffff81410242>] ? bch_ptr_invalid+0x1a/0x1a
Mar  2 09:15:15 localhost kernel: [  732.175000]  [<ffffffff814119b2>] ? bch_btree_iter_next_filter+0x18/0x38
Mar  2 09:15:15 localhost kernel: [  732.175000]  [<ffffffff8140e69d>] ? btree_gc_recurse+0x141/0x859
Mar  2 09:15:15 localhost kernel: [  732.175000]  [<ffffffff81410164>] ? bch_btree_ptr_invalid+0x36/0x87
Mar  2 09:15:15 localhost kernel: [  732.175000]  [<ffffffff814119b2>] ? bch_btree_iter_next_filter+0x18/0x38
Mar  2 09:15:15 localhost kernel: [  732.175000]  [<ffffffff8140d772>] ? btree_gc_mark_node+0xbe/0x16d
Mar  2 09:15:15 localhost kernel: [  732.175000]  [<ffffffff8140ef96>] ? bch_btree_gc+0x1e1/0x33a
Mar  2 09:15:15 localhost kernel: [  732.175000]  [<ffffffff81524871>] ? __schedule+0x415/0x4c6
Mar  2 09:15:15 localhost kernel: [  732.175000]  [<ffffffff8140f11c>] ? bch_gc_thread+0x2d/0xe0
Mar  2 09:15:15 localhost kernel: [  732.175000]  [<ffffffff8140f0ef>] ? bch_btree_gc+0x33a/0x33a
Mar  2 09:15:15 localhost kernel: [  732.175000]  [<ffffffff81061c39>] ? kthread+0x99/0xa1
Mar  2 09:15:15 localhost kernel: [  732.175000]  [<ffffffff81060000>] ? param_get_bool+0x10/0x1d
Mar  2 09:15:15 localhost kernel: [  732.175000]  [<ffffffff81061ba0>] ? __kthread_parkme+0x59/0x59
Mar  2 09:15:15 localhost kernel: [  732.175000]  [<ffffffff8152748c>] ? ret_from_fork+0x7c/0xb0
Mar  2 09:15:15 localhost kernel: [  732.175000]  [<ffffffff81061ba0>] ? __kthread_parkme+0x59/0x59
Mar  2 09:15:15 localhost kernel: [  732.175000] Code: eb 0e 66 66 66 66 66 2e 0f 1f 84 00 00 00 00 00 48 ff c8 75 fb 48 ff c8 c3 48 8b 05 68 11 53 00 ff e0 65 48 8b 14 25 e0 22 01 00 <48> 69 d2 fa 00 00 00 48 8d 04 bd 00 00 00 00 f7 e2 48 8d 7a 01 
Mar  2 09:15:15 localhost kernel: [  732.175000] NMI backtrace for cpu 1
Mar  2 09:15:15 localhost kernel: [  732.175000] CPU: 1 PID: 0 Comm: swapper/1 Tainted: P         C O 3.13.5 #1
Mar  2 09:15:15 localhost kernel: [  732.175000] Hardware name: OEM OEM/132-BL-E758, BIOS 6.00 PG 04/20/2011
Mar  2 09:15:15 localhost kernel: [  732.175000] task: ffff880351903cc0 ti: ffff880351926000 task.ti: ffff880351926000
Mar  2 09:15:15 localhost kernel: [  732.175000] RIP: 0010:[<ffffffff812a457b>]  [<ffffffff812a457b>] intel_idle+0xc7/0xec
Mar  2 09:15:15 localhost kernel: [  732.175000] RSP: 0018:ffff880351927e48  EFLAGS: 00000046
Mar  2 09:15:15 localhost kernel: [  732.175000] RAX: 0000000000000020 RBX: 0000000000000008 RCX: 0000000000000001
Mar  2 09:15:15 localhost kernel: [  732.175000] RDX: 0000000000000000 RSI: ffff880351927fd8 RDI: 0000000000000046
Mar  2 09:15:15 localhost kernel: [  732.175000] RBP: 0000000000000004 R08: 00000000000003bb R09: 0000000000000008
Mar  2 09:15:15 localhost kernel: [  732.175000] R10: ffff880351900d80 R11: 0000000000000001 R12: 0000000000000020
Mar  2 09:15:15 localhost kernel: [  732.175000] R13: 0000000000000003 R14: 0000000000000000 R15: 0000000000000000
Mar  2 09:15:15 localhost kernel: [  732.175000] FS:  0000000000000000(0000) GS:ffff88035fc20000(0000) knlGS:0000000000000000
Mar  2 09:15:15 localhost kernel: [  732.175000] CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
Mar  2 09:15:15 localhost kernel: [  732.175000] CR2: 00000000f0500000 CR3: 000000000175f000 CR4: 00000000000007e0
Mar  2 09:15:15 localhost kernel: [  732.175000] Stack:
Mar  2 09:15:15 localhost kernel: [  732.175000]  ffff88035fc38a90 0000000181084e0d ffff88035fc38a90 ffff88035fc38a90
Mar  2 09:15:15 localhost kernel: [  732.175000]  ffffffff8179a728 000000aa78fa4aed ffff880351927f00 ffffffff8144d5f7
Mar  2 09:15:15 localhost kernel: [  732.175000]  0000000000000004 ffffffff8179a5b0 0000000000000000 00000000000dab03
Mar  2 09:15:15 localhost kernel: [  732.175000] Call Trace:
Mar  2 09:15:15 localhost kernel: [  732.175000]  [<ffffffff8144d5f7>] ? cpuidle_enter_state+0x37/0xb1
Mar  2 09:15:15 localhost kernel: [  732.175000]  [<ffffffff8144d739>] ? cpuidle_idle_call+0xc8/0x10e
Mar  2 09:15:15 localhost kernel: [  732.175000]  [<ffffffff8101071b>] ? arch_cpu_idle+0x6/0x1a
Mar  2 09:15:15 localhost kernel: [  732.175000]  [<ffffffff8107d1f9>] ? cpu_startup_entry+0xb1/0x138
Mar  2 09:15:15 localhost kernel: [  732.175000] Code: 48 8b 34 25 60 c7 00 00 48 8d 86 38 e0 ff ff 48 89 d1 0f 01 c8 0f ae f0 48 8b 86 38 e0 ff ff a8 08 75 08 b1 01 4c 89 e0 0f 01 c9 <85> 1d c7 63 4f 00 75 0f 48 8d 74 24 0c bf 05 00 00 00 e8 8a 4f 
Mar  2 09:15:15 localhost kernel: [  732.175000] NMI backtrace for cpu 2
Mar  2 09:15:15 localhost kernel: [  732.175000] CPU: 2 PID: 0 Comm: swapper/2 Tainted: P         C O 3.13.5 #1
Mar  2 09:15:15 localhost kernel: [  732.175000] Hardware name: OEM OEM/132-BL-E758, BIOS 6.00 PG 04/20/2011
Mar  2 09:15:15 localhost kernel: [  732.175000] task: ffff880351904380 ti: ffff880351928000 task.ti: ffff880351928000
Mar  2 09:15:15 localhost kernel: [  732.175000] RIP: 0010:[<ffffffff812a457b>]  [<ffffffff812a457b>] intel_idle+0xc7/0xec
Mar  2 09:15:15 localhost kernel: [  732.175000] RSP: 0018:ffff880351929e48  EFLAGS: 00000046
Mar  2 09:15:15 localhost kernel: [  732.175000] RAX: 0000000000000010 RBX: 0000000000000004 RCX: 0000000000000001
Mar  2 09:15:15 localhost kernel: [  732.175000] RDX: 0000000000000000 RSI: ffff880351929fd8 RDI: 0000000000000046
Mar  2 09:15:15 localhost kernel: [  732.175000] RBP: 0000000000000003 R08: 000000000000033d R09: 0000000000000006
Mar  2 09:15:15 localhost kernel: [  732.175000] R10: ffff880329306c00 R11: 0000000000000002 R12: 0000000000000010
Mar  2 09:15:15 localhost kernel: [  732.175000] R13: 0000000000000002 R14: 0000000000000000 R15: 0000000000000000
Mar  2 09:15:15 localhost kernel: [  732.175000] FS:  0000000000000000(0000) GS:ffff88035fc40000(0000) knlGS:0000000000000000
Mar  2 09:15:15 localhost kernel: [  732.175000] CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
Mar  2 09:15:15 localhost kernel: [  732.175000] CR2: 00000000f6371000 CR3: 000000000175f000 CR4: 00000000000007e0
Mar  2 09:15:15 localhost kernel: [  732.175000] Stack:
Mar  2 09:15:15 localhost kernel: [  732.175000]  ffff88035fc58a90 0000000281084e0d ffff88035fc58a90 ffff88035fc58a90
Mar  2 09:15:15 localhost kernel: [  732.175000]  ffffffff8179a6d0 000000aa78fe75eb ffff880351929f00 ffffffff8144d5f7
Mar  2 09:15:15 localhost kernel: [  732.175000]  0000000000000003 ffffffff8179a5b0 0000000000000000 00000000000dc34b
Mar  2 09:15:15 localhost kernel: [  732.175000] Call Trace:
Mar  2 09:15:15 localhost kernel: [  732.175000]  [<ffffffff8144d5f7>] ? cpuidle_enter_state+0x37/0xb1
Mar  2 09:15:15 localhost kernel: [  732.175000]  [<ffffffff8144d739>] ? cpuidle_idle_call+0xc8/0x10e
Mar  2 09:15:15 localhost kernel: [  732.175000]  [<ffffffff8101071b>] ? arch_cpu_idle+0x6/0x1a
Mar  2 09:15:15 localhost kernel: [  732.175000]  [<ffffffff8107d1f9>] ? cpu_startup_entry+0xb1/0x138
Mar  2 09:15:15 localhost kernel: [  732.175000] Code: 48 8b 34 25 60 c7 00 00 48 8d 86 38 e0 ff ff 48 89 d1 0f 01 c8 0f ae f0 48 8b 86 38 e0 ff ff a8 08 75 08 b1 01 4c 89 e0 0f 01 c9 <85> 1d c7 63 4f 00 75 0f 48 8d 74 24 0c bf 05 00 00 00 e8 8a 4f 
Mar  2 09:15:15 localhost kernel: [  732.175000] NMI backtrace for cpu 3
Mar  2 09:15:15 localhost kernel: [  732.175000] CPU: 3 PID: 0 Comm: swapper/3 Tainted: P         C O 3.13.5 #1
Mar  2 09:15:15 localhost kernel: [  732.175000] Hardware name: OEM OEM/132-BL-E758, BIOS 6.00 PG 04/20/2011
Mar  2 09:15:15 localhost kernel: [  732.175000] task: ffff880351904a40 ti: ffff88035192a000 task.ti: ffff88035192a000
Mar  2 09:15:15 localhost kernel: [  732.175000] RIP: 0010:[<ffffffff812a457b>]  [<ffffffff812a457b>] intel_idle+0xc7/0xec
Mar  2 09:15:15 localhost kernel: [  732.175000] RSP: 0018:ffff88035192be48  EFLAGS: 00000046
Mar  2 09:15:15 localhost kernel: [  732.175000] RAX: 0000000000000010 RBX: 0000000000000004 RCX: 0000000000000001
Mar  2 09:15:15 localhost kernel: [  732.175000] RDX: 0000000000000000 RSI: ffff88035192bfd8 RDI: 0000000000000046
Mar  2 09:15:15 localhost kernel: [  732.175000] RBP: 0000000000000003 R08: 0000000000000308 R09: 0000000000000006
Mar  2 09:15:15 localhost kernel: [  732.175000] R10: ffff880320855100 R11: 0000000000000003 R12: 0000000000000010
Mar  2 09:15:15 localhost kernel: [  732.175000] R13: 0000000000000002 R14: 0000000000000000 R15: 0000000000000000
Mar  2 09:15:15 localhost kernel: [  732.175000] FS:  0000000000000000(0000) GS:ffff88035fc60000(0000) knlGS:0000000000000000
Mar  2 09:15:15 localhost kernel: [  732.175000] CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
Mar  2 09:15:15 localhost kernel: [  732.175000] CR2: 00000000f0501000 CR3: 000000000175f000 CR4: 00000000000007e0
Mar  2 09:15:15 localhost kernel: [  732.175000] Stack:
Mar  2 09:15:15 localhost kernel: [  732.175000]  ffff88035fc78a90 0000000381084e0d ffff88035fc78a90 ffff88035fc78a90
Mar  2 09:15:15 localhost kernel: [  732.175000]  ffffffff8179a6d0 000000aa78fa2d77 ffff88035192bf00 ffffffff8144d5f7
Mar  2 09:15:15 localhost kernel: [  732.175000]  0000000000000003 ffffffff8179a5b0 0000000000000000 00000000000dbf33
Mar  2 09:15:15 localhost kernel: [  732.175000] Call Trace:
Mar  2 09:15:15 localhost kernel: [  732.175000]  [<ffffffff8144d5f7>] ? cpuidle_enter_state+0x37/0xb1
Mar  2 09:15:15 localhost kernel: [  732.175000]  [<ffffffff8144d739>] ? cpuidle_idle_call+0xc8/0x10e
Mar  2 09:15:15 localhost kernel: [  732.175000]  [<ffffffff8101071b>] ? arch_cpu_idle+0x6/0x1a
Mar  2 09:15:15 localhost kernel: [  732.175000]  [<ffffffff8107d1f9>] ? cpu_startup_entry+0xb1/0x138
Mar  2 09:15:15 localhost kernel: [  732.175000] Code: 48 8b 34 25 60 c7 00 00 48 8d 86 38 e0 ff ff 48 89 d1 0f 01 c8 0f ae f0 48 8b 86 38 e0 ff ff a8 08 75 08 b1 01 4c 89 e0 0f 01 c9 <85> 1d c7 63 4f 00 75 0f 48 8d 74 24 0c bf 05 00 00 00 e8 8a 4f 
Mar  2 09:15:15 localhost kernel: [  732.175000] NMI backtrace for cpu 4
Mar  2 09:15:15 localhost kernel: [  732.175000] CPU: 4 PID: 0 Comm: swapper/4 Tainted: P         C O 3.13.5 #1
Mar  2 09:15:15 localhost kernel: [  732.175000] Hardware name: OEM OEM/132-BL-E758, BIOS 6.00 PG 04/20/2011
Mar  2 09:15:15 localhost kernel: [  732.175000] task: ffff880351905100 ti: ffff88035192c000 task.ti: ffff88035192c000
Mar  2 09:15:15 localhost kernel: [  732.175000] RIP: 0010:[<ffffffff812a457b>]  [<ffffffff812a457b>] intel_idle+0xc7/0xec
Mar  2 09:15:15 localhost kernel: [  732.175000] RSP: 0018:ffff88035192de48  EFLAGS: 00000046
Mar  2 09:15:15 localhost kernel: [  732.175000] RAX: 0000000000000010 RBX: 0000000000000004 RCX: 0000000000000001
Mar  2 09:15:15 localhost kernel: [  732.175000] RDX: 0000000000000000 RSI: ffff88035192dfd8 RDI: 0000000000000046
Mar  2 09:15:15 localhost kernel: [  732.175000] RBP: 0000000000000003 R08: 000000000000033d R09: 0000000000000006
Mar  2 09:15:15 localhost kernel: [  732.175000] R10: ffff88032bab8000 R11: 0000000000000004 R12: 0000000000000010
Mar  2 09:15:15 localhost kernel: [  732.175000] R13: 0000000000000002 R14: 0000000000000000 R15: 0000000000000000
Mar  2 09:15:15 localhost kernel: [  732.175000] FS:  0000000000000000(0000) GS:ffff88035fc80000(0000) knlGS:0000000000000000
Mar  2 09:15:15 localhost kernel: [  732.175000] CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
Mar  2 09:15:15 localhost kernel: [  732.175000] CR2: 00000000f0501000 CR3: 000000000175f000 CR4: 00000000000007e0
Mar  2 09:15:15 localhost kernel: [  732.175000] Stack:
Mar  2 09:15:15 localhost kernel: [  732.175000]  ffff88035fc98a90 0000000481084e0d ffff88035fc98a90 ffff88035fc98a90
Mar  2 09:15:15 localhost kernel: [  732.175000]  ffffffff8179a6d0 000000aa78fe65d2 ffff88035192df00 ffffffff8144d5f7
Mar  2 09:15:15 localhost kernel: [  732.175000]  0000000000000003 ffffffff8179a5b0 0000000000000000 00000000000dce34
Mar  2 09:15:15 localhost kernel: [  732.175000] Call Trace:
Mar  2 09:15:15 localhost kernel: [  732.175000]  [<ffffffff8144d5f7>] ? cpuidle_enter_state+0x37/0xb1
Mar  2 09:15:15 localhost kernel: [  732.175000]  [<ffffffff8144d739>] ? cpuidle_idle_call+0xc8/0x10e
Mar  2 09:15:15 localhost kernel: [  732.175000]  [<ffffffff8101071b>] ? arch_cpu_idle+0x6/0x1a
Mar  2 09:15:15 localhost kernel: [  732.175000]  [<ffffffff8107d1f9>] ? cpu_startup_entry+0xb1/0x138
Mar  2 09:15:15 localhost kernel: [  732.175000] Code: 48 8b 34 25 60 c7 00 00 48 8d 86 38 e0 ff ff 48 89 d1 0f 01 c8 0f ae f0 48 8b 86 38 e0 ff ff a8 08 75 08 b1 01 4c 89 e0 0f 01 c9 <85> 1d c7 63 4f 00 75 0f 48 8d 74 24 0c bf 05 00 00 00 e8 8a 4f 
Mar  2 09:15:15 localhost kernel: [  732.175000] NMI backtrace for cpu 5
Mar  2 09:15:15 localhost kernel: [  732.175000] CPU: 5 PID: 0 Comm: swapper/5 Tainted: P         C O 3.13.5 #1
Mar  2 09:15:15 localhost kernel: [  732.175000] Hardware name: OEM OEM/132-BL-E758, BIOS 6.00 PG 04/20/2011
Mar  2 09:15:15 localhost kernel: [  732.175000] task: ffff8803519057c0 ti: ffff88035192e000 task.ti: ffff88035192e000
Mar  2 09:15:15 localhost kernel: [  732.175000] RIP: 0010:[<ffffffff812a457b>]  [<ffffffff812a457b>] intel_idle+0xc7/0xec
Mar  2 09:15:15 localhost kernel: [  732.175000] RSP: 0018:ffff88035192fe48  EFLAGS: 00000046
Mar  2 09:15:15 localhost kernel: [  732.175000] RAX: 0000000000000010 RBX: 0000000000000004 RCX: 0000000000000001
Mar  2 09:15:15 localhost kernel: [  732.175000] RDX: 0000000000000000 RSI: ffff88035192ffd8 RDI: 0000000000000046
Mar  2 09:15:15 localhost kernel: [  732.175000] RBP: 0000000000000003 R08: 0000000000000340 R09: 0000000000000006
Mar  2 09:15:15 localhost kernel: [  732.175000] R10: ffff8803208557c0 R11: 0000000000000005 R12: 0000000000000010
Mar  2 09:15:15 localhost kernel: [  732.175000] R13: 0000000000000002 R14: 0000000000000000 R15: 0000000000000000
Mar  2 09:15:15 localhost kernel: [  732.175000] FS:  0000000000000000(0000) GS:ffff88035fca0000(0000) knlGS:0000000000000000
Mar  2 09:15:15 localhost kernel: [  732.175000] CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
Mar  2 09:15:15 localhost kernel: [  732.175000] CR2: 00000000f2934000 CR3: 000000000175f000 CR4: 00000000000007e0
Mar  2 09:15:15 localhost kernel: [  732.175000] Stack:
Mar  2 09:15:15 localhost kernel: [  732.175000]  ffff88035fcb8a90 0000000581084e0d ffff88035fcb8a90 ffff88035fcb8a90
Mar  2 09:15:15 localhost kernel: [  732.175000]  ffffffff8179a6d0 000000aa78fe6d30 ffff88035192ff00 ffffffff8144d5f7
Mar  2 09:15:15 localhost kernel: [  732.175000]  0000000000000003 ffffffff8179a5b0 0000000000000000 00000000000dcc06
Mar  2 09:15:15 localhost kernel: [  732.175000] Call Trace:
Mar  2 09:15:15 localhost kernel: [  732.175000]  [<ffffffff8144d5f7>] ? cpuidle_enter_state+0x37/0xb1
Mar  2 09:15:15 localhost kernel: [  732.175000]  [<ffffffff8144d739>] ? cpuidle_idle_call+0xc8/0x10e
Mar  2 09:15:15 localhost kernel: [  732.175000]  [<ffffffff8101071b>] ? arch_cpu_idle+0x6/0x1a
Mar  2 09:15:15 localhost kernel: [  732.175000]  [<ffffffff8107d1f9>] ? cpu_startup_entry+0xb1/0x138
Mar  2 09:15:15 localhost kernel: [  732.175000] Code: 48 8b 34 25 60 c7 00 00 48 8d 86 38 e0 ff ff 48 89 d1 0f 01 c8 0f ae f0 48 8b 86 38 e0 ff ff a8 08 75 08 b1 01 4c 89 e0 0f 01 c9 <85> 1d c7 63 4f 00 75 0f 48 8d 74 24 0c bf 05 00 00 00 e8 8a 4f 
Mar  2 09:15:15 localhost kernel: [  732.175000] NMI backtrace for cpu 6
Mar  2 09:15:15 localhost kernel: [  732.175000] CPU: 6 PID: 0 Comm: swapper/6 Tainted: P         C O 3.13.5 #1
Mar  2 09:15:15 localhost kernel: [  732.175000] Hardware name: OEM OEM/132-BL-E758, BIOS 6.00 PG 04/20/2011
Mar  2 09:15:15 localhost kernel: [  732.175000] task: ffff880351905e80 ti: ffff880351930000 task.ti: ffff880351930000
Mar  2 09:15:15 localhost kernel: [  732.175000] RIP: 0010:[<ffffffff812a457b>]  [<ffffffff812a457b>] intel_idle+0xc7/0xec
Mar  2 09:15:15 localhost kernel: [  732.175000] RSP: 0018:ffff880351931e48  EFLAGS: 00000046
Mar  2 09:15:15 localhost kernel: [  732.175000] RAX: 0000000000000020 RBX: 0000000000000008 RCX: 0000000000000001
Mar  2 09:15:15 localhost kernel: [  732.175000] RDX: 0000000000000000 RSI: ffff880351931fd8 RDI: 0000000000000046
Mar  2 09:15:15 localhost kernel: [  732.175000] RBP: 0000000000000004 R08: 00000000000003c9 R09: 0000000000000008
Mar  2 09:15:15 localhost kernel: [  732.175000] R10: ffff8803519dbcc0 R11: 0000000000000006 R12: 0000000000000020
Mar  2 09:15:15 localhost kernel: [  732.175000] R13: 0000000000000003 R14: 0000000000000000 R15: 0000000000000000
Mar  2 09:15:15 localhost kernel: [  732.175000] FS:  0000000000000000(0000) GS:ffff88035fcc0000(0000) knlGS:0000000000000000
Mar  2 09:15:15 localhost kernel: [  732.175000] CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
Mar  2 09:15:15 localhost kernel: [  732.175000] CR2: 00000000f018b000 CR3: 000000000175f000 CR4: 00000000000007e0
Mar  2 09:15:15 localhost kernel: [  732.175000] Stack:
Mar  2 09:15:15 localhost kernel: [  732.175000]  ffff88035fcd8a90 0000000681084e0d ffff88035fcd8a90 ffff88035fcd8a90
Mar  2 09:15:15 localhost kernel: [  732.175000]  ffffffff8179a728 000000aa78fa2b48 ffff880351931f00 ffffffff8144d5f7
Mar  2 09:15:15 localhost kernel: [  732.175000]  0000000000000004 ffffffff8179a5b0 0000000000000000 00000000000dc7a8
Mar  2 09:15:15 localhost kernel: [  732.175000] Call Trace:
Mar  2 09:15:15 localhost kernel: [  732.175000]  [<ffffffff8144d5f7>] ? cpuidle_enter_state+0x37/0xb1
Mar  2 09:15:15 localhost kernel: [  732.175000]  [<ffffffff8144d739>] ? cpuidle_idle_call+0xc8/0x10e
Mar  2 09:15:15 localhost kernel: [  732.175000]  [<ffffffff8101071b>] ? arch_cpu_idle+0x6/0x1a
Mar  2 09:15:15 localhost kernel: [  732.175000]  [<ffffffff8107d1f9>] ? cpu_startup_entry+0xb1/0x138
Mar  2 09:15:15 localhost kernel: [  732.175000] Code: 48 8b 34 25 60 c7 00 00 48 8d 86 38 e0 ff ff 48 89 d1 0f 01 c8 0f ae f0 48 8b 86 38 e0 ff ff a8 08 75 08 b1 01 4c 89 e0 0f 01 c9 <85> 1d c7 63 4f 00 75 0f 48 8d 74 24 0c bf 05 00 00 00 e8 8a 4f 
Mar  2 09:15:15 localhost kernel: [  732.175000] NMI backtrace for cpu 7
Mar  2 09:15:15 localhost kernel: [  732.175000] CPU: 7 PID: 0 Comm: swapper/7 Tainted: P         C O 3.13.5 #1
Mar  2 09:15:15 localhost kernel: [  732.175000] Hardware name: OEM OEM/132-BL-E758, BIOS 6.00 PG 04/20/2011
Mar  2 09:15:15 localhost kernel: [  732.175000] task: ffff880351906540 ti: ffff880351932000 task.ti: ffff880351932000
Mar  2 09:15:15 localhost kernel: [  732.175000] RIP: 0010:[<ffffffff812a457b>]  [<ffffffff812a457b>] intel_idle+0xc7/0xec
Mar  2 09:15:15 localhost kernel: [  732.175000] RSP: 0018:ffff880351933e48  EFLAGS: 00000046
Mar  2 09:15:15 localhost kernel: [  732.175000] RAX: 0000000000000010 RBX: 0000000000000004 RCX: 0000000000000001
Mar  2 09:15:15 localhost kernel: [  732.175000] RDX: 0000000000000000 RSI: ffff880351933fd8 RDI: 0000000000000046
Mar  2 09:15:15 localhost kernel: [  732.175000] RBP: 0000000000000003 R08: 00000000000003cd R09: 0000000000000008
Mar  2 09:15:15 localhost kernel: [  732.175000] R10: ffff88032bab8000 R11: 0000000000000007 R12: 0000000000000010
Mar  2 09:15:15 localhost kernel: [  732.175000] R13: 0000000000000002 R14: 0000000000000000 R15: 0000000000000000
Mar  2 09:15:15 localhost kernel: [  732.175000] FS:  0000000000000000(0000) GS:ffff88035fce0000(0000) knlGS:0000000000000000
Mar  2 09:15:15 localhost kernel: [  732.175000] CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
Mar  2 09:15:15 localhost kernel: [  732.175000] CR2: 00000000f0dba000 CR3: 000000000175f000 CR4: 00000000000007e0
Mar  2 09:15:15 localhost kernel: [  732.175000] Stack:
Mar  2 09:15:15 localhost kernel: [  732.175000]  ffff88035fcf8a90 0000000781084e0d ffff88035fcf8a90 ffff88035fcf8a90
Mar  2 09:15:15 localhost kernel: [  732.175000]  ffffffff8179a6d0 000000aa78fa0f2e ffff880351933f00 ffffffff8144d5f7
Mar  2 09:15:15 localhost kernel: [  732.175000]  0000000000000003 ffffffff8179a5b0 0000000000000000 00000000000ddd7b
Mar  2 09:15:15 localhost kernel: [  732.175000] Call Trace:
Mar  2 09:15:15 localhost kernel: [  732.175000]  [<ffffffff8144d5f7>] ? cpuidle_enter_state+0x37/0xb1
Mar  2 09:15:15 localhost kernel: [  732.175000]  [<ffffffff8144d739>] ? cpuidle_idle_call+0xc8/0x10e
Mar  2 09:15:15 localhost kernel: [  732.175000]  [<ffffffff8101071b>] ? arch_cpu_idle+0x6/0x1a
Mar  2 09:15:15 localhost kernel: [  732.175000]  [<ffffffff8107d1f9>] ? cpu_startup_entry+0xb1/0x138
Mar  2 09:15:15 localhost kernel: [  732.175000] Code: 48 8b 34 25 60 c7 00 00 48 8d 86 38 e0 ff ff 48 89 d1 0f 01 c8 0f ae f0 48 8b 86 38 e0 ff ff a8 08 75 08 b1 01 4c 89 e0 0f 01 c9 <85> 1d c7 63 4f 00 75 0f 48 8d 74 24 0c bf 05 00 00 00 e8 8a 4f
Comment 1 devsk 2014-03-02 22:21:06 UTC
Created attachment 127791 [details]
The dmesg in a file.

Adding that log as a file because its hard to read the above text.
Comment 2 devsk 2014-03-03 01:05:54 UTC
I formatted the cache and backing device using 'make-bcache -b 512k -w 512 -C /dev/sda5 -B /dev/sdg1'.

I chose 512k for bucket size to match my erase block size. I am emulating standard disk with 512 byte sector for ZFS, so I used -w 512.

Everything else is default. No writeback.
Comment 3 Coly Li 2020-02-15 17:08:02 UTC
Does this problem still show up in Linux v5.5 or v5.6-rc ?

Thanks.

Coly Li