#8870 Multiple nightly test failures with "Custodia uses 'master.ipa.test' as master peer" and "DBusException"
Closed: worksforme by frenaud. Opened by mpolovka.

The test test_integration/test_uninstallation.py::TestUninstallBase::test_install_uninstall_replica is failing in [testing_ipa-4.9_latest] Nightly PR #935 with an error

E           subprocess.CalledProcessError: Command '['ipa-replica-install', '--admin-password', 'Secret.123', '--password', 'Secret.123', '-U', '--setup-ca', '--force-join', '--realm', 'IPA.TEST', '--domain', 'ipa.test', '--dirsrv-config-file', '/ipatests/ipatests_dse.ldif']' returned non-zero exit status 1.
pytest_ipa/integration/host.py:202: CalledProcessError
 ------------------------------Captured stderr call------------------------------ 
ipa: WARNING: ipa: ERROR: DNS is not configured
ipa: ERROR: stderr: Custodia uses 'master.ipa.test' as master peer.
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.
The ipa-replica-install command failed. See /var/log/ipareplica-install.log for more information

The ipareplica-install.log contains

2021-05-29T09:54:30Z DEBUG step duration: pki-tomcatd __import_ra_key 8.28 sec
2021-05-29T09:54:30Z DEBUG   [23/29]: configure certificate renewals
2021-05-29T09:54:30Z DEBUG Loading StateFile from '/var/lib/ipa/sysrestore/sysrestore.state'
2021-05-29T09:54:55Z DEBUG Traceback (most recent call last):
  File "/usr/lib/python3.9/site-packages/ipaserver/install/service.py", line 635, in start_creation
    run_step(full_msg, method)
  File "/usr/lib/python3.9/site-packages/ipaserver/install/service.py", line 621, in run_step
    method()
  File "/usr/lib/python3.9/site-packages/ipaserver/install/dogtaginstance.py", line 478, in configure_renewal
    certmonger.start_tracking(
  File "/usr/lib/python3.9/site-packages/ipalib/install/certmonger.py", line 576, in start_tracking
    result = cm.obj_if.add_request(params)
  File "/usr/lib64/python3.9/site-packages/dbus/proxies.py", line 141, in __call__
    return self._connection.call_blocking(self._named_service,
  File "/usr/lib64/python3.9/site-packages/dbus/connection.py", line 652, in call_blocking
    reply_message = self.send_message_with_reply_and_block(
dbus.exceptions.DBusException: 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.
...
2021-05-29T09:54:55Z DEBUG The ipa-replica-install command failed, exception: DBusException: 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.
2021-05-29T09:54:55Z 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.
2021-05-29T09:54:55Z ERROR The ipa-replica-install command failed. See /var/log/ipareplica-install.log for more information

which would suggest either #8506, network issue or something completely new.

Full logs


Also present in test_integration/test_replication_layouts.py::TestCompleteTopologyWithCA::test_complete_topology_with_ca in [testing_ipa-4.9_latest_selinux] Nightly PR #918 , report

Also goes for test_uninstallation in [testing_master_previous] Nightly PR #929 , report

Also happened in test_simple_replication.py::TestSimpleReplication::test_user_replication_to_replica in [testing_master_testing] Nightly PR #956, report on fedora34 + updates-testing enabled

I fixed similar DBus fails in fb58b76a801971748f6b10b732e81763df81c69a . I'm not sure if this is the same root cause or not.

All seem to be hitting the hardcoded (not by us) 25 second DBus timeout.

From the install log and journal its not possible to see whether certmonger has gone out to lunch or not. It has just been started so I suppose its possible it is busy doing something during this first request.

I'll work up a PR to increase the certmonger debug level and maybe that will tell us more.

Issue is seen again: PR, report

Reproduced in [testing_master_rawhide], PR #1967, in test_replication_layouts_TestLineTopologyWithCA (logs)

Closing as this issue hasn't been seen recently.

Metadata Update from @frenaud:
- Issue close_status updated to: worksforme
- Issue status updated to: Closed (was: Open)

Metadata