This service will be undergoing maintenance at 00:00 UTC, 2016-08-01. It is expected to last about 1 hours
Bug 957191 - LVMError: lvdeactivate failed for boot: running lvm lvchange -a n --config devices { filter=["r|/loop3$|","r|/loop4$|","r|/loop5$|","r|/loop6$|","r|/loop7$|"] } fedora_rtt6/boot failed
LVMError: lvdeactivate failed for boot: running lvm lvchange -a n --config d...
Status: CLOSED WORKSFORME
Product: Fedora
Classification: Fedora
Component: anaconda (Show other bugs)
19
Unspecified Linux
medium Severity medium
: ---
: ---
Assigned To: Anaconda Maintenance Team
Fedora Extras Quality Assurance
:
Depends On:
Blocks: ZedoraTracker fedora19rtt
  Show dependency treegraph
 
Reported: 2013-04-26 10:50 EDT by Jan Stodola
Modified: 2014-12-10 09:11 EST (History)
7 users (show)

See Also:
Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of:
Environment:
Last Closed: 2014-12-10 09:11:33 EST
Type: Bug
Regression: ---
Mount Type: ---
Documentation: ---
CRM:
Verified Versions:
Category: ---
oVirt Team: ---
RHEL 7.3 requirements from Atomic Host:


Attachments (Terms of Use)
kickstart (198 bytes, text/plain)
2013-04-26 10:50 EDT, Jan Stodola
no flags Details

  None (edit)
Description Jan Stodola 2013-04-26 10:50:20 EDT
Description of problem:
Following traceback appeared during kickstart installation in vnc mode on s390x:

anaconda 19.21-1 exception report
Traceback (most recent call first):
  File "/usr/lib/python2.7/site-packages/blivet/devicelibs/lvm.py", line 395, in lvdeactivate
    raise LVMError("lvdeactivate failed for %s: %s" % (lv_name, msg))
  File "/usr/lib/python2.7/site-packages/blivet/devices.py", line 2559, in _teardown
    lvm.lvdeactivate(self.vg.name, self._name)
  File "/usr/lib/python2.7/site-packages/blivet/devices.py", line 760, in teardown
    self._teardown(recursive=recursive)
  File "/usr/lib/python2.7/site-packages/blivet/__init__.py", line 2776, in findExistingInstallations
    device.teardown()
  File "/usr/lib/python2.7/site-packages/blivet/__init__.py", line 417, in reset
    self.roots = findExistingInstallations(self.devicetree)
  File "/usr/lib/python2.7/site-packages/blivet/__init__.py", line 137, in storageInitialize
    storage.reset()
  File "/usr/lib64/python2.7/threading.py", line 763, in run
    self.__target(*self.__args, **self.__kwargs)
  File "/usr/lib64/python2.7/site-packages/pyanaconda/threads.py", line 141, in run
    threading.Thread.run(self, *args, **kwargs)
LVMError: lvdeactivate failed for boot: running lvm lvchange -a n --config  devices { filter=["r|/loop3$|","r|/loop4$|","r|/loop5$|","r|/loop6$|","r|/loop7$|"] }  fedora_rtt6/boot failed


Version-Release number of selected component (if applicable):
anaconda 19.21-1

How reproducible:
2 out of 10 installation failed with this traceback

Steps to Reproduce:
1. repeat kickstart installations with attached kickstart
  
Actual results:
anaconda traceback

Expected results:
successful installation

Additional info:
[anaconda root@rtt6 tmp]# lsblk 
NAME                        MAJ:MIN RM   SIZE RO TYPE MOUNTPOINT
dasda                        94:0    0   2.3G  0 disk 
`-dasda1                     94:1    0   2.3G  0 part 
  |-fedora_rtt6-boot (dm-1) 253:1    0   500M  0 lvm  /mnt/sysimage/boot
  `-fedora_rtt6-root (dm-3) 253:3    0  24.2G  0 lvm  /mnt/sysimage
dasdb                        94:4    0   9.2G  0 disk 
`-dasdb1                     94:5    0   9.2G  0 part 
  `-fedora_rtt6-root (dm-3) 253:3    0  24.2G  0 lvm  /mnt/sysimage
dasdc                        94:8    0   2.3G  0 disk 
`-dasdc1                     94:9    0   2.3G  0 part 
  `-fedora_rtt6-root (dm-3) 253:3    0  24.2G  0 lvm  /mnt/sysimage
dasdd                        94:12   0   2.3G  0 disk 
`-dasdd1                     94:13   0   2.3G  0 part 
  `-fedora_rtt6-root (dm-3) 253:3    0  24.2G  0 lvm  /mnt/sysimage
dasde                        94:16   0   2.3G  0 disk 
`-dasde1                     94:17   0   2.3G  0 part 
  `-fedora_rtt6-root (dm-3) 253:3    0  24.2G  0 lvm  /mnt/sysimage
dasdf                        94:20   0   2.3G  0 disk 
`-dasdf1                     94:21   0   2.3G  0 part 
  `-fedora_rtt6-root (dm-3) 253:3    0  24.2G  0 lvm  /mnt/sysimage
dasdg                        94:24   0   2.3G  0 disk 
`-dasdg1                     94:25   0   2.3G  0 part
  `-fedora_rtt6-root (dm-3) 253:3    0  24.2G  0 lvm  /mnt/sysimage
dasdh                        94:28   0   2.3G  0 disk
`-dasdh1                     94:29   0   2.3G  0 part
  `-fedora_rtt6-root (dm-3) 253:3    0  24.2G  0 lvm  /mnt/sysimage
dasdi                        94:32   0   2.3G  0 disk
`-dasdi1                     94:33   0   2.3G  0 part
  `-fedora_rtt6-root (dm-3) 253:3    0  24.2G  0 lvm  /mnt/sysimage
loop0                         7:0    0 171.7M  1 loop
loop1                         7:1    0     1G  1 loop
`-live-rw (dm-0)            253:0    0     1G  0 dm   /
loop2                         7:2    0   512M  0 loop
`-live-rw (dm-0)            253:0    0     1G  0 dm   /


[anaconda root@rtt6 tmp]# pvs
  PV          VG          Fmt  Attr PSize PFree
  /dev/dasda1 fedora_rtt6 lvm2 a--  2.29g    0 
  /dev/dasdb1 fedora_rtt6 lvm2 a--  9.17g    0 
  /dev/dasdc1 fedora_rtt6 lvm2 a--  2.29g    0 
  /dev/dasdd1 fedora_rtt6 lvm2 a--  2.29g    0 
  /dev/dasde1 fedora_rtt6 lvm2 a--  2.29g    0 
  /dev/dasdf1 fedora_rtt6 lvm2 a--  2.29g    0 
  /dev/dasdg1 fedora_rtt6 lvm2 a--  2.29g    0 
  /dev/dasdh1 fedora_rtt6 lvm2 a--  2.29g    0 
  /dev/dasdi1 fedora_rtt6 lvm2 a--  2.29g    0 
[anaconda root@rtt6 tmp]# vgs
  VG          #PV #LV #SN Attr   VSize  VFree
  fedora_rtt6   9   3   0 wz--n- 27.48g    0 
[anaconda root@rtt6 tmp]# lvs
  LV   VG          Attr      LSize   Pool Origin Data%  Move Log Copy%  Convert
  boot fedora_rtt6 -wi-ao--- 500.00m                                           
  root fedora_rtt6 -wi-ao---  24.18g                                           
  swap fedora_rtt6 -wi------   2.81g                                           
[anaconda root@rtt6 tmp]#
Comment 1 Jan Stodola 2013-04-26 10:50:46 EDT
Created attachment 740439 [details]
kickstart
Comment 3 David Shea 2014-12-08 16:38:30 EST
09:18:37,700 INFO program:   Logical volume fedora_rtt6/boot contains a filesystem in use.

Was /boot mounted elsewhere? Is this issue reproducible?
Comment 4 Jan Stodola 2014-12-09 08:30:58 EST
David,
I don't remember if /boot was mounted or not, I'm sorry.

But looking at logs from anaconda-tb, there are really weird things happening:
1) not all packages were installed:
...
09:17:54,051 DEBUG packaging: Installing chrony (246/255)
09:17:56,025 DEBUG packaging: Installing audit (247/255)
09:17:57,598 DEBUG packaging: Installing selinux-policy-targeted (248/255)
13:18:28,449 INFO packaging: about to acquire _yum_lock for MainThread at /usr/lib64/python2.7/site-packages/pyanaconda/packaging/yumpayload.py:187 (reset)
13:18:28,450 INFO packaging: have _yum_lock for MainThread
13:18:28,450 DEBUG packaging: getting release version from tree at None (20130424)
13:18:28,450 DEBUG packaging: got a release version of rawhide
13:18:28,450 INFO packaging: gave up _yum_lock for MainThread
09:18:33,760 INFO packaging: about to acquire _yum_lock for MainThread at /usr/lib64/python2.7/site-packages/pyanaconda/ui/gui/spokes/source.py:462 (completed)
09:18:33,763 INFO packaging: have _yum_lock for MainThread
09:18:33,765 INFO packaging: gave up _yum_lock for MainThread
09:18:33,777 INFO packaging: about to acquire _yum_lock for MainThread at /usr/lib64/python2.7/site-packages/pyanaconda/ui/gui/spokes/source.py:462 (completed)
09:18:33,781 INFO packaging: have _yum_lock for MainThread
09:18:33,783 INFO packaging: gave up _yum_lock for MainThread

2) deactivation of logical volumes happened before unmounting /boot and rootfs filesystems. (LV with swap was deactivated successfully). Later you can see an attempt to mount /dev/mapper/fedora_rtt6-boot to /mnt/sysimage (why?). At the end is another attempt to deactivate LV with /boot:

09:18:37,556 INFO program: Running... lvm lvchange -a n --config  devices { filter=["r|/loop3$|","r|/loop4$|","r|/loop5$|","r|/loop6$|","r|/loop7$|"] }  fedora_rtt6/boot
09:18:37,700 INFO program:   Logical volume fedora_rtt6/boot contains a filesystem in use.
09:18:37,701 DEBUG program: Return code: 5
09:18:37,706 INFO program: Running... udevadm settle --timeout=300
09:18:37,762 DEBUG program: Return code: 0
09:18:37,768 INFO program: Running... lvm lvchange -a n --config  devices { filter=["r|/loop3$|","r|/loop4$|","r|/loop5$|","r|/loop6$|","r|/loop7$|"] }  fedora_rtt6/root
09:18:37,898 INFO program:   Logical volume fedora_rtt6/root contains a filesystem in use.
09:18:37,900 DEBUG program: Return code: 5
09:18:37,909 INFO program: Running... swapoff /dev/mapper/fedora_rtt6-swap
09:19:12,666 DEBUG program: Return code: 0
09:19:12,682 INFO program: Running... udevadm settle --timeout=300
09:19:12,788 DEBUG program: Return code: 0
09:19:12,792 INFO program: Running... lvm lvchange -a n --config  devices { filter=["r|/loop3$|","r|/loop4$|","r|/loop5$|","r|/loop6$|","r|/loop7$|"] }  fedora_rtt6/swap
09:19:13,007 DEBUG program: Return code: 0
09:19:13,017 INFO program: Running... udevadm settle --timeout=300
09:19:13,075 DEBUG program: Return code: 0
09:19:13,083 INFO program: Running... lvm vgchange -a n --config  devices { filter=["r|/loop3$|","r|/loop4$|","r|/loop5$|","r|/loop6$|","r|/loop7$|"] }  fedora_rtt6
09:19:13,213 INFO program:   Can't deactivate volume group "fedora_rtt6" with 2 open logical volume(s)
09:19:13,216 DEBUG program: Return code: 5
09:19:13,275 INFO program: Running... mount -t ext4 -o defaults,ro /dev/mapper/fedora_rtt6-boot /mnt/sysimage
09:19:13,340 INFO program: mount: /dev/mapper/fedora_rtt6-boot is already mounted or /mnt/sysimage busy
09:19:13,341 INFO program:        /dev/mapper/fedora_rtt6-boot is already mounted on /mnt/sysimage/boot
09:19:13,341 DEBUG program: Return code: 32
09:19:13,346 INFO program: Running... udevadm settle --timeout=300
09:19:13,404 DEBUG program: Return code: 0
09:19:13,408 INFO program: Running... lvm lvchange -a n --config  devices { filter=["r|/loop3$|","r|/loop4$|","r|/loop5$|","r|/loop6$|","r|/loop7$|"] }  fedora_rtt6/boot
09:19:13,544 INFO program:   Logical volume fedora_rtt6/boot contains a filesystem in use.
09:19:13,548 DEBUG program: Return code: 5


I will try to reproduce on latest F21 compose for s390x and I will update the bug.
Comment 5 Jan Stodola 2014-12-10 09:11:33 EST
I've tried about 20 installations with the latest Fedora 21/s390x compose (contains anaconda-21.48.22-1.fc21) and this problem didn't appear.

I'm closing this bug and I will reopen it or create a new one if I see this issue again in the future.

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