Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

dnfdaemon do_transaction error #1978

Open
anaselli opened this issue Jan 2, 2025 · 12 comments
Open

dnfdaemon do_transaction error #1978

anaselli opened this issue Jan 2, 2025 · 12 comments

Comments

@anaselli
Copy link

anaselli commented Jan 2, 2025

Using dnfdragora I often have a noreply from dbus after a do_transaction call.

Called at
2025-01-02 17:09:52,987 [dnfdaemon.client]{dnfd_client.py:424}(DEBUG) __async_thread_loop proxy org.rpm.dnf.v0.Goal method do_transaction

Then i had some download signals and next:

2025-01-02 17:10:18,320 [dnfdaemon.client]{dnfd_client.py:478}(ERROR) __async_thread_loop (RunTransaction) proxy org.rpm.dnf.v0.Goal, method do_transaction - Exception org.freedesktop.DBus.Error.NoReply: Did not receive a reply. Possible causes include: the remote application did not send a reply, the message bus security policy blocked the reply, the reply timeout expired, or the network connection was broken.

@anaselli
Copy link
Author

anaselli commented Jan 6, 2025

I should say that this is issue is blocking. It happens very often here. Can we talk about this as we had for list_fd? i experienced it in both fedora and mageia

@m-blaha
Copy link
Member

m-blaha commented Jan 13, 2025

Hmm, this sounds like the do_transaction() call doesn’t have a proper timeout set. By default, the D-Bus call timeout is around 30 seconds, but running the transaction (which also involves downloading the required packages) can easily take much longer. Have you tried setting a longer timeout? For example:
iface_goal.do_transaction(dbus.Dictionary({}, signature='sv'), timeout=600)

@anaselli
Copy link
Author

I haven't found that option described, anyway it seems not to work:

2025-01-14 19:38:31,366 [dnfdragora.ui]{ui.py:2549}(DEBUG) Event received BuildTransaction - status DNFDragoraStatus.RUNNING
2025-01-14 19:38:31,366 [dnfdragora.ui]{ui.py:2569}(DEBUG) Event received BuildTransaction, {'result': (0, [['Package', 'Upgrade', 'External User', {'replaces': [117]}, {'arch': 'x86_64', 'download_size': 143273889, 'epoch': '0', 'evr': '1.96.3-1736454428.el8', 'from_repo_id': '', 'full_nevra': 'code-0:1.96.3-1736454428.el8.x86_64', 'id': 46564, 'install_size': 400269215, 'name': 'code', 'reason': 'External User', 'release': '1736454428.el8', 'repo_id': 'code', 'version': '1.96.3'}], ['Package', 'Upgrade', 'External User', {'replaces': [247]}, {'arch': 'x86_64', 'download_size': 71657644, 'epoch': '0', 'evr': '128.6.0-1.mga9', 'from_repo_id': '', 'full_nevra': 'firefox-0:128.6.0-1.mga9.x86_64', 'id': 35404, 'install_size': 232953672, 'name': 'firefox', 'reason': 'External User', 'release': '1.mga9', 'repo_id': 'updates-x86_64', 'version': '128.6.0'}], ['Package', 'Upgrade', 'External User', {'replaces': [248]}, {'arch': 'noarch', 'download_size': 525503, 'epoch': '0', 'evr': '128.6.0-1.mga9', 'from_repo_id': '', 'full_nevra': 'firefox-it-0:128.6.0-1.mga9.noarch', 'id': 36186, 'install_size': 584354, 'name': 'firefox-it', 'reason': 'External User', 'release': '1.mga9', 'repo_id': 'updates-x86_64', 'version': '128.6.0'}], ['Package', 'Upgrade', 'External User', {'replaces': [3991]}, {'arch': 'x86_64', 'download_size': 79917962, 'epoch': '0', 'evr': '128.6.0-1.mga9', 'from_repo_id': '', 'full_nevra': 'thunderbird-0:128.6.0-1.mga9.x86_64', 'id': 44204, 'install_size': 266805293, 'name': 'thunderbird', 'reason': 'External User', 'release': '1.mga9', 'repo_id': 'updates-x86_64', 'version': '128.6.0'}], ['Package', 'Upgrade', 'External User', {'replaces': [3993]}, {'arch': 'noarch', 'download_size': 631078, 'epoch': '0', 'evr': '128.6.0-1.mga9', 'from_repo_id': '', 'full_nevra': 'thunderbird-it-0:128.6.0-1.mga9.noarch', 'id': 44939, 'install_size': 697093, 'name': 'thunderbird-it', 'reason': 'External User', 'release': '1.mga9', 'repo_id': 'updates-x86_64', 'version': '128.6.0'}], ['Package', 'Replaced', 'External User', {}, {'arch': 'x86_64', 'download_size': 0, 'epoch': '0', 'evr': '1.96.2-1734607808.el8', 'from_repo_id': '<unknown>', 'full_nevra': 'code-0:1.96.2-1734607808.el8.x86_64', 'id': 117, 'install_size': 400268926, 'name': 'code', 'reason': 'External User', 'release': '1734607808.el8', 'repo_id': '@System', 'version': '1.96.2'}], ['Package', 'Replaced', 'External User', {}, {'arch': 'x86_64', 'download_size': 0, 'epoch': '0', 'evr': '128.5.0-1.mga9', 'from_repo_id': '<unknown>', 'full_nevra': 'firefox-0:128.5.0-1.mga9.x86_64', 'id': 247, 'install_size': 232867394, 'name': 'firefox', 'reason': 'External User', 'release': '1.mga9', 'repo_id': '@System', 'version': '128.5.0'}], ['Package', 'Replaced', 'External User', {}, {'arch': 'noarch', 'download_size': 0, 'epoch': '0', 'evr': '128.5.0-1.mga9', 'from_repo_id': '<unknown>', 'full_nevra': 'firefox-it-0:128.5.0-1.mga9.noarch', 'id': 248, 'install_size': 584359, 'name': 'firefox-it', 'reason': 'External User', 'release': '1.mga9', 'repo_id': '@System', 'version': '128.5.0'}], ['Package', 'Replaced', 'External User', {}, {'arch': 'x86_64', 'download_size': 0, 'epoch': '0', 'evr': '128.5.2-1.mga9', 'from_repo_id': '<unknown>', 'full_nevra': 'thunderbird-0:128.5.2-1.mga9.x86_64', 'id': 3991, 'install_size': 266716775, 'name': 'thunderbird', 'reason': 'External User', 'release': '1.mga9', 'repo_id': '@System', 'version': '128.5.2'}], ['Package', 'Replaced', 'External User', {}, {'arch': 'noarch', 'download_size': 0, 'epoch': '0', 'evr': '128.5.2-1.mga9', 'from_repo_id': '<unknown>', 'full_nevra': 'thunderbird-it-0:128.5.2-1.mga9.noarch', 'id': 3993, 'install_size': 697097, 'name': 'thunderbird-it', 'reason': 'External User', 'release': '1.mga9', 'repo_id': '@System', 'version': '128.5.2'}]]), 'error': None} - status DNFDragoraStatus.RUNNING
2025-01-14 19:38:38,385 [dnfdaemon.client]{dnfd_client.py:492}(DEBUG) run_dbus_async RunTransaction (return=0) args: (({'timeout': 600},))
2025-01-14 19:38:38,385 [dnfdaemon.client]{dnfd_client.py:421}(DEBUG) __async_thread_loop Command RunTransaction(({'timeout': 600},)) requested 
2025-01-14 19:38:38,575 [dnfdaemon.client]{dnfd_client.py:424}(DEBUG) __async_thread_loop proxy org.rpm.dnf.v0.Goal method do_transaction
2025-01-14 19:38:48,317 [dnfdragora.ui]{ui.py:2728}(DEBUG) {'session_object_path': '/org/rpm/dnf/v0/4c4c9d354359040c32a61efcb32bf53f', 'download_id': 'package:46564', 'description': 'code-0:1.96.3-1736454428.el8.x86_64', 'total_to_download': 143273889}
2025-01-14 19:38:48,317 [dnfdragora.ui]{ui.py:2222}(DEBUG) OnDownloadStart(/org/rpm/dnf/v0/4c4c9d354359040c32a61efcb32bf53f) ('package:46564', 'code-0:1.96.3-1736454428.el8.x86_64', 143273889)
2025-01-14 19:38:48,317 [dnfdragora.ui]{ui.py:2728}(DEBUG) {'session_object_path': '/org/rpm/dnf/v0/4c4c9d354359040c32a61efcb32bf53f', 'download_id': 'package:35404', 'description': 'firefox-0:128.6.0-1.mga9.x86_64', 'total_to_download': 71657644}
2025-01-14 19:38:48,317 [dnfdragora.ui]{ui.py:2222}(DEBUG) OnDownloadStart(/org/rpm/dnf/v0/4c4c9d354359040c32a61efcb32bf53f) ('package:35404', 'firefox-0:128.6.0-1.mga9.x86_64', 71657644)
2025-01-14 19:38:48,317 [dnfdragora.ui]{ui.py:2728}(DEBUG) {'session_object_path': '/org/rpm/dnf/v0/4c4c9d354359040c32a61efcb32bf53f', 'download_id': 'package:36186', 'description': 'firefox-it-0:128.6.0-1.mga9.noarch', 'total_to_download': 525503}
2025-01-14 19:38:48,317 [dnfdragora.ui]{ui.py:2222}(DEBUG) OnDownloadStart(/org/rpm/dnf/v0/4c4c9d354359040c32a61efcb32bf53f) ('package:36186', 'firefox-it-0:128.6.0-1.mga9.noarch', 525503)
2025-01-14 19:38:48,317 [dnfdragora.ui]{ui.py:2728}(DEBUG) {'session_object_path': '/org/rpm/dnf/v0/4c4c9d354359040c32a61efcb32bf53f', 'download_id': 'package:44204', 'description': 'thunderbird-0:128.6.0-1.mga9.x86_64', 'total_to_download': 79917962}
2025-01-14 19:38:48,317 [dnfdragora.ui]{ui.py:2222}(DEBUG) OnDownloadStart(/org/rpm/dnf/v0/4c4c9d354359040c32a61efcb32bf53f) ('package:44204', 'thunderbird-0:128.6.0-1.mga9.x86_64', 79917962)
2025-01-14 19:38:48,317 [dnfdragora.ui]{ui.py:2728}(DEBUG) {'session_object_path': '/org/rpm/dnf/v0/4c4c9d354359040c32a61efcb32bf53f', 'download_id': 'package:44939', 'description': 'thunderbird-it-0:128.6.0-1.mga9.noarch', 'total_to_download': 631078}
2025-01-14 19:38:48,317 [dnfdragora.ui]{ui.py:2222}(DEBUG) OnDownloadStart(/org/rpm/dnf/v0/4c4c9d354359040c32a61efcb32bf53f) ('package:44939', 'thunderbird-it-0:128.6.0-1.mga9.noarch', 631078)
2025-01-14 19:38:48,318 [dnfdragora.ui]{ui.py:2253}(WARNING) Dimension does not match for object [package:46564]:[code-0:1.96.3-1736454428.el8.x86_64]
2025-01-14 19:38:49,917 [dnfdragora.ui]{ui.py:2733}(DEBUG) {'session_object_path': '/org/rpm/dnf/v0/4c4c9d354359040c32a61efcb32bf53f', 'download_id': 'package:46564', 'status': 0, 'error': ''}
2025-01-14 19:38:49,918 [dnfdragora.ui]{ui.py:2277}(DEBUG) OnDownloadEnd ('package:46564', 'code-0:1.96.3-1736454428.el8.x86_64', 0, '')
2025-01-14 19:38:49,918 [dnfdragora.ui]{ui.py:2284}(DEBUG) Downloaded : package:46564 - code-0:1.96.3-1736454428.el8.x86_64
2025-01-14 19:38:51,517 [dnfdragora.ui]{ui.py:2733}(DEBUG) {'session_object_path': '/org/rpm/dnf/v0/4c4c9d354359040c32a61efcb32bf53f', 'download_id': 'package:36186', 'status': 0, 'error': ''}
2025-01-14 19:38:51,517 [dnfdragora.ui]{ui.py:2277}(DEBUG) OnDownloadEnd ('package:36186', 'firefox-it-0:128.6.0-1.mga9.noarch', 0, '')
2025-01-14 19:38:51,517 [dnfdragora.ui]{ui.py:2284}(DEBUG) Downloaded : package:36186 - firefox-it-0:128.6.0-1.mga9.noarch
2025-01-14 19:39:03,840 [dnfdaemon.client]{dnfd_client.py:478}(ERROR) __async_thread_loop (RunTransaction) proxy org.rpm.dnf.v0.Goal, method do_transaction - Exception org.freedesktop.DBus.Error.NoReply: Did not receive a reply. Possible causes include: the remote application did not send a reply, the message bus security policy blocked the reply, the reply timeout expired, or the network connection was broken.
2025-01-14 19:39:03,917 [dnfdaemon.client]{dnfd_client.py:369}(DEBUG) return_handler RunTransaction
2025-01-14 19:39:04,117 [dnfdaemon.client]{dnfd_client.py:391}(DEBUG) get_result RunTransaction
2025-01-14 19:39:04,256 [dnfdaemon.client]{dnfd_client.py:382}(DEBUG) Quit return_handler error org.freedesktop.DBus.Error.NoReply: Did not receive a reply. Possible causes include: the remote application did not send a reply, the message bus security policy blocked the reply, the reply timeout expired, or the network connection was broken.
2025-01-14 19:39:04,317 [dnfdragora.ui]{ui.py:2556}(ERROR) Event received RunTransaction, org.freedesktop.DBus.Error.NoReply: Did not receive a reply. Possible causes include: the remote application did not send a reply, the message bus security policy blocked the reply, the reply timeout expired, or the network connection was broken. - status DNFDragoraStatus.RUN_TRANSACTION
2025-01-14 19:39:42,607 [dnfdragora]{dnfdragora:101}(ERROR) Unexpected error: <class 'dbus.exceptions.DBusException'> 

@m-blaha
Copy link
Member

m-blaha commented Jan 15, 2025

The timeout option is not specific to dnfdaemon. It's the option of the dbus Python library to set number of seconds to wait for the message reply. In case you use a different library to communicate with D-Bus, the specific option can be different. From your log I can see that the do_transaction failed after cca 25 seconds which is consistent with the default timeout set in dbus library (see https://gitlab.freedesktop.org/dbus/dbus/-/blob/dbus-1.14/dbus/dbus-connection-internal.h#L46)

Let me share the whole testing script, not only the line which set the timeout. I used made up long_running package package which simulates long running rpm transaction (so that the transaction took at least 5 minutes to complete) by having sleeps in post install scriptlet.

import dbus

DNFDAEMON_BUS_NAME = 'org.rpm.dnf.v0'
DNFDAEMON_OBJECT_PATH = '/' + DNFDAEMON_BUS_NAME.replace('.', '/')

IFACE_SESSION_MANAGER = '{}.SessionManager'.format(DNFDAEMON_BUS_NAME)
IFACE_RPM = '{}.rpm.Rpm'.format(DNFDAEMON_BUS_NAME)
IFACE_GOAL = '{}.Goal'.format(DNFDAEMON_BUS_NAME)


bus = dbus.SystemBus()
iface_session = dbus.Interface(
    bus.get_object(DNFDAEMON_BUS_NAME, DNFDAEMON_OBJECT_PATH),
    dbus_interface=IFACE_SESSION_MANAGER)

session = iface_session.open_session(
    dbus.Dictionary({}, signature=dbus.Signature('sv')))

iface_rpm = dbus.Interface(
    bus.get_object(DNFDAEMON_BUS_NAME, session),
    dbus_interface=IFACE_RPM)
iface_goal = dbus.Interface(
    bus.get_object(DNFDAEMON_BUS_NAME, session),
    dbus_interface=IFACE_GOAL)

iface_rpm.install(['long_running'], dbus.Dictionary({}, signature='sv'))

# resolve the transaction
resolved, result = iface_goal.resolve({})

# now you can print the transaction table and ask the user for confirmation
print("Resolved.")

if result == 0:
    print("Running the transaction")
    iface_goal.do_transaction(dbus.Dictionary({}, signature='sv'), timeout=600)
    print("Installed")

@anaselli
Copy link
Author

I maybe wrong in something, my patch is:

diff --git a/dnfdragora/dnfd_client.py b/dnfdragora/dnfd_client.py
index 9da9ed9..0f92fc9 100644
--- a/dnfdragora/dnfd_client.py
+++ b/dnfdragora/dnfd_client.py
@@ -469,6 +469,9 @@ class Client:
 
                 #no needs to unpack results
                 self._return_handler(pkglist, data)
+            elif method == "do_transaction":
+                result = func(dbus.Dictionary({*args}, signature='sv'), timeout=600)
+                self._return_handler(unpack_dbus(result), data)
             else:
                 result = func(*args)
                 self._return_handler(unpack_dbus(result), data)

Same issue. I wonder if i can trap the exception and connect to daemon again. The transaction finishes correctly as far as i can say.

@m-blaha
Copy link
Member

m-blaha commented Jan 20, 2025

Thank you, I'll check out the dnfdragora sources.

@anaselli
Copy link
Author

I also created a test case by using a single script.
However that does not fail always, just from now and then. I've so realized that if i disable logging from dnfdragora, this issue happens less (with more packages or at the end of the transaction).
Anyway btanks is long enough to make do_transaction reply always failing in dnfdragora with logging at debug level enabled.

@m-blaha
Copy link
Member

m-blaha commented Jan 27, 2025

I tested the script on Mageia Cauldron 10 using DNF5 from the distribution. The only time I managed to reproduce a failure was when I artificially slowed down the network connection. In that case, I observed timeout failures during the iface_goal.resolve({}) call (that's when repository metadata is being downloaded, a process that can take a while).

After adding a timeout to this call as well, I was no longer able to reproduce the issue.

@anaselli
Copy link
Author

have you tried enabling logging at debug level and by installing "btanks"?

@m-blaha
Copy link
Member

m-blaha commented Jan 28, 2025

Hm, the dnfdragora was not running at all. But if it is running, I can observe some strange behavior - like your script is not resolving the transaction with "No match for argument: btanks" error message.

Btw, how can I enable logging for dnfdragora? I switched log_level_debug to True in /etc/dnfdragora/dnfdragora.yaml, but I'm still getting:

# dnfdragora 
Try reading configuration file
From ./dnfdragora.yaml
Skipped exception: <[Errno 2] No such file or directory: './dnfdragora.yaml'> 
From /etc/dnfdragora/dnfdragora.yaml
Finally read user settings from /root/.config/dnfdragora.yaml
Skipped exception: <[Errno 2] No such file or directory: '/root/.config/dnfdragora.yaml'> 
Warning logging must be set in user preferences, discarded
Logging disabled

@anaselli
Copy link
Author

by editing ~/.config/dnfdragora.yaml

settings:
  always_yes: false
  do not show groups at startup: false
  interval for checking updates: 180
  log:
    directory: /path/to/your/writable/directory
    enabled: true
    level_debug: true
  metadata:
    last_update: 2023-02-18 11:07
    update_interval: 48
  search:
    fuzzy_search: false
    newest_only: false
  show updates at startup: false
  upgrades as updates: true
view:
  filter: to_update
  show: groups

or by enabling it from menu Options//User preferences/Logging

@anaselli
Copy link
Author

Hm, the dnfdragora was not running at all. But if it is running, I can observe some strange behavior - like your script is not resolving the transaction with "No match for argument: btanks" error message.

Sorry i don't understand what you've seen. But please open an issue I'll be happy to fix it (or just explain it here if you prefer). I could have forgotteb to perform some checks or...

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

2 participants