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]#
Created attachment 740439 [details] kickstart
09:18:37,700 INFO program: Logical volume fedora_rtt6/boot contains a filesystem in use. Was /boot mounted elsewhere? Is this issue reproducible?
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.
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.