RHEL Engineering is moving the tracking of its product development work on RHEL 6 through RHEL 9 to Red Hat Jira (issues.redhat.com). If you're a Red Hat customer, please continue to file support cases via the Red Hat customer portal. If you're not, please head to the "RHEL project" in Red Hat Jira and file new tickets here. Individual Bugzilla bugs in the statuses "NEW", "ASSIGNED", and "POST" are being migrated throughout September 2023. Bugs of Red Hat partners with an assigned Engineering Partner Manager (EPM) are migrated in late September as per pre-agreed dates. Bugs against components "kernel", "kernel-rt", and "kpatch" are only migrated if still in "NEW" or "ASSIGNED". If you cannot log in to RH Jira, please consult article #7032570. That failing, please send an e-mail to the RH Jira admins at rh-issues@redhat.com to troubleshoot your issue as a user management inquiry. The email creates a ServiceNow ticket with Red Hat. Individual Bugzilla bugs that are migrated will be moved to status "CLOSED", resolution "MIGRATED", and set with "MigratedToJIRA" in "Keywords". The link to the successor Jira issue will be found under "Links", have a little "two-footprint" icon next to it, and direct you to the "RHEL project" in Red Hat Jira (issue links are of type "https://issues.redhat.com/browse/RHEL-XXXX", where "X" is a digit). This same link will be available in a blue banner at the top of the page informing you that that bug has been migrated.
Bug 1444800 - DBus can not activate service com.redhat.SubscriptionManager
Summary: DBus can not activate service com.redhat.SubscriptionManager
Keywords:
Status: CLOSED ERRATA
Alias: None
Product: Red Hat Enterprise Linux 7
Classification: Red Hat
Component: subscription-manager
Version: 7.3
Hardware: All
OS: Linux
medium
low
Target Milestone: rc
: ---
Assignee: Jiri Hnidek
QA Contact: John Sefler
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2017-04-24 10:57 UTC by Jiri Hnidek
Modified: 2017-08-01 19:23 UTC (History)
4 users (show)

Fixed In Version: subscription-manager-1.19.10-1
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed: 2017-08-01 19:23:41 UTC
Target Upstream Version:
Embargoed:


Attachments (Terms of Use)


Links
System ID Private Priority Status Summary Last Updated
Github candlepin subscription-manager pull 1603 0 'None' closed 1444800: Added mising policy file for com.redhat.SubscriptionManager . 2021-02-03 13:21:09 UTC
Red Hat Product Errata RHBA-2017:2083 0 normal SHIPPED_LIVE python-rhsm and subscription-manager bug fix and enhancement update 2017-08-01 18:14:19 UTC

Description Jiri Hnidek 2017-04-24 10:57:14 UTC
Description of problem:
Any command of subscription-manager is very slow, because attempt to connect to DBus service com.redhat.SubscriptionManager timed out.

Version-Release number of selected component (if applicable):
[root@rhel01 subscription_manager]# ./bin/subscription-manager version
server type: Red Hat Subscription Management
subscription management server: 0.9.51.21-1
subscription management rules: 5.15.1
subscription-manager: RPM_VERSION
python-rhsm: 0.0.0-1

master version from GitHub

How reproducible:
always

Steps to Reproduce:
1. git clone git:candlepin/subscription-manager.git
2. cd subscription-manager
3. cd python-rhsm
4. python ./setup.py
5. python ./setup.py build_ext --inplace
6. cd ..
7. make
8. su
9. export PYTHONPATH=./src/:./python-rhsm/src/
10. export SUBMAN_GTK_VERSION=3
11. ./bin/subscription-manager version


Actual results:
Following errors in logs.

journalctl -f print following errors in my case:

Apr 24 12:30:49 rhel01 dbus[613]: [system] Activating service name='com.redhat.SubscriptionManager' (using servicehelper)
Apr 24 12:30:49 rhel01 dbus-daemon[613]: dbus[613]: [system] Activating service name='com.redhat.SubscriptionManager' (using servicehelper)
Apr 24 12:31:14 rhel01 dbus[613]: [system] Failed to activate service 'com.redhat.SubscriptionManager': timed out
Apr 24 12:31:14 rhel01 dbus-daemon[613]: dbus[613]: [system] Failed to activate service 'com.redhat.SubscriptionManager': timed out

tail -f /var/log/rhsm/rhsm.log

2017-04-24 12:42:02,551 [ERROR] subscription-manager:2942:MainThread @dbus_interface.py:52 - 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.
Traceback (most recent call last):
  File "/home/jhnidek/github/candlepin/subscription_manager/src/subscription_manager/dbus_interface.py", line 41, in __init__
    follow_name_owner_changes=self.has_main_loop)
  File "/home/jhnidek/github/candlepin/subscription_manager/src/subscription_manager/dbus_interface.py", line 74, in _get_validity_object
    return self.bus.get_object(*args, **kwargs)
  File "/usr/lib64/python2.7/site-packages/dbus/bus.py", line 241, in get_object
    follow_name_owner_changes=follow_name_owner_changes)
  File "/usr/lib64/python2.7/site-packages/dbus/proxies.py", line 248, in __init__
    self._named_service = conn.activate_name_owner(bus_name)
  File "/usr/lib64/python2.7/site-packages/dbus/bus.py", line 180, in activate_name_owner
    self.start_service_by_name(bus_name)
  File "/usr/lib64/python2.7/site-packages/dbus/bus.py", line 278, in start_service_by_name
    'su', (bus_name, flags)))
  File "/usr/lib64/python2.7/site-packages/dbus/connection.py", line 651, in call_blocking
    message, timeout)
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.
2017-04-24 12:42:02,625 [INFO] subscription-manager:2942:MainThread @managercli.py:507 - X-Correlation-ID: 9c9ac3cac4dc42d5aacc5edacd1ba18e
2017-04-24 12:42:02,625 [INFO] subscription-manager:2942:MainThread @managercli.py:396 - Client Versions: {'python-rhsm': '0.0.0-1', 'subscription-manager': 'RPM_VERSION'}
2017-04-24 12:42:02,625 [INFO] subscription-manager:2942:MainThread @connection.py:780 - Connection built: host=subscription.rhsm.stage.redhat.com port=443 handler=/subscription auth=identity_cert ca_dir=/etc/rhsm/ca/ insecure=False
2017-04-24 12:42:02,626 [INFO] subscription-manager:2942:MainThread @connection.py:780 - Connection built: host=subscription.rhsm.stage.redhat.com port=443 handler=/subscription auth=none

Expected results:
No errors in log and faster response.

Additional info:

time ./bin/subscription-manager version | grep real
real	0m28.319s

time subscription-manager version | grep real
real	0m2.636s

When SELinux is not enforcing, then results are the same.

Comment 2 Jiri Hnidek 2017-04-24 11:34:44 UTC
There is no .policy file for this DBus service in /usr/share/polkit-1/actions/ and GitHub repository doesn't include any either.

Comment 4 Sean Toner 2017-05-09 17:21:58 UTC
Running the version command was very fast and I didn't notice any slowness, nor were there errors in the logs. I ran the steps in the repro section with a few modifications on my system (mostly for missing devel packages):

  185  git clone https://github.com/candlepin/subscription-manager.git
  186  cd subscription-manager/
  187  cd python-rhsm/
  188  python ./setup.py 
  189  python ./setup.py build_ext --inplace
  190  cd ..
  191  make
  192  dnf search glib
  193  yum search glib
  194  yum install glib2-devel
  195  yum install glib-devel
  196  make
  197  yum search gtk3
  198  yum install gtk3-devel
  199  make
  200  yum search libnotify
  201  yum install libnotify-devel
  202  ls
  203  make
  204  yum search dbus-glib
  205  yum install -y dbus-glib-devel
  206  make
  207  export PYTHONPATH=./src/:./python-rhsm/src/
  208  export SUBMAN_GTK_VERSION=3
  209  ./bin/subscription-manager version

journalctl output
=================
The journalctl -f message log did not show the original error, though it did show a repeating message like this:

[root@stoner-rh74-test ~]# journalctl -f
-- Logs begin at Sat 2017-05-06 16:49:42 EDT. --
May 09 11:46:54 stoner-rh74-test.localdomain NetworkManager[597]: Error while sending AddMatch() message: The connection is closed
May 09 11:46:54 stoner-rh74-test.localdomain NetworkManager[597]: <warn>  [1494344814.4716] bus-manager: could not create org.freedesktop.DBus proxy (Error calling StartServiceByName for org.freedesktop.DBus: The connection is closed); only the private D-Bus socket will be available
May 09 11:46:57 stoner-rh74-test.localdomain NetworkManager[597]: Error while sending AddMatch() message: The connection is closed
May 09 11:46:57 stoner-rh74-test.localdomain NetworkManager[597]: <warn>  [1494344817.4719] bus-manager: could not create org.freedesktop.DBus proxy (Error calling StartServiceByName for org.freedesktop.DBus: The connection is closed); only the private D-Bus socket will be available
...

However, this appears to be unrelated as it is with the NetworkManager service.

rhsm.log output
===============

The output of the rhsm.log while running the subscription-manager version command showed no errors:

2017-05-09 11:46:30,940 [DEBUG] subscription-manager:12084:MainThread @https.py:54 - Using standard libs to provide httplib and ssl
2017-05-09 11:46:31,009 [DEBUG] subscription-manager:12084:MainThread @dbus_interface.py:35 - self.has_main_loop=False
2017-05-09 11:46:31,049 [DEBUG] subscription-manager:12084:MainThread @ga_loader.py:89 - ga_loader GaImporterGtk3
2017-05-09 11:46:31,053 [DEBUG] subscription-manager:12084:MainThread @plugins.py:569 - loaded plugin modules: [<module 'container_content' from '/usr/share/rhsm-plugins/container_content.pyc'>, <module 'ostree_content' from '/usr/share/rhsm-plugins/ostree_content.pyc'>]
2017-05-09 11:46:31,054 [DEBUG] subscription-manager:12084:MainThread @plugins.py:570 - loaded plugins: {'container_content.ContainerContentPlugin': <container_content.ContainerContentPlugin object at 0x2ec8e10>, 'ostree_content.OstreeContentPlugin': <ostree_content.OstreeContentPlugin object at 0x2ed0110>}
2017-05-09 11:46:31,054 [DEBUG] subscription-manager:12084:MainThread @identity.py:132 - Loading consumer info from identity certificates.
2017-05-09 11:46:31,054 [DEBUG] subscription-manager:12084:MainThread @identity.py:147 - Reload of consumer identity cert /etc/pki/consumer/cert.pem raised an exception with msg: [Errno 2] No such file or directory: '/etc/pki/consumer/key.pem'
2017-05-09 11:46:31,081 [INFO] subscription-manager:12084:MainThread @managercli.py:522 - X-Correlation-ID: a4c55afc5f4346e1872a15a8ed56fd84
2017-05-09 11:46:31,081 [INFO] subscription-manager:12084:MainThread @managercli.py:411 - Client Versions: {'python-rhsm': '0.0.0-1', 'subscription-manager': 'RPM_VERSION'}
2017-05-09 11:46:31,082 [INFO] subscription-manager:12084:MainThread @connection.py:780 - Connection built: host=stoner-candle.usersys.redhat.com port=8443 handler=/candlepin auth=identity_cert ca_dir=/etc/rhsm/ca/ insecure=False
2017-05-09 11:46:31,082 [INFO] subscription-manager:12084:MainThread @connection.py:780 - Connection built: host=stoner-candle.usersys.redhat.com port=8443 handler=/candlepin auth=none
2017-05-09 11:46:31,095 [DEBUG] subscription-manager:12084:MainThread @connection.py:440 - Loaded CA certificates from /etc/rhsm/ca/: redhat-uep.pem, redhat-entitlement-authority.pem, stoner-candle.pem
2017-05-09 11:46:31,095 [DEBUG] subscription-manager:12084:MainThread @connection.py:484 - Making request: GET /candlepin/
2017-05-09 11:46:31,112 [INFO] subscription-manager:12084:MainThread @connection.py:520 - Response: status=200, requestUuid=baca5c57-791e-42f3-bae4-d28d7b7b1f21, request="GET /candlepin/"
2017-05-09 11:46:31,113 [DEBUG] subscription-manager:12084:MainThread @connection.py:797 - Server supports the following resources: {u'': u'/', u'guestids': u'/consumers/{consumer_uuid}/guestids', u'cdn': u'/cdn', u'content_overrides': u'/consumers/{consumer_uuid}/content_overrides', u'hypervisors': u'/hypervisors', u'serials': u'/serials', u'deleted_consumers': u'/deleted_consumers', u'consumers': u'/consumers', u'content': u'/content', u'entitlements': u'/entitlements', u'events': u'/events', u'status': u'/status', u'jobs': u'/jobs', u'users': u'/users', u'subscriptions': u'/subscriptions', u'rules': u'/rules', u'distributor_versions': u'/distributor_versions', u'consumertypes': u'/consumertypes', u'pools': u'/pools', u'atom': u'/atom', u'owners': u'/owners', u'roles': u'/roles', u'admin': u'/admin', u'products': u'/products', u'activation_keys': u'/activation_keys', u'crl': u'/crl'}
2017-05-09 11:46:31,114 [DEBUG] subscription-manager:12084:MainThread @connection.py:440 - Loaded CA certificates from /etc/rhsm/ca/: redhat-uep.pem, redhat-entitlement-authority.pem, stoner-candle.pem
2017-05-09 11:46:31,114 [DEBUG] subscription-manager:12084:MainThread @connection.py:484 - Making request: GET /candlepin/status
2017-05-09 11:46:31,119 [INFO] subscription-manager:12084:MainThread @connection.py:520 - Response: status=200, requestUuid=200833c5-fe96-4736-a1ec-ead82c97ab00, request="GET /candlepin/status"
2017-05-09 11:46:31,120 [INFO] subscription-manager:12084:MainThread @managercli.py:422 - Server Versions: {'rules-version': u'5.20', 'candlepin': u'2.0.19-1', 'server-type': 'This system is currently not registered.'}

Output of subscription-manager version
======================================

[root@stoner-rh74-test subscription-manager]# ./bin/subscription-manager version
server type: This system is currently not registered.
subscription management server: 2.0.19-1
subscription management rules: 5.20
subscription-manager: RPM_VERSION
python-rhsm: 0.0.0-1

Comment 5 errata-xmlrpc 2017-08-01 19:23:41 UTC
Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory, and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://access.redhat.com/errata/RHBA-2017:2083


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