Bug 1868577 - dasbus.error.DBusError: The object with LVM ID 'fedora_storageqe-16' doesn't exist
Summary: dasbus.error.DBusError: The object with LVM ID 'fedora_storageqe-16' doesn't ...
Keywords:
Status: CLOSED NEXTRELEASE
Alias: None
Product: Fedora
Classification: Fedora
Component: anaconda
Version: 33
Hardware: x86_64
OS: Unspecified
unspecified
unspecified
Target Milestone: ---
Assignee: Vendula Poncova
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard: abrt_hash:443933b757c3e4e57e1fed83c96...
: 1886033 (view as bug list)
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2020-08-13 07:39 UTC by lnie
Modified: 2021-04-30 07:28 UTC (History)
14 users (show)

Fixed In Version: anaconda-34.4-1
Clone Of:
Environment:
Last Closed: 2021-04-30 07:28:47 UTC
Type: ---
Embargoed:


Attachments (Terms of Use)
File: anaconda-tb (1.06 MB, text/plain)
2020-08-13 07:39 UTC, lnie
no flags Details
File: anaconda.log (48.33 KB, text/plain)
2020-08-13 07:39 UTC, lnie
no flags Details
File: dbus.log (2.63 KB, text/plain)
2020-08-13 07:39 UTC, lnie
no flags Details
File: dnf.librepo.log (4.33 KB, text/plain)
2020-08-13 07:39 UTC, lnie
no flags Details
File: environ (637 bytes, text/plain)
2020-08-13 07:39 UTC, lnie
no flags Details
File: lorax-packages.log (24.65 KB, text/plain)
2020-08-13 07:39 UTC, lnie
no flags Details
File: lsblk_output (2.74 KB, text/plain)
2020-08-13 07:39 UTC, lnie
no flags Details
File: lvm.log (216.13 KB, text/plain)
2020-08-13 07:39 UTC, lnie
no flags Details
File: nmcli_dev_list (6.77 KB, text/plain)
2020-08-13 07:39 UTC, lnie
no flags Details
File: os_info (791 bytes, text/plain)
2020-08-13 07:39 UTC, lnie
no flags Details
File: program.log (24.06 KB, text/plain)
2020-08-13 07:39 UTC, lnie
no flags Details
File: storage.log (698.19 KB, text/plain)
2020-08-13 07:39 UTC, lnie
no flags Details
File: packaging.log (16.56 KB, text/plain)
2020-08-13 07:39 UTC, lnie
no flags Details
another claim (146.92 KB, image/png)
2020-08-13 09:37 UTC, lnie
no flags Details
another claim2 (178.52 KB, image/png)
2020-08-13 09:38 UTC, lnie
no flags Details
screenshot of comment17 (71.27 KB, image/png)
2020-08-13 13:42 UTC, lnie
no flags Details

Description lnie 2020-08-13 07:39:31 UTC
Version-Release number of selected component:
anaconda-33.25

The following was filed automatically by anaconda:
anaconda 33.25 exception report
Traceback (most recent call first):
  File "/usr/lib/python3.9/site-packages/dasbus/client/handler.py", line 497, in _handle_method_error
    raise exception from None
  File "/usr/lib/python3.9/site-packages/dasbus/client/handler.py", line 477, in _get_method_reply
    return self._handle_method_error(error)
  File "/usr/lib/python3.9/site-packages/dasbus/client/handler.py", line 444, in _call_method
    return self._get_method_reply(
  File "/usr/lib64/python3.9/site-packages/pyanaconda/modules/common/task/__init__.py", line 46, in sync_run_task
    task_proxy.Finish()
  File "/usr/lib64/python3.9/site-packages/pyanaconda/installation_tasks.py", line 521, in run_task
    sync_run_task(self._task_proxy)
  File "/usr/lib64/python3.9/site-packages/pyanaconda/installation_tasks.py", line 490, in start
    self.run_task()
  File "/usr/lib64/python3.9/site-packages/pyanaconda/installation_tasks.py", line 311, in start
    item.start()
  File "/usr/lib64/python3.9/site-packages/pyanaconda/installation_tasks.py", line 311, in start
    item.start()
  File "/usr/lib64/python3.9/site-packages/pyanaconda/installation_tasks.py", line 311, in start
    item.start()
  File "/usr/lib64/python3.9/site-packages/pyanaconda/installation.py", line 394, in run_installation
    queue.start()
  File "/usr/lib64/python3.9/threading.py", line 888, in run
    self._target(*self._args, **self._kwargs)
  File "/usr/lib64/python3.9/site-packages/pyanaconda/threading.py", line 280, in run
    threading.Thread.run(self)
dasbus.error.DBusError: The object with LVM ID 'fedora_storageqe-16' doesn't exist

Additional info:
addons:         com_redhat_kdump
cmdline:        /usr/bin/python3  /sbin/anaconda
cmdline_file:   initrd=/images/storageqe-16.sqe.lab.eng.bos.redhat.com/initrd console=ttyS1,115200 inst.vnc inst.vncconnect=10.72.12.146:9955 ks=http://beaker.engineering.redhat.com/kickstart/7163493 ksdevice=e8:39:35:2d:e1:c8 netboot_method=pxe BOOT_IMAGE=/images/storageqe-16.sqe.lab.eng.bos.redhat.com/kernel BOOTIF=01-e8-39-35-2d-e1-c8 
executable:     /sbin/anaconda
hashmarkername: anaconda
hawkey.log:     INFO Aug-13 02:26:50 === Started libdnf-0.48.0 ===
kernel:         5.8.0-1.fc33.x86_64
product:        Fedora
release:        Fedora release 33 (Rawhide)
release_type:   pre-release
type:           anaconda
version:        rawhide

Potential duplicate: bug 1844589

Comment 1 lnie 2020-08-13 07:39:34 UTC
Created attachment 1711267 [details]
File: anaconda-tb

Comment 2 lnie 2020-08-13 07:39:35 UTC
Created attachment 1711268 [details]
File: anaconda.log

Comment 3 lnie 2020-08-13 07:39:37 UTC
Created attachment 1711269 [details]
File: dbus.log

Comment 4 lnie 2020-08-13 07:39:38 UTC
Created attachment 1711270 [details]
File: dnf.librepo.log

Comment 5 lnie 2020-08-13 07:39:40 UTC
Created attachment 1711271 [details]
File: environ

Comment 6 lnie 2020-08-13 07:39:42 UTC
Created attachment 1711272 [details]
File: lorax-packages.log

Comment 7 lnie 2020-08-13 07:39:43 UTC
Created attachment 1711273 [details]
File: lsblk_output

Comment 8 lnie 2020-08-13 07:39:45 UTC
Created attachment 1711274 [details]
File: lvm.log

Comment 9 lnie 2020-08-13 07:39:46 UTC
Created attachment 1711275 [details]
File: nmcli_dev_list

Comment 10 lnie 2020-08-13 07:39:47 UTC
Created attachment 1711276 [details]
File: os_info

Comment 11 lnie 2020-08-13 07:39:49 UTC
Created attachment 1711277 [details]
File: program.log

Comment 12 lnie 2020-08-13 07:39:51 UTC
Created attachment 1711278 [details]
File: storage.log

Comment 13 lnie 2020-08-13 07:39:52 UTC
Created attachment 1711279 [details]
File: packaging.log

Comment 14 lnie 2020-08-13 09:31:24 UTC
The reproducer is:
1)Boot the installer,click into"Add a disk",and create a fcoe instance on the CNA,
2)Click "Done" without selecting the fcoe disk
3)Set /boot and / to standard partition as you will see #1866175 if you set Device type to Lvm.
4)Continue the installation,you will see the crash after you click "Begin Installation" Button

Comment 15 lnie 2020-08-13 09:37:05 UTC
Created attachment 1711299 [details]
another claim

Comment 16 lnie 2020-08-13 09:38:03 UTC
Created attachment 1711300 [details]
another claim2

Comment 17 lnie 2020-08-13 13:39:40 UTC
If you select the fcoe disk in #com14,and click into "Manual Partitioning" page,and click "click here to create them automatically",and continue the installation,you will also see this crash.

Comment 18 lnie 2020-08-13 13:42:11 UTC
Created attachment 1711326 [details]
screenshot of comment17

Comment 19 Vladimír Slávik 2020-08-21 11:21:31 UTC
Hello Radek, this is fcoe, can you please take a look?

Comment 20 Vladimír Slávik 2020-08-21 16:29:53 UTC
Similar problem has been detected:

Investigated bug 1869143. During the investigation, I reloaded storage from custom partitioning several times. Initially I did not paz attention, but later noticed that the disk selection did not propagate to the partitioning spoke immediately, instead the used selection was the previous one (!). I selected vdb+vdc, entered the spoke, left it, selected vda+vdb, and configured partitioning with vdb+vdc. (At least that's how I remember it.) After starting installation, the inconsistency between allowed disks led to the reported crash.

addons:         com_redhat_kdump
cmdline:        /usr/bin/python3  /sbin/anaconda
cmdline_file:   initrd=/test/rawhide/initrd.img inst.stage2=ftp://cobra02/rawhide inst.updates=http://cobra02/ks/vs/master_updates.img inst.lang=en_US.utf8  BOOT_IMAGE=/test/rawhide/vmlinuz 
hashmarkername: anaconda
kernel:         5.8.0-1.fc33.x86_64
package:        anaconda-33.25
product:        Fedora
reason:         dasbus.error.DBusError: Failed to call the 'PvCreate' method on the '/com/redhat/lvmdbus1/Manager' object: GDBus.Error:org.freedesktop.DBus.Python.dbus.exceptions.DBusException: ('com.redhat.lvmdbus1.Manager', 'Exit code 5, stderr =   Device /dev/vdc1 excluded by a filter.\n')
release:        Fedora release 34 (Rawhide)
release_type:   pre-release
version:        rawhide

Comment 21 Vladimír Slávik 2020-08-21 16:34:49 UTC
Not sure why the report ended up here. Either it is not a duplicate, or fcoe does not matter at all.

Comment 22 Vladimír Slávik 2020-08-25 14:04:54 UTC
I think this is blocker material, so let's get started. Taking the bug and switching to F33 where it really belongs.

---

Notes to self: So far the storage spoke appears to do the right thing. That leaves the custom part. spoke and module.

Comment 23 Vladimír Slávik 2020-08-26 12:55:41 UTC
More notes to self...

Suppose I have three disks. If I select only the first two and proceed to custom partitioning, here [1] I get ['vda', 'vdb'] for each of selected_disks, partitioned_devices, and self._selected_disks. If I return and change the selection to the first and last disk, I get selected_disks ['vda', 'vdc'] which is correct, but partitioned_devices is ['vda', 'vdb'] and predictably, self._selected_disks is ['vda'].

[1] https://github.com/rhinstaller/anaconda/blob/master/pyanaconda/ui/gui/spokes/custom_storage.py#L305

Comment 24 Jonathan Watt 2020-08-26 13:56:53 UTC
Similar problem has been detected:

Automatic partitioning install, selected to delete all existing partitions.

addons:         com_redhat_kdump
cmdline:        /usr/bin/python3  /sbin/anaconda --liveinst --graphical
cmdline_file:   BOOT_IMAGE=/images/pxeboot/vmlinuz root=live:CDLABEL=Fedora-WS-Live-33-20200826-n-0 rd.live.image quiet
hashmarkername: anaconda
kernel:         5.8.3-300.fc33.x86_64
other involved packages: python3-dasbus-1.4-2.fc33.noarch, python3-libs-3.9.0~rc1-2.fc33.x86_64
package:        anaconda-core-33.25.2-1.fc33.x86_64
packaging.log:  
product:        Fedora
reason:         dasbus.error.DBusError: Process reported exit code 1: /dev/mapper/luks-16cd3e6e-d69e-4093-9e4b-c1086707da35 appears to contain a partition table (atari).
release:        Fedora release 33 (Thirty Three)
release_type:   pre-release
version:        33

Comment 25 Vladimír Slávik 2020-08-27 10:40:05 UTC
After sleeping on it a bit more, I think the high level behavior (as I understand it so far) can be rephrased this way:

The selection of disks in the installation destination spoke is guaranteed to apply correctly only on the first exit from there. All subsequent changes of selected disks (applied during subsequent exits from the spoke) can introduce an inconsistent internal state. The inconsistency is that once a disk is not-selected, it can never be used again, despite what the GUI shows. The inconsistency eventually leads to a crash during actual installation, because some of the planned storage operations are forbidden.

Or, in anacondese: We tell blivet to hide non-selected disks but somehow they don't come back on the next go. Obviously we would have to unhide them somewhere, and apparently we're not doing that.

Comment 26 Vladimír Slávik 2020-08-27 11:03:21 UTC
This went public with Fedora 32, Jirka thinks probably with the introduction of storage module.

Comment 27 Vladimír Slávik 2020-08-27 17:58:09 UTC
Notes to self, treat this as yet-unverified. tl;dr: "why is apply() not called?"

I believe StorageSpoke.apply() is what's meant to do the job of setting the disks with apply_disk_selection(), as one exits the spoke. But apply is called only in one place in the code explicitly. What does actually happen instead is that the storage is always reset on changing the disks, *before* apply would run. Thus the state taken in that event is the old one, which hides the disks according to previous selection. Somewhat weirdly, the actual selection propagates correctly. So the inconsistency lives inside the storage module it seems.

It follows that disks can never come back from being hidden this way. There are two ways of making the correct selection "take". One leverages apply() being called explicitly when one selects the automatic partitioning: Change disk selection, select automatic partitioning with freeing up space, confirm, reenter, change to custom partitioning, and the selection is correct. Another is that a change in the partitioning method apparently is enough to trigger the correct propagation, but I haven't investigated that one in depth yet.

The actual mystery is that in StorageSpoke.on_back_clicked(), at the bottom there are self._skip_to_spoke() calls where the second parameter defaults to True, and that should propagate until Hub.spoke_done(), where we have spoke.changed which is True by default, and spoke.applyOnSkip which should again be True from the above... and then spoke,apply would be called. Which is not what's happening. Or so I believe.

Comment 28 Vladimír Slávik 2020-08-27 18:37:47 UTC
I misread the logs and it's not the apply() that is the problem. Instead it's rather that InstallerStorage.select_disks() is not called as a consequence of running apply(). There is a lot of stuff in between these two however, so that is not much help...

Comment 29 Pavel Holica 2020-09-01 20:14:43 UTC
Similar problem has been detected:

On system with previously installed Fedora 32 (autopart with LUKS) I've tried to install autopart with LUKS (deleting all previous partitions).

addons:         com_redhat_kdump
cmdline:        /usr/bin/python3  /sbin/anaconda --liveinst --graphical
cmdline_file:   BOOT_IMAGE=/images/pxeboot/vmlinuz root=live:CDLABEL=Fedora-KDE-Live-33-20200901-n-0 rd.live.image quiet
hashmarkername: anaconda
kernel:         5.8.3-300.fc33.x86_64
other involved packages: python3-libs-3.9.0~rc1-2.fc33.x86_64, python3-dasbus-1.4-2.fc33.noarch
package:        anaconda-core-33.25.2-1.fc33.x86_64
packaging.log:  
product:        Fedora
reason:         dasbus.error.DBusError: Process reported exit code 1: /dev/mapper/luks-517e2c69-c7d1-4838-8999-871f103e72c6 appears to contain a partition table (atari).
release:        Fedora release 33 (Thirty Three)
release_type:   pre-release
version:        33

Comment 30 Pavel Holica 2020-09-02 12:06:55 UTC
It seems to me, that the issue described in comment 24 and comment 29 are different than the one in the description and should be probably filed on blivet (as it looks similar to RHEL-8 bug 1768494 and Fedora bug 1643655).
Please note that those were reported through abrt and there's risk that more reports like these will appear.

Comment 31 Vladimír Slávik 2020-09-02 12:12:45 UTC
I completely agree, but what should I do to stop these reports from coming here?

Comment 33 Vendula Poncova 2020-09-02 14:32:11 UTC
Fix of the bug reported in the comment 20 is provided by the pull request: https://github.com/rhinstaller/anaconda/pull/2823

Comment 34 Vladimír Slávik 2020-09-04 11:38:05 UTC
*** Bug 1830640 has been marked as a duplicate of this bug. ***

Comment 35 Vendula Poncova 2020-09-15 11:17:48 UTC
Hi lnie,

could you please try to reproduce the bug on the latest rawhide? The fix from the comment 33 is released in anaconda-34.4-1 and it might help with the original issue as well.

Comment 36 lnie 2020-09-15 14:47:11 UTC
Hi,
I have checked on the fcoe server with Fedora-Rawhide-20200911.n.0,the bug is gone,so is #1869140

Comment 37 lnie 2020-09-16 11:57:22 UTC
Please note that Fedora-Rawhide-20200911.n.0 has anaconda-34.4-1 but not anaconda-33.25.3-1

Comment 38 J.C. Beijlevelt 2020-10-07 14:07:15 UTC
*** Bug 1886033 has been marked as a duplicate of this bug. ***


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