Note: This is a public test instance of Red Hat Bugzilla. The data contained within is a snapshot of the live data so any changes you make will not be reflected in the production Bugzilla. Email is disabled so feel free to test any aspect of the site that you want. File any problems you find or give feedback at bugzilla.redhat.com.
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
Summary: LVMError: lvdeactivate failed for boot: running lvm lvchange -a n --config d...
Keywords:
Status: CLOSED WORKSFORME
Alias: None
Product: Fedora
Classification: Fedora
Component: anaconda
Version: 19
Hardware: Unspecified
OS: Linux
medium
medium
Target Milestone: ---
Assignee: Anaconda Maintenance Team
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
Depends On:
Blocks: ZedoraTracker fedora19rtt
TreeView+ depends on / blocked
 
Reported: 2013-04-26 14:50 UTC by Jan Stodola
Modified: 2014-12-10 14:11 UTC (History)
7 users (show)

Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed: 2014-12-10 14:11:33 UTC
Type: Bug
Embargoed:

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

Description Jan Stodola 2013-04-26 14:50:20 UTC 
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 14:50:46 UTC 
Created attachment 740439 [details]
kickstart
Comment 3 David Shea 2014-12-08 21:38:30 UTC 
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 13:30:58 UTC 
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 14:11:33 UTC 
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.