Bug 1665575

Thanks, I recall seeing something like this once while playing with various sizes of bcache blocks and io sizes, I need to see if I have any record of it.  It may have been related to a single io being split into too many bcache blocks.

This is a bug in the way that lvm sets the number of blocks in the bcache, which in this case is too small.  To fix this we need to either use a value that is always sufficiently large (which is hard to do without always allocating a lot of unnecessary memory), or dynamically increase the number of blocks, or fall back to using temporary buffers on demand that are not cached.

lvm sets the number of bcache blocks to the number of devices on the system, and this comment explains when that may not be a good choice:

https://sourceware.org/git/?p=lvm2.git;a=blob;f=lib/label/label.c;h=e01608d2ce571e714669567b179575b28dd9e7f5;hb=refs/heads/2018-06-01-stable#l775

I had assumed that if this value was too small, bcache would fall back to recycling blocks which would just reduce efficiency.  That's true, but in this case, all of the blocks are needed to complete a single write (since the metadata is so large.)

I don't see a good way of temporarily working around this problem until we can put out a fix.  Options include keeping the size of the metadata lower, or possibly adding an artificial number of additional devices that lvm would count when setting the size of the bcache.

Joe, what are your thoughts fixing this in RHEL7?  The simplest and quickest solution is to always allocate a larger number of blocks.  In combination with that, we would probably want to add a config setting that could set the bcache size even larger (since I don't think lvm imposes any limit on the max metadata size.)  I'd probably go for this option unless you think one of the others looks simple.

Could bug#1639470 be a related somehow?   We hit bug#1639470 and tried to fix it up by deleting the queued create message1 in pool0.  When attempting to restore the dump we hit bug#166575 (this thread). We are now wiping the PV header and reloading the VG using the procedure above.  

Since there are so many snapshots, lvremove takes about 30 seconds per removal, even when listed on the same commandline (eg, xargs).  To speed this up, we are deleting them by programatically updating the metadata and calling `dmsetup message pool0 0 'delete dev_id'` for each ID matching our regex.  (nb, it would be nice to have lvremove handle bulk removes without treating them individually.)

I'll attach the lv-delete-bulk script we use in case it helps anyone else.

Created attachment 1521162 [details]
Bulk-delete lvthin logical volumes

We could add a method to grow the bcache which would be called when large metadata was discovered.  Have to be careful to call it at a point where memory allocation is allowed though.

Another logical effect that I reproduced with more testing, is that the scanning phase will fail to read the metadata when it's larger than the bcache size (when a vg already exists with metadata larger than the bcache size.)  So, this bug will prevent existing large vgs from being read, not just from being modified.

Growing the bcache would probably be required in two places:

1. In response to a "bcache full" error returned during the scanning phase, to handle existing vgs that won't fit in bcache.

2. After the scanning phase is done, checking the max metadata size that was seen, and growing the bcache size to some larger size that would accomodate any possible modification the command might make.

That sounds a little too complex for rhel7 at this point.  For rhel7 I think we should add an lvm.conf setting that lets users forcibly increase the bcache size.  To reduce the cases where users have to do this, I think we can add some more intelligence to the bcache size we create.

I thought of another hint we could use to pick a large enough bcache size, and that is looking at the size of the metadata backup files in /etc/lvm/backup, and setting the bcache size to the largest seen.  This would not be entirely accurate, but in most cases should be effective.  (The backup files can be disabled, and backup files are not removed when a vg is removed which could lead to unnecessarily large bcache sizes after a large vg is removed.)  I'm not yet sure how this would look, or if it's a good idea.

Pushed three commits to stable-2.02 branch:

https://sourceware.org/git/?p=lvm2.git;a=commit;h=8dbfdb5b737cf916a8b95b8d19eec67a960a6392
https://sourceware.org/git/?p=lvm2.git;a=commit;h=863a2e693ee95b95463d60fa8b21f4c7c084292c
https://sourceware.org/git/?p=lvm2.git;a=commit;h=590a1ebcf78b8aae2a1e5ebaba1ac24a54435690

commit 8dbfdb5b737cf916a8b95b8d19eec67a960a6392
Author: David Teigland <teigland>
Date:   Fri Mar 1 13:55:59 2019 -0600

    config: add new setting io_memory_size
    
    which defines the amount of memory that lvm will allocate
    for bcache.  Increasing this setting is required if it is
    smaller than a single copy of VG metadata.

commit 863a2e693ee95b95463d60fa8b21f4c7c084292c
Author: David Teigland <teigland>
Date:   Mon Mar 4 10:57:52 2019 -0600

    io: warn when metadata size approaches io memory size
    
    When a single copy of metadata gets within 1MB of the
    current io_memory_size value, begin printing a warning
    that the io_memory_size should be increased.

commit 590a1ebcf78b8aae2a1e5ebaba1ac24a54435690
Author: David Teigland <teigland>
Date:   Mon Mar 4 11:18:34 2019 -0600

    io: increase the default io memory from 4 to 8 MiB
    
    This is the default bcache size that is created at the
    start of the command.  It needs to be large enough to
    hold a single copy of metadata for a given VG, or the
    VG cannot be read or written (since the entire VG would
    not fit into available memory.)
    
    Increasing the default reduces the chances of anyone
    needing to increase the default to use their VG.
    
    The size can be set in lvm.conf global/io_memory_size;
    the lower limit is 4 MiB and the upper limit is 128 MiB.

Marking this verified (SanityOnly) with the latest rpms. I know that in the original comment for this bug the circular buffer was not filed, but i never saw a point in between filling it up where I couldn't create, and after it was full, I was able to remove, create and resize.

3.10.0-1057.el7.x86_64
lvm2-2.02.185-2.el7    BUILT: Fri Jun 21 04:18:48 CDT 2019
lvm2-libs-2.02.185-2.el7    BUILT: Fri Jun 21 04:18:48 CDT 2019
lvm2-cluster-2.02.185-2.el7    BUILT: Fri Jun 21 04:18:48 CDT 2019
lvm2-lockd-2.02.185-2.el7    BUILT: Fri Jun 21 04:18:48 CDT 2019
lvm2-python-boom-0.9-18.el7    BUILT: Fri Jun 21 04:18:58 CDT 2019
cmirror-2.02.185-2.el7    BUILT: Fri Jun 21 04:18:48 CDT 2019
device-mapper-1.02.158-2.el7    BUILT: Fri Jun 21 04:18:48 CDT 2019
device-mapper-libs-1.02.158-2.el7    BUILT: Fri Jun 21 04:18:48 CDT 2019
device-mapper-event-1.02.158-2.el7    BUILT: Fri Jun 21 04:18:48 CDT 2019
device-mapper-event-libs-1.02.158-2.el7    BUILT: Fri Jun 21 04:18:48 CDT 2019
device-mapper-persistent-data-0.8.5-1.el7    BUILT: Mon Jun 10 03:58:20 CDT 2019



[root@hayes-02 ~]# systemctl status lvm2-lvmetad
â— lvm2-lvmetad.service - LVM2 metadata daemon
   Loaded: loaded (/usr/lib/systemd/system/lvm2-lvmetad.service; static; vendor preset: enabled)
   Active: active (running) since Tue 2019-07-02 16:32:36 CDT; 31min ago
     Docs: man:lvmetad(8)
 Main PID: 1043 (lvmetad)
   CGroup: /system.slice/lvm2-lvmetad.service
           └─1043 /usr/sbin/lvmetad -f

Jul 02 16:32:36 hayes-02.lab.msp.redhat.com systemd[1]: Started LVM2 metadata daemon.


[root@hayes-02 ~]# pvcreate --metadatasize 100k /dev/sdb1
  Physical volume "/dev/sdb1" successfully created.

[root@hayes-02 ~]# vgcreate vg /dev/sdb1
  Volume group "vg" successfully created

[root@hayes-02 ~]#  pvs -a -o +devices,vg_mda_size
  PV         VG Fmt  Attr PSize    PFree    Devices VMdaSize 
  /dev/sdb1  vg lvm2 a--  <931.25g <931.25g          1020.00k


[root@hayes-02 ~]# for i in `seq 1 2000`; do lvcreate -an -l1 -n lv$i vg; done
  [...]
  VG vg metadata on /dev/sdb1 (522150 bytes) too large for circular buffer (1043968 bytes with 521842 used)
  Failed to write VG vg.
  VG vg metadata on /dev/sdb1 (522150 bytes) too large for circular buffer (1043968 bytes with 521842 used)
  Failed to write VG vg.
  VG vg metadata on /dev/sdb1 (522150 bytes) too large for circular buffer (1043968 bytes with 521842 used)
  Failed to write VG vg.
  VG vg metadata on /dev/sdb1 (522150 bytes) too large for circular buffer (1043968 bytes with 521842 used)
  Failed to write VG vg.
  VG vg metadata on /dev/sdb1 (522150 bytes) too large for circular buffer (1043968 bytes with 521842 used)
  Failed to write VG vg.
  VG vg metadata on /dev/sdb1 (522150 bytes) too large for circular buffer (1043968 bytes with 521842 used)
  Failed to write VG vg.
  VG vg metadata on /dev/sdb1 (522150 bytes) too large for circular buffer (1043968 bytes with 521842 used)
  Failed to write VG vg.

# removes worked
[root@hayes-02 ~]# for i in `seq 901 1000`; do lvremove -f vg/lv$i; done
  Logical volume "lv901" successfully removed
  Logical volume "lv902" successfully removed
  Logical volume "lv903" successfully removed
  [...]
  Logical volume "lv998" successfully removed
  Logical volume "lv999" successfully removed
  Logical volume "lv1000" successfully removed

# creates worked
[root@hayes-02 ~]# for i in `seq 2000 2100`; do lvcreate -an -l1 -n lv$i vg; done
  [...]
  WARNING: Logical volume vg/lv2097 not zeroed.
  Logical volume "lv2097" created.
  WARNING: Logical volume vg/lv2098 not zeroed.
  Logical volume "lv2098" created.
  WARNING: Logical volume vg/lv2099 not zeroed.
  Logical volume "lv2099" created.
  VG vg metadata on /dev/sdb1 (522249 bytes) too large for circular buffer (1043968 bytes with 521941 used)
  Failed to write VG vg.


[root@hayes-02 ~]# vgextend vg /dev/sdc1
  Physical volume "/dev/sdc1" successfully created.
  VG vg metadata on /dev/sdb1 (522110 bytes) too large for circular buffer (1043968 bytes with 521941 used)
  WARNING: Failed to write an MDA of VG vg.
  Volume group "vg" successfully extended


[root@hayes-02 ~]# vgextend -vvvv vg /dev/sde1 > /tmp/vgextend  2>&1
[root@hayes-02 ~]# grep bcache /tmp/vgextend
#device/bcache.c:211           Limit write at 0 len 131072 to len 8192
#device/bcache.c:211           Limit write at 0 len 131072 to len 2048
#device/bcache.c:211           Limit write at 0 len 131072 to len 4608
#device/bcache.c:211           Limit write at 0 len 131072 to len 1024
#device/bcache.c:211           Limit write at 0 len 131072 to len 1024
#device/bcache.c:211           Limit write at 0 len 131072 to len 4608
#device/bcache.c:211           Limit write at 0 len 131072 to len 4608

Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory, and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://access.redhat.com/errata/RHBA-2019:2253