Comment 6 for bug 1445273

Revision history for this message
Peter Maloney (peter-maloney) wrote :

I get the same problem with kernel 3.13.0-103-generic on Ubuntu 14.04.5

I can reproduce it easily with this script (ssd1 is a volume group, and sdb is a whole disk that already has bcache with writeback enabled).

(
csetuuid=$(bcache-super-show /dev/ssd1/bcache_sdb | awk '$1 == "cset.uuid" {print $2}')
echo "$csetuuid" > /sys/block/bcache0/bcache/detach
[ -n "$csetuuid" ] && echo 1 > /sys/fs/bcache/"$csetuuid"/stop
dd if=/dev/zero of=/dev/ssd1/bcache_sdb bs=1M count=1
make-bcache -C /dev/ssd1/bcache_sdb
echo /dev/ssd1/bcache_sdb > /sys/fs/bcache/register
csetuuid=$(bcache-super-show /dev/ssd1/bcache_sdb | awk '$1 == "cset.uuid" {print $2}')
echo "$csetuuid" > /sys/block/bcache0/bcache/attach

bcache-super-show /dev/sdb
)

3,612,50699700,-;bcache: __cached_dev_store() Can't attach 375f533e-0fbf-4fd9-9849-a0e4f10fd11c\x0a: cache set not found
5,613,50720567,-;bcache: run_cache_set() invalidating existing data
6,614,50729841,-;bcache: bch_cached_dev_attach() Caching sdb as bcache0 on set 375f533e-0fbf-4fd9-9849-a0e4f10fd11c
6,615,50729857,-;bcache: register_cache() registered cache device dm-1
6,616,63752822,-;bcache: cached_dev_detach_finish() Caching disabled for sdb
6,617,63756250,-;bcache: cache_set_free() Cache set 375f533e-0fbf-4fd9-9849-a0e4f10fd11c unregistered
1,618,63852168,-;BUG: unable to handle kernel NULL pointer dereference at 0000000000000a00
1,619,63852267,-;IP: [<ffffffffa0070440>] journal_write_unlocked+0x130/0x570 [bcache]
4,620,63852363,-;PGD 0
4,621,63852391,-;Oops: 0000 [#1] SMP
4,622,63852435,-;Modules linked in: ocfs2_dlmfs ocfs2_stack_o2cb ocfs2_dlm ocfs2_nodemanager ocfs2_stackglue configfs ppdev xfs serio_raw lpc_ich shpchp parport_pc mac_hid lp parport btrfs xor bcache raid6_pq libcrc32c psmouse ahci libahci virtio_scsi
4,623,63852702,-;CPU: 0 PID: 32 Comm: kworker/0:1 Not tainted 3.13.0-103-generic #150-Ubuntu
4,624,63852759,-;Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS 1.10.0-20161027_200622-foutrelis 04/01/2014
4,625,63852836,-;Workqueue: events journal_write_work [bcache]
4,626,63852876,-;task: ffff88005c833000 ti: ffff88005c83a000 task.ti: ffff88005c83a000
4,627,63852929,-;RIP: 0010:[<ffffffffa0070440>] [<ffffffffa0070440>] journal_write_unlocked+0x130/0x570 [bcache]
4,628,63853006,-;RSP: 0018:ffff88005c83bd88 EFLAGS: 00010202
4,629,63853044,-;RAX: 0000000000000000 RBX: ffff880058e6cba0 RCX: 0000000000000000
4,630,63853094,-;RDX: ffff880058e60c48 RSI: ffff880058e6cad8 RDI: ffff880041808040
4,631,63853144,-;RBP: ffff88005c83bde0 R08: 2001639b2f400000 R09: 5e80000000000000
4,632,63853193,-;R10: dffe246529a6cbd0 R11: 0000000000000000 R12: 0000000000000001
4,633,63853243,-;R13: ffff880058e6ccc8 R14: 0000000000000001 R15: ffff880058e60000
4,634,63853294,-;FS: 0000000000000000(0000) GS:ffff88005fc00000(0000) knlGS:0000000000000000
4,635,63853350,-;CS: 0010 DS: 0000 ES: 0000 CR0: 000000008005003b
4,636,63853391,-;CR2: 0000000000000a00 CR3: 000000005a349000 CR4: 00000000000006f0
4,637,63853444,-;Stack:
4,638,63853460,-; ffffffff810a0d78 ffff880058e60000 ffff88005c83bde8 ffffffff81013558
4,639,63853522,-; 000000005c83bdf8 ffff88005c8334e8 ffff880058e60000 ffff880058e6cba0
4,640,63853582,-; ffff88005fc16900 0000000000000000 ffff880058e6cbd0 ffff88005c83be00
4,641,63853644,-;Call Trace:
4,642,63853667,-; [<ffffffff810a0d78>] ? sched_clock_cpu+0xa8/0x100
4,643,63853712,-; [<ffffffff81013558>] ? __switch_to+0xe8/0x4f0
4,644,63853790,-; [<ffffffffa00708d0>] journal_try_write+0x50/0x60 [bcache]
4,645,63855084,-; [<ffffffffa0070902>] journal_write_work+0x22/0x30 [bcache]
4,646,63856120,-; [<ffffffff81086fc8>] process_one_work+0x178/0x470
4,647,63856120,-; [<ffffffff81087de1>] worker_thread+0x121/0x410
4,648,63856120,-; [<ffffffff81087cc0>] ? rescuer_thread+0x430/0x430
4,649,63856120,-; [<ffffffff8108ebc9>] kthread+0xc9/0xe0
4,650,63856120,-; [<ffffffff8108eb00>] ? kthread_create_on_node+0x1c0/0x1c0
4,651,63856120,-; [<ffffffff8173d928>] ret_from_fork+0x58/0x90
4,652,63856120,-; [<ffffffff8108eb00>] ? kthread_create_on_node+0x1c0/0x1c0
4,653,63856120,-;Code: 10 00 00 00 e8 b2 86 30 e1 31 c0 66 83 bb 94 38 ff ff 00 48 8b 8b a0 40 ff ff 49 8d 97 48 0c 00 00 74 3b 0f 1f 84 00 00 00 00 00 <48> 8b b9 00 0a 00 00 0f b7 89 ce 00 00 00 83 c0 01 49 8b 75 00
1,654,63856120,-;RIP [<ffffffffa0070440>] journal_write_unlocked+0x130/0x570 [bcache]
4,655,63856120,-; RSP <ffff88005c83bd88>
4,656,63856120,-;CR2: 0000000000000a00
4,657,63856120,-;---[ end trace 2a39e8b0821fe990 ]---

And on kernel 4.4.0-51-generic (linux-image-generic-lts-xenial), instead of this, what happens when repeatedly running the above script is (much more rarely, usually only while there's io load) the link /sys/block/bcache0/bcache becomes broken and I can't seem to fix it without reboot.

6,1065,4763943994,-;bcache: bch_cached_dev_attach() Caching sdb as bcache0 on set f1ad8c4b-badb-4f17-a55f-719679886817
6,1066,4764286098,-;bcache: cached_dev_detach_finish() Caching disabled for sdb
6,1067,4764292801,-;bcache: cache_set_free() Cache set f1ad8c4b-badb-4f17-a55f-719679886817 unregistered
5,1068,4764330806,-;bcache: run_cache_set() invalidating existing data
6,1069,4764338346,-;bcache: register_cache() registered cache device dm-1
6,1070,4764342565,-;bcache: bch_cached_dev_attach() Caching sdb as bcache0 on set c332e002-021b-459d-b15f-919d01d6222e
6,1071,4764641572,-;bcache: cached_dev_detach_finish() Caching disabled for sdb
6,1072,4764647868,-;bcache: cache_set_free() Cache set c332e002-021b-459d-b15f-919d01d6222e unregistered
6,1073,4764648050,-;bcache: register_bcache() error opening /dev/ssd1/bcache_sdb: Not a bcache superblock
5,1074,4764944627,-;bcache: run_cache_set() invalidating existing data
6,1075,4764952544,-;bcache: register_cache() registered cache device dm-1
6,1076,4764956435,-;bcache: bch_cached_dev_attach() Caching sdb as bcache0 on set 97eab8e1-ef13-4f7d-ab12-823e9fcf443e
6,1077,4774637932,-;bcache: register_bcache() error opening /dev/ssd1/bcache_sdb: device already registered
6,1078,4774824790,-;bcache: cached_dev_detach_finish() Caching disabled for sdb
6,1079,4774828952,-;bcache: cache_set_free() Cache set 97eab8e1-ef13-4f7d-ab12-823e9fcf443e unregistered
5,1080,4775086661,-;bcache: run_cache_set() invalidating existing data
6,1081,4775094966,-;bcache: register_cache() registered cache device dm-1
6,1082,4777033082,-;bcache: cache_set_free() Cache set 4abf4565-90bf-4ace-ac1d-32e067e7af5c unregistered
5,1083,4777064506,-;bcache: run_cache_set() invalidating existing data
6,1084,4777070580,-;bcache: register_cache() registered cache device dm-1
6,1085,4777736620,-;bcache: cache_set_free() Cache set bc7ef43c-72c6-4287-b8a0-0d06dd017241 unregistered
5,1086,4777762411,-;bcache: run_cache_set() invalidating existing data
6,1087,4777769844,-;bcache: register_cache() registered cache device dm-1

# file /sys/block/bcache0/bcache
/sys/block/bcache0/bcache: broken symbolic link to `../../../pci0000:00/0000:00:02.0/virtio0/host0/target0:0:1/0:0:1:0/block/sdb/bcache'