Bug 957191
| Summary: | 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 | ||||||
|---|---|---|---|---|---|---|---|
| Product: | [Fedora] Fedora | Reporter: | Jan Stodola <jstodola> | ||||
| Component: | anaconda | Assignee: | Anaconda Maintenance Team <anaconda-maint-list> | ||||
| Status: | CLOSED WORKSFORME | QA Contact: | Fedora Extras Quality Assurance <extras-qa> | ||||
| Severity: | medium | Docs Contact: | |||||
| Priority: | medium | ||||||
| Version: | 19 | CC: | anaconda-maint-list, g.kaviyarasu, jonathan, jstodola, mkolman, sbueno, vanmeeuwen+fedora | ||||
| Target Milestone: | --- | ||||||
| Target Release: | --- | ||||||
| Hardware: | Unspecified | ||||||
| OS: | Linux | ||||||
| Whiteboard: | |||||||
| Fixed In Version: | Doc Type: | Bug Fix | |||||
| Doc Text: | Story Points: | --- | |||||
| Clone Of: | Environment: | ||||||
| Last Closed: | 2014-12-10 14:11:33 UTC | Type: | Bug | ||||
| Regression: | --- | Mount Type: | --- | ||||
| Documentation: | --- | CRM: | |||||
| Verified Versions: | Category: | --- | |||||
| oVirt Team: | --- | RHEL 7.3 requirements from Atomic Host: | |||||
| Cloudforms Team: | --- | Target Upstream Version: | |||||
| Embargoed: | |||||||
| Bug Depends On: | |||||||
| Bug Blocks: | 467765, 920667 | ||||||
| Attachments: |
|
||||||
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. |
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]#