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 1741935 - emulation deficiency breaks rpmdb on s390x
Summary: emulation deficiency breaks rpmdb on s390x
Keywords:
Status: CLOSED RAWHIDE
Alias: None
Product: Fedora
Classification: Fedora
Component: qemu
Version: rawhide
Hardware: All
OS: Unspecified
unspecified
unspecified
Target Milestone: ---
Assignee: Fedora Virtualization Maintainers
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard: abrt_hash:9b9691c40db5d0bcea22de6d8b4...
: 1763111 (view as bug list)
Depends On:
Blocks: ZedoraTracker
TreeView+ depends on / blocked
 
Reported: 2019-08-16 13:22 UTC by Stephan Mueller
Modified: 2020-04-01 08:13 UTC (History)
22 users (show)

Fixed In Version:
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed: 2020-01-13 17:06:11 UTC
Type: ---
Embargoed:


Attachments (Terms of Use)
File: anaconda-tb (1.19 MB, text/plain)
2019-08-16 13:22 UTC, Stephan Mueller
no flags Details
File: anaconda.log (64.22 KB, text/plain)
2019-08-16 13:22 UTC, Stephan Mueller
no flags Details
File: dbus.log (2.92 KB, text/plain)
2019-08-16 13:22 UTC, Stephan Mueller
no flags Details
File: dnf.librepo.log (14.58 KB, text/plain)
2019-08-16 13:22 UTC, Stephan Mueller
no flags Details
File: environ (637 bytes, text/plain)
2019-08-16 13:22 UTC, Stephan Mueller
no flags Details
File: hawkey.log (1.71 KB, text/plain)
2019-08-16 13:22 UTC, Stephan Mueller
no flags Details
File: lorax-packages.log (22.32 KB, text/plain)
2019-08-16 13:22 UTC, Stephan Mueller
no flags Details
File: lsblk_output (2.04 KB, text/plain)
2019-08-16 13:22 UTC, Stephan Mueller
no flags Details
File: lvm.log (157.23 KB, text/plain)
2019-08-16 13:22 UTC, Stephan Mueller
no flags Details
File: nmcli_dev_list (1.60 KB, text/plain)
2019-08-16 13:22 UTC, Stephan Mueller
no flags Details
File: os_info (683 bytes, text/plain)
2019-08-16 13:22 UTC, Stephan Mueller
no flags Details
File: program.log (49.93 KB, text/plain)
2019-08-16 13:22 UTC, Stephan Mueller
no flags Details
File: storage.log (84.81 KB, text/plain)
2019-08-16 13:22 UTC, Stephan Mueller
no flags Details
File: syslog (246.18 KB, text/plain)
2019-08-16 13:22 UTC, Stephan Mueller
no flags Details
File: packaging.log (124.88 KB, text/plain)
2019-08-16 13:22 UTC, Stephan Mueller
no flags Details
qemu log (7.24 KB, text/plain)
2019-09-06 15:55 UTC, Dan Horák
no flags Details

Description Stephan Mueller 2019-08-16 13:22:31 UTC
Description of problem:


Version-Release number of selected component:
anaconda-30.25.6

The following was filed automatically by anaconda:
anaconda 30.25.6 exception report
Traceback (most recent call first):
  File "/usr/lib64/python3.7/subprocess.py", line 1522, in _execute_child
    raise child_exception_type(errno_num, err_msg, err_filename)
  File "/usr/lib64/python3.7/subprocess.py", line 775, in __init__
    restore_signals, start_new_session)
  File "/usr/lib64/python3.7/site-packages/pyanaconda/core/util.py", line 208, in startProgram
    preexec_fn=preexec, cwd=root, env=env, **kwargs)
  File "/usr/lib64/python3.7/site-packages/pyanaconda/core/util.py", line 291, in _run_program
    env_prune=env_prune)
  File "/usr/lib64/python3.7/site-packages/pyanaconda/core/util.py", line 380, in execWithCapture
    filter_stderr=filter_stderr)[1]
  File "/usr/lib64/python3.7/site-packages/pyanaconda/bootloader/zipl.py", line 152, in install
    buf = util.execWithCapture("zipl", [], root=util.getSysroot())
  File "/usr/lib64/python3.7/site-packages/pyanaconda/bootloader/base.py", line 896, in write
    self.install()
  File "/usr/lib64/python3.7/site-packages/pyanaconda/bootloader/installation.py", line 188, in install_boot_loader
    storage.bootloader.write()
  File "/usr/lib64/python3.7/site-packages/pyanaconda/bootloader/installation.py", line 53, in write_boot_loader
    install_boot_loader(storage)
  File "/usr/lib64/python3.7/site-packages/pyanaconda/installation_tasks.py", line 438, in run_task
    self._task(*self._task_args, **self._task_kwargs)
  File "/usr/lib64/python3.7/site-packages/pyanaconda/installation_tasks.py", line 472, in start
    self.run_task()
  File "/usr/lib64/python3.7/site-packages/pyanaconda/installation_tasks.py", line 304, in start
    item.start()
  File "/usr/lib64/python3.7/site-packages/pyanaconda/installation_tasks.py", line 304, in start
    item.start()
  File "/usr/lib64/python3.7/site-packages/pyanaconda/installation.py", line 398, in doInstall
    installation_queue.start()
  File "/usr/lib64/python3.7/threading.py", line 865, in run
    self._target(*self._args, **self._kwargs)
  File "/usr/lib64/python3.7/site-packages/pyanaconda/threading.py", line 280, in run
    threading.Thread.run(self)
FileNotFoundError: [Errno 2] No such file or directory: 'zipl': 'zipl'

Additional info:
addons:         com_redhat_kdump
cmdline:        /usr/bin/python3  /sbin/anaconda
cmdline_file:   ro
executable:     /sbin/anaconda
hashmarkername: anaconda
kernel:         5.0.9-301.fc30.s390x
product:        Fedora
release:        Fedora release 30 (Thirty)
type:           anaconda
version:        30

Comment 1 Stephan Mueller 2019-08-16 13:22:36 UTC
Created attachment 1604461 [details]
File: anaconda-tb

Comment 2 Stephan Mueller 2019-08-16 13:22:38 UTC
Created attachment 1604462 [details]
File: anaconda.log

Comment 3 Stephan Mueller 2019-08-16 13:22:39 UTC
Created attachment 1604463 [details]
File: dbus.log

Comment 4 Stephan Mueller 2019-08-16 13:22:41 UTC
Created attachment 1604464 [details]
File: dnf.librepo.log

Comment 5 Stephan Mueller 2019-08-16 13:22:42 UTC
Created attachment 1604465 [details]
File: environ

Comment 6 Stephan Mueller 2019-08-16 13:22:43 UTC
Created attachment 1604466 [details]
File: hawkey.log

Comment 7 Stephan Mueller 2019-08-16 13:22:45 UTC
Created attachment 1604467 [details]
File: lorax-packages.log

Comment 8 Stephan Mueller 2019-08-16 13:22:46 UTC
Created attachment 1604468 [details]
File: lsblk_output

Comment 9 Stephan Mueller 2019-08-16 13:22:48 UTC
Created attachment 1604469 [details]
File: lvm.log

Comment 10 Stephan Mueller 2019-08-16 13:22:50 UTC
Created attachment 1604470 [details]
File: nmcli_dev_list

Comment 11 Stephan Mueller 2019-08-16 13:22:51 UTC
Created attachment 1604471 [details]
File: os_info

Comment 12 Stephan Mueller 2019-08-16 13:22:53 UTC
Created attachment 1604472 [details]
File: program.log

Comment 13 Stephan Mueller 2019-08-16 13:22:55 UTC
Created attachment 1604473 [details]
File: storage.log

Comment 14 Stephan Mueller 2019-08-16 13:22:57 UTC
Created attachment 1604474 [details]
File: syslog

Comment 15 Stephan Mueller 2019-08-16 13:22:59 UTC
Created attachment 1604475 [details]
File: packaging.log

Comment 16 Jiri Konecny 2019-08-21 17:32:29 UTC
If I understand the problem correctly we are missing requirement to add zipl package to the installation.

Hello, could you please verify if this will happen when you manually add zipl to the installation?

Comment 17 Stephan Mueller 2019-08-22 05:14:34 UTC
I booted from the S390 ISO installation image to install the system. As one of the last steps, Anaconda tries to install the boot loader which fails since the zipl command is not found by Anaconda. So, up to this point I yet do not have a system that I have under my control. I.e. I cannot install anything myself so far.

Comment 18 Jiri Konecny 2019-08-22 08:34:50 UTC
Yes, I understand that you can't boot to the system. What I was asking is to make a kickstart installation with zipl in the %packages section, my assumption is that it should work correctly. Could you please verify this assumption?

If you need, I can provide you a kickstart file which can be used to start the installation.

Comment 19 Vendula Poncova 2019-08-22 09:46:23 UTC
From packaging.log:
13:12:36,627 INF packaging: Verifying: s390utils-base-2:2.8.0-2.fc30.s390x

The package s390utils-base is installed on the new system and zipl should be part of this package.
Reassigning to s390utils.

Comment 20 Dan Horák 2019-08-22 10:46:57 UTC
13:12:50,109 WRN bootloader.installation: No kernel was installed. The boot loader configuration unchanged.

from the anaconda.log looks weird

I see it's an installation in KVM guest, what method or command did you use?

Comment 21 Stephan Mueller 2019-08-22 12:36:57 UTC
Yes, it is a KVM guest installation.

Comment 22 Stephan Mueller 2019-08-22 12:38:21 UTC
Re kickstart script: I am not versed in the kickstart script configuration. But it should be easy to recreate: create a z390 KVM on x86 and try to install the s390 ISO from Fedora 30.

Comment 23 Dan Horák 2019-08-22 12:56:34 UTC
Not sure I understand, is your installation run on a real s390x machine, or do you use the full system emulation in qemu from a x86 machine?

Comment 24 Stephan Mueller 2019-08-22 13:41:47 UTC
I use an emulated machine provided by QEMU

Comment 25 Dan Horák 2019-09-04 17:51:37 UTC
Stephan, hasn't you see a bunch of rpmdb/db5 errors on the console? It looks like the installation transaction crashes and installs only a portion of the rpms even when it then says "Verified" for all of them. I still suspect some emulation issue.

Comment 26 Dan Horák 2019-09-05 08:26:27 UTC
So the actual problem can be seen in the console log

...
Installing ebtables.s390x (269/352)
Installing iputils.s390x (270/352)
Installing libkcapi.s390x (271/352)
Installing libkcapi-hmaccalc.s390x (272/352)
Installing systemd-bootchart.s390x (273/352)
Installing NetworkManager-libnm.s390x (274/352)
Performing post-installation setup tasks
Verifying NetworkManager.s390x (1/352)
Verifying NetworkManager-libnm.s390x (2/352)
Verifying acl.s390x (3/352)
Verifying alternatives.s390x (4/352)
Verifying audit.s390x (5/352)
Verifying audit-libs.s390x (6/352)
Verifying authselect.s390x (7/352)
Verifying authselect-libs.s390x (8/352)
Verifying basesystem.noarch (9/352)
...
Verifying whois-nls.noarch (347/352)
Verifying xkeyboard-config.noarch (348/352)
Verifying xz.s390x (349/352)
Verifying xz-libs.s390x (350/352)
Verifying zchunk-libs.s390x (351/352)
Verifying zlib.s390x (352/352)
error: rpmdb: BDB0060 PANIC: fatal region error detected; run recovery
error: db5 error(-30973) from db->close: BDB0087 DB_RUNRECOVERY: Fatal error, run database recovery
error: rpmdb: BDB0060 PANIC: fatal region error detected; run recovery
error: db5 error(-30973) from db->close: BDB0087 DB_RUNRECOVERY: Fatal error, run database recovery
error: rpmdb: BDB0060 PANIC: fatal region error detected; run recovery
error: db5 error(-30973) from db->close: BDB0087 DB_RUNRECOVERY: Fatal error, run database recovery
error: rpmdb: BDB0060 PANIC: fatal region error detected; run recovery
error: db5 error(-30973) from db->close: BDB0087 DB_RUNRECOVERY: Fatal error, run database recovery
error: rpmdb: BDB0060 PANIC: fatal region error detected; run recovery
error: db5 error(-30973) from db->close: BDB0087 DB_RUNRECOVERY: Fatal error, run database recovery
error: rpmdb: BDB0060 PANIC: fatal region error detected; run recovery
error: db5 error(-30973) from db->close: BDB0087 DB_RUNRECOVERY: Fatal error, run database recovery
error: rpmdb: BDB0060 PANIC: fatal region error detected; run recovery
error: db5 error(-30973) from db->close: BDB0087 DB_RUNRECOVERY: Fatal error, run database recovery
error: rpmdb: BDB0060 PANIC: fatal region error detected; run recovery

error: rpmdb: BDB0060 PANIC: fatal region error detected; run recovery
error: db5 error(-30973) from db->close: BDB0087 DB_RUNRECOVERY: Fatal error, run database recovery
error: rpmdb: BDB0060 PANIC: fatal region error detected; run recovery
error: db5 error(-30973) from db->close: BDB0087 DB_RUNRECOVERY: Fatal error, run database recovery
error: rpmdb: BDB0060 PANIC: fatal region error detected; run recovery
error: db5 error(-30973) from db->close: BDB0087 DB_RUNRECOVERY: Fatal error, run database recovery
error: rpmdb: BDB0060 PANIC: fatal region error detected; run recovery
error: db5 error(-30973) from db->close: BDB0087 DB_RUNRECOVERY: Fatal error, run database recovery
error: rpmdb: BDB0060 PANIC: fatal region error detected; run recovery
error: db5 error(-30973) from db->close: BDB0087 DB_RUNRECOVERY: Fatal error, run database recovery
error: rpmdb: BDB1581 File handles still open at environment close
error: rpmdb: BDB1582 Open file handle: /mnt/sysimage/var/lib/rpm/__db.001
error: rpmdb: BDB1582 Open file handle: /mnt/sysimage/var/lib/rpm/__db.001
error: rpmdb: BDB1582 Open file handle: /mnt/sysimage/var/lib/rpm/__db.002
error: rpmdb: BDB1582 Open file handle: /mnt/sysimage/var/lib/rpm/__db.003
error: rpmdb: BDB1582 Open file handle: /mnt/sysimage/var/lib/rpm/Packages
error: rpmdb: BDB1582 Open file handle: /mnt/sysimage/var/lib/rpm/Name

error: rpmdb: BDB1582 Open file handle: /mnt/sysimage/var/lib/rpm/Group
error: rpmdb: BDB1582 Open file handle: /mnt/sysimage/var/lib/rpm/Requirename
error: rpmdb: BDB1582 Open file handle: /mnt/sysimage/var/lib/rpm/Providename
error: rpmdb: BDB1582 Open file handle: /mnt/sysimage/var/lib/rpm/Conflictname
error: rpmdb: BDB1582 Open file handle: /mnt/sysimage/var/lib/rpm/Obsoletename
error: rpmdb: BDB1582 Open file handle: /mnt/sysimage/var/lib/rpm/Triggername
error: rpmdb: BDB1582 Open file handle: /mnt/sysimage/var/lib/rpm/Dirnames
error: rpmdb: BDB1582 Open file handle: /mnt/sysimage/var/lib/rpm/Installtid
error: rpmdb: BDB1582 Open file handle: /mnt/sysimage/var/lib/rpm/Sigmd5
error: rpmdb: BDB1582 Open file handle: /mnt/sysimage/var/lib/rpm/Sha1header
error: rpmdb: BDB1582 Open file handle: /mnt/sysimage/var/lib/rpm/Filetriggername
...

There is a crash/data corruption during the installation phase, which skips some packages from installing and goes to verifying, where it clearly lies. In your case s390utils-base isn't installed (even when dnf says "Verifying"), so no /usr/sbin/zipl and the error, in my case the kernel wasn't present. My tests were run with qemu-system-s390x-4.1.0-1.fc30.ppc64le, but got confirmation from a x86 host as well.

There is no such problem when using real HW, with or without KVM, so my conclusion is that there is a subtle emulation bug in qemu (TCG) causing all this.

Comment 27 Dan Horák 2019-09-05 08:29:08 UTC
Updated summary and it's a general issue in the full system emulation of a s390x guest on any host arch (confirmed on x86_64, ppc64le).

Comment 28 Cole Robinson 2019-09-06 15:37:43 UTC
So to summarize: installing Fedora 30 in qemu s390x TCG and rpmdb hits some issue, presumably emulation related. Reproduced on x86 and ppc64le host. Reported version is qemu-system-s390x-4.1.0-1.fc30, which must be from virt-preview repo.

Dan can you provide /var/log/libvirt/qemu/$vmname.log

CCing some qemu s390x folks

Comment 29 Dan Horák 2019-09-06 15:55:21 UTC
Created attachment 1612461 [details]
qemu log

Yes, the summary is correct.

Comment 30 Dan Horák 2019-09-06 16:06:43 UTC
For the record - dgilmore was able to install F-29 just fine (using x86_64 host). So likely there is something changed between F-29 and F-30 that breaks the emulation. A rather big change is gcc8 (F-29) vs gcc9 (F-30) and there can be more.

Comment 31 David Hildenbrand 2019-09-09 07:50:07 UTC
Known, issue, please refer to

https://patchew.org/QEMU/20190906075750.14791-1-david@redhat.com/

Triggered by recent glibc memmove changes (that triggers under rpm and rpmbuild so far only). I am able to install Fedora Rawhide with these patches applied just fine.

Comment 32 Dan Horák 2019-09-16 16:33:29 UTC
new version available at https://patchew.org/QEMU/20190916135806.1269-1-david@redhat.com/

Comment 33 David Hildenbrand 2019-09-16 17:01:49 UTC
Latest version available at https://github.com/davidhildenbrand/qemu/tree/mvc (kept updated). Just did an install of Fedora 30 and Fedora 31 (rawhide) without running into issues.

Comment 34 David Hildenbrand 2019-09-24 15:45:35 UTC
Fixes are upstream.

Comment 35 Cole Robinson 2019-09-24 17:59:55 UTC
Thanks David. Does anyone know if this is a regression from previous Fedora releases, or just something that never worked? I'm trying to decide whether to backport that big series, or just point people at virt-preview repo when the next qemu release is out

Comment 36 Dan Horák 2019-09-24 20:28:30 UTC
If I understood right, then the bug was always there, but the newer Fedora (glibc) exposed it. I'm running our virt stack from virt-preview, so no backporting needed for me :-)

Comment 37 David Hildenbrand 2019-09-25 07:08:56 UTC
Dan is correct, just to state what used to work:

Upstream QEMU was able to install+run at least Fedora 27,28,29.

Fedora 30 and 31 could never have worked correctly under any QEMU version, due to the glibc thingy.

Depending on which QEMU version we had in the Fedora releases, installing Fedora 27,28,29 worked, but never 30,31.

Comment 38 Cole Robinson 2019-09-26 23:12:02 UTC
I'll move this to rawhide then, and close when I rebase the next qemu release. It will trickle into virt-preview after that

Comment 39 Cole Robinson 2020-01-13 17:06:11 UTC
This is in qemu 4.2.0 which is in rawhide/virt-preview now

Comment 40 Pavel Raiskup 2020-04-01 08:13:58 UTC
*** Bug 1763111 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.