Bug 1599332 - Flatpak postinstall scriptlet freezes dnf update --refresh
Summary: Flatpak postinstall scriptlet freezes dnf update --refresh
Keywords:
Status: CLOSED EOL
Alias: None
Product: Fedora
Classification: Fedora
Component: dbus
Version: 28
Hardware: Unspecified
OS: Unspecified
unspecified
unspecified
Target Milestone: ---
Assignee: Colin Walters
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2018-07-09 14:16 UTC by Lukas Ruzicka
Modified: 2019-05-28 23:37 UTC (History)
12 users (show)

Fixed In Version:
Clone Of:
Environment:
Last Closed: 2019-05-28 23:37:54 UTC
Type: Bug
Embargoed:


Attachments (Terms of Use)
Packages installed with dnf update until flatpak. (29.18 KB, text/plain)
2018-07-10 08:10 UTC, Lukas Ruzicka
lruzicka: review+
Details
Packages installed with dnf update dbus and dnf update until flatpak. (29.50 KB, text/plain)
2018-07-10 08:11 UTC, Lukas Ruzicka
lruzicka: review+
Details

Description Lukas Ruzicka 2018-07-09 14:16:23 UTC
Description of problem:

If one wants to update a freshly installed Fedora 27, the process gets stalled when flatpak is being updated. The last dnf message to the console says:

====
Upgrading: flatpak-0.99.2-1.fc27.x86_64
Running scriptlet: flatpak-0.99.2-1.fc27.x86_64
====

It seems that flatpak gets stalled while executing the remote-list command (https://src.fedoraproject.org/rpms/flatpak/blob/master/f/flatpak.spec#_91).
If you try to run the command on another console, the results is the same, it gets stalled.

journalctl produces lots of messages:
====
systemd: Looping too fast. Throttling execution a little.
====

The dnf logs are quiet about this.

Version-Release number of selected component (if applicable):

flatpak 0.99.2-1.fc27.x86_64

How reproducible:

Always

Steps to Reproduce:
1. Install a fresh Live CD of Fedora 27
2. Run dnf update --refresh
3. Wait until the update process gets stalled.

Actual results:

Fresh Fedora 27 cannot be updated.

Expected results:

Update should work with no problems.

Additional info:

Running `dnf update flatpak` works
Running `dnf update dnf* rpm* systemd* flatpak` works, too.

I will try some more combination and will let you know.

Comment 1 Lukas Ruzicka 2018-07-09 15:05:04 UTC
The problem does not show when:
 1) I first update flatpak and then run `dnf update --refresh`.
 2) I first update systemd and then run `dnf update --refresh`.
 3) I first update dbus and then run `dnf update --refresh`.
 4) I run `dnf update dbus flatpak systemd`.

Comment 2 Lukas Ruzicka 2018-07-09 17:20:07 UTC
Further debugging showed that we can also be dealing with a DNF bug. I found out that there is a race condition when running `dnf update`, because DNF only installs systemd-libs package and then tries to install flatpak, while `dnf update systemd flatpak` installs systemd completely first and then installs flatpak.

I will check that with the DNF team tomorrow.

Comment 3 Lukas Ruzicka 2018-07-10 08:10:50 UTC
Created attachment 1457714 [details]
Packages installed with dnf update until flatpak.

Comment 4 Lukas Ruzicka 2018-07-10 08:11:57 UTC
Created attachment 1457715 [details]
Packages installed with dnf update dbus and dnf update until flatpak.

Comment 5 Lukas Ruzicka 2018-07-10 08:21:46 UTC
More investigations showed that the problem can be caused by a different order of packages being updated. See the attachments, where the order of the packages is clearly visible.

For example:
1) When I update with "dnf update dbus systemd flatpak", then both dbus and systemd get fully updated first and flatpak will be updated last.
2) When I update with "dnf update" then only dbus-libs and systemd-libs are updated when flatpak is being updated, but the dbus and systemd packages are not updated yet -> can this be the problem?
3) When I update dbus first and then do "dnf update" the package order again is a bit different.

I have not been able to spot the one package that is responsible for that particular order yet. But can someone from the systemd team also take a look if perhaps they might have an idea?

Comment 6 Lukas Ruzicka 2018-07-10 09:10:43 UTC
Some more info: In journalctl, I found a dbus error happening exactly at the moment, when the flatpak update is going on. I think that it also might be a reason for this issue. I will reassing this bug to dbus people for investigations.

Comment 7 Lukas Ruzicka 2018-07-10 09:12:36 UTC
The journal error is:

====
-- Logs begin at Fri 2018-06-22 13:44:45 CEST, end at Mon 2018-06-25 12:06:26 CEST. --
Jun 25 12:03:02 localhost.localdomain dbus-daemon[682]: [system] Reloaded configuration
Jun 25 12:03:02 localhost.localdomain dbus-daemon[682]: [system] Reloaded configuration
Jun 25 12:03:09 localhost.localdomain chronyd[724]: Received KoD RATE from 45.56.118.161
Jun 25 12:03:10 localhost.localdomain dbus-daemon[682]: [system] Reloaded configuration
Jun 25 12:03:10 localhost.localdomain dbus-daemon[682]: [system] Reloaded configuration
Jun 25 12:03:11 localhost.localdomain dbus-daemon[682]: [system] Reloaded configuration
Jun 25 12:03:11 localhost.localdomain dbus-daemon[682]: [system] Reloaded configuration
Jun 25 12:03:11 localhost.localdomain dbus-daemon[936]: [session uid=42 pid=936] Reloaded configuration
Jun 25 12:03:11 localhost.localdomain dbus-daemon[936]: [session uid=42 pid=936] Reloaded configuration
Jun 25 12:03:25 localhost.localdomain dbus-daemon[682]: [system] Reloaded configuration
Jun 25 12:03:25 localhost.localdomain dbus-daemon[682]: [system] Reloaded configuration
Jun 25 12:03:25 localhost.localdomain dbus-daemon[936]: [session uid=42 pid=936] Reloaded configuration
Jun 25 12:03:25 localhost.localdomain dbus-daemon[936]: [session uid=42 pid=936] Reloaded configuration
Jun 25 12:03:25 localhost.localdomain dbus-daemon[936]: [session uid=42 pid=936] Reloaded configuration
Jun 25 12:03:25 localhost.localdomain dbus-daemon[936]: [session uid=42 pid=936] Reloaded configuration
Jun 25 12:03:25 localhost.localdomain dbus-daemon[682]: [system] Reloaded configuration
Jun 25 12:03:25 localhost.localdomain dbus-daemon[936]: [session uid=42 pid=936] Reloaded configuration
Jun 25 12:03:25 localhost.localdomain dbus-daemon[682]: [system] Reloaded configuration
Jun 25 12:03:25 localhost.localdomain polkitd[731]: Reloading rules
Jun 25 12:03:25 localhost.localdomain polkitd[731]: Collecting garbage unconditionally...
Jun 25 12:03:25 localhost.localdomain polkitd[731]: Loading rules from directory /etc/polkit-1/rules.d
Jun 25 12:03:25 localhost.localdomain polkitd[731]: Loading rules from directory /usr/share/polkit-1/rules.d
Jun 25 12:03:25 localhost.localdomain polkitd[731]: Finished loading, compiling and executing 10 rules
Jun 25 12:03:25 localhost.localdomain polkitd[731]: Reloading rules
Jun 25 12:03:25 localhost.localdomain polkitd[731]: Collecting garbage unconditionally...
Jun 25 12:03:25 localhost.localdomain polkitd[731]: Loading rules from directory /etc/polkit-1/rules.d
Jun 25 12:03:25 localhost.localdomain polkitd[731]: Loading rules from directory /usr/share/polkit-1/rules.d
Jun 25 12:03:25 localhost.localdomain polkitd[731]: Finished loading, compiling and executing 10 rules
Jun 25 12:03:25 localhost.localdomain systemd[3369]: Started D-Bus User Message Bus.
Jun 25 12:03:25 localhost.localdomain dbus-daemon[4054]: /usr/bin/dbus-daemon: /lib64/libdbus-1.so.3: version `LIBDBUS_PRIVATE_1.11.20' not found (required by /usr/bin/dbus-daemon)
Jun 25 12:03:50 localhost.localdomain systemd[3369]: Failed to subscribe to activation signal: Connection timed out
Jun 25 12:03:50 localhost.localdomain systemd[3369]: Failed to register name: Connection timed out
Jun 25 12:03:50 localhost.localdomain systemd[3369]: Failed to set up API bus: Connection timed out
Jun 25 12:03:50 localhost.localdomain systemd[3369]: dbus.service: Main process exited, code=exited, status=1/FAILURE
Jun 25 12:03:50 localhost.localdomain systemd[3369]: dbus.service: Unit entered failed state.
Jun 25 12:03:50 localhost.localdomain systemd[3369]: dbus.service: Failed with result 'exit-code'.
Jun 25 12:03:50 localhost.localdomain systemd[3369]: Looping too fast. Throttling execution a little.
Jun 25 12:03:52 localhost.localdomain systemd[3369]: Looping too fast. Throttling execution a little.
Jun 25 12:03:53 localhost.localdomain systemd[3369]: Looping too fast. Throttling execution a little.
Jun 25 12:03:55 localhost.localdomain systemd[3369]: Looping too fast. Throttling execution a little.
Jun 25 12:03:56 localhost.localdomain systemd[3369]: Looping too fast. Throttling execution a little.
Jun 25 12:03:57 localhost.localdomain systemd[3369]: Looping too fast. Throttling execution a little.
====

Comment 8 Lukas Ruzicka 2018-07-10 09:53:12 UTC
On the side, updating the system via Gnome Software works without issues.

Comment 9 Andrew Haveland-Robinson 2018-10-07 23:24:22 UTC
I just had this upgrading fc27->fc28 on a machine that hadn't been used for nearly a year.
Solved by logging in with a new terminal and:

# ps aux | grep flat
root      7755  0.0  0.1 357256 12816 pts/0    Sl+  Oct07   0:00 flatpak remote-list --system

# kill -9 7755

Installation then continued.

Hope this helps someone else - recovering from a failed upgrade is a lengthy and harrowing experience!

Comment 10 Ben Cotton 2018-11-27 14:07:55 UTC
This message is a reminder that Fedora 27 is nearing its end of life.
On 2018-Nov-30  Fedora will stop maintaining and issuing updates for
Fedora 27. It is Fedora's policy to close all bug reports from releases
that are no longer maintained. At that time this bug will be closed as
EOL if it remains open with a Fedora  'version' of '27'.

Package Maintainer: If you wish for this bug to remain open because you
plan to fix it in a currently maintained version, simply change the 'version' 
to a later Fedora version.

Thank you for reporting this issue and we are sorry that we were not 
able to fix it before Fedora 27 is end of life. If you would still like 
to see this bug fixed and are able to reproduce it against a later version 
of Fedora, you are encouraged  change the 'version' to a later Fedora 
version prior this bug is closed as described in the policy above.

Although we aim to fix as many bugs as possible during every release's 
lifetime, sometimes those efforts are overtaken by events. Often a 
more recent Fedora release includes newer upstream software that fixes 
bugs or makes them obsolete.

Comment 11 Ben Cotton 2018-11-30 23:08:42 UTC
Fedora 27 changed to end-of-life (EOL) status on 2018-11-30. Fedora 27 is
no longer maintained, which means that it will not receive any further
security or bug fix updates. As a result we are closing this bug.

If you can reproduce this bug against a currently maintained version of
Fedora please feel free to reopen this bug against that version. If you
are unable to reopen this bug, please file a new report against the
current release. If you experience problems, please add a comment to this
bug.

Thank you for reporting this bug and we are sorry it could not be fixed.

Comment 12 Laszlo Ersek 2019-02-01 20:34:58 UTC
Reopening. I've just run into this while executing "dnf upgrade --refresh" in a Fedora 28 virtual machine, in preparation for a system-upgrade to Fedora 29. I found this BZ by googling "dnf upgrade hang flatpak".

Kudos to Andrew in comment 9: the stuck process was exactly the same for me, and killing it allowed the package installation to continue.

Versions:

    Upgraded flatpak-0.11.7-1.fc28.x86_64                                      @updates
    Upgrade          1.0.6-4.fc28.x86_64                                       @updates

Comment 13 Ben Cotton 2019-05-02 19:56:50 UTC
This message is a reminder that Fedora 28 is nearing its end of life.
On 2019-May-28 Fedora will stop maintaining and issuing updates for
Fedora 28. It is Fedora's policy to close all bug reports from releases
that are no longer maintained. At that time this bug will be closed as
EOL if it remains open with a Fedora 'version' of '28'.

Package Maintainer: If you wish for this bug to remain open because you
plan to fix it in a currently maintained version, simply change the 'version' 
to a later Fedora version.

Thank you for reporting this issue and we are sorry that we were not 
able to fix it before Fedora 28 is end of life. If you would still like 
to see this bug fixed and are able to reproduce it against a later version 
of Fedora, you are encouraged  change the 'version' to a later Fedora 
version prior this bug is closed as described in the policy above.

Although we aim to fix as many bugs as possible during every release's 
lifetime, sometimes those efforts are overtaken by events. Often a 
more recent Fedora release includes newer upstream software that fixes 
bugs or makes them obsolete.

Comment 14 Ben Cotton 2019-05-28 23:37:54 UTC
Fedora 28 changed to end-of-life (EOL) status on 2019-05-28. Fedora 28 is
no longer maintained, which means that it will not receive any further
security or bug fix updates. As a result we are closing this bug.

If you can reproduce this bug against a currently maintained version of
Fedora please feel free to reopen this bug against that version. If you
are unable to reopen this bug, please file a new report against the
current release. If you experience problems, please add a comment to this
bug.

Thank you for reporting this bug and we are sorry it could not be fixed.


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