Note: This is a beta release of Red Hat Bugzilla 5.0. The data contained within is a snapshot of the live data so any changes you make will not be reflected in the production Bugzilla. Also email is disabled so feel free to test any aspect of the site that you want. File any problems you find or give feedback here.
Bug 1353993 - When insufficient free space cache pool creation is aborted, left-over devices appear
Summary: When insufficient free space cache pool creation is aborted, left-over device...
Keywords:
Status: CLOSED DUPLICATE of bug 1278515
Alias: None
Product: Red Hat Enterprise Linux 7
Classification: Red Hat
Component: lvm2
Version: 7.3
Hardware: x86_64
OS: Linux
unspecified
medium
Target Milestone: rc
: ---
Assignee: Zdenek Kabelac
QA Contact: cluster-qe@redhat.com
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2016-07-08 16:07 UTC by Corey Marthaler
Modified: 2017-11-05 16:24 UTC (History)
6 users (show)

Fixed In Version:
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed: 2017-11-05 16:24:38 UTC
Target Upstream Version:


Attachments (Terms of Use)

Description Corey Marthaler 2016-07-08 16:07:48 UTC
Description of problem:
This appears to be another version of bugs 1161347 and 1167431. This is also a regression from .156.

[root@host-084 ~]# pvcreate --setphysicalvolumesize 100M /dev/sdb1 /dev/sdc1 /dev/sdd1 /dev/sdh1
  Physical volume "/dev/sdb1" successfully created.
  Physical volume "/dev/sdc1" successfully created.
  Physical volume "/dev/sdd1" successfully created.
  Physical volume "/dev/sdh1" successfully created.

[root@host-084 ~]# vgcreate cache_sanity /dev/sdb1 /dev/sdc1 /dev/sdd1 /dev/sdh1
  Volume group "cache_sanity" successfully created

[root@host-084 ~]# lvcreate -vvvv  -L 2G --type cache-pool cache_sanity/over_size_pool > /tmp/lvcreate 2>&1 
[...]

#activate/fs.c:489         Syncing device names
#libdm-common.c:2273         Udev cookie 0xd4d0ae1 (semid 16416769) decremented to 1
#libdm-common.c:2559         Udev cookie 0xd4d0ae1 (semid 16416769) waiting for zero
#libdm-common.c:2288         Udev cookie 0xd4d0ae1 (semid 16416769) destroyed
#libdm-common.c:1427         cache_sanity-lvol0: Skipping NODE_ADD (253,2) 0:6 0660 [trust_udev]
#libdm-common.c:1437         cache_sanity-lvol0: Processing NODE_READ_AHEAD 8192 (flags=1)
#libdm-common.c:1191         cache_sanity-lvol0 (253:2): read ahead is 256
#libdm-common.c:1241         cache_sanity-lvol0 (253:2): Setting read ahead to 8192
#activate/dev_manager.c:755         Getting device info for cache_sanity-lvol0 [LVM-6HRBVPk14m9ZeL0Nb3pcHONIcuxjCPKJmDXBbzJeSjbA9GAnkt6yf23dfiL8lGp6]
#ioctl/libdm-iface.c:1838         dm info  LVM-6HRBVPk14m9ZeL0Nb3pcHONIcuxjCPKJmDXBbzJeSjbA9GAnkt6yf23dfiL8lGp6 [ noopencount flush ]   [16384] (*1)
#activate/activate.c:1487       cache_sanity/lvol0 is active locally
#device/dev-cache.c:356         /dev/cache_sanity/lvol0: Added to device cache (253:2)
#device/dev-cache.c:1402         Using /dev/cache_sanity/lvol0
#device/dev-io.c:570         Opened /dev/cache_sanity/lvol0 RW O_DIRECT
#metadata/lv_manip.c:6843     Initializing 4.00 KiB of logical volume "cache_sanity/lvol0" with value 0.
#device/dev-io.c:808         Wiping /dev/cache_sanity/lvol0 at sector 0 length 8 sectors
#device/dev-io.c:145         /dev/cache_sanity/lvol0: block size is 4096 bytes
#device/dev-io.c:156         /dev/cache_sanity/lvol0: physical block size is 512 bytes
#device/dev-io.c:625         Closed /dev/cache_sanity/lvol0
#metadata/lv_manip.c:7761     Temporary logical volume "lvol0" created.
#locking/file_locking.c:99       Locking LV 6HRBVPk14m9ZeL0Nb3pcHONIcuxjCPKJmDXBbzJeSjbA9GAnkt6yf23dfiL8lGp6 (NL)
#activate/activate.c:2216         Deactivating cache_sanity/lvol0.
#activate/dev_manager.c:755         Getting device info for cache_sanity-lvol0 [LVM-6HRBVPk14m9ZeL0Nb3pcHONIcuxjCPKJmDXBbzJeSjbA9GAnkt6yf23dfiL8lGp6]
#ioctl/libdm-iface.c:1838         dm info  LVM-6HRBVPk14m9ZeL0Nb3pcHONIcuxjCPKJmDXBbzJeSjbA9GAnkt6yf23dfiL8lGp6 [ noopencount flush ]   [16384] (*1)
#activate/dev_manager.c:755         Getting device info for cache_sanity-lvol0 [LVM-6HRBVPk14m9ZeL0Nb3pcHONIcuxjCPKJmDXBbzJeSjbA9GAnkt6yf23dfiL8lGp6]
#ioctl/libdm-iface.c:1838         dm info  LVM-6HRBVPk14m9ZeL0Nb3pcHONIcuxjCPKJmDXBbzJeSjbA9GAnkt6yf23dfiL8lGp6 [ opencount flush ]   [16384] (*1)
#mm/memlock.c:582         Entering critical section (deactivating).
#mm/memlock.c:551         Lock:   Memlock counters: locked:0 critical:1 daemon:0 suspended:0
#mm/memlock.c:475       Locking memory
#libdm-config.c:1036       Setting activation/use_mlockall to 0
#mm/memlock.c:259         mlock default filter 'locale/locale-archive' matches '7fa873c6d000-7fa87a194000 r--p 00000000 fd:00 17365023                   /usr/lib/locale/locale-archive': Skipping.
#mm/memlock.c:259         mlock default filter '/libpcre.so.' matches '7fa87a194000-7fa87a1f4000 r-xp 00000000 fd:00 16928966                   /usr/lib64/libpcre.so.1.2.0': Skipping.
#mm/memlock.c:241         mlock area unreadable 7fa87a1f4000-7fa87a3f3000 ---p 00060000 fd:00 16928966                   /usr/lib64/libpcre.so.1.2.0 : Skipping.
#mm/memlock.c:259         mlock default filter '/libpcre.so.' matches '7fa87a3f3000-7fa87a3f4000 r--p 0005f000 fd:00 16928966                   /usr/lib64/libpcre.so.1.2.0': Skipping.
#mm/memlock.c:259         mlock default filter '/libpcre.so.' matches '7fa87a3f4000-7fa87a3f5000 rw-p 00060000 fd:00 16928966                   /usr/lib64/libpcre.so.1.2.0': Skipping.
#mm/memlock.c:259         mlock default filter '/libz.so.' matches '7fa87a3f5000-7fa87a40a000 r-xp 00000000 fd:00 16928980                   /usr/lib64/libz.so.1.2.7': Skipping.
#mm/memlock.c:241         mlock area unreadable 7fa87a40a000-7fa87a609000 ---p 00015000 fd:00 16928980                   /usr/lib64/libz.so.1.2.7 : Skipping.

[...]

#mm/memlock.c:287         mlock        132KiB 7ffccc74c000 - 7ffccc76d000 rw-p 00000000 00:00 0                          [stack]
#mm/memlock.c:249         mlock ignore filter '[vdso]' matches '7ffccc7fc000-7ffccc7fe000 r-xp 00000000 00:00 0                          [vdso]': Skipping.
#mm/memlock.c:249         mlock ignore filter '[vsyscall]' matches 'ffffffffff600000-ffffffffff601000 r-xp 00000000 00:00 0                  [vsyscall]': Skipping.
#mm/memlock.c:373         Locked 13168640 bytes
#activate/dev_manager.c:3106         Creating DEACTIVATE tree for cache_sanity/lvol0.
#activate/dev_manager.c:1758         Getting device info for cache_sanity-lvol0 [LVM-6HRBVPk14m9ZeL0Nb3pcHONIcuxjCPKJmDXBbzJeSjbA9GAnkt6yf23dfiL8lGp6]
#ioctl/libdm-iface.c:1838         dm info  LVM-6HRBVPk14m9ZeL0Nb3pcHONIcuxjCPKJmDXBbzJeSjbA9GAnkt6yf23dfiL8lGp6 [ opencount flush ]   [16384] (*1)
#ioctl/libdm-iface.c:1838         dm deps   (253:2) [ opencount flush ]   [16384] (*1)
#activate/dev_manager.c:1758         Getting device info for cache_sanity-lvol0-real [LVM-6HRBVPk14m9ZeL0Nb3pcHONIcuxjCPKJmDXBbzJeSjbA9GAnkt6yf23dfiL8lGp6-real]
#ioctl/libdm-iface.c:1838         dm info  LVM-6HRBVPk14m9ZeL0Nb3pcHONIcuxjCPKJmDXBbzJeSjbA9GAnkt6yf23dfiL8lGp6-real [ opencount flush ]   [16384] (*1)
#activate/dev_manager.c:1758         Getting device info for cache_sanity-lvol0-cow [LVM-6HRBVPk14m9ZeL0Nb3pcHONIcuxjCPKJmDXBbzJeSjbA9GAnkt6yf23dfiL8lGp6-cow]
#ioctl/libdm-iface.c:1838         dm info  LVM-6HRBVPk14m9ZeL0Nb3pcHONIcuxjCPKJmDXBbzJeSjbA9GAnkt6yf23dfiL8lGp6-cow [ opencount flush ]   [16384] (*1)
#ioctl/libdm-iface.c:1838         dm info   (253:2) [ opencount flush ]   [16384] (*1)
#libdm-deptree.c:1026     Removing cache_sanity-lvol0 (253:2)
#libdm-common.c:2346         Udev cookie 0xd4dab0a (semid 16449537) created
#libdm-common.c:2366         Udev cookie 0xd4dab0a (semid 16449537) incremented to 1
#libdm-common.c:2238         Udev cookie 0xd4dab0a (semid 16449537) incremented to 2
#libdm-common.c:2488         Udev cookie 0xd4dab0a (semid 16449537) assigned to REMOVE task(2) with flags DISABLE_LIBRARY_FALLBACK         (0x20)
#ioctl/libdm-iface.c:1838         dm remove   (253:2) [ noopencount flush retryremove ]   [16384] (*1)
#libdm-common.c:1430         cache_sanity-lvol0: Stacking NODE_DEL [trust_udev]
#mm/memlock.c:592         Leaving critical section (deactivated).
#activate/dev_manager.c:755         Getting device info for cache_sanity-lvol0 [LVM-6HRBVPk14m9ZeL0Nb3pcHONIcuxjCPKJmDXBbzJeSjbA9GAnkt6yf23dfiL8lGp6]
#ioctl/libdm-iface.c:1838         dm info  LVM-6HRBVPk14m9ZeL0Nb3pcHONIcuxjCPKJmDXBbzJeSjbA9GAnkt6yf23dfiL8lGp6 [ noopencount flush ]   [16384] (*1)
#metadata/pool_manip.c:832     Renaming lvol0 as pool metadata spare volume lvol0_pmspare.
#metadata/lv_manip.c:5700         LV lvol0_pmspare in VG cache_sanity is now hidden.
#lvcreate.c:1516     Making pool over_size_pool in VG cache_sanity using segtype cache-pool
#metadata/lv_manip.c:7350   Volume group "cache_sanity" has insufficient free space (94 extents): 512 required.
#metadata/lv_manip.c:7758         <backtrace>
#lvcreate.c:1537         <backtrace>
#toollib.c:1965         <backtrace>
#cache/lvmetad.c:1224         Sending lvmetad updated VG cache_sanity (seqno 2)
#libdm-config.c:941       Setting response to OK
#libdm-config.c:941       Setting response to OK
#libdm-config.c:941       Setting response to OK
#cache/lvmetad.c:1651         Telling lvmetad to store PV /dev/sdb1 (D4QPgk-xLXQ-4rbS-bzbk-iolu-QD4y-sCXd6E)
#libdm-config.c:941       Setting response to OK


[root@host-084 ~]# lvs -a -o +devices
  LV              VG            Attr       LSize   Pool Origin Data%  Meta%  Move Log Cpy%Sync Convert Devices       
  [lvol0_pmspare] cache_sanity  ewi-------   8.00m                                                     /dev/sdb1(0)  


[root@host-084 ~]# vgremove -f cache_sanity > /tmp/vgremove 2>&1

[...]

#metadata/vg.c:74         Allocated VG cache_sanity at 0x7f6818374b10.
#format_text/import_vsn1.c:572         Importing logical volume cache_sanity/lvol0_pmspare.
#format_text/import_vsn1.c:690         Logical volume cache_sanity/lvol0_pmspare is pool metadata spare.
#toollib.c:1960       Process single VG cache_sanity
#misc/lvm-flock.c:200       Locking /run/lock/lvm/P_orphans WB
#libdm-common.c:926         Preparing SELinux context for /run/lock/lvm/P_orphans to system_u:object_r:lvm_lock_t:s0.
#misc/lvm-flock.c:101         _do_flock /run/lock/lvm/P_orphans:aux WB
#misc/lvm-flock.c:101         _do_flock /run/lock/lvm/P_orphans WB
#misc/lvm-flock.c:48         _undo_flock /run/lock/lvm/P_orphans:aux
#libdm-common.c:929         Resetting SELinux context to default value.
#cache/lvmcache.c:522         lvmcache has no info for vgname "#orphans".
#cache/lvmetad.c:1288         Sending lvmetad pending remove VG cache_sanity
#libdm-config.c:941       Setting response to OK
#libdm-config.c:941       Setting response to OK
#libdm-config.c:941       Setting response to OK
#device/dev-io.c:625         Closed /dev/sdb1
#device/dev-io.c:570         Opened /dev/sdb1 RW O_DIRECT
#device/dev-io.c:145         /dev/sdb1: block size is 4096 bytes
#device/dev-io.c:156         /dev/sdb1: physical block size is 512 bytes
#device/dev-io.c:625         Closed /dev/sdc1
#device/dev-io.c:570         Opened /dev/sdc1 RW O_DIRECT
#device/dev-io.c:145         /dev/sdc1: block size is 4096 bytes
#device/dev-io.c:156         /dev/sdc1: physical block size is 512 bytes
#device/dev-io.c:625         Closed /dev/sdd1
#device/dev-io.c:570         Opened /dev/sdd1 RW O_DIRECT
#device/dev-io.c:145         /dev/sdd1: block size is 4096 bytes
#device/dev-io.c:156         /dev/sdd1: physical block size is 512 bytes
#device/dev-io.c:625         Closed /dev/sdh1
#device/dev-io.c:570         Opened /dev/sdh1 RW O_DIRECT
#device/dev-io.c:145         /dev/sdh1: block size is 4096 bytes
#device/dev-io.c:156         /dev/sdh1: physical block size is 512 bytes
#metadata/metadata.c:588     Removing physical volume "/dev/sdb1" from volume group "cache_sanity"
#device/dev-io.c:308       /dev/sdb1: using cached size 52420032 sectors
#metadata/metadata.c:5278   Assertion failed: can't _pv_write non-orphan PV (in VG )
#metadata/metadata.c:602   Failed to remove physical volume "/dev/sdb1" from volume group "cache_sanity"
#metadata/metadata.c:588     Removing physical volume "/dev/sdc1" from volume group "cache_sanity"
#device/dev-io.c:308       /dev/sdc1: using cached size 52420032 sectors
#cache/lvmcache.c:1873         lvmcache /dev/sdc1: now in VG #orphans_lvm2 (#orphans_lvm2) with 1 mda(s).
#format_text/format-text.c:1377         Creating metadata area on /dev/sdc1 at sector 8 size 2040 sectors
#format_text/text_label.c:184         /dev/sdc1: Preparing PV label header pVAczK-zwWf-V5vb-Gs00-sfEB-vl0Q-Lkd5M7 size 26839056384 with da1 (2048s, 0s) mda1 (8s, 2040s)
#label/label.c:338       /dev/sdc1: Writing label to sector 1 with stored offset 32.
#cache/lvmetad.c:1651         Telling lvmetad to store PV /dev/sdc1 (pVAczK-zwWf-V5vb-Gs00-sfEB-vl0Q-Lkd5M7)
#libdm-config.c:941       Setting response to OK
#libdm-config.c:941       Setting response to OK
#libdm-config.c:941       Setting response to OK
#metadata/metadata.c:588     Removing physical volume "/dev/sdd1" from volume group "cache_sanity"
#device/dev-io.c:308       /dev/sdd1: using cached size 52420032 sectors
#cache/lvmcache.c:1873         lvmcache /dev/sdd1: now in VG #orphans_lvm2 (#orphans_lvm2) with 1 mda(s).
#format_text/format-text.c:1377         Creating metadata area on /dev/sdd1 at sector 8 size 2040 sectors
#format_text/text_label.c:184         /dev/sdd1: Preparing PV label header TWz71g-Qf7S-5ePh-h1X9-idCg-YYfZ-24uxRO size 26839056384 with da1 (2048s, 0s) mda1 (8s, 2040s)
#label/label.c:338       /dev/sdd1: Writing label to sector 1 with stored offset 32.
#cache/lvmetad.c:1651         Telling lvmetad to store PV /dev/sdd1 (TWz71g-Qf7S-5ePh-h1X9-idCg-YYfZ-24uxRO)
#libdm-config.c:941       Setting response to OK
#libdm-config.c:941       Setting response to OK
#libdm-config.c:941       Setting response to OK
#metadata/metadata.c:588     Removing physical volume "/dev/sdh1" from volume group "cache_sanity"
#device/dev-io.c:308       /dev/sdh1: using cached size 52420032 sectors
#cache/lvmcache.c:1873         lvmcache /dev/sdh1: now in VG #orphans_lvm2 (#orphans_lvm2) with 1 mda(s).
#format_text/format-text.c:1377         Creating metadata area on /dev/sdh1 at sector 8 size 2040 sectors
#format_text/text_label.c:184         /dev/sdh1: Preparing PV label header kZs2rs-3aE2-JcfG-oiQV-rTjs-leR3-x9NEZA size 26839056384 with da1 (2048s, 0s) mda1 (8s, 2040s)
#label/label.c:338       /dev/sdh1: Writing label to sector 1 with stored offset 32.
#cache/lvmetad.c:1651         Telling lvmetad to store PV /dev/sdh1 (kZs2rs-3aE2-JcfG-oiQV-rTjs-leR3-x9NEZA)
#libdm-config.c:941       Setting response to OK



Version-Release number of selected component (if applicable):
3.10.0-419.el7.x86_64
lvm2-2.02.160-1.el7    BUILT: Wed Jul  6 11:16:47 CDT 2016
lvm2-libs-2.02.160-1.el7    BUILT: Wed Jul  6 11:16:47 CDT 2016
lvm2-cluster-2.02.160-1.el7    BUILT: Wed Jul  6 11:16:47 CDT 2016
device-mapper-1.02.130-1.el7    BUILT: Wed Jul  6 11:16:47 CDT 2016
device-mapper-libs-1.02.130-1.el7    BUILT: Wed Jul  6 11:16:47 CDT 2016
device-mapper-event-1.02.130-1.el7    BUILT: Wed Jul  6 11:16:47 CDT 2016
device-mapper-event-libs-1.02.130-1.el7    BUILT: Wed Jul  6 11:16:47 CDT 2016
device-mapper-persistent-data-0.6.2-0.1.rc8.el7    BUILT: Wed May  4 02:56:34 CDT 2016
cmirror-2.02.160-1.el7    BUILT: Wed Jul  6 11:16:47 CDT 2016
sanlock-3.3.0-1.el7    BUILT: Wed Feb 24 09:52:30 CST 2016
sanlock-lib-3.3.0-1.el7    BUILT: Wed Feb 24 09:52:30 CST 2016
lvm2-lockd-2.02.160-1.el7    BUILT: Wed Jul  6 11:16:47 CDT 2016


Note You need to log in before you can comment on or make changes to this bug.