Bug 1351370
| Summary: | [ERROR] subscription-manager:31276 @dbus_interface.py:60 - org.freedesktop.DBus.Python.OSError: Traceback | ||
|---|---|---|---|
| Product: | Red Hat Enterprise Linux 7 | Reporter: | John Sefler <jsefler> |
| Component: | subscription-manager | Assignee: | Chris Snyder <csnyder> |
| Status: | CLOSED ERRATA | QA Contact: | John Sefler <jsefler> |
| Severity: | high | Docs Contact: | |
| Priority: | high | ||
| Version: | 7.3 | CC: | redakkan, skallesh, vrjain |
| Target Milestone: | rc | Keywords: | Triaged |
| Target Release: | --- | ||
| Hardware: | Unspecified | ||
| OS: | Unspecified | ||
| Whiteboard: | |||
| Fixed In Version: | Doc Type: | If docs needed, set a value | |
| Doc Text: | Story Points: | --- | |
| Clone Of: | Environment: | ||
| Last Closed: | 2016-11-03 20:29:52 UTC | Type: | Bug |
| Regression: | --- | Mount Type: | --- |
| Documentation: | --- | CRM: | |
| Verified Versions: | Category: | --- | |
| oVirt Team: | --- | RHEL 7.3 requirements from Atomic Host: | |
| Cloudforms Team: | --- | Target Upstream Version: | |
| Embargoed: | |||
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
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 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
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) [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
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 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 |
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).