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 1351370 - [ERROR] subscription-manager:31276 @dbus_interface.py:60 - org.freedesktop.DBus.Python.OSError: Traceback
Summary: [ERROR] subscription-manager:31276 @dbus_interface.py:60 - org.freedesktop.DB...
Keywords:
Status: CLOSED ERRATA
Alias: None
Product: Red Hat Enterprise Linux 7
Classification: Red Hat
Component: subscription-manager
Version: 7.3
Hardware: Unspecified
OS: Unspecified
high
high
Target Milestone: rc
: ---
Assignee: Chris Snyder
QA Contact: John Sefler
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2016-06-29 22:13 UTC by John Sefler
Modified: 2016-11-03 20:29 UTC (History)
3 users (show)

Fixed In Version:
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed: 2016-11-03 20:29:52 UTC
Target Upstream Version:
Embargoed:

Attachments (Terms of Use)


Links
System ID Private Priority Status Summary Last Updated
Red Hat Product Errata RHSA-2016:2592 0 normal SHIPPED_LIVE Moderate: subscription-manager security, bug fix, and enhancement update 2016-11-03 12:10:42 UTC

Description John Sefler 2016-06-29 22:13:35 UTC 
Description of problem:
Automated testing has caught a strange bug that seems to hang /usr/libexec/rhsmd after changing the default rhsm.conf configurations.  Unfortunatley we can't seem to recover from the hung /usr/libexec/rhsmd process even after resetting back to the default rhsm.conf configuration.

Version-Release number of selected component (if applicable):
[root@jsefler-rhel7 ~]# subscription-manager version
server type: This system is currently not registered.
subscription management server: 2.0.13-1
subscription management rules: 5.20
subscription-manager: 1.17.8-1.el7
python-rhsm: 1.17.4-1.el7
[root@jsefler-rhel7 ~]# rpm -q selinux-policy
selinux-policy-3.13.1-75.el7.noarch


How reproducible:


Steps to Reproduce:
[root@jsefler-rhel7 ~]# cp -R /etc/pki/product-default/ /tmp/
[root@jsefler-rhel7 ~]# ls -R /tmp/product-default/
/tmp/product-default/:
69.pem
[root@jsefler-rhel7 ~]#
[root@jsefler-rhel7 ~]# subscription-manager config --rhsm.productcertdir=/tmp/product-default/
[root@jsefler-rhel7 ~]# 
[root@jsefler-rhel7 ~]# ps -aux | grep rhsmd
root     31189  0.0  0.0 112648   976 pts/1    S+   17:38   0:00 grep --color=auto rhsmd
[root@jsefler-rhel7 ~]# 

NOTICE: In the commands above we see there is no runaway rhsmd process (other than the grep itself)
NOTICE: Also note that I changed the default configuration for rhsm.productcertdir to a valid location in /tmp

NOW. Let's run a harmless subscription-manager command such as clean while tailing the rhsm.log...

[root@jsefler-rhel7 ~]# subscription-manager clean
All local data removed

2016-06-29 17:42:19,259 [DEBUG] subscription-manager:31276 @ga_loader.py:89 - ga_loader GaImporterGtk3
2016-06-29 17:42:19,267 [DEBUG] subscription-manager:31276 @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'>]
2016-06-29 17:42:19,267 [DEBUG] subscription-manager:31276 @plugins.py:570 - loaded plugins: {'container_content.ContainerContentPlugin': <container_content.ContainerContentPlugin object at 0x135f790>, 'ostree_content.OstreeContentPlugin': <ostree_content.OstreeContentPlugin object at 0x135fd50>}
2016-06-29 17:42:19,267 [DEBUG] subscription-manager:31276 @identity.py:131 - Loading consumer info from identity certificates.
2016-06-29 17:42:19,267 [DEBUG] subscription-manager:31276 @identity.py:146 - 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'
2016-06-29 17:42:19,307 [INFO] subscription-manager:31276 @managercli.py:384 - Client Versions: {'python-rhsm': '1.17.4-1.el7', 'subscription-manager': '1.17.8-1.el7'}
2016-06-29 17:42:19,307 [DEBUG] subscription-manager:31276 @identity.py:131 - Loading consumer info from identity certificates.
2016-06-29 17:42:19,307 [DEBUG] subscription-manager:31276 @identity.py:146 - 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'
2016-06-29 17:42:19,309 [INFO] subscription-manager:31276 @managerlib.py:879 - Cleaned local data
2016-06-29 17:42:19,314 [DEBUG] subscription-manager:31276 @certdirectory.py:216 - Installed product IDs: ['69']
2016-06-29 17:42:19,314 [DEBUG] subscription-manager:31276 @cert_sorter.py:126 - Unregistered, skipping server compliance check.
2016-06-29 17:42:19,315 [DEBUG] subscription-manager:31276 @identity.py:131 - Loading consumer info from identity certificates.
2016-06-29 17:42:19,315 [DEBUG] subscription-manager:31276 @identity.py:146 - 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'
2016-06-29 17:42:19,465 [INFO] rhsmd:31278 @rhsmd:232 - rhsmd started
2016-06-29 17:42:19,472 [DEBUG] rhsmd:31278 @rhsmd:184 - D-Bus interface com.redhat.SubscriptionManager.EntitlementStatus.update_status called with status = 0
2016-06-29 17:42:19,516 [DEBUG] rhsmd:31278 @identity.py:131 - Loading consumer info from identity certificates.
2016-06-29 17:42:19,516 [DEBUG] rhsmd:31278 @identity.py:146 - 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'
2016-06-29 17:42:19,518 [DEBUG] subscription-manager:31276 @dbus_interface.py:59 - Failed to update rhsmd
2016-06-29 17:42:19,518 [ERROR] subscription-manager:31276 @dbus_interface.py:60 - org.freedesktop.DBus.Python.OSError: Traceback (most recent call last):
  File "/usr/lib64/python2.7/site-packages/dbus/service.py", line 707, in _message_cb
    retval = candidate_method(self, *args, **keywords)
  File "/usr/libexec/rhsmd", line 185, in update_status
    pre_result = pre_check_status(self.force_signal)
  File "/usr/libexec/rhsmd", line 110, in pre_check_status
    sorter = require(CERT_SORTER)
  File "/usr/lib/python2.7/site-packages/subscription_manager/injection.py", line 103, in require
    return FEATURES.require(feature, *args, **kwargs)
  File "/usr/lib/python2.7/site-packages/subscription_manager/injection.py", line 77, in require
    self.providers[feature] = provider()
  File "/usr/lib/python2.7/site-packages/subscription_manager/cert_sorter.py", line 322, in __init__
    self.installed_mgr = inj.require(inj.INSTALLED_PRODUCTS_MANAGER)
  File "/usr/lib/python2.7/site-packages/subscription_manager/injection.py", line 103, in require
    return FEATURES.require(feature, *args, **kwargs)
  File "/usr/lib/python2.7/site-packages/subscription_manager/injection.py", line 77, in require
    self.providers[feature] = provider()
  File "/usr/lib/python2.7/site-packages/subscription_manager/cache.py", line 431, in __init__
    self.product_dir = inj.require(inj.PROD_DIR)
  File "/usr/lib/python2.7/site-packages/subscription_manager/injection.py", line 103, in require
    return FEATURES.require(feature, *args, **kwargs)
  File "/usr/lib/python2.7/site-packages/subscription_manager/injection.py", line 77, in require
    self.providers[feature] = provider()
  File "/usr/lib/python2.7/site-packages/subscription_manager/certdirectory.py", line 224, in __init__
    self.installed_prod_dir = ProductCertificateDirectory(path=installed_prod_path)
  File "/usr/lib/python2.7/site-packages/subscription_manager/certdirectory.py", line 106, in __init__
    self.create()
  File "/usr/lib/python2.7/site-packages/subscription_manager/certdirectory.py", line 70, in create
    os.makedirs(self.path)
  File "/usr/lib64/python2.7/os.py", line 157, in makedirs
    mkdir(name, mode)
OSError: [Errno 17] File exists: '/tmp/product-default/'
Traceback (most recent call last):
  File "/usr/lib/python2.7/site-packages/subscription_manager/dbus_interface.py", line 56, in _update
    ignore_reply=self.has_main_loop)
  File "/usr/lib64/python2.7/site-packages/dbus/proxies.py", line 70, in __call__
    return self._proxy_method(*args, **keywords)
  File "/usr/lib64/python2.7/site-packages/dbus/proxies.py", line 145, in __call__
    **keywords)
  File "/usr/lib64/python2.7/site-packages/dbus/connection.py", line 651, in call_blocking
    message, timeout)
DBusException: org.freedesktop.DBus.Python.OSError: Traceback (most recent call last):
  File "/usr/lib64/python2.7/site-packages/dbus/service.py", line 707, in _message_cb
    retval = candidate_method(self, *args, **keywords)
  File "/usr/libexec/rhsmd", line 185, in update_status
    pre_result = pre_check_status(self.force_signal)
  File "/usr/libexec/rhsmd", line 110, in pre_check_status
    sorter = require(CERT_SORTER)
  File "/usr/lib/python2.7/site-packages/subscription_manager/injection.py", line 103, in require
    return FEATURES.require(feature, *args, **kwargs)
  File "/usr/lib/python2.7/site-packages/subscription_manager/injection.py", line 77, in require
    self.providers[feature] = provider()
  File "/usr/lib/python2.7/site-packages/subscription_manager/cert_sorter.py", line 322, in __init__
    self.installed_mgr = inj.require(inj.INSTALLED_PRODUCTS_MANAGER)
  File "/usr/lib/python2.7/site-packages/subscription_manager/injection.py", line 103, in require
    return FEATURES.require(feature, *args, **kwargs)
  File "/usr/lib/python2.7/site-packages/subscription_manager/injection.py", line 77, in require
    self.providers[feature] = provider()
  File "/usr/lib/python2.7/site-packages/subscription_manager/cache.py", line 431, in __init__
    self.product_dir = inj.require(inj.PROD_DIR)
  File "/usr/lib/python2.7/site-packages/subscription_manager/injection.py", line 103, in require
    return FEATURES.require(feature, *args, **kwargs)
  File "/usr/lib/python2.7/site-packages/subscription_manager/injection.py", line 77, in require
    self.providers[feature] = provider()
  File "/usr/lib/python2.7/site-packages/subscription_manager/certdirectory.py", line 224, in __init__
    self.installed_prod_dir = ProductCertificateDirectory(path=installed_prod_path)
  File "/usr/lib/python2.7/site-packages/subscription_manager/certdirectory.py", line 106, in __init__
    self.create()
  File "/usr/lib/python2.7/site-packages/subscription_manager/certdirectory.py", line 70, in create
    os.makedirs(self.path)
  File "/usr/lib64/python2.7/os.py", line 157, in makedirs
    mkdir(name, mode)
OSError: [Errno 17] File exists: '/tmp/product-default/'

2016-06-29 17:42:19,519 [DEBUG] subscription-manager:31276 @utils.py:294 - No virt-who pid file, not attempting to restart



BANG! The rhsm.log above has Tracebacks that appear to stem from the changed rhsm configuration.
WORSE: In the ps -aux | grep rhsmd call below, you will see that /usr/libexec/rhsmd stays running.  This is bad because....

[root@jsefler-rhel7 ~]# ps -aux | grep rhsmd
root     31278  0.2  2.7 359016 28432 ?        Sl   17:42   0:00 /usr/bin/python /usr/libexec/rhsmd
root     31328  0.0  0.0 112648   976 pts/1    S+   17:43   0:00 grep --color=auto rhsmd

... because even after restiring the rhsm.conf back to its default, Tracebacks continue to be logged to rhsm.conf because it appears that the runaway /usr/libexec/rhsmd process is holding onto an old state as shown below. 

[root@jsefler-rhel7 ~]# subscription-manager config --rhsm.productcertdir=/etc/pki/product/
[root@jsefler-rhel7 ~]# subscription-manager clean
All local data removed
[root@jsefler-rhel7 ~]# 

2016-06-29 17:44:57,796 [DEBUG] subscription-manager:31347 @ga_loader.py:89 - ga_loader GaImporterGtk3
2016-06-29 17:44:57,803 [DEBUG] subscription-manager:31347 @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'>]
2016-06-29 17:44:57,803 [DEBUG] subscription-manager:31347 @plugins.py:570 - loaded plugins: {'container_content.ContainerContentPlugin': <container_content.ContainerContentPlugin object at 0x1bf3710>, 'ostree_content.OstreeContentPlugin': <ostree_content.OstreeContentPlugin object at 0x1bf3cd0>}
2016-06-29 17:44:57,803 [DEBUG] subscription-manager:31347 @identity.py:131 - Loading consumer info from identity certificates.
2016-06-29 17:44:57,803 [DEBUG] subscription-manager:31347 @identity.py:146 - 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'
2016-06-29 17:44:57,843 [INFO] subscription-manager:31347 @managercli.py:384 - Client Versions: {'python-rhsm': '1.17.4-1.el7', 'subscription-manager': '1.17.8-1.el7'}
2016-06-29 17:45:19,316 [DEBUG] subscription-manager:31356 @ga_loader.py:89 - ga_loader GaImporterGtk3
2016-06-29 17:45:19,323 [DEBUG] subscription-manager:31356 @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'>]
2016-06-29 17:45:19,323 [DEBUG] subscription-manager:31356 @plugins.py:570 - loaded plugins: {'container_content.ContainerContentPlugin': <container_content.ContainerContentPlugin object at 0x169a710>, 'ostree_content.OstreeContentPlugin': <ostree_content.OstreeContentPlugin object at 0x169acd0>}
2016-06-29 17:45:19,323 [DEBUG] subscription-manager:31356 @identity.py:131 - Loading consumer info from identity certificates.
2016-06-29 17:45:19,323 [DEBUG] subscription-manager:31356 @identity.py:146 - 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'
2016-06-29 17:45:19,364 [INFO] subscription-manager:31356 @managercli.py:384 - Client Versions: {'python-rhsm': '1.17.4-1.el7', 'subscription-manager': '1.17.8-1.el7'}
2016-06-29 17:45:19,364 [DEBUG] subscription-manager:31356 @identity.py:131 - Loading consumer info from identity certificates.
2016-06-29 17:45:19,364 [DEBUG] subscription-manager:31356 @identity.py:146 - 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'
2016-06-29 17:45:19,366 [INFO] subscription-manager:31356 @managerlib.py:879 - Cleaned local data
2016-06-29 17:45:19,394 [DEBUG] subscription-manager:31356 @certdirectory.py:216 - Installed product IDs: ['100000000000006', '1000000000000023', '100000000000011', '27060', '69', '5050', '5051', '917571', '1', '37069', '37068', '37080', '37065', '37067', '37060', '37062', '100000000000060', '100000000000005', '100000000000002', '100000000000003', '100000000000000', '100000000000001', '213412341236', '213412341237', '98121', '213412341235', '100000000000020', '32060', '88888', '100000000000069', '900', '213412341234', '908', '6050', '37090', '37091', '801', '6051', '806', '37070']
2016-06-29 17:45:19,394 [DEBUG] subscription-manager:31356 @cert_sorter.py:126 - Unregistered, skipping server compliance check.
2016-06-29 17:45:19,395 [DEBUG] subscription-manager:31356 @identity.py:131 - Loading consumer info from identity certificates.
2016-06-29 17:45:19,395 [DEBUG] subscription-manager:31356 @identity.py:146 - 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'
2016-06-29 17:45:19,400 [DEBUG] rhsmd:31278 @rhsmd:184 - D-Bus interface com.redhat.SubscriptionManager.EntitlementStatus.update_status called with status = 0
2016-06-29 17:45:19,402 [DEBUG] subscription-manager:31356 @dbus_interface.py:59 - Failed to update rhsmd
2016-06-29 17:45:19,402 [ERROR] subscription-manager:31356 @dbus_interface.py:60 - org.freedesktop.DBus.Python.OSError: Traceback (most recent call last):
  File "/usr/lib64/python2.7/site-packages/dbus/service.py", line 707, in _message_cb
    retval = candidate_method(self, *args, **keywords)
  File "/usr/libexec/rhsmd", line 185, in update_status
    pre_result = pre_check_status(self.force_signal)
  File "/usr/libexec/rhsmd", line 110, in pre_check_status
    sorter = require(CERT_SORTER)
  File "/usr/lib/python2.7/site-packages/subscription_manager/injection.py", line 103, in require
    return FEATURES.require(feature, *args, **kwargs)
  File "/usr/lib/python2.7/site-packages/subscription_manager/injection.py", line 77, in require
    self.providers[feature] = provider()
  File "/usr/lib/python2.7/site-packages/subscription_manager/cert_sorter.py", line 322, in __init__
    self.installed_mgr = inj.require(inj.INSTALLED_PRODUCTS_MANAGER)
  File "/usr/lib/python2.7/site-packages/subscription_manager/injection.py", line 103, in require
    return FEATURES.require(feature, *args, **kwargs)
  File "/usr/lib/python2.7/site-packages/subscription_manager/injection.py", line 77, in require
    self.providers[feature] = provider()
  File "/usr/lib/python2.7/site-packages/subscription_manager/cache.py", line 431, in __init__
    self.product_dir = inj.require(inj.PROD_DIR)
  File "/usr/lib/python2.7/site-packages/subscription_manager/injection.py", line 103, in require
    return FEATURES.require(feature, *args, **kwargs)
  File "/usr/lib/python2.7/site-packages/subscription_manager/injection.py", line 77, in require
    self.providers[feature] = provider()
  File "/usr/lib/python2.7/site-packages/subscription_manager/certdirectory.py", line 224, in __init__
    self.installed_prod_dir = ProductCertificateDirectory(path=installed_prod_path)
  File "/usr/lib/python2.7/site-packages/subscription_manager/certdirectory.py", line 106, in __init__
    self.create()
  File "/usr/lib/python2.7/site-packages/subscription_manager/certdirectory.py", line 70, in create
    os.makedirs(self.path)
  File "/usr/lib64/python2.7/os.py", line 157, in makedirs
    mkdir(name, mode)
OSError: [Errno 17] File exists: '/tmp/product-default/'
Traceback (most recent call last):
  File "/usr/lib/python2.7/site-packages/subscription_manager/dbus_interface.py", line 56, in _update
    ignore_reply=self.has_main_loop)
  File "/usr/lib64/python2.7/site-packages/dbus/proxies.py", line 70, in __call__
    return self._proxy_method(*args, **keywords)
  File "/usr/lib64/python2.7/site-packages/dbus/proxies.py", line 145, in __call__
    **keywords)
  File "/usr/lib64/python2.7/site-packages/dbus/connection.py", line 651, in call_blocking
    message, timeout)
DBusException: org.freedesktop.DBus.Python.OSError: Traceback (most recent call last):
  File "/usr/lib64/python2.7/site-packages/dbus/service.py", line 707, in _message_cb
    retval = candidate_method(self, *args, **keywords)
  File "/usr/libexec/rhsmd", line 185, in update_status
    pre_result = pre_check_status(self.force_signal)
  File "/usr/libexec/rhsmd", line 110, in pre_check_status
    sorter = require(CERT_SORTER)
  File "/usr/lib/python2.7/site-packages/subscription_manager/injection.py", line 103, in require
    return FEATURES.require(feature, *args, **kwargs)
  File "/usr/lib/python2.7/site-packages/subscription_manager/injection.py", line 77, in require
    self.providers[feature] = provider()
  File "/usr/lib/python2.7/site-packages/subscription_manager/cert_sorter.py", line 322, in __init__
    self.installed_mgr = inj.require(inj.INSTALLED_PRODUCTS_MANAGER)
  File "/usr/lib/python2.7/site-packages/subscription_manager/injection.py", line 103, in require
    return FEATURES.require(feature, *args, **kwargs)
  File "/usr/lib/python2.7/site-packages/subscription_manager/injection.py", line 77, in require
    self.providers[feature] = provider()
  File "/usr/lib/python2.7/site-packages/subscription_manager/cache.py", line 431, in __init__
    self.product_dir = inj.require(inj.PROD_DIR)
  File "/usr/lib/python2.7/site-packages/subscription_manager/injection.py", line 103, in require
    return FEATURES.require(feature, *args, **kwargs)
  File "/usr/lib/python2.7/site-packages/subscription_manager/injection.py", line 77, in require
    self.providers[feature] = provider()
  File "/usr/lib/python2.7/site-packages/subscription_manager/certdirectory.py", line 224, in __init__
    self.installed_prod_dir = ProductCertificateDirectory(path=installed_prod_path)
  File "/usr/lib/python2.7/site-packages/subscription_manager/certdirectory.py", line 106, in __init__
    self.create()
  File "/usr/lib/python2.7/site-packages/subscription_manager/certdirectory.py", line 70, in create
    os.makedirs(self.path)
  File "/usr/lib64/python2.7/os.py", line 157, in makedirs
    mkdir(name, mode)
OSError: [Errno 17] File exists: '/tmp/product-default/'

2016-06-29 17:45:19,402 [DEBUG] subscription-manager:31356 @utils.py:294 - No virt-who pid file, not attempting to restart


[root@jsefler-rhel7 ~]# ps -aux | grep rhsmd
root     31278  0.0  2.7 359016 28432 ?        Sl   17:42   0:00 /usr/bin/python /usr/libexec/rhsmd
root     31375  0.0  0.0 112648   972 pts/1    S+   17:46   0:00 grep --color=auto rhsmd



Actual results:
  above

Expected results:
  the /usr/libexec/rhsmd should not throw OSErrors into rhsm.log and the process should not stay running.

Additional info:


ADDTIONAL INFO: If I turn off selinux and rerun the clean command, then the /usr/libexec/rhsmd recovers.

[root@jsefler-rhel7 ~]# setenforce 0
[root@jsefler-rhel7 ~]# subscription-manager clean
All local data removed
[root@jsefler-rhel7 ~]# ps -aux | grep rhsmd
root     31743  0.0  0.0 112648   972 pts/1    R+   18:08   0:00 grep --color=auto rhsmd
[root@jsefler-rhel7 ~]# 


2016-06-29 18:07:56,745 [DEBUG] subscription-manager:31713 @ga_loader.py:89 - ga_loader GaImporterGtk3
2016-06-29 18:07:56,752 [DEBUG] subscription-manager:31713 @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'>]
2016-06-29 18:07:56,752 [DEBUG] subscription-manager:31713 @plugins.py:570 - loaded plugins: {'container_content.ContainerContentPlugin': <container_content.ContainerContentPlugin object at 0x150f710>, 'ostree_content.OstreeContentPlugin': <ostree_content.OstreeContentPlugin object at 0x150fcd0>}
2016-06-29 18:07:56,752 [DEBUG] subscription-manager:31713 @identity.py:131 - Loading consumer info from identity certificates.
2016-06-29 18:07:56,753 [DEBUG] subscription-manager:31713 @identity.py:146 - 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'
2016-06-29 18:07:56,791 [INFO] subscription-manager:31713 @managercli.py:384 - Client Versions: {'python-rhsm': '1.17.4-1.el7', 'subscription-manager': '1.17.8-1.el7'}
2016-06-29 18:07:56,791 [DEBUG] subscription-manager:31713 @identity.py:131 - Loading consumer info from identity certificates.
2016-06-29 18:07:56,791 [DEBUG] subscription-manager:31713 @identity.py:146 - 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'
2016-06-29 18:07:56,792 [INFO] subscription-manager:31713 @managerlib.py:879 - Cleaned local data
2016-06-29 18:07:56,820 [DEBUG] subscription-manager:31713 @certdirectory.py:216 - Installed product IDs: ['100000000000006', '1000000000000023', '100000000000011', '27060', '69', '5050', '5051', '917571', '1', '37069', '37068', '37080', '37065', '37067', '37060', '37062', '100000000000060', '100000000000005', '100000000000002', '100000000000003', '100000000000000', '100000000000001', '213412341236', '213412341237', '98121', '213412341235', '100000000000020', '32060', '88888', '100000000000069', '900', '213412341234', '908', '6050', '37090', '37091', '801', '6051', '806', '37070']
2016-06-29 18:07:56,820 [DEBUG] subscription-manager:31713 @cert_sorter.py:126 - Unregistered, skipping server compliance check.
2016-06-29 18:07:56,821 [DEBUG] subscription-manager:31713 @identity.py:131 - Loading consumer info from identity certificates.
2016-06-29 18:07:56,821 [DEBUG] subscription-manager:31713 @identity.py:146 - 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'
2016-06-29 18:07:56,824 [DEBUG] rhsmd:31278 @rhsmd:184 - D-Bus interface com.redhat.SubscriptionManager.EntitlementStatus.update_status called with status = 0
2016-06-29 18:07:56,830 [DEBUG] rhsmd:31278 @certdirectory.py:216 - Installed product IDs: ['69']
2016-06-29 18:07:56,830 [DEBUG] rhsmd:31278 @cert_sorter.py:126 - Unregistered, skipping server compliance check.
2016-06-29 18:07:56,830 [DEBUG] rhsmd:31278 @identity.py:131 - Loading consumer info from identity certificates.
2016-06-29 18:07:56,831 [DEBUG] rhsmd:31278 @identity.py:146 - 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'
2016-06-29 18:07:56,831 [DEBUG] rhsmd:31278 @cache.py:110 - Wrote cache: /var/lib/rhsm/cache/rhsm_icon.json
2016-06-29 18:07:56,842 [DEBUG] subscription-manager:31713 @utils.py:294 - No virt-who pid file, not attempting to restart

NO MORE TRACEBACK ABOVE WHEN SELINUX WAS TURNED OFF (and back on).
Comment 1 John Sefler 2016-06-29 23:03:15 UTC 
I think these example denials that occur during an automated test that sets the --rhsm.productcertdir to a directory under /tmp/ are suspicious...

[root@jsefler-rhel7 ~]# grep --text 'denied' /var/log/audit/audit.log
type=AVC msg=audit(1467240982.004:16768): avc:  denied  { read } for  pid=8389 comm="rhsmd" name="sm-allProductsSubscribableByMoreThanOneCommonServiceLevel" dev="dm-0" ino=9860328 scontext=system_u:system_r:rhsmcertd_t:s0-s0:c0.c1023 tcontext=unconfined_u:object_r:user_tmp_t:s0 tclass=dir
type=AVC msg=audit(1467240982.004:16769): avc:  denied  { open } for  pid=8389 comm="rhsmd" path="/tmp/sm-allProductsSubscribableByMoreThanOneCommonServiceLevel/37065_.pem" dev="dm-0" ino=8835163 scontext=system_u:system_r:rhsmcertd_t:s0-s0:c0.c1023 tcontext=unconfined_u:object_r:user_tmp_t:s0 tclass=file
Comment 2 Chris Snyder 2016-07-22 19:10:05 UTC 
The initial issue, as reported in the bz, has to do with the default selinux policy of the system. This policy prevents rhsmd from having access to files in /tmp. The check made for the existence of the directory '/tmp/product-default' on initialization of a new instance of ProductCertificateDirectory returns false due to the lack of permissions. This, in turn, causes the ProductCertificateDirectory instance to attempt to create it. The inevitably fails as in the bz above, the directory does in fact exist.

The problem fixed here is that after a failure as described above rhsmd continues to run and hold on to objects that are in a stale state. This is the result of some of our injection code.

The solution was to ensure that rhsmd exits even on exceptions. An alternative would be to modify our injection code to keep creating new instances of objects when requested by rhsmd. While this alternative would fix it in theory, I believe the fix in this PR to be the simplest and most true to the desired behaviour of rhsmd.

PR here: 
https://github.com/candlepin/subscription-manager/pull/1456
Comment 4 Shwetha Kallesh 2016-08-30 13:51:44 UTC 
Reproducer :

[root@dhcp35-208 ~]# subscription-manager version
server type: This system is currently not registered.
subscription management server: 0.9.51.11-1
subscription management rules: 5.15
subscription-manager: 1.17.8-1.el7
python-rhsm: 1.17.4-1.el7


[root@dhcp35-208 ~]# cp -R /etc/pki/product-default/ /tmp/
[root@dhcp35-208 ~]# ls -R /tmp/product-default/
/tmp/product-default/:
69.pem
[root@dhcp35-208 ~]# subscription-manager config --rhsm.productcertdir=/tmp/product-default/
[root@dhcp35-208 ~]# ps -aux | grep rhsmd
root      7734  0.0  0.0 112648   960 pts/1    S+   19:16   0:00 grep --color=auto rhsmd
[root@dhcp35-208 ~]# subscription-manager clean
All local data removed
[root@dhcp35-208 ~]#  ps -aux | grep rhsmd
root      7799  0.6  2.7 359004 28404 ?        Sl   19:17   0:00 /usr/bin/python /usr/libexec/rhsmd
root      7802  0.0  0.0 112648   956 pts/1    S+   19:17   0:00 grep --color=auto rhsmd

Traceback in rhsm.log

[root@dhcp35-208 ~]# tail -f /var/log/rhsm/rhsm.log
2016-08-30 19:17:04,105 [INFO] rhsmd:7799 @rhsmd:232 - rhsmd started
2016-08-30 19:17:04,114 [DEBUG] rhsmd:7799 @rhsmd:184 - D-Bus interface com.redhat.SubscriptionManager.EntitlementStatus.update_status called with status = 0
2016-08-30 19:17:04,158 [DEBUG] rhsmd:7799 @identity.py:131 - Loading consumer info from identity certificates.
2016-08-30 19:17:04,159 [DEBUG] rhsmd:7799 @identity.py:146 - 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'
2016-08-30 19:17:04,199 [DEBUG] subscription-manager:7797 @dbus_interface.py:59 - Failed to update rhsmd
2016-08-30 19:17:04,199 [ERROR] subscription-manager:7797 @dbus_interface.py:60 - org.freedesktop.DBus.Python.OSError: Traceback (most recent call last):
  File "/usr/lib64/python2.7/site-packages/dbus/service.py", line 707, in _message_cb
    retval = candidate_method(self, *args, **keywords)
  File "/usr/libexec/rhsmd", line 185, in update_status
    pre_result = pre_check_status(self.force_signal)
  File "/usr/libexec/rhsmd", line 110, in pre_check_status
    sorter = require(CERT_SORTER)
  File "/usr/lib/python2.7/site-packages/subscription_manager/injection.py", line 103, in require
    return FEATURES.require(feature, *args, **kwargs)
  File "/usr/lib/python2.7/site-packages/subscription_manager/injection.py", line 77, in require
    self.providers[feature] = provider()
  File "/usr/lib/python2.7/site-packages/subscription_manager/cert_sorter.py", line 322, in __init__
    self.installed_mgr = inj.require(inj.INSTALLED_PRODUCTS_MANAGER)
  File "/usr/lib/python2.7/site-packages/subscription_manager/injection.py", line 103, in require
    return FEATURES.require(feature, *args, **kwargs)
  File "/usr/lib/python2.7/site-packages/subscription_manager/injection.py", line 77, in require
    self.providers[feature] = provider()
  File "/usr/lib/python2.7/site-packages/subscription_manager/cache.py", line 431, in __init__
    self.product_dir = inj.require(inj.PROD_DIR)
  File "/usr/lib/python2.7/site-packages/subscription_manager/injection.py", line 103, in require
    return FEATURES.require(feature, *args, **kwargs)
  File "/usr/lib/python2.7/site-packages/subscription_manager/injection.py", line 77, in require
    self.providers[feature] = provider()
  File "/usr/lib/python2.7/site-packages/subscription_manager/certdirectory.py", line 224, in __init__
    self.installed_prod_dir = ProductCertificateDirectory(path=installed_prod_path)
  File "/usr/lib/python2.7/site-packages/subscription_manager/certdirectory.py", line 106, in __init__
    self.create()
  File "/usr/lib/python2.7/site-packages/subscription_manager/certdirectory.py", line 70, in create
    os.makedirs(self.path)
  File "/usr/lib64/python2.7/os.py", line 157, in makedirs
    mkdir(name, mode)
OSError: [Errno 17] File exists: '/tmp/product-default/'
Traceback (most recent call last):
  File "/usr/lib/python2.7/site-packages/subscription_manager/dbus_interface.py", line 56, in _update
    ignore_reply=self.has_main_loop)
  File "/usr/lib64/python2.7/site-packages/dbus/proxies.py", line 70, in __call__
    return self._proxy_method(*args, **keywords)
  File "/usr/lib64/python2.7/site-packages/dbus/proxies.py", line 145, in __call__
    **keywords)
  File "/usr/lib64/python2.7/site-packages/dbus/connection.py", line 651, in call_blocking
    message, timeout)
DBusException: org.freedesktop.DBus.Python.OSError: Traceback (most recent call last):
  File "/usr/lib64/python2.7/site-packages/dbus/service.py", line 707, in _message_cb
    retval = candidate_method(self, *args, **keywords)
  File "/usr/libexec/rhsmd", line 185, in update_status
    pre_result = pre_check_status(self.force_signal)
  File "/usr/libexec/rhsmd", line 110, in pre_check_status
    sorter = require(CERT_SORTER)
  File "/usr/lib/python2.7/site-packages/subscription_manager/injection.py", line 103, in require
    return FEATURES.require(feature, *args, **kwargs)
  File "/usr/lib/python2.7/site-packages/subscription_manager/injection.py", line 77, in require
    self.providers[feature] = provider()
  File "/usr/lib/python2.7/site-packages/subscription_manager/cert_sorter.py", line 322, in __init__
    self.installed_mgr = inj.require(inj.INSTALLED_PRODUCTS_MANAGER)
  File "/usr/lib/python2.7/site-packages/subscription_manager/injection.py", line 103, in require
    return FEATURES.require(feature, *args, **kwargs)
  File "/usr/lib/python2.7/site-packages/subscription_manager/injection.py", line 77, in require
    self.providers[feature] = provider()
  File "/usr/lib/python2.7/site-packages/subscription_manager/cache.py", line 431, in __init__
    self.product_dir = inj.require(inj.PROD_DIR)
  File "/usr/lib/python2.7/site-packages/subscription_manager/injection.py", line 103, in require
    return FEATURES.require(feature, *args, **kwargs)
  File "/usr/lib/python2.7/site-packages/subscription_manager/injection.py", line 77, in require
    self.providers[feature] = provider()
  File "/usr/lib/python2.7/site-packages/subscription_manager/certdirectory.py", line 224, in __init__
    self.installed_prod_dir = ProductCertificateDirectory(path=installed_prod_path)
  File "/usr/lib/python2.7/site-packages/subscription_manager/certdirectory.py", line 106, in __init__
    self.create()
  File "/usr/lib/python2.7/site-packages/subscription_manager/certdirectory.py", line 70, in create
    os.makedirs(self.path)
  File "/usr/lib64/python2.7/os.py", line 157, in makedirs
    mkdir(name, mode)
OSError: [Errno 17] File exists: '/tmp/product-default/'

Traceback still appears after changing produtcert location to default 

[root@dhcp35-208 ~]# subscription-manager config --rhsm.productcertdir=/etc/pki/product/
[root@dhcp35-208 ~]# subscription-manager clean
All local data removed
Comment 5 Chris Snyder 2016-08-30 14:04:15 UTC 
The fix that was put in for this was not to stop the traceback from occurring but instead to stop rhsmd from running forever after there was an error that occurred.

The traceback you are seeing there (specifically the "OSError: [Errno 17] File exists" bit) is the result of selinux denying rhsmd access to the file '/tmp/product-default'. Why this was designed in Python to fail in a similar fashion as if the file / path did not exist is a mystery to me.

In my opinion the success criteria for a patch for this bug should be (after running your reproducer):

$ pgrep rhsmd
$

(no output as rhsmd is not running)

The traceback will still appear (to fix that we'll need a separate BZ)
Comment 6 Shwetha Kallesh 2016-08-31 10:56:53 UTC 
[root@dhcp35-208 ~]# subscription-manager version
server type: This system is currently not registered.
subscription management server: 0.9.51.15-1
subscription management rules: 5.15.1
subscription-manager: 1.17.11-1.el7
python-rhsm: 1.17.7-1.el7


[root@dhcp35-208 ~]# subscription-manager config --rhsm.productcertdir=/tmp/product-default/

[root@dhcp35-208 ~]#  ps -aux | grep rhsmd
root     22916  0.0  0.0 112648   960 pts/1    R+   16:21   0:00 grep --color=auto rhsmd

[root@dhcp35-208 ~]# subscription-manager clean
All local data removed

 the /usr/libexec/rhsmd process does not stay running but OSErrors are still logged into rhsm.log

[root@dhcp35-208 ~]#  ps -aux | grep rhsmd
root     22923  0.0  0.0 112648   960 pts/1    R+   16:22   0:00 grep --color=auto rhsmd

2016-08-31 16:20:59,639 [INFO] subscription-manager:22902:MainThread @managercli.py:384 - Client Versions: {'python-rhsm': '1.17.7-1.el7', 'subscription-manager': '1.17.11-1.el7'}
2016-08-31 16:22:14,216 [INFO] subscription-manager:22918:MainThread @managercli.py:384 - Client Versions: {'python-rhsm': '1.17.7-1.el7', 'subscription-manager': '1.17.11-1.el7'}
2016-08-31 16:22:14,218 [INFO] subscription-manager:22918:MainThread @managerlib.py:879 - Cleaned local data
2016-08-31 16:22:14,363 [INFO] rhsmd:22920:MainThread @rhsmd:261 - rhsmd started
2016-08-31 16:22:14,417 [ERROR] subscription-manager:22918:MainThread @dbus_interface.py:60 - org.freedesktop.DBus.Python.OSError: Traceback (most recent call last):
  File "/usr/lib64/python2.7/site-packages/dbus/service.py", line 707, in _message_cb
    retval = candidate_method(self, *args, **keywords)
  File "<string>", line 2, in update_status
  File "/usr/libexec/rhsmd", line 147, in ensure_exit
    return func(*args, **kwargs)
  File "/usr/libexec/rhsmd", line 216, in update_status
    pre_result = pre_check_status(self.force_signal)
  File "/usr/libexec/rhsmd", line 111, in pre_check_status
    sorter = require(CERT_SORTER)
  File "/usr/lib/python2.7/site-packages/subscription_manager/injection.py", line 103, in require
    return FEATURES.require(feature, *args, **kwargs)
  File "/usr/lib/python2.7/site-packages/subscription_manager/injection.py", line 77, in require
    self.providers[feature] = provider()
  File "/usr/lib/python2.7/site-packages/subscription_manager/cert_sorter.py", line 322, in __init__
    self.installed_mgr = inj.require(inj.INSTALLED_PRODUCTS_MANAGER)
  File "/usr/lib/python2.7/site-packages/subscription_manager/injection.py", line 103, in require
    return FEATURES.require(feature, *args, **kwargs)
  File "/usr/lib/python2.7/site-packages/subscription_manager/injection.py", line 77, in require
    self.providers[feature] = provider()
  File "/usr/lib/python2.7/site-packages/subscription_manager/cache.py", line 431, in __init__
    self.product_dir = inj.require(inj.PROD_DIR)
  File "/usr/lib/python2.7/site-packages/subscription_manager/injection.py", line 103, in require
    return FEATURES.require(feature, *args, **kwargs)
  File "/usr/lib/python2.7/site-packages/subscription_manager/injection.py", line 77, in require
    self.providers[feature] = provider()
  File "/usr/lib/python2.7/site-packages/subscription_manager/certdirectory.py", line 224, in __init__
    self.installed_prod_dir = ProductCertificateDirectory(path=installed_prod_path)
  File "/usr/lib/python2.7/site-packages/subscription_manager/certdirectory.py", line 106, in __init__
    self.create()
  File "/usr/lib/python2.7/site-packages/subscription_manager/certdirectory.py", line 70, in create
    os.makedirs(self.path)
  File "/usr/lib64/python2.7/os.py", line 157, in makedirs
    mkdir(name, mode)
OSError: [Errno 17] File exists: '/tmp/product-default/'
Traceback (most recent call last):
  File "/usr/lib/python2.7/site-packages/subscription_manager/dbus_interface.py", line 56, in _update
    ignore_reply=self.has_main_loop)
  File "/usr/lib64/python2.7/site-packages/dbus/proxies.py", line 70, in __call__
    return self._proxy_method(*args, **keywords)
  File "/usr/lib64/python2.7/site-packages/dbus/proxies.py", line 145, in __call__
    **keywords)
  File "/usr/lib64/python2.7/site-packages/dbus/connection.py", line 651, in call_blocking
    message, timeout)
DBusException: org.freedesktop.DBus.Python.OSError: Traceback (most recent call last):
  File "/usr/lib64/python2.7/site-packages/dbus/service.py", line 707, in _message_cb
    retval = candidate_method(self, *args, **keywords)
  File "<string>", line 2, in update_status
  File "/usr/libexec/rhsmd", line 147, in ensure_exit
    return func(*args, **kwargs)
  File "/usr/libexec/rhsmd", line 216, in update_status
    pre_result = pre_check_status(self.force_signal)
  File "/usr/libexec/rhsmd", line 111, in pre_check_status
    sorter = require(CERT_SORTER)
  File "/usr/lib/python2.7/site-packages/subscription_manager/injection.py", line 103, in require
    return FEATURES.require(feature, *args, **kwargs)
  File "/usr/lib/python2.7/site-packages/subscription_manager/injection.py", line 77, in require
    self.providers[feature] = provider()
  File "/usr/lib/python2.7/site-packages/subscription_manager/cert_sorter.py", line 322, in __init__
    self.installed_mgr = inj.require(inj.INSTALLED_PRODUCTS_MANAGER)
  File "/usr/lib/python2.7/site-packages/subscription_manager/injection.py", line 103, in require
    return FEATURES.require(feature, *args, **kwargs)
  File "/usr/lib/python2.7/site-packages/subscription_manager/injection.py", line 77, in require
    self.providers[feature] = provider()
  File "/usr/lib/python2.7/site-packages/subscription_manager/cache.py", line 431, in __init__
    self.product_dir = inj.require(inj.PROD_DIR)
  File "/usr/lib/python2.7/site-packages/subscription_manager/injection.py", line 103, in require
    return FEATURES.require(feature, *args, **kwargs)
  File "/usr/lib/python2.7/site-packages/subscription_manager/injection.py", line 77, in require
    self.providers[feature] = provider()
  File "/usr/lib/python2.7/site-packages/subscription_manager/certdirectory.py", line 224, in __init__
    self.installed_prod_dir = ProductCertificateDirectory(path=installed_prod_path)
  File "/usr/lib/python2.7/site-packages/subscription_manager/certdirectory.py", line 106, in __init__
    self.create()
  File "/usr/lib/python2.7/site-packages/subscription_manager/certdirectory.py", line 70, in create
    os.makedirs(self.path)
  File "/usr/lib64/python2.7/os.py", line 157, in makedirs
    mkdir(name, mode)
OSError: [Errno 17] File exists: '/tmp/product-default/'


But do not see any oserror being logged into rhsm.log after changing the product certdir to default one


[root@dhcp35-208 ~]#  subscription-manager config --rhsm.productcertdir=/etc/pki/product/
[root@dhcp35-208 ~]# subscription-manager clean
All local data removed
[root@dhcp35-208 ~]#  ps -aux | grep rhsmd
root     22948  0.0  0.0 112648   960 pts/1    R+   16:22   0:00 grep --color=auto rhsmd

2016-08-31 16:22:47,562 [INFO] subscription-manager:22932:MainThread @managercli.py:384 - Client Versions: {'python-rhsm': '1.17.7-1.el7', 'subscription-manager': '1.17.11-1.el7'}
2016-08-31 16:22:55,262 [INFO] subscription-manager:22933:MainThread @managercli.py:384 - Client Versions: {'python-rhsm': '1.17.7-1.el7', 'subscription-manager': '1.17.11-1.el7'}
2016-08-31 16:22:55,263 [INFO] subscription-manager:22933:MainThread @managerlib.py:879 - Cleaned local data
2016-08-31 16:22:55,426 [INFO] rhsmd:22935:MainThread @rhsmd:261 - rhsmd started
Comment 7 John Sefler 2016-08-31 16:41:06 UTC 
As verified in comment 6 and explained in comment 5, the patch from comment 2 fixes the WORSE problem from comment 0 that /usr/libexec/rhsmd stays running.

Regarding the OSError, we will have to apply a temporary SELinux policy since we have strayed from the standard RHEL configuration to use a /tmp location for --rhsm.productcertdir.   This is not a bug against subscription-manager, it is the consequence of making a non-default configuration change by the system administrator that she must handle.

Putting this all together, let's re-test the original scenario with a fixed build of subscription-manager and a temporary SELinux policy modification...

Verifying Version...
[root@jsefler-rhel7 ~]# rpm -q subscription-manager --changelog | grep 1351370
- 1351370: Ensure rhsmd exits on exceptions (csnyder)
[root@jsefler-rhel7 ~]# rpm -q subscription-manager selinux-policy
subscription-manager-1.17.11-1.el7.x86_64
selinux-policy-3.13.1-95.el7.noarch


[root@jsefler-rhel7 ~]# cp -R /etc/pki/product-default/ /tmp/
[root@jsefler-rhel7 ~]# ls -R /tmp/product-default/
/tmp/product-default/:
69.pem
[root@jsefler-rhel7 ~]# subscription-manager config --rhsm.productcertdir=/tmp/product-default/

FIRST, we'll verify that the rhsmd process no longer hangs despite an OSError 

[root@jsefler-rhel7 ~]# subscription-manager clean 
All local data removed

[root@jsefler-rhel7 ~]# tail -f /var/log/rhsm/rhsm.log | grep OSError
2016-08-31 12:32:37,646 [ERROR] subscription-manager:30754:MainThread @dbus_interface.py:60 - org.freedesktop.DBus.Python.OSError: Traceback (most recent call last):
OSError: [Errno 17] File exists: '/tmp/product-default/'
DBusException: org.freedesktop.DBus.Python.OSError: Traceback (most recent call last):
OSError: [Errno 17] File exists: '/tmp/product-default/'

[root@jsefler-rhel7 ~]# ps -aux | grep rhsmd
root     30768  0.0  0.0 112648   960 pts/1    S+   12:33   0:00 grep --color=auto rhsmd

VERIFIED: despite the OSError, the rhsmd process no longer hangs.

NOW, let's apply a temporary selinux modification to /tmp/product-default/ and get rid of the OSError

[root@jsefler-rhel7 ~]# semanage fcontext -a -t cert_t -s system_u "/tmp/product-default(/.*)?"
[root@jsefler-rhel7 ~]# restorecon -R -v /tmp/product-default
restorecon reset /tmp/product-default context unconfined_u:object_r:user_tmp_t:s0->unconfined_u:object_r:cert_t:s0
restorecon reset /tmp/product-default/69.pem context unconfined_u:object_r:user_tmp_t:s0->unconfined_u:object_r:cert_t:s0
[root@jsefler-rhel7 ~]# getenforce
Enforcing


NOW, let's run the clean command while tailing the rhsm.log for Tracebacks

[root@jsefler-rhel7 ~]# subscription-manager clean
All local data removed

[root@jsefler-rhel7 ~]# tail -f /var/log/rhsm/rhsm.log
2016-08-31 12:19:45,862 [DEBUG] subscription-manager:30428:MainThread @ga_loader.py:89 - ga_loader GaImporterGtk3
2016-08-31 12:19:45,870 [DEBUG] subscription-manager:30428: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'>]
2016-08-31 12:19:45,870 [DEBUG] subscription-manager:30428:MainThread @plugins.py:570 - loaded plugins: {'container_content.ContainerContentPlugin': <container_content.ContainerContentPlugin object at 0x2a4e3d0>, 'ostree_content.OstreeContentPlugin': <ostree_content.OstreeContentPlugin object at 0x2a4e690>}
2016-08-31 12:19:45,870 [DEBUG] subscription-manager:30428:MainThread @identity.py:131 - Loading consumer info from identity certificates.
2016-08-31 12:19:45,871 [DEBUG] subscription-manager:30428:MainThread @identity.py:146 - 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'
2016-08-31 12:19:45,917 [INFO] subscription-manager:30428:MainThread @managercli.py:384 - Client Versions: {'python-rhsm': '1.17.7-1.el7', 'subscription-manager': '1.17.11-1.el7'}
2016-08-31 12:19:45,918 [DEBUG] subscription-manager:30428:MainThread @identity.py:131 - Loading consumer info from identity certificates.
2016-08-31 12:19:45,918 [DEBUG] subscription-manager:30428:MainThread @identity.py:146 - 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'
2016-08-31 12:19:45,919 [INFO] subscription-manager:30428:MainThread @managerlib.py:879 - Cleaned local data
2016-08-31 12:19:45,926 [DEBUG] subscription-manager:30428:MainThread @certdirectory.py:216 - Installed product IDs: ['69']
2016-08-31 12:19:45,926 [DEBUG] subscription-manager:30428:MainThread @cert_sorter.py:126 - Unregistered, skipping server compliance check.
2016-08-31 12:19:45,926 [DEBUG] subscription-manager:30428:MainThread @identity.py:131 - Loading consumer info from identity certificates.
2016-08-31 12:19:45,926 [DEBUG] subscription-manager:30428:MainThread @identity.py:146 - 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'
2016-08-31 12:19:46,107 [INFO] rhsmd:30430:MainThread @rhsmd:261 - rhsmd started
2016-08-31 12:19:46,114 [DEBUG] rhsmd:30430:MainThread @rhsmd:215 - D-Bus interface com.redhat.SubscriptionManager.EntitlementStatus.update_status called with status = 0
2016-08-31 12:19:46,167 [DEBUG] rhsmd:30430:MainThread @identity.py:131 - Loading consumer info from identity certificates.
2016-08-31 12:19:46,167 [DEBUG] rhsmd:30430:MainThread @identity.py:146 - 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'
2016-08-31 12:19:46,173 [DEBUG] rhsmd:30430:MainThread @certdirectory.py:216 - Installed product IDs: ['69']
2016-08-31 12:19:46,173 [DEBUG] rhsmd:30430:MainThread @cert_sorter.py:126 - Unregistered, skipping server compliance check.
2016-08-31 12:19:46,173 [DEBUG] rhsmd:30430:MainThread @identity.py:131 - Loading consumer info from identity certificates.
2016-08-31 12:19:46,174 [DEBUG] rhsmd:30430:MainThread @identity.py:146 - 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'
2016-08-31 12:19:46,174 [DEBUG] rhsmd:30430:MainThread @cache.py:110 - Wrote cache: /var/lib/rhsm/cache/rhsm_icon.json
2016-08-31 12:19:46,176 [DEBUG] subscription-manager:30428:MainThread @utils.py:294 - No virt-who pid file, not attempting to restart


VERIFIED: No more OSError traceback in the log, and...

[root@jsefler-rhel7 ~]# ps -aux | grep rhsmd
root     30846  0.0  0.0 112648   960 pts/1    S+   12:36   0:00 grep --color=auto rhsmd

VERIFIED: still no more runaway rhsmd process. 


Finally, let's delete the temporary policy and files
[root@jsefler-rhel7 ~]# semanage fcontext -d "/tmp/product-default(/.*)?"
[root@jsefler-rhel7 ~]# restorecon -R -v /tmp/product-default
restorecon:  Warning no default label for /tmp/product-default
restorecon:  Warning no default label for /tmp/product-default/69.pem
[root@jsefler-rhel7 ~]# rm -rf /tmp/product-default
Comment 9 errata-xmlrpc 2016-11-03 20:29:52 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://rhn.redhat.com/errata/RHSA-2016-2592.html
Note You need to log in before you can comment on or make changes to this bug.