All of lore.kernel.org
 help / color / mirror / Atom feed
* bcacheX is missing after removing a backend and adding it again
@ 2021-02-25  3:12 wubenqing
  2021-02-25 14:54 ` Coly Li
  0 siblings, 1 reply; 3+ messages in thread
From: wubenqing @ 2021-02-25  3:12 UTC (permalink / raw)
  To: linux-bcache

Hi guys,
I am testing a scenario where multiple backend attach one cache. When I removed one of the backend and added it back, I found that bcacheX was missing. I configured cache_mode to writeback.

Before:
/dev/sdd
└─bcache0
/dev/sdc
└─bcache1

After:
/dev/sdg
/dev/sdc
└─bcache1


The name of the block device /dev/sdd is changed to /dev/sdg, and bcache0 is missing when excuting lsblk. I found that /sys/bkock/bache0/bcache link to the old device which does not exist.
# ll /sys/block/bcache0/bcache
lrwxrwxrwx 1 root root 0 Feb 23 17:36 /sys/block/bcache0/bcache -> ../../../pci0000:80/0000:80:01.0/0000:82:00.0/host1/port-1:3/end_device-1:3/target1:0:3/1:0:3:0/block/sdd/bcache


The super block of /dev/sdg shows that there is still dirty data stored on the cache device.
# bcache-super-show /dev/sdg
sb.magicok
sb.first_sector8 [match]
sb.csum 80AE8CFCCC740075 [match]
sb.version1 [backing device]

dev.label(empty)
dev.uuid22cb8e47-67d8-4f54-97b4-a8c86d986aac
dev.sectors_per_block 1
dev.sectors_per_bucket 1024
dev.data.first_sector 16
dev.data.cache_mode 1 [writeback]
dev.data.cache_state 2 [dirty]


When I checked the kernel log, I found that:
...
[81701.447130] bcache: bch_count_backing_io_errors() sdd: IO error on backing device, unrecoverable
[81701.487543] bcache: bch_count_backing_io_errors() sdd: IO error on backing device, unrecoverable
[81701.985562] bcache: bch_count_backing_io_errors() sdd: IO error on backing device, unrecoverable
[81702.590435] bcache: backing_request_endio() Can't flush sdd: returned bi_status 10

...
[81849.890604] bcache: register_bdev() registered backing device sdg
[81849.890608] bcache: bch_cached_dev_attach() Tried to attach sdg but duplicate UUID already attached

...

"IO error on backing device, unrecoverable" appeared 63 times in total. It may be that the io_disable of the backend device is set to true due to io_error_limit is 64, but I did not find the log "too many IO errors on backing device" which bch_cached_dev_error will print.

bch_writeback_thread is very high cpu usage and the SSD(cache) shows very high read traffic but no write traffic.

Device:         rrqm/s   wrqm/s     r/s     w/s    rMB/s    wMB/s avgrq-sz avgqu-sz   await r_await w_await  svctm  %util
nvme0n1           0.00     0.00 33836.00    0.00  1619.07     0.00    98.00    76.55    2.68    2.68    0.00   0.03 100.00


The important problem is that there is no way to recover bcache0, even if I try to re-execute "echo /dev/sdg > /sys/fs/bcache/register". The kernel log shows that:
[91091.621773] bcache: register_bcache() error : device already registered

I suspect that /dev/sdd still remains in c->cached_devs, and it is set to io_disable, and /dev/sdd does not exist anymore, so writeback cannot flush dirty data. Since the name of the block device has become /dev/sdg, /dev/sdg cannot be reattached successfully.
Does bcache support backend for hot-swapping scenarios? If not, what command should I use to manually restore bcache0.

Thank you.






^ permalink raw reply	[flat|nested] 3+ messages in thread

* Re: bcacheX is missing after removing a backend and adding it again
  2021-02-25  3:12 bcacheX is missing after removing a backend and adding it again wubenqing
@ 2021-02-25 14:54 ` Coly Li
  0 siblings, 0 replies; 3+ messages in thread
From: Coly Li @ 2021-02-25 14:54 UTC (permalink / raw)
  To: wubenqing; +Cc: linux-bcache

On 2/25/21 11:12 AM, wubenqing@ruijie.com.cn wrote:
> Hi guys,
> I am testing a scenario where multiple backend attach one cache. When I removed one of the backend and added it back, I found that bcacheX was missing. I configured cache_mode to writeback.
> 
> Before:
> /dev/sdd
> └─bcache0
> /dev/sdc
> └─bcache1
> 
> After:
> /dev/sdg
> /dev/sdc
> └─bcache1
> 
> 
> The name of the block device /dev/sdd is changed to /dev/sdg, and bcache0 is missing when excuting lsblk. I found that /sys/bkock/bache0/bcache link to the old device which does not exist.
> # ll /sys/block/bcache0/bcache
> lrwxrwxrwx 1 root root 0 Feb 23 17:36 /sys/block/bcache0/bcache -> ../../../pci0000:80/0000:80:01.0/0000:82:00.0/host1/port-1:3/end_device-1:3/target1:0:3/1:0:3:0/block/sdd/bcache
> 
> 
> The super block of /dev/sdg shows that there is still dirty data stored on the cache device.
> # bcache-super-show /dev/sdg
> sb.magicok
> sb.first_sector8 [match]
> sb.csum 80AE8CFCCC740075 [match]
> sb.version1 [backing device]
> 
> dev.label(empty)
> dev.uuid22cb8e47-67d8-4f54-97b4-a8c86d986aac
> dev.sectors_per_block 1
> dev.sectors_per_bucket 1024
> dev.data.first_sector 16
> dev.data.cache_mode 1 [writeback]
> dev.data.cache_state 2 [dirty]
> 
> 
> When I checked the kernel log, I found that:
> ...
> [81701.447130] bcache: bch_count_backing_io_errors() sdd: IO error on backing device, unrecoverable
> [81701.487543] bcache: bch_count_backing_io_errors() sdd: IO error on backing device, unrecoverable
> [81701.985562] bcache: bch_count_backing_io_errors() sdd: IO error on backing device, unrecoverable
> [81702.590435] bcache: backing_request_endio() Can't flush sdd: returned bi_status 10
> 
> ...
> [81849.890604] bcache: register_bdev() registered backing device sdg
> [81849.890608] bcache: bch_cached_dev_attach() Tried to attach sdg but duplicate UUID already attached
> 
> ...
> 
> "IO error on backing device, unrecoverable" appeared 63 times in total. It may be that the io_disable of the backend device is set to true due to io_error_limit is 64, but I did not find the log "too many IO errors on backing device" which bch_cached_dev_error will print.
> 
> bch_writeback_thread is very high cpu usage and the SSD(cache) shows very high read traffic but no write traffic.
> 
> Device:         rrqm/s   wrqm/s     r/s     w/s    rMB/s    wMB/s avgrq-sz avgqu-sz   await r_await w_await  svctm  %util
> nvme0n1           0.00     0.00 33836.00    0.00  1619.07     0.00    98.00    76.55    2.68    2.68    0.00   0.03 100.00
> 
> 
> The important problem is that there is no way to recover bcache0, even if I try to re-execute "echo /dev/sdg > /sys/fs/bcache/register". The kernel log shows that:
> [91091.621773] bcache: register_bcache() error : device already registered
> 
> I suspect that /dev/sdd still remains in c->cached_devs, and it is set to io_disable, and /dev/sdd does not exist anymore, so writeback cannot flush dirty data. Since the name of the block device has become /dev/sdg, /dev/sdg cannot be reattached successfully.
> Does bcache support backend for hot-swapping scenarios? If not, what command should I use to manually restore bcache0.

Which kernel version do you use ?

A reboot might solve the problem. But I feel it could be improved to
avoid the extra reboot.

Let me add it into my todo list, if no one else posts patch before I
work on it...

Thanks for the suggestion.

Coly Li

^ permalink raw reply	[flat|nested] 3+ messages in thread

* Re: bcacheX is missing after removing a backend and adding it again
@ 2021-02-26  3:16 wubenqing
  0 siblings, 0 replies; 3+ messages in thread
From: wubenqing @ 2021-02-26  3:16 UTC (permalink / raw)
  To: colyli; +Cc: linux-bcache

> On 2/25/21 11:12 AM, wubenqing@ruijie.com.cn wrote:
> > Hi guys,
> > I am testing a scenario where multiple backend attach one cache. When I
> removed one of the backend and added it back, I found that bcacheX was
> missing. I configured cache_mode to writeback.
> >
> > Before:
> > /dev/sdd
> > └─bcache0
> > /dev/sdc
> > └─bcache1
> >
> > After:
> > /dev/sdg
> > /dev/sdc
> > └─bcache1
> >
> >
> > The name of the block device /dev/sdd is changed to /dev/sdg, and
> bcache0 is missing when excuting lsblk. I found that
> /sys/bkock/bache0/bcache link to the old device which does not exist.
> > # ll /sys/block/bcache0/bcache
> > lrwxrwxrwx 1 root root 0 Feb 23 17:36 /sys/block/bcache0/bcache ->
> > ../../../pci0000:80/0000:80:01.0/0000:82:00.0/host1/port-1:3/end_devic
> > e-1:3/target1:0:3/1:0:3:0/block/sdd/bcache
> >
> >
> > The super block of /dev/sdg shows that there is still dirty data stored on
> the cache device.
> > # bcache-super-show /dev/sdg
> > sb.magicok
> > sb.first_sector8 [match]
> > sb.csum 80AE8CFCCC740075 [match]
> > sb.version1 [backing device]
> >
> > dev.label(empty)
> > dev.uuid22cb8e47-67d8-4f54-97b4-a8c86d986aac
> > dev.sectors_per_block 1
> > dev.sectors_per_bucket 1024
> > dev.data.first_sector 16
> > dev.data.cache_mode 1 [writeback]
> > dev.data.cache_state 2 [dirty]
> >
> >
> > When I checked the kernel log, I found that:
> > ...
> > [81701.447130] bcache: bch_count_backing_io_errors() sdd: IO error on
> > backing device, unrecoverable [81701.487543] bcache:
> > bch_count_backing_io_errors() sdd: IO error on backing device,
> > unrecoverable [81701.985562] bcache: bch_count_backing_io_errors()
> > sdd: IO error on backing device, unrecoverable [81702.590435] bcache:
> > backing_request_endio() Can't flush sdd: returned bi_status 10
> >
> > ...
> > [81849.890604] bcache: register_bdev() registered backing device sdg
> > [81849.890608] bcache: bch_cached_dev_attach() Tried to attach sdg but
> > duplicate UUID already attached
> >
> > ...
> >
> > "IO error on backing device, unrecoverable" appeared 63 times in total. It
> may be that the io_disable of the backend device is set to true due to
> io_error_limit is 64, but I did not find the log "too many IO errors on backing
> device" which bch_cached_dev_error will print.
> >
> > bch_writeback_thread is very high cpu usage and the SSD(cache) shows
> very high read traffic but no write traffic.
> >
> > Device:         rrqm/s   wrqm/s     r/s     w/s    rMB/s
> wMB/s avgrq-sz avgqu-sz   await r_await w_await  svctm  %util
> > nvme0n1           0.00     0.00 33836.00    0.00  1619.07
> 0.00    98.00    76.55    2.68    2.68    0.00   0.03 100.00
> >
> >
> > The important problem is that there is no way to recover bcache0, even if I
> try to re-execute "echo /dev/sdg > /sys/fs/bcache/register". The kernel log
> shows that:
> > [91091.621773] bcache: register_bcache() error : device already
> > registered
> >
> > I suspect that /dev/sdd still remains in c->cached_devs, and it is set to
> io_disable, and /dev/sdd does not exist anymore, so writeback cannot flush
> dirty data. Since the name of the block device has become /dev/sdg,
> /dev/sdg cannot be reattached successfully.
> > Does bcache support backend for hot-swapping scenarios? If not, what
> command should I use to manually restore bcache0.
> 
> Which kernel version do you use ?
> 
> A reboot might solve the problem. But I feel it could be improved to avoid
> the extra reboot.
> 
> Let me add it into my todo list, if no one else posts patch before I work on
> it...
> 
> Thanks for the suggestion.
> 
> Coly Li

Thank you, your suggestion worked. When I restarted the machine, the problem disappeared. The kernel version is "5.4.90-1.el7.elrepo.x86_64". 
What is the reason why bch_writeback_thread occupies a high CPU, and always reads data from SSDs at a very high rate. This phenomenon continued for several hours until I restarted the machine. Please help to confirm whether it is a bug.

Another question is about the cache device. I also unplugged and plugged the cache device and found a problem. After the cache disk was back online, the backend did not automatically attach successfully. And manually using the command can only make one of the backend attach succeed, and the other one fails.

Before:
NAME              MAJ:MIN RM   SIZE RO TYPE MOUNTPOINT
sdd                 8:48   0   9.1T  0 disk 
└─bcache0         252:0    0   9.1T  0 disk 
sdb                 8:16   0 931.5G  0 disk 
└─bcache1         252:128  0 931.5G  0 disk 
sdh                 8:112  0 447.1G  0 disk 
├─sdh1              8:113  0   200G  0 part 
│ ├─bcache0       252:0    0   9.1T  0 disk 
│ └─bcache1       252:128  0 931.5G  0 disk 
└─sdh2              8:114  0 247.1G  0 part
/dev/sdh is cache device.

After:
NAME              MAJ:MIN RM   SIZE RO TYPE MOUNTPOINT
sdd                 8:48   0   9.1T  0 disk 
└─bcache0         252:0    0   9.1T  0 disk 
sdb                 8:16   0 931.5G  0 disk 
└─bcache1         252:128  0 931.5G  0 disk 
sdg                 8:96   0 447.1G  0 disk 
├─sdg1              8:97   0   200G  0 part 
└─sdg2              8:98   0 247.1G  0 part
/dev/sdg is cache device.

The kernel log is:
...
[82566.436157] blk_update_request: I/O error, dev sdh, sector 17868400 op 0x0:(READ) flags 0x0 phys_seg 1 prio class 0
[82566.436162] bcache: bch_count_io_errors() sdh1: IO error on reading from cache, recovering.
[82566.436171] blk_update_request: I/O error, dev sdh, sector 28192496 op 0x1:(WRITE) flags 0x0 phys_seg 4 prio class 0
[82566.436173] bcache: bch_count_io_errors() sdh1: IO error on writing data to cache.
[82566.436175] bcache: bch_count_io_errors() sdh1: IO error on writing data to cache.
[82566.436180] blk_update_request: I/O error, dev sdh, sector 29303936 op 0x1:(WRITE) flags 0x0 phys_seg 3 prio class 0
[82566.436182] bcache: bch_count_io_errors() sdh1: IO error on writing data to cache.
[82566.436186] blk_update_request: I/O error, dev sdh, sector 30462320 op 0x1:(WRITE) flags 0x0 phys_seg 1 prio class 0
[82566.436188] bcache: bch_count_io_errors() sdh1: IO error on writing data to cache.
[82566.436691] bcache: bch_count_io_errors() sdh1: IO error on writing data to cache.
[82566.438654] blk_update_request: I/O error, dev sdh, sector 28192528 op 0x1:(WRITE) flags 0x0 phys_seg 16 prio class 0
[82566.440356] bcache: bch_cache_set_error() bcache: error on f4e8b4d6-c354-45be-9510-725fe69c1b16: 
[82566.443227] bcache: bch_cache_set_error() CACHE_SET_IO_DISABLE already set
[82566.445156] sdh1: too many IO errors writing data to cache
[82566.445158] bcache: bch_cache_set_error() , disabling caching

[82566.445183] bcache: conditional_stop_bcache_device() stop_when_cache_set_failed of bcache0 is "auto" and cache is dirty, stop it to avoid potential data corruption.
[82566.448983] bcache: bch_cache_set_error() bcache: error on f4e8b4d6-c354-45be-9510-725fe69c1b16: 
[82566.450875] bcache: conditional_stop_bcache_device() stop_when_cache_set_failed of bcache1 is "auto" and cache is clean, keep it alive.
[82566.452653] sdh1: too many IO errors writing data to cache
[82566.452654] bcache: bch_cache_set_error() , disabling caching

[82566.454453] bcache: cached_dev_detach_finish() Caching disabled for sdb
[82566.459006] bcache: cached_dev_detach_finish() Caching disabled for sdd
[82566.499025] bcache: cache_set_free() Cache set f4e8b4d6-c354-45be-9510-725fe69c1b16 unregistered
...
[82866.099218] scsi 1:0:2:0: Direct-Access     ATA      INTEL SSDSC2KB48 0110 PQ: 0 ANSI: 6
[82866.099229] scsi 1:0:2:0: SATA: handle(0x000b), sas_addr(0x4433221103000000), phy(3), device_name(0x55cd2e4152128da4)
[82866.099232] scsi 1:0:2:0: enclosure logical id (0x56c92bf0002b9105), slot(1) 
[82866.099234] scsi 1:0:2:0: enclosure level(0x0000), connector name(     )
[82866.099298] scsi 1:0:2:0: atapi(n), ncq(y), asyn_notify(n), smart(y), fua(y), sw_preserve(y)
[82866.100072] sd 1:0:2:0: Attached scsi generic sg3 type 0
[82866.101121] sd 1:0:2:0: [sdg] 937703088 512-byte logical blocks: (480 GB/447 GiB)
[82866.101125] sd 1:0:2:0: [sdg] 4096-byte physical blocks
[82866.101366] sd 1:0:2:0: [sdg] Write Protect is off
[82866.101369] sd 1:0:2:0: [sdg] Mode Sense: 9b 00 10 08
[82866.101646] sd 1:0:2:0: [sdg] Write cache: enabled, read cache: enabled, supports DPO and FUA
[82866.118234]  sdg: sdg1 sdg2
[82866.121101] sd 1:0:2:0: [sdg] Attached SCSI disk
[82866.432383] bcache: bch_journal_replay() journal replay done, 75408 keys in 376 entries, seq 4483
[82866.432655] bcache: register_cache() registered cache device sdg1
...

# bcache-super-show /dev/sdd
sb.magic		ok
sb.first_sector		8 [match]
sb.csum			59C6B401494EAB2F [match]
sb.version		1 [backing device]

dev.label		(empty)
dev.uuid		8307dc11-4dff-4286-a4c5-76a79f518b27
dev.sectors_per_block	1
dev.sectors_per_bucket	1024
dev.data.first_sector	16
dev.data.cache_mode	1 [writeback]
dev.data.cache_state	0 [detached]

cset.uuid		00000000-0000-0000-0000-000000000000
# bcache-super-show /dev/sdb
sb.magic		ok
sb.first_sector		8 [match]
sb.csum			4BDD5D546EA35D9E [match]
sb.version		1 [backing device]

dev.label		(empty)
dev.uuid		0996b86e-a467-4dda-9fa3-8f2f3da8567a
dev.sectors_per_block	1
dev.sectors_per_bucket	1024
dev.data.first_sector	16
dev.data.cache_mode	1 [writeback]
dev.data.cache_state	0 [detached]

cset.uuid		00000000-0000-0000-0000-000000000000

# bcache-super-show /dev/sdg1
sb.magic		ok
sb.first_sector		8 [match]
sb.csum			9D67FC82E9F8952A [match]
sb.version		3 [cache device]

dev.label		(empty)
dev.uuid		021c2064-ca55-4228-97e1-e95af4dd9113
dev.sectors_per_block	1
dev.sectors_per_bucket	1024
dev.cache.first_sector	1024
dev.cache.cache_sectors	419429376
dev.cache.total_sectors	419430400
dev.cache.ordered	yes
dev.cache.discard	no
dev.cache.pos		0
dev.cache.replacement	0 [lru]

cset.uuid		f4e8b4d6-c354-45be-9510-725fe69c1b16

bcache1 failed. I find that /sys/block/sdd/bcache disappeared, and I do not know why.
# echo f4e8b4d6-c354-45be-9510-725fe69c1b16 > /sys/block/bcache0/bcache/attach
-bash: /sys/block/bcache0/bcache/attach: No such file or directory

I tried to manually register the backend and it failed. How can I restore the backend's bcache directory, if I don't restart the machine.
# echo /dev/sdd > /sys/fs/bcache/register
-bash: echo: write error: Invalid argument
[132767.174638] bcache: register_bcache() error : device already registered

bcache0 Succeed.
# echo f4e8b4d6-c354-45be-9510-725fe69c1b16 > /sys/block/bcache1/bcache/attach

^ permalink raw reply	[flat|nested] 3+ messages in thread

end of thread, other threads:[~2021-02-26  3:20 UTC | newest]

Thread overview: 3+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2021-02-25  3:12 bcacheX is missing after removing a backend and adding it again wubenqing
2021-02-25 14:54 ` Coly Li
2021-02-26  3:16 wubenqing

This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.