Description of problem: error in /var/log/rhsm/rhsm.log when rhsmcertd service is restarted on client with no installed products Version-Release number of selected component (if applicable): [root@localhost ~]# subscription-manager version server type: Red Hat Subscription Management subscription management server: 0.8.0-1 subscription-manager: 1.8.5-1.git.4.82e4aee.el7 python-rhsm: 1.8.8-1.git.0.c7ea5c0.el7 How reproducible: Steps to Reproduce: [root@localhost ~]# subscription-manager register --org=admin --force The system with UUID 04f17d9c-534a-47a1-826a-0324e0971b68 has been unregistered Username: admin Password: The system has been registered with id: 6eaa916a-1439-4d19-a364-a9f05455b0da [root@localhost ~]# subscription-manager list --installed No installed products to list [root@localhost ~]# service rhsmcertd restart Redirecting to /bin/systemctl restart rhsmcertd.service [root@localhost ~]# tail -f /var/log/rhsm/rhsm.log 2013-04-01 02:44:53,185 [DEBUG] @connection.py:376 - Loading CA certificate: '/etc/rhsm/ca/redhat-uep.pem' 2013-04-01 02:44:53,185 [DEBUG] @connection.py:376 - Loading CA certificate: '/etc/rhsm/ca/candlepin-ca.pem' 2013-04-01 02:44:53,186 [DEBUG] @connection.py:415 - Making request: GET /candlepin/ 2013-04-01 02:44:53,197 [DEBUG] @connection.py:434 - Response status: 200 2013-04-01 02:44:53,197 [WARNING] @connection.py:438 - Clock skew detected, please check your system time 2013-04-01 02:44:53,197 [DEBUG] @connection.py:613 - Server supports the following resources: 2013-04-01 02:44:53,198 [DEBUG] @connection.py:614 - {'': '/', 'hypervisors': '/hypervisors', 'serials': '/serials', 'consumers': '/consumers', 'migrations': '/migrations', 'content': '/content', 'entitlements': '/entitlements', 'statistics/generate': '/statistics/generate', 'status': '/status', 'jobs': '/jobs', 'users': '/users', 'subscriptions': '/subscriptions', 'rules': '/rules', 'consumertypes': '/consumertypes', 'activation_keys': '/activation_keys', 'atom': '/atom', 'owners': '/owners', 'roles': '/roles', 'admin': '/admin', 'events': '/events', 'products': '/products', 'pools': '/pools', 'crl': '/crl'} 2013-04-01 02:44:53,198 [INFO] @cache.py:304 - Server does not support packages, skipping profile upload. 2013-04-01 02:44:53,199 [DEBUG] @cache.py:137 - Wrote cache: /var/lib/rhsm/facts/facts.json 2013-04-01 02:44:53,199 [DEBUG] @cache.py:137 - Wrote cache: /var/lib/rhsm/cache/installed_products.json 2013-04-01 02:47:11,165 [DEBUG] @profile.py:95 - Loading current RPM profile. 2013-04-01 02:47:11,166 [ERROR] @rhsmcertd-worker:87 - Error while updating certificates using daemon 2013-04-01 02:47:11,166 [ERROR] @rhsmcertd-worker:89 - rpmdb open failed Traceback (most recent call last): File "/usr/libexec/rhsmcertd-worker", line 77, in <module> main(options, log) File "/usr/libexec/rhsmcertd-worker", line 47, in main key_file=ConsumerIdentity.keypath()) File "/usr/lib64/python2.7/site-packages/rhsm/connection.py", line 582, in __init__ ssl_verify_depth=self.ssl_verify_depth) File "/usr/lib64/python2.7/site-packages/rhsm/connection.py", line 313, in __init__ v = Versions() File "/usr/lib64/python2.7/site-packages/rhsm/version.py", line 42, in __init__ self._collect_data() File "/usr/lib64/python2.7/site-packages/rhsm/version.py", line 47, in _collect_data for package_def in self._get_packages(): File "/usr/lib64/python2.7/site-packages/rhsm/version.py", line 53, in _get_packages profile = RPMProfile() File "/usr/lib64/python2.7/site-packages/rhsm/profile.py", line 98, in __init__ installed = ts.dbMatch() error: rpmdb open failed 2013-04-01 02:47:11,287 [DEBUG] @profile.py:95 - Loading current RPM profile. 2013-04-01 02:47:11,288 [ERROR] @rhsmcertd-worker:87 - Error while updating certificates using daemon 2013-04-01 02:47:11,288 [ERROR] @rhsmcertd-worker:89 - rpmdb open failed Traceback (most recent call last): File "/usr/libexec/rhsmcertd-worker", line 77, in <module> main(options, log) File "/usr/libexec/rhsmcertd-worker", line 47, in main key_file=ConsumerIdentity.keypath()) File "/usr/lib64/python2.7/site-packages/rhsm/connection.py", line 582, in __init__ ssl_verify_depth=self.ssl_verify_depth) File "/usr/lib64/python2.7/site-packages/rhsm/connection.py", line 313, in __init__ v = Versions() File "/usr/lib64/python2.7/site-packages/rhsm/version.py", line 42, in __init__ self._collect_data() File "/usr/lib64/python2.7/site-packages/rhsm/version.py", line 47, in _collect_data for package_def in self._get_packages(): File "/usr/lib64/python2.7/site-packages/rhsm/version.py", line 53, in _get_packages profile = RPMProfile() File "/usr/lib64/python2.7/site-packages/rhsm/profile.py", line 98, in __init__ installed = ts.dbMatch() error: rpmdb open failed Actual results: Expected results: Additional info:
This request was evaluated by Red Hat Product Management for inclusion in a Red Hat Enterprise Linux release. Product Management has requested further review of this request by Red Hat Engineering, for potential inclusion in a Red Hat Enterprise Linux release for currently deployed products. This request is not yet committed for inclusion in a release.
I can not recreate. Can you please retest? Were you registering against a local candlepin?
Its working fine [root@localhost ~]# subscription-manager version server type: Red Hat Subscription Management subscription management server: 0.8.5-1 subscription-manager: 1.8.6-1.git.4.b3f4bbf.el7 python-rhsm: 1.8.9-1.git.1.bbbb773.el7 Steps: [root@localhost ~]# subscription-manager register --org=admin --force The system with UUID 1b49e891-01d3-4430-8771-e2d4b3a56157 has been unregistered Username: admin Password: The system has been registered with ID: 1f759953-dd5e-4f8d-9fc7-9edefab10a4f [root@localhost ~]# subscription-manager list --installed No installed products to list [root@localhost ~]# service rhsmcertd restart Redirecting to /bin/systemctl restart rhsmcertd.service [root@localhost ~]# [root@localhost ~]# tail -f /var/log/rhsm/rhsm.log 2013-05-02 19:25:02,345 [DEBUG] @profile.py:95 - Loading current RPM profile. 2013-05-02 19:25:07,938 [INFO] @connection.py:586 - Using certificate authentication: key = /etc/pki/consumer/key.pem, cert = /etc/pki/consumer/cert.pem, ca = /etc/rhsm/ca/, insecure = False 2013-05-02 19:25:07,938 [INFO] @connection.py:597 - Connection Built: host: 10.70.35.193, port: 8443, handler: /candlepin 2013-05-02 19:25:07,939 [DEBUG] @plugins.py:508 - loaded plugin modules: [] 2013-05-02 19:25:07,939 [DEBUG] @plugins.py:509 - loaded plugins: {} 2013-05-02 19:25:07,939 [DEBUG] @plugins.py:481 - Calling PluginManager init 2013-05-02 19:25:07,951 [DEBUG] @connection.py:394 - Loading CA PEM certificates from: /etc/rhsm/ca/ 2013-05-02 19:25:07,951 [DEBUG] @connection.py:376 - Loading CA certificate: '/etc/rhsm/ca/candlepin-ca.pem' 2013-05-02 19:25:07,952 [DEBUG] @connection.py:376 - Loading CA certificate: '/etc/rhsm/ca/10.pem' 2013-05-02 19:25:07,952 [DEBUG] @connection.py:376 - Loading CA certificate: '/etc/rhsm/ca/candlepin-stage.pem' 2013-05-02 19:25:07,952 [DEBUG] @connection.py:376 - Loading CA certificate: '/etc/rhsm/ca/redhat-uep.pem' 2013-05-02 19:25:07,953 [DEBUG] @connection.py:415 - Making request: GET /candlepin/consumers/1f759953-dd5e-4f8d-9fc7-9edefab10a4f/certificates/serials 2013-05-02 19:25:08,034 [DEBUG] @connection.py:434 - Response status: 200 2013-05-02 19:25:08,035 [WARNING] @connection.py:438 - Clock skew detected, please check your system time 2013-05-02 19:25:08,036 [DEBUG] @injection.py:65 - Returning callable provider for feature ENT_DIR: <class 'subscription_manager.certdirectory.EntitlementDirectory'> 2013-05-02 19:25:08,036 [INFO] @certlib.py:236 - certs updated: Total updates: 0 Found (local) serial# [] Expected (UEP) serial# [] Added (new) <NONE> Deleted (rogue): <NONE> Expired (deleted): <NONE> 2013-05-02 19:25:08,038 [INFO] @cache.py:163 - Checking current system info against cache: /var/lib/rhsm/cache/installed_products.json 2013-05-02 19:25:08,048 [INFO] @cache.py:180 - No changes. 2013-05-02 19:25:08,050 [DEBUG] @connection.py:394 - Loading CA PEM certificates from: /etc/rhsm/ca/ 2013-05-02 19:25:08,050 [DEBUG] @connection.py:376 - Loading CA certificate: '/etc/rhsm/ca/candlepin-ca.pem' 2013-05-02 19:25:08,050 [DEBUG] @connection.py:376 - Loading CA certificate: '/etc/rhsm/ca/10.pem' 2013-05-02 19:25:08,050 [DEBUG] @connection.py:376 - Loading CA certificate: '/etc/rhsm/ca/candlepin-stage.pem' 2013-05-02 19:25:08,051 [DEBUG] @connection.py:376 - Loading CA certificate: '/etc/rhsm/ca/redhat-uep.pem' 2013-05-02 19:25:08,051 [DEBUG] @connection.py:415 - Making request: GET /candlepin/consumers/1f759953-dd5e-4f8d-9fc7-9edefab10a4f 2013-05-02 19:25:08,118 [DEBUG] @connection.py:434 - Response status: 200 2013-05-02 19:25:08,118 [WARNING] @connection.py:438 - Clock skew detected, please check your system time 2013-05-02 19:25:08,119 [INFO] @certlib.py:112 - Checking if system requires healing. 2013-05-02 19:25:08,119 [DEBUG] @injection.py:65 - Returning callable provider for feature CERT_SORTER: <class 'subscription_manager.cert_sorter.CertSorter'> 2013-05-02 19:25:08,120 [DEBUG] @injection.py:68 - Returning instance for feature IDENTITY 2013-05-02 19:25:08,120 [DEBUG] @certdirectory.py:188 - Installed product IDs: [] 2013-05-02 19:25:08,120 [DEBUG] @injection.py:65 - Returning callable provider for feature STATUS_CACHE: <class 'subscription_manager.cache.StatusCache'> 2013-05-02 19:25:08,120 [DEBUG] @connection.py:394 - Loading CA PEM certificates from: /etc/rhsm/ca/ 2013-05-02 19:25:08,121 [DEBUG] @connection.py:376 - Loading CA certificate: '/etc/rhsm/ca/candlepin-ca.pem' 2013-05-02 19:25:08,121 [DEBUG] @connection.py:376 - Loading CA certificate: '/etc/rhsm/ca/10.pem' 2013-05-02 19:25:08,121 [DEBUG] @connection.py:376 - Loading CA certificate: '/etc/rhsm/ca/candlepin-stage.pem' 2013-05-02 19:25:08,122 [DEBUG] @connection.py:376 - Loading CA certificate: '/etc/rhsm/ca/redhat-uep.pem' 2013-05-02 19:25:08,122 [DEBUG] @connection.py:415 - Making request: GET /candlepin/consumers/1f759953-dd5e-4f8d-9fc7-9edefab10a4f/compliance 2013-05-02 19:25:08,179 [DEBUG] @connection.py:434 - Response status: 200 2013-05-02 19:25:08,179 [WARNING] @connection.py:438 - Clock skew detected, please check your system time 2013-05-02 19:25:08,180 [DEBUG] @cache.py:136 - Wrote cache: /var/lib/rhsm/cache/entitlement_status.json 2013-05-02 19:25:08,180 [DEBUG] @cert_sorter.py:168 - valid entitled products: [] 2013-05-02 19:25:08,181 [DEBUG] @cert_sorter.py:169 - expired entitled products: [] 2013-05-02 19:25:08,181 [DEBUG] @cert_sorter.py:170 - partially entitled products: [] 2013-05-02 19:25:08,181 [DEBUG] @cert_sorter.py:171 - unentitled products: [] 2013-05-02 19:25:08,181 [DEBUG] @cert_sorter.py:172 - future products: [] 2013-05-02 19:25:08,181 [DEBUG] @cert_sorter.py:173 - partial stacks: [] 2013-05-02 19:25:08,182 [DEBUG] @cert_sorter.py:174 - entitlements valid until: None 2013-05-02 19:25:08,182 [INFO] @certlib.py:136 - Entitlements are valid for today: 2013-05-02 13:55:08.119859+00:00 2013-05-02 19:25:08,182 [WARNING] @certlib.py:142 - Got valid status from server but no valid until date. 2013-05-02 19:25:08,182 [INFO] @certlib.py:159 - Auto-heal check complete. 2013-05-02 19:25:09,637 [DEBUG] @profile.py:95 - Loading current RPM profile
Closing: appears to be working as demonstrated in comment 3
The log message indicates this failed because it couldn't open the rpmdb, and nothing handles that exception except the top level handler that logs it and exits. So rhsmcertd-worker will continue to fail if it can't read the rpm db. I suspect this may be more of an issue on rhel5 than 6 (6 seems happy to lazy load the db, and do it read only). So I think the bug summary is wrong, it's not related to no installed certs, but to something else having the rpmdb open (or otherwise causing rpmdb open failures) Should I reopen this guy, or spin it into a new bug?