Bug 995292
| Summary: | Error to unregister rhel 5.10 from SAM server | ||||||
|---|---|---|---|---|---|---|---|
| Product: | [Retired] Subscription Asset Manager | Reporter: | gaoshang <sgao> | ||||
| Component: | katello | Assignee: | Katello Bug Bin <katello-bugs> | ||||
| Status: | CLOSED WONTFIX | QA Contact: | SAM QE List <sam-qe-list> | ||||
| Severity: | high | Docs Contact: | |||||
| Priority: | unspecified | ||||||
| Version: | 1.3 | CC: | alikins, awood, bkearney, liliu, pjanda, qianzhan, shihliu, sthirugn, tomckay | ||||
| Target Milestone: | rc | ||||||
| Target Release: | --- | ||||||
| Hardware: | Unspecified | ||||||
| OS: | Unspecified | ||||||
| Whiteboard: | |||||||
| Fixed In Version: | Doc Type: | Bug Fix | |||||
| Doc Text: | Story Points: | --- | |||||
| Clone Of: | Environment: | ||||||
| Last Closed: | 2017-06-26 20:31:59 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: | |||||||
| Bug Depends On: | |||||||
| Bug Blocks: | 971511 | ||||||
| Attachments: |
|
||||||
Created attachment 784709 [details]
katello-debug log info attached
katello-debug log info
@gaoshang - Please always include output of katello-devel as an attachment. This script creates a .tar.gz file with all relevant logs and config files. Please mark this attachment private. Thank you! (In reply to Tom McKay from comment #2) > @gaoshang - Please always include output of katello-devel as an attachment. > This script creates a .tar.gz file with all relevant logs and config files. > Please mark this attachment private. Thank you! Hi Tom, thanks for your infomation, but I still have a little problem on how to run "katello-devel", pls see following command, seems like katello-devel is not installed at all, so what can we do to get required info? [root@samserv katello]# katello- katello-configure katello-debug-certificates katello-selinux-enable katello-ssl-tool katello-configure-answer katello-generate-passphrase katello-selinux-relabel katello-sudo-ssl-tool katello-debug katello-passwd katello-service katello-upgrade [root@samserv katello]# rpm -qa | grep katello katello-common-1.4.3-6.el6sam_splice.noarch katello-selinux-1.4.4-2.el6sat.noarch katello-glue-candlepin-1.4.3-6.el6sam_splice.noarch katello-configure-1.4.4-2.el6sat.noarch katello-cli-1.4.3-5.el6sat.noarch signo-katello-0.0.10-2.el6sat.noarch katello-headpin-all-1.4.3-6.el6sam_splice.noarch katello-cli-common-1.4.3-5.el6sat.noarch katello-candlepin-cert-key-pair-1.0-1.noarch katello-certs-tools-1.4.2-2.el6sat.noarch katello-glue-elasticsearch-1.4.3-6.el6sam_splice.noarch katello-headpin-1.4.3-6.el6sam_splice.noarch SAM installed by command: yum install -y katello-headpin-all Running latest RHEL510 canidate subman against a standalone cp, this seems to work ok. However.. 1) client ends up making requests for that consumer after the consumer has been deleted (it try's the clients entitlement status to reflect unregistration, but that process now involves making a request to the server using consumer auth, which will now cause a 401. 5.10subman and latest candlepin seem okay with this and return a 401 and handle it. 2) client's handling of 401 errors will be different depending on the body of the 401 response. Basically, if the body is valid JSON with the error info, this ends up raising a RestlibException If the body is empty or otherwise fails to parse as json, this is going to raise a NetworkException. And for that code path, NetworkException ends up showing the error message referencing the log. Based on the logs, I'd guess that sam/katello is not returning a JSON error blob in the body for the 401, but just the string "No Credentials provided" So, katello should return that 401 as a JSON blob. subscription-manager shouldn't make those requests in the first place. subscription-manager should not depend on the body of the 401 in it's exception handling. Based on comment #4, the most expedient fix would be for Katello to return a 401 with a response body of { "displayMessage" : "Invalid credentials." } I have filed bug #997935 to address this issue in subscription-manager. 401s in katello return this value No Credentials provided[root@bkearney ~]# curl -k -u "bkearney:bkearney" https://sam13/sam/api/consumers {"displayMessage":"Invalid credentials","errors":["Invalid credentials"]}[root@bkearney ~]# I have verified against SAM-1.3-snapshot4, and the bug still exists. We will verify it again when SAM-1.3-snapshot5 comes out. According to my tests bug exists still in SAM-1.3-snapshot5 When I test RHEL5.11 against SAM, the bug still exists, and the error message also prompts when execute "subscription-manager clean": [root@localhost ~]# subscription-manager register Username: admin Password: The system has been registered with ID: ce84d9d5-8c75-462a-b25c-35f8c534e6ea [root@localhost ~]# subscription-manager clean All local data removed Error updating system data on the server, see /var/log/rhsm/rhsm.log for more details. The release of Satellite 5.8 we are deprecating the support of Subscription Asset Manager. The release notes for 5.8 can be found at https://access.redhat.com/documentation/en-us/red_hat_satellite/5.8/pdf/release_notes/Red_Hat_Satellite-5.8-Release_Notes-en-US.pdf. I am therefore closing out this bug as WONTFIX. If you believe this to be an error, please feel free tor each out to either Rich Jerrido or Bryan Kearney. Thank you! |
Description of problem: Register rhel 5.10 system to SAM server and then unregister it, an error occurs: "Error updating system data on the server, see /var/log/rhsm/rhsm.log for more details." Version-Release number of selected component (if applicable): # cat /etc/redhat-release Red Hat Enterprise Linux Client release 5.10 Beta (Tikanga) # rpm -qa | grep subscription subscription-manager-firstboot-1.8.19-1.el5 subscription-manager-gui-1.8.19-1.el5 subscription-manager-1.8.19-1.el5 katello-candlepin-cert-key-pair-1.0-1.noarch katello-certs-tools-1.4.2-2.el6sat.noarch katello-cli-1.4.3-5.el6sat.noarch katello-cli-common-1.4.3-5.el6sat.noarch katello-common-1.4.3-6.el6sam_splice.noarch katello-configure-1.4.4-2.el6sat.noarch katello-glue-candlepin-1.4.3-6.el6sam_splice.noarch katello-glue-elasticsearch-1.4.3-6.el6sam_splice.noarch katello-headpin-1.4.3-6.el6sam_splice.noarch katello-headpin-all-1.4.3-6.el6sam_splice.noarch katello-selinux-1.4.4-2.el6sat.noarch signo-katello-0.0.10-2.el6sat.noarch candlepin-0.8.19-1.el6sam.noarch candlepin-scl-1-5.el6_4.noarch candlepin-scl-quartz-2.1.5-5.el6_4.noarch candlepin-scl-rhino-1.7R3-1.el6_4.noarch candlepin-scl-runtime-1-5.el6_4.noarch candlepin-selinux-0.8.19-1.el6sam.noarch candlepin-tomcat6-0.8.19-1.el6sam.noarch thumbslug-0.0.32-1.el6sam.noarch thumbslug-selinux-0.0.32-1.el6sam.noarch How reproducible: always Steps to Reproduce: 1. Register rhel 5.10 system to SAM server # subscription-manager register --user admin --password admin The system has been registered with ID: c84e976b-546c-47c7-a845-ebfc965c5f37 2. Unregister it # subscription-manager unregister Error updating system data on the server, see /var/log/rhsm/rhsm.log for more details. Actual results: Unregister failed Expected results: Unregister should succeed and no error should appear. Additional info: rhsm log file: [root@dhcp-13-25 pki]# cat /var/log/rhsm/rhsm.log 2013-08-08 21:18:59,033 [DEBUG] @injection.py:54 - Registering provider for feature IDENTITY: <class 'subscription_manager.identity.Identity'> 2013-08-08 21:18:59,033 [DEBUG] @injection.py:54 - Registering provider for feature PRODUCT_DATE_RANGE_CALCULATOR: <function factory at 0x8c601b4> 2013-08-08 21:18:59,033 [DEBUG] @injection.py:54 - Registering provider for feature ENT_DIR: <class 'subscription_manager.certdirectory.EntitlementDirectory'> 2013-08-08 21:18:59,033 [DEBUG] @injection.py:54 - Registering provider for feature PROD_DIR: <class 'subscription_manager.certdirectory.ProductDirectory'> 2013-08-08 21:18:59,033 [DEBUG] @injection.py:54 - Registering provider for feature STATUS_CACHE: <class 'subscription_manager.cache.StatusCache'> 2013-08-08 21:18:59,034 [DEBUG] @injection.py:54 - Registering provider for feature PROD_STATUS_CACHE: <class 'subscription_manager.cache.ProductStatusCache'> 2013-08-08 21:18:59,034 [DEBUG] @injection.py:54 - Registering provider for feature CP_PROVIDER: <class 'subscription_manager.cp_provider.CPProvider'> 2013-08-08 21:18:59,034 [DEBUG] @injection.py:54 - Registering provider for feature CERT_SORTER: <class 'subscription_manager.cert_sorter.CertSorter'> 2013-08-08 21:18:59,034 [DEBUG] @injection.py:54 - Registering provider for feature PLUGIN_MANAGER: <class 'subscription_manager.plugins.PluginManager'> 2013-08-08 21:18:59,041 [DEBUG] @injection.py:54 - Registering provider for feature DBUS_IFACE: <class 'subscription_manager.dbus_interface.DbusIface'> 2013-08-08 21:18:59,054 [DEBUG] @injection.py:72 - Initializing singleton for feature ENT_DIR 2013-08-08 21:18:59,055 [DEBUG] @injection.py:80 - Returning instance for feature ENT_DIR 2013-08-08 21:18:59,055 [DEBUG] @injection.py:72 - Initializing singleton for feature PROD_DIR 2013-08-08 21:18:59,055 [DEBUG] @injection.py:80 - Returning instance for feature PROD_DIR 2013-08-08 21:18:59,055 [DEBUG] @injection.py:72 - Initializing singleton for feature PLUGIN_MANAGER 2013-08-08 21:18:59,056 [DEBUG] @plugins.py:519 - loaded plugin modules: [] 2013-08-08 21:18:59,056 [DEBUG] @plugins.py:520 - loaded plugins: {} 2013-08-08 21:18:59,056 [DEBUG] @injection.py:80 - Returning instance for feature PLUGIN_MANAGER 2013-08-08 21:18:59,057 [DEBUG] @injection.py:80 - Returning instance for feature PLUGIN_MANAGER 2013-08-08 21:18:59,058 [DEBUG] @injection.py:80 - Returning instance for feature ENT_DIR 2013-08-08 21:18:59,058 [DEBUG] @injection.py:80 - Returning instance for feature PROD_DIR 2013-08-08 21:18:59,059 [DEBUG] @injection.py:80 - Returning instance for feature PLUGIN_MANAGER 2013-08-08 21:18:59,059 [DEBUG] @injection.py:80 - Returning instance for feature ENT_DIR 2013-08-08 21:18:59,059 [DEBUG] @injection.py:80 - Returning instance for feature PROD_DIR 2013-08-08 21:18:59,060 [DEBUG] @injection.py:80 - Returning instance for feature PLUGIN_MANAGER 2013-08-08 21:18:59,063 [DEBUG] @injection.py:80 - Returning instance for feature ENT_DIR 2013-08-08 21:18:59,063 [DEBUG] @injection.py:80 - Returning instance for feature PROD_DIR 2013-08-08 21:18:59,064 [DEBUG] @injection.py:80 - Returning instance for feature PLUGIN_MANAGER 2013-08-08 21:18:59,065 [DEBUG] @injection.py:80 - Returning instance for feature PLUGIN_MANAGER 2013-08-08 21:18:59,065 [DEBUG] @injection.py:80 - Returning instance for feature ENT_DIR 2013-08-08 21:18:59,065 [DEBUG] @injection.py:80 - Returning instance for feature PROD_DIR 2013-08-08 21:18:59,066 [DEBUG] @injection.py:80 - Returning instance for feature PLUGIN_MANAGER 2013-08-08 21:18:59,067 [DEBUG] @injection.py:80 - Returning instance for feature ENT_DIR 2013-08-08 21:18:59,067 [DEBUG] @injection.py:80 - Returning instance for feature PROD_DIR 2013-08-08 21:18:59,068 [DEBUG] @injection.py:80 - Returning instance for feature PLUGIN_MANAGER 2013-08-08 21:18:59,068 [DEBUG] @injection.py:80 - Returning instance for feature ENT_DIR 2013-08-08 21:18:59,069 [DEBUG] @injection.py:80 - Returning instance for feature PROD_DIR 2013-08-08 21:18:59,069 [DEBUG] @injection.py:80 - Returning instance for feature PLUGIN_MANAGER 2013-08-08 21:18:59,070 [DEBUG] @injection.py:80 - Returning instance for feature ENT_DIR 2013-08-08 21:18:59,070 [DEBUG] @injection.py:80 - Returning instance for feature PROD_DIR 2013-08-08 21:18:59,071 [DEBUG] @injection.py:80 - Returning instance for feature PLUGIN_MANAGER 2013-08-08 21:18:59,072 [DEBUG] @injection.py:80 - Returning instance for feature ENT_DIR 2013-08-08 21:18:59,072 [DEBUG] @injection.py:80 - Returning instance for feature PROD_DIR 2013-08-08 21:18:59,072 [DEBUG] @injection.py:80 - Returning instance for feature PLUGIN_MANAGER 2013-08-08 21:18:59,073 [DEBUG] @injection.py:80 - Returning instance for feature ENT_DIR 2013-08-08 21:18:59,073 [DEBUG] @injection.py:80 - Returning instance for feature PROD_DIR 2013-08-08 21:18:59,074 [DEBUG] @injection.py:80 - Returning instance for feature PLUGIN_MANAGER 2013-08-08 21:18:59,074 [DEBUG] @injection.py:80 - Returning instance for feature ENT_DIR 2013-08-08 21:18:59,074 [DEBUG] @injection.py:80 - Returning instance for feature PROD_DIR 2013-08-08 21:18:59,075 [DEBUG] @injection.py:80 - Returning instance for feature PLUGIN_MANAGER 2013-08-08 21:18:59,075 [DEBUG] @injection.py:80 - Returning instance for feature ENT_DIR 2013-08-08 21:18:59,076 [DEBUG] @injection.py:80 - Returning instance for feature PROD_DIR 2013-08-08 21:18:59,076 [DEBUG] @injection.py:80 - Returning instance for feature PLUGIN_MANAGER 2013-08-08 21:18:59,077 [DEBUG] @injection.py:80 - Returning instance for feature ENT_DIR 2013-08-08 21:18:59,077 [DEBUG] @injection.py:80 - Returning instance for feature PROD_DIR 2013-08-08 21:18:59,077 [DEBUG] @injection.py:80 - Returning instance for feature PLUGIN_MANAGER 2013-08-08 21:18:59,078 [DEBUG] @injection.py:80 - Returning instance for feature ENT_DIR 2013-08-08 21:18:59,078 [DEBUG] @injection.py:80 - Returning instance for feature PROD_DIR 2013-08-08 21:18:59,079 [DEBUG] @injection.py:80 - Returning instance for feature PLUGIN_MANAGER 2013-08-08 21:18:59,080 [DEBUG] @injection.py:80 - Returning instance for feature ENT_DIR 2013-08-08 21:18:59,080 [DEBUG] @injection.py:80 - Returning instance for feature PROD_DIR 2013-08-08 21:18:59,081 [DEBUG] @injection.py:80 - Returning instance for feature PLUGIN_MANAGER 2013-08-08 21:18:59,081 [DEBUG] @injection.py:80 - Returning instance for feature ENT_DIR 2013-08-08 21:18:59,081 [DEBUG] @injection.py:80 - Returning instance for feature PROD_DIR 2013-08-08 21:18:59,082 [DEBUG] @injection.py:80 - Returning instance for feature PLUGIN_MANAGER 2013-08-08 21:18:59,083 [DEBUG] @injection.py:80 - Returning instance for feature ENT_DIR 2013-08-08 21:18:59,083 [DEBUG] @injection.py:80 - Returning instance for feature PROD_DIR 2013-08-08 21:18:59,083 [DEBUG] @injection.py:80 - Returning instance for feature PLUGIN_MANAGER 2013-08-08 21:18:59,084 [DEBUG] @injection.py:80 - Returning instance for feature ENT_DIR 2013-08-08 21:18:59,084 [DEBUG] @injection.py:80 - Returning instance for feature PROD_DIR 2013-08-08 21:18:59,085 [DEBUG] @injection.py:80 - Returning instance for feature PLUGIN_MANAGER 2013-08-08 21:18:59,086 [DEBUG] @injection.py:80 - Returning instance for feature ENT_DIR 2013-08-08 21:18:59,086 [DEBUG] @injection.py:80 - Returning instance for feature PROD_DIR 2013-08-08 21:18:59,087 [DEBUG] @injection.py:80 - Returning instance for feature PLUGIN_MANAGER 2013-08-08 21:18:59,088 [DEBUG] @injection.py:80 - Returning instance for feature ENT_DIR 2013-08-08 21:18:59,088 [DEBUG] @injection.py:80 - Returning instance for feature PROD_DIR 2013-08-08 21:18:59,088 [DEBUG] @injection.py:80 - Returning instance for feature PLUGIN_MANAGER 2013-08-08 21:18:59,089 [DEBUG] @injection.py:80 - Returning instance for feature ENT_DIR 2013-08-08 21:18:59,089 [DEBUG] @injection.py:80 - Returning instance for feature PROD_DIR 2013-08-08 21:18:59,090 [DEBUG] @injection.py:80 - Returning instance for feature PLUGIN_MANAGER 2013-08-08 21:18:59,090 [DEBUG] @injection.py:80 - Returning instance for feature ENT_DIR 2013-08-08 21:18:59,091 [DEBUG] @injection.py:80 - Returning instance for feature PROD_DIR 2013-08-08 21:18:59,091 [DEBUG] @injection.py:80 - Returning instance for feature PLUGIN_MANAGER 2013-08-08 21:18:59,092 [DEBUG] @injection.py:72 - Initializing singleton for feature IDENTITY 2013-08-08 21:18:59,092 [DEBUG] @identity.py:130 - Loading consumer info from identity certificates. 2013-08-08 21:18:59,092 [DEBUG] @injection.py:80 - Returning instance for feature IDENTITY 2013-08-08 21:18:59,093 [DEBUG] @injection.py:80 - Returning instance for feature ENT_DIR 2013-08-08 21:18:59,093 [DEBUG] @injection.py:80 - Returning instance for feature PROD_DIR 2013-08-08 21:18:59,093 [DEBUG] @injection.py:80 - Returning instance for feature PLUGIN_MANAGER 2013-08-08 21:18:59,094 [DEBUG] @injection.py:72 - Initializing singleton for feature CP_PROVIDER 2013-08-08 21:18:59,094 [DEBUG] @injection.py:80 - Returning instance for feature CP_PROVIDER 2013-08-08 21:18:59,095 [DEBUG] @profile.py:96 - Loading current RPM profile. 2013-08-08 21:18:59,159 [INFO] @managercli.py:292 - Client Versions: {'python-rhsm': '1.8.16-1.el5', 'subscription-manager': '1.8.19-1.el5'} 2013-08-08 21:18:59,159 [INFO] @connection.py:583 - Using certificate authentication: key = /etc/pki/consumer/key.pem, cert = /etc/pki/consumer/cert.pem, ca = /etc/rhsm/ca/, insecure = False 2013-08-08 21:18:59,159 [INFO] @connection.py:596 - Connection Built: host: samserv.redhat.com, port: 443, handler: /subscription 2013-08-08 21:18:59,160 [INFO] @connection.py:593 - Using no auth 2013-08-08 21:18:59,160 [INFO] @connection.py:596 - Connection Built: host: samserv.redhat.com, port: 443, handler: /subscription 2013-08-08 21:18:59,192 [DEBUG] @connection.py:394 - Loading CA PEM certificates from: /etc/rhsm/ca/ 2013-08-08 21:18:59,192 [DEBUG] @connection.py:376 - Loading CA certificate: '/etc/rhsm/ca/redhat-uep.pem' 2013-08-08 21:18:59,192 [DEBUG] @connection.py:376 - Loading CA certificate: '/etc/rhsm/ca/candlepin-stage.pem' 2013-08-08 21:18:59,193 [DEBUG] @connection.py:376 - Loading CA certificate: '/etc/rhsm/ca/candlepin-local.pem' 2013-08-08 21:18:59,193 [DEBUG] @connection.py:415 - Making request: GET /subscription/ 2013-08-08 21:18:59,261 [DEBUG] @connection.py:434 - Response status: 200 2013-08-08 21:18:59,261 [WARNING] @connection.py:438 - Clock skew detected, please check your system time 2013-08-08 21:18:59,261 [DEBUG] @connection.py:613 - Server supports the following resources: 2013-08-08 21:18:59,262 [DEBUG] @connection.py:614 - {'status': '/api/status/', 'organizations': '/api/organizations/', 'roles': '/api/roles/', 'sync_plans': '/api/sync_plans/', 'users': '/api/users/', 'distributors': '/api/distributors/', 'providers': '/api/providers/', 'entitlements': '/api/entitlements/', 'content_views': '/api/content_views/', 'system_groups': '/api/system_groups/', 'products': '/api/products/', 'systems': '/api/systems/', 'activation_keys': '/api/activation_keys/', 'content_view_definitions': '/api/content_view_definitions/', 'consumers': '/api/consumers/'} 2013-08-08 21:18:59,262 [DEBUG] @connection.py:394 - Loading CA PEM certificates from: /etc/rhsm/ca/ 2013-08-08 21:18:59,262 [DEBUG] @connection.py:376 - Loading CA certificate: '/etc/rhsm/ca/redhat-uep.pem' 2013-08-08 21:18:59,262 [DEBUG] @connection.py:376 - Loading CA certificate: '/etc/rhsm/ca/candlepin-stage.pem' 2013-08-08 21:18:59,263 [DEBUG] @connection.py:376 - Loading CA certificate: '/etc/rhsm/ca/candlepin-local.pem' 2013-08-08 21:18:59,263 [DEBUG] @connection.py:415 - Making request: GET /subscription/status 2013-08-08 21:18:59,311 [DEBUG] @connection.py:434 - Response status: 200 2013-08-08 21:18:59,311 [WARNING] @connection.py:438 - Clock skew detected, please check your system time 2013-08-08 21:18:59,312 [INFO] @managercli.py:303 - Server Versions: {'candlepin': '1.4.3-6.el6sam_splice-Headpin', 'server-type': 'This system is currently not registered.'} 2013-08-08 21:18:59,312 [INFO] @managercli.py:292 - Client Versions: {'python-rhsm': '1.8.16-1.el5', 'subscription-manager': '1.8.19-1.el5'} 2013-08-08 21:18:59,312 [DEBUG] @injection.py:80 - Returning instance for feature PROD_DIR 2013-08-08 21:18:59,318 [INFO] @connection.py:575 - Using basic authentication as: admin 2013-08-08 21:18:59,318 [INFO] @connection.py:596 - Connection Built: host: samserv.redhat.com, port: 443, handler: /subscription 2013-08-08 21:18:59,320 [DEBUG] @hwprobe.py:519 - cpu info: {'cpu.cpu(s)': 1, 'cpu.core(s)_per_socket': 1, 'cpu.thread(s)_per_core': 1, 'cpu.topology_source': 'kernel /sys cpu sibling lists', 'cpu.cpu_socket(s)': 1} 2013-08-08 21:18:59,344 [DEBUG] @connection.py:394 - Loading CA PEM certificates from: /etc/rhsm/ca/ 2013-08-08 21:18:59,344 [DEBUG] @connection.py:376 - Loading CA certificate: '/etc/rhsm/ca/redhat-uep.pem' 2013-08-08 21:18:59,345 [DEBUG] @connection.py:376 - Loading CA certificate: '/etc/rhsm/ca/candlepin-stage.pem' 2013-08-08 21:18:59,345 [DEBUG] @connection.py:376 - Loading CA certificate: '/etc/rhsm/ca/candlepin-local.pem' 2013-08-08 21:18:59,345 [DEBUG] @connection.py:415 - Making request: GET /subscription/users/admin/owners 2013-08-08 21:18:59,397 [DEBUG] @connection.py:434 - Response status: 200 2013-08-08 21:18:59,397 [WARNING] @connection.py:438 - Clock skew detected, please check your system time 2013-08-08 21:18:59,399 [DEBUG] @connection.py:394 - Loading CA PEM certificates from: /etc/rhsm/ca/ 2013-08-08 21:18:59,399 [DEBUG] @connection.py:376 - Loading CA certificate: '/etc/rhsm/ca/redhat-uep.pem' 2013-08-08 21:18:59,400 [DEBUG] @connection.py:376 - Loading CA certificate: '/etc/rhsm/ca/candlepin-stage.pem' 2013-08-08 21:18:59,400 [DEBUG] @connection.py:376 - Loading CA certificate: '/etc/rhsm/ca/candlepin-local.pem' 2013-08-08 21:18:59,401 [DEBUG] @connection.py:415 - Making request: POST /subscription/consumers?owner=ACME_Corporation 2013-08-08 21:19:00,294 [DEBUG] @injection.py:54 - Registering provider for feature IDENTITY: <class 'subscription_manager.identity.Identity'> 2013-08-08 21:19:00,294 [DEBUG] @injection.py:54 - Registering provider for feature PRODUCT_DATE_RANGE_CALCULATOR: <function factory at 0xa0cba3c> 2013-08-08 21:19:00,294 [DEBUG] @injection.py:54 - Registering provider for feature ENT_DIR: <class 'subscription_manager.certdirectory.EntitlementDirectory'> 2013-08-08 21:19:00,294 [DEBUG] @injection.py:54 - Registering provider for feature PROD_DIR: <class 'subscription_manager.certdirectory.ProductDirectory'> 2013-08-08 21:19:00,294 [DEBUG] @injection.py:54 - Registering provider for feature STATUS_CACHE: <class 'subscription_manager.cache.StatusCache'> 2013-08-08 21:19:00,294 [DEBUG] @injection.py:54 - Registering provider for feature PROD_STATUS_CACHE: <class 'subscription_manager.cache.ProductStatusCache'> 2013-08-08 21:19:00,295 [DEBUG] @injection.py:54 - Registering provider for feature CP_PROVIDER: <class 'subscription_manager.cp_provider.CPProvider'> 2013-08-08 21:19:00,295 [DEBUG] @injection.py:54 - Registering provider for feature CERT_SORTER: <class 'subscription_manager.cert_sorter.CertSorter'> 2013-08-08 21:19:00,295 [DEBUG] @injection.py:54 - Registering provider for feature PLUGIN_MANAGER: <class 'subscription_manager.plugins.PluginManager'> 2013-08-08 21:19:00,295 [DEBUG] @injection.py:54 - Registering provider for feature DBUS_IFACE: <class 'subscription_manager.dbus_interface.DbusIface'> 2013-08-08 21:19:00,297 [INFO] @rhsmd:192 - rhsmd started 2013-08-08 21:19:00,299 [INFO] @rhsmd:147 - D-Bus interface com.redhat.SubscriptionManager.EntitlementStatus.update_status called with status = 0 2013-08-08 21:19:00,331 [INFO] @rhsmd:115 - D-Bus signal com.redhat.SubscriptionManager.EntitlementStatus.entitlement_status_changed emitted 2013-08-08 21:19:01,295 [DEBUG] @connection.py:434 - Response status: 200 2013-08-08 21:19:01,296 [WARNING] @connection.py:438 - Clock skew detected, please check your system time 2013-08-08 21:19:01,298 [DEBUG] @cache.py:140 - Wrote cache: /var/lib/rhsm/cache/installed_products.json 2013-08-08 21:19:01,300 [INFO] @managerlib.py:69 - Consumer created: {'consumer_name': 'dhcp-13-25.nay.redhat.com', 'uuid': 'c84e976b-546c-47c7-a845-ebfc965c5f37'} 2013-08-08 21:19:01,300 [DEBUG] @utils.py:381 - No virt-who pid file, not attempting to restart 2013-08-08 21:19:01,301 [DEBUG] @injection.py:80 - Returning instance for feature IDENTITY 2013-08-08 21:19:01,301 [DEBUG] @identity.py:130 - Loading consumer info from identity certificates. 2013-08-08 21:19:01,302 [DEBUG] @connection.py:394 - Loading CA PEM certificates from: /etc/rhsm/ca/ 2013-08-08 21:19:01,302 [DEBUG] @connection.py:376 - Loading CA certificate: '/etc/rhsm/ca/redhat-uep.pem' 2013-08-08 21:19:01,302 [DEBUG] @connection.py:376 - Loading CA certificate: '/etc/rhsm/ca/candlepin-stage.pem' 2013-08-08 21:19:01,303 [DEBUG] @connection.py:376 - Loading CA certificate: '/etc/rhsm/ca/candlepin-local.pem' 2013-08-08 21:19:01,303 [DEBUG] @connection.py:415 - Making request: GET /subscription/status 2013-08-08 21:19:01,353 [DEBUG] @connection.py:434 - Response status: 200 2013-08-08 21:19:01,353 [WARNING] @connection.py:438 - Clock skew detected, please check your system time 2013-08-08 21:19:01,354 [INFO] @managercli.py:303 - Server Versions: {'candlepin': '1.4.3-6.el6sam_splice-Headpin', 'server-type': 'Red Hat Subscription Management'} 2013-08-08 21:19:01,354 [DEBUG] @connection.py:394 - Loading CA PEM certificates from: /etc/rhsm/ca/ 2013-08-08 21:19:01,355 [DEBUG] @connection.py:376 - Loading CA certificate: '/etc/rhsm/ca/redhat-uep.pem' 2013-08-08 21:19:01,355 [DEBUG] @connection.py:376 - Loading CA certificate: '/etc/rhsm/ca/candlepin-stage.pem' 2013-08-08 21:19:01,356 [DEBUG] @connection.py:376 - Loading CA certificate: '/etc/rhsm/ca/candlepin-local.pem' 2013-08-08 21:19:01,357 [DEBUG] @connection.py:415 - Making request: GET /subscription/ 2013-08-08 21:19:01,431 [DEBUG] @connection.py:434 - Response status: 200 2013-08-08 21:19:01,431 [WARNING] @connection.py:438 - Clock skew detected, please check your system time 2013-08-08 21:19:01,431 [DEBUG] @connection.py:613 - Server supports the following resources: 2013-08-08 21:19:01,431 [DEBUG] @connection.py:614 - {'status': '/api/status/', 'organizations': '/api/organizations/', 'roles': '/api/roles/', 'sync_plans': '/api/sync_plans/', 'users': '/api/users/', 'distributors': '/api/distributors/', 'providers': '/api/providers/', 'entitlements': '/api/entitlements/', 'content_views': '/api/content_views/', 'system_groups': '/api/system_groups/', 'products': '/api/products/', 'systems': '/api/systems/', 'activation_keys': '/api/activation_keys/', 'content_view_definitions': '/api/content_view_definitions/', 'consumers': '/api/consumers/'} 2013-08-08 21:19:01,432 [INFO] @cache.py:346 - Server does not support packages, skipping profile upload. 2013-08-08 21:19:01,432 [DEBUG] @cache.py:140 - Wrote cache: /var/lib/rhsm/facts/facts.json 2013-08-08 21:19:01,432 [INFO] @cache.py:168 - Checking current system info against cache: /var/lib/rhsm/cache/installed_products.json 2013-08-08 21:19:01,432 [INFO] @cache.py:185 - No changes. 2013-08-08 21:19:01,432 [DEBUG] @injection.py:72 - Initializing singleton for feature CERT_SORTER 2013-08-08 21:19:01,433 [DEBUG] @injection.py:80 - Returning instance for feature CP_PROVIDER 2013-08-08 21:19:01,433 [DEBUG] @injection.py:80 - Returning instance for feature PROD_DIR 2013-08-08 21:19:01,433 [DEBUG] @injection.py:80 - Returning instance for feature ENT_DIR 2013-08-08 21:19:01,433 [DEBUG] @injection.py:80 - Returning instance for feature IDENTITY 2013-08-08 21:19:01,433 [DEBUG] @injection.py:80 - Returning instance for feature PROD_DIR 2013-08-08 21:19:01,433 [INFO] @cache.py:168 - Checking current system info against cache: /var/lib/rhsm/cache/installed_products.json 2013-08-08 21:19:01,433 [INFO] @cache.py:185 - No changes. 2013-08-08 21:19:01,433 [DEBUG] @certdirectory.py:204 - Installed product IDs: ['68'] 2013-08-08 21:19:01,433 [DEBUG] @injection.py:72 - Initializing singleton for feature STATUS_CACHE 2013-08-08 21:19:01,434 [DEBUG] @injection.py:80 - Returning instance for feature STATUS_CACHE 2013-08-08 21:19:01,434 [DEBUG] @connection.py:394 - Loading CA PEM certificates from: /etc/rhsm/ca/ 2013-08-08 21:19:01,434 [DEBUG] @connection.py:376 - Loading CA certificate: '/etc/rhsm/ca/redhat-uep.pem' 2013-08-08 21:19:01,434 [DEBUG] @connection.py:376 - Loading CA certificate: '/etc/rhsm/ca/candlepin-stage.pem' 2013-08-08 21:19:01,434 [DEBUG] @connection.py:376 - Loading CA certificate: '/etc/rhsm/ca/candlepin-local.pem' 2013-08-08 21:19:01,435 [DEBUG] @connection.py:415 - Making request: GET /subscription/consumers/c84e976b-546c-47c7-a845-ebfc965c5f37/compliance 2013-08-08 21:19:01,487 [DEBUG] @connection.py:434 - Response status: 403 2013-08-08 21:19:01,487 [WARNING] @connection.py:438 - Clock skew detected, please check your system time 2013-08-08 21:19:01,488 [DEBUG] @injection.py:80 - Returning instance for feature CERT_SORTER 2013-08-08 21:19:01,488 [DEBUG] @injection.py:72 - Initializing singleton for feature DBUS_IFACE 2013-08-08 21:19:01,489 [DEBUG] @dbus_interface.py:74 - installed python-dbus doesn't support 'get_default_main_loop' 2013-08-08 21:19:01,491 [DEBUG] @dbus_interface.py:67 - installed python-dbus doesn't support 'follow_name_owner_changes' 2013-08-08 21:19:01,491 [DEBUG] @injection.py:80 - Returning instance for feature DBUS_IFACE 2013-08-08 21:19:01,491 [DEBUG] @injection.py:80 - Returning instance for feature CERT_SORTER 2013-08-08 21:19:01,580 [DEBUG] @injection.py:54 - Registering provider for feature IDENTITY: <class 'subscription_manager.identity.Identity'> 2013-08-08 21:19:01,580 [DEBUG] @injection.py:54 - Registering provider for feature PRODUCT_DATE_RANGE_CALCULATOR: <function factory at 0x8716a3c> 2013-08-08 21:19:01,580 [DEBUG] @injection.py:54 - Registering provider for feature ENT_DIR: <class 'subscription_manager.certdirectory.EntitlementDirectory'> 2013-08-08 21:19:01,580 [DEBUG] @injection.py:54 - Registering provider for feature PROD_DIR: <class 'subscription_manager.certdirectory.ProductDirectory'> 2013-08-08 21:19:01,580 [DEBUG] @injection.py:54 - Registering provider for feature STATUS_CACHE: <class 'subscription_manager.cache.StatusCache'> 2013-08-08 21:19:01,580 [DEBUG] @injection.py:54 - Registering provider for feature PROD_STATUS_CACHE: <class 'subscription_manager.cache.ProductStatusCache'> 2013-08-08 21:19:01,580 [DEBUG] @injection.py:54 - Registering provider for feature CP_PROVIDER: <class 'subscription_manager.cp_provider.CPProvider'> 2013-08-08 21:19:01,581 [DEBUG] @injection.py:54 - Registering provider for feature CERT_SORTER: <class 'subscription_manager.cert_sorter.CertSorter'> 2013-08-08 21:19:01,581 [DEBUG] @injection.py:54 - Registering provider for feature PLUGIN_MANAGER: <class 'subscription_manager.plugins.PluginManager'> 2013-08-08 21:19:01,581 [DEBUG] @injection.py:54 - Registering provider for feature DBUS_IFACE: <class 'subscription_manager.dbus_interface.DbusIface'> 2013-08-08 21:19:01,583 [INFO] @rhsmd:192 - rhsmd started 2013-08-08 21:19:01,586 [INFO] @rhsmd:147 - D-Bus interface com.redhat.SubscriptionManager.EntitlementStatus.update_status called with status = 0 2013-08-08 21:19:01,623 [INFO] @rhsmd:115 - D-Bus signal com.redhat.SubscriptionManager.EntitlementStatus.entitlement_status_changed emitted 2013-08-08 21:19:02,581 [DEBUG] @injection.py:54 - Registering provider for feature IDENTITY: <class 'subscription_manager.identity.Identity'> 2013-08-08 21:19:02,581 [DEBUG] @injection.py:54 - Registering provider for feature PRODUCT_DATE_RANGE_CALCULATOR: <function factory at 0x8c72a3c> 2013-08-08 21:19:02,582 [DEBUG] @injection.py:54 - Registering provider for feature ENT_DIR: <class 'subscription_manager.certdirectory.EntitlementDirectory'> 2013-08-08 21:19:02,582 [DEBUG] @injection.py:54 - Registering provider for feature PROD_DIR: <class 'subscription_manager.certdirectory.ProductDirectory'> 2013-08-08 21:19:02,582 [DEBUG] @injection.py:54 - Registering provider for feature STATUS_CACHE: <class 'subscription_manager.cache.StatusCache'> 2013-08-08 21:19:02,582 [DEBUG] @injection.py:54 - Registering provider for feature PROD_STATUS_CACHE: <class 'subscription_manager.cache.ProductStatusCache'> 2013-08-08 21:19:02,582 [DEBUG] @injection.py:54 - Registering provider for feature CP_PROVIDER: <class 'subscription_manager.cp_provider.CPProvider'> 2013-08-08 21:19:02,582 [DEBUG] @injection.py:54 - Registering provider for feature CERT_SORTER: <class 'subscription_manager.cert_sorter.CertSorter'> 2013-08-08 21:19:02,582 [DEBUG] @injection.py:54 - Registering provider for feature PLUGIN_MANAGER: <class 'subscription_manager.plugins.PluginManager'> 2013-08-08 21:19:02,582 [DEBUG] @injection.py:54 - Registering provider for feature DBUS_IFACE: <class 'subscription_manager.dbus_interface.DbusIface'> 2013-08-08 21:19:02,585 [INFO] @rhsmd:192 - rhsmd started 2013-08-08 21:19:02,587 [INFO] @rhsmd:147 - D-Bus interface com.redhat.SubscriptionManager.EntitlementStatus.update_status called with status = 0 2013-08-08 21:19:02,624 [INFO] @rhsmd:115 - D-Bus signal com.redhat.SubscriptionManager.EntitlementStatus.entitlement_status_changed emitted 2013-08-08 21:19:05,655 [DEBUG] @injection.py:54 - Registering provider for feature IDENTITY: <class 'subscription_manager.identity.Identity'> 2013-08-08 21:19:05,655 [DEBUG] @injection.py:54 - Registering provider for feature PRODUCT_DATE_RANGE_CALCULATOR: <function factory at 0x9f6b1b4> 2013-08-08 21:19:05,655 [DEBUG] @injection.py:54 - Registering provider for feature ENT_DIR: <class 'subscription_manager.certdirectory.EntitlementDirectory'> 2013-08-08 21:19:05,655 [DEBUG] @injection.py:54 - Registering provider for feature PROD_DIR: <class 'subscription_manager.certdirectory.ProductDirectory'> 2013-08-08 21:19:05,655 [DEBUG] @injection.py:54 - Registering provider for feature STATUS_CACHE: <class 'subscription_manager.cache.StatusCache'> 2013-08-08 21:19:05,656 [DEBUG] @injection.py:54 - Registering provider for feature PROD_STATUS_CACHE: <class 'subscription_manager.cache.ProductStatusCache'> 2013-08-08 21:19:05,656 [DEBUG] @injection.py:54 - Registering provider for feature CP_PROVIDER: <class 'subscription_manager.cp_provider.CPProvider'> 2013-08-08 21:19:05,656 [DEBUG] @injection.py:54 - Registering provider for feature CERT_SORTER: <class 'subscription_manager.cert_sorter.CertSorter'> 2013-08-08 21:19:05,656 [DEBUG] @injection.py:54 - Registering provider for feature PLUGIN_MANAGER: <class 'subscription_manager.plugins.PluginManager'> 2013-08-08 21:19:05,663 [DEBUG] @injection.py:54 - Registering provider for feature DBUS_IFACE: <class 'subscription_manager.dbus_interface.DbusIface'> 2013-08-08 21:19:05,676 [DEBUG] @injection.py:72 - Initializing singleton for feature ENT_DIR 2013-08-08 21:19:05,677 [DEBUG] @injection.py:80 - Returning instance for feature ENT_DIR 2013-08-08 21:19:05,677 [DEBUG] @injection.py:72 - Initializing singleton for feature PROD_DIR 2013-08-08 21:19:05,677 [DEBUG] @injection.py:80 - Returning instance for feature PROD_DIR 2013-08-08 21:19:05,677 [DEBUG] @injection.py:72 - Initializing singleton for feature PLUGIN_MANAGER 2013-08-08 21:19:05,678 [DEBUG] @plugins.py:519 - loaded plugin modules: [] 2013-08-08 21:19:05,678 [DEBUG] @plugins.py:520 - loaded plugins: {} 2013-08-08 21:19:05,678 [DEBUG] @injection.py:80 - Returning instance for feature PLUGIN_MANAGER 2013-08-08 21:19:05,680 [DEBUG] @injection.py:80 - Returning instance for feature PLUGIN_MANAGER 2013-08-08 21:19:05,680 [DEBUG] @injection.py:80 - Returning instance for feature ENT_DIR 2013-08-08 21:19:05,680 [DEBUG] @injection.py:80 - Returning instance for feature PROD_DIR 2013-08-08 21:19:05,681 [DEBUG] @injection.py:80 - Returning instance for feature PLUGIN_MANAGER 2013-08-08 21:19:05,681 [DEBUG] @injection.py:80 - Returning instance for feature ENT_DIR 2013-08-08 21:19:05,681 [DEBUG] @injection.py:80 - Returning instance for feature PROD_DIR 2013-08-08 21:19:05,682 [DEBUG] @injection.py:80 - Returning instance for feature PLUGIN_MANAGER 2013-08-08 21:19:05,685 [DEBUG] @injection.py:80 - Returning instance for feature ENT_DIR 2013-08-08 21:19:05,686 [DEBUG] @injection.py:80 - Returning instance for feature PROD_DIR 2013-08-08 21:19:05,686 [DEBUG] @injection.py:80 - Returning instance for feature PLUGIN_MANAGER 2013-08-08 21:19:05,687 [DEBUG] @injection.py:80 - Returning instance for feature PLUGIN_MANAGER 2013-08-08 21:19:05,687 [DEBUG] @injection.py:80 - Returning instance for feature ENT_DIR 2013-08-08 21:19:05,687 [DEBUG] @injection.py:80 - Returning instance for feature PROD_DIR 2013-08-08 21:19:05,688 [DEBUG] @injection.py:80 - Returning instance for feature PLUGIN_MANAGER 2013-08-08 21:19:05,689 [DEBUG] @injection.py:80 - Returning instance for feature ENT_DIR 2013-08-08 21:19:05,689 [DEBUG] @injection.py:80 - Returning instance for feature PROD_DIR 2013-08-08 21:19:05,690 [DEBUG] @injection.py:80 - Returning instance for feature PLUGIN_MANAGER 2013-08-08 21:19:05,691 [DEBUG] @injection.py:80 - Returning instance for feature ENT_DIR 2013-08-08 21:19:05,691 [DEBUG] @injection.py:80 - Returning instance for feature PROD_DIR 2013-08-08 21:19:05,691 [DEBUG] @injection.py:80 - Returning instance for feature PLUGIN_MANAGER 2013-08-08 21:19:05,692 [DEBUG] @injection.py:80 - Returning instance for feature ENT_DIR 2013-08-08 21:19:05,692 [DEBUG] @injection.py:80 - Returning instance for feature PROD_DIR 2013-08-08 21:19:05,693 [DEBUG] @injection.py:80 - Returning instance for feature PLUGIN_MANAGER 2013-08-08 21:19:05,694 [DEBUG] @injection.py:80 - Returning instance for feature ENT_DIR 2013-08-08 21:19:05,694 [DEBUG] @injection.py:80 - Returning instance for feature PROD_DIR 2013-08-08 21:19:05,694 [DEBUG] @injection.py:80 - Returning instance for feature PLUGIN_MANAGER 2013-08-08 21:19:05,695 [DEBUG] @injection.py:80 - Returning instance for feature ENT_DIR 2013-08-08 21:19:05,695 [DEBUG] @injection.py:80 - Returning instance for feature PROD_DIR 2013-08-08 21:19:05,696 [DEBUG] @injection.py:80 - Returning instance for feature PLUGIN_MANAGER 2013-08-08 21:19:05,696 [DEBUG] @injection.py:80 - Returning instance for feature ENT_DIR 2013-08-08 21:19:05,696 [DEBUG] @injection.py:80 - Returning instance for feature PROD_DIR 2013-08-08 21:19:05,697 [DEBUG] @injection.py:80 - Returning instance for feature PLUGIN_MANAGER 2013-08-08 21:19:05,698 [DEBUG] @injection.py:80 - Returning instance for feature ENT_DIR 2013-08-08 21:19:05,698 [DEBUG] @injection.py:80 - Returning instance for feature PROD_DIR 2013-08-08 21:19:05,698 [DEBUG] @injection.py:80 - Returning instance for feature PLUGIN_MANAGER 2013-08-08 21:19:05,699 [DEBUG] @injection.py:80 - Returning instance for feature ENT_DIR 2013-08-08 21:19:05,699 [DEBUG] @injection.py:80 - Returning instance for feature PROD_DIR 2013-08-08 21:19:05,699 [DEBUG] @injection.py:80 - Returning instance for feature PLUGIN_MANAGER 2013-08-08 21:19:05,700 [DEBUG] @injection.py:80 - Returning instance for feature ENT_DIR 2013-08-08 21:19:05,701 [DEBUG] @injection.py:80 - Returning instance for feature PROD_DIR 2013-08-08 21:19:05,701 [DEBUG] @injection.py:80 - Returning instance for feature PLUGIN_MANAGER 2013-08-08 21:19:05,702 [DEBUG] @injection.py:80 - Returning instance for feature ENT_DIR 2013-08-08 21:19:05,702 [DEBUG] @injection.py:80 - Returning instance for feature PROD_DIR 2013-08-08 21:19:05,703 [DEBUG] @injection.py:80 - Returning instance for feature PLUGIN_MANAGER 2013-08-08 21:19:05,704 [DEBUG] @injection.py:80 - Returning instance for feature ENT_DIR 2013-08-08 21:19:05,704 [DEBUG] @injection.py:80 - Returning instance for feature PROD_DIR 2013-08-08 21:19:05,704 [DEBUG] @injection.py:80 - Returning instance for feature PLUGIN_MANAGER 2013-08-08 21:19:05,705 [DEBUG] @injection.py:80 - Returning instance for feature ENT_DIR 2013-08-08 21:19:05,705 [DEBUG] @injection.py:80 - Returning instance for feature PROD_DIR 2013-08-08 21:19:05,706 [DEBUG] @injection.py:80 - Returning instance for feature PLUGIN_MANAGER 2013-08-08 21:19:05,706 [DEBUG] @injection.py:80 - Returning instance for feature ENT_DIR 2013-08-08 21:19:05,707 [DEBUG] @injection.py:80 - Returning instance for feature PROD_DIR 2013-08-08 21:19:05,707 [DEBUG] @injection.py:80 - Returning instance for feature PLUGIN_MANAGER 2013-08-08 21:19:05,709 [DEBUG] @injection.py:80 - Returning instance for feature ENT_DIR 2013-08-08 21:19:05,709 [DEBUG] @injection.py:80 - Returning instance for feature PROD_DIR 2013-08-08 21:19:05,709 [DEBUG] @injection.py:80 - Returning instance for feature PLUGIN_MANAGER 2013-08-08 21:19:05,710 [DEBUG] @injection.py:80 - Returning instance for feature ENT_DIR 2013-08-08 21:19:05,710 [DEBUG] @injection.py:80 - Returning instance for feature PROD_DIR 2013-08-08 21:19:05,710 [DEBUG] @injection.py:80 - Returning instance for feature PLUGIN_MANAGER 2013-08-08 21:19:05,711 [DEBUG] @injection.py:80 - Returning instance for feature ENT_DIR 2013-08-08 21:19:05,711 [DEBUG] @injection.py:80 - Returning instance for feature PROD_DIR 2013-08-08 21:19:05,712 [DEBUG] @injection.py:80 - Returning instance for feature PLUGIN_MANAGER 2013-08-08 21:19:05,713 [DEBUG] @injection.py:80 - Returning instance for feature ENT_DIR 2013-08-08 21:19:05,713 [DEBUG] @injection.py:80 - Returning instance for feature PROD_DIR 2013-08-08 21:19:05,713 [DEBUG] @injection.py:80 - Returning instance for feature PLUGIN_MANAGER 2013-08-08 21:19:05,714 [DEBUG] @injection.py:72 - Initializing singleton for feature IDENTITY 2013-08-08 21:19:05,714 [DEBUG] @identity.py:130 - Loading consumer info from identity certificates. 2013-08-08 21:19:05,718 [DEBUG] @injection.py:80 - Returning instance for feature IDENTITY 2013-08-08 21:19:05,719 [DEBUG] @injection.py:80 - Returning instance for feature ENT_DIR 2013-08-08 21:19:05,719 [DEBUG] @injection.py:80 - Returning instance for feature PROD_DIR 2013-08-08 21:19:05,719 [DEBUG] @injection.py:80 - Returning instance for feature PLUGIN_MANAGER 2013-08-08 21:19:05,720 [DEBUG] @injection.py:72 - Initializing singleton for feature CP_PROVIDER 2013-08-08 21:19:05,721 [DEBUG] @injection.py:80 - Returning instance for feature CP_PROVIDER 2013-08-08 21:19:05,721 [DEBUG] @profile.py:96 - Loading current RPM profile. 2013-08-08 21:19:05,785 [INFO] @managercli.py:292 - Client Versions: {'python-rhsm': '1.8.16-1.el5', 'subscription-manager': '1.8.19-1.el5'} 2013-08-08 21:19:05,786 [INFO] @connection.py:583 - Using certificate authentication: key = /etc/pki/consumer/key.pem, cert = /etc/pki/consumer/cert.pem, ca = /etc/rhsm/ca/, insecure = False 2013-08-08 21:19:05,786 [INFO] @connection.py:596 - Connection Built: host: samserv.redhat.com, port: 443, handler: /subscription 2013-08-08 21:19:05,786 [INFO] @connection.py:593 - Using no auth 2013-08-08 21:19:05,786 [INFO] @connection.py:596 - Connection Built: host: samserv.redhat.com, port: 443, handler: /subscription 2013-08-08 21:19:05,820 [DEBUG] @connection.py:394 - Loading CA PEM certificates from: /etc/rhsm/ca/ 2013-08-08 21:19:05,820 [DEBUG] @connection.py:376 - Loading CA certificate: '/etc/rhsm/ca/redhat-uep.pem' 2013-08-08 21:19:05,820 [DEBUG] @connection.py:376 - Loading CA certificate: '/etc/rhsm/ca/candlepin-stage.pem' 2013-08-08 21:19:05,820 [DEBUG] @connection.py:376 - Loading CA certificate: '/etc/rhsm/ca/candlepin-local.pem' 2013-08-08 21:19:05,821 [DEBUG] @connection.py:415 - Making request: GET /subscription/ 2013-08-08 21:19:05,951 [DEBUG] @connection.py:434 - Response status: 200 2013-08-08 21:19:05,951 [WARNING] @connection.py:438 - Clock skew detected, please check your system time 2013-08-08 21:19:05,952 [DEBUG] @connection.py:613 - Server supports the following resources: 2013-08-08 21:19:05,952 [DEBUG] @connection.py:614 - {'status': '/api/status/', 'organizations': '/api/organizations/', 'roles': '/api/roles/', 'sync_plans': '/api/sync_plans/', 'users': '/api/users/', 'distributors': '/api/distributors/', 'providers': '/api/providers/', 'entitlements': '/api/entitlements/', 'content_views': '/api/content_views/', 'system_groups': '/api/system_groups/', 'products': '/api/products/', 'systems': '/api/systems/', 'activation_keys': '/api/activation_keys/', 'content_view_definitions': '/api/content_view_definitions/', 'consumers': '/api/consumers/'} 2013-08-08 21:19:05,953 [DEBUG] @connection.py:394 - Loading CA PEM certificates from: /etc/rhsm/ca/ 2013-08-08 21:19:05,953 [DEBUG] @connection.py:376 - Loading CA certificate: '/etc/rhsm/ca/redhat-uep.pem' 2013-08-08 21:19:05,954 [DEBUG] @connection.py:376 - Loading CA certificate: '/etc/rhsm/ca/candlepin-stage.pem' 2013-08-08 21:19:05,954 [DEBUG] @connection.py:376 - Loading CA certificate: '/etc/rhsm/ca/candlepin-local.pem' 2013-08-08 21:19:05,955 [DEBUG] @connection.py:415 - Making request: GET /subscription/status 2013-08-08 21:19:06,004 [DEBUG] @connection.py:434 - Response status: 200 2013-08-08 21:19:06,005 [WARNING] @connection.py:438 - Clock skew detected, please check your system time 2013-08-08 21:19:06,005 [INFO] @managercli.py:303 - Server Versions: {'candlepin': '1.4.3-6.el6sam_splice-Headpin', 'server-type': 'Red Hat Subscription Management'} 2013-08-08 21:19:06,008 [DEBUG] @connection.py:394 - Loading CA PEM certificates from: /etc/rhsm/ca/ 2013-08-08 21:19:06,009 [DEBUG] @connection.py:376 - Loading CA certificate: '/etc/rhsm/ca/redhat-uep.pem' 2013-08-08 21:19:06,009 [DEBUG] @connection.py:376 - Loading CA certificate: '/etc/rhsm/ca/candlepin-stage.pem' 2013-08-08 21:19:06,010 [DEBUG] @connection.py:376 - Loading CA certificate: '/etc/rhsm/ca/candlepin-local.pem' 2013-08-08 21:19:06,010 [DEBUG] @connection.py:415 - Making request: DELETE /subscription/consumers/c84e976b-546c-47c7-a845-ebfc965c5f37 2013-08-08 21:19:06,226 [DEBUG] @connection.py:434 - Response status: 204 2013-08-08 21:19:06,226 [WARNING] @connection.py:438 - Clock skew detected, please check your system time 2013-08-08 21:19:06,227 [INFO] @managerlib.py:767 - Successfully un-registered. 2013-08-08 21:19:06,228 [INFO] @cache.py:116 - Deleting cache: /var/lib/rhsm/facts/facts.json 2013-08-08 21:19:06,229 [INFO] @cache.py:116 - Deleting cache: /var/lib/rhsm/cache/installed_products.json 2013-08-08 21:19:06,230 [DEBUG] @injection.py:72 - Initializing singleton for feature STATUS_CACHE 2013-08-08 21:19:06,230 [DEBUG] @injection.py:80 - Returning instance for feature STATUS_CACHE 2013-08-08 21:19:06,230 [DEBUG] @injection.py:72 - Initializing singleton for feature PROD_STATUS_CACHE 2013-08-08 21:19:06,230 [DEBUG] @injection.py:80 - Returning instance for feature PROD_STATUS_CACHE 2013-08-08 21:19:06,231 [INFO] @cache.py:116 - Deleting cache: /var/lib/rhsm/cache/product_status.json 2013-08-08 21:19:06,234 [DEBUG] @injection.py:80 - Returning instance for feature ENT_DIR 2013-08-08 21:19:06,234 [DEBUG] @injection.py:80 - Returning instance for feature PROD_DIR 2013-08-08 21:19:06,235 [DEBUG] @injection.py:80 - Returning instance for feature PLUGIN_MANAGER 2013-08-08 21:19:06,235 [DEBUG] @injection.py:80 - Returning instance for feature PROD_DIR 2013-08-08 21:19:06,235 [DEBUG] @injection.py:80 - Returning instance for feature PLUGIN_MANAGER 2013-08-08 21:19:06,236 [DEBUG] @injection.py:80 - Returning instance for feature ENT_DIR 2013-08-08 21:19:06,236 [DEBUG] @injection.py:80 - Returning instance for feature ENT_DIR 2013-08-08 21:19:06,236 [INFO] @certlib.py:243 - certs updated: Total updates: 0 Found (local) serial# [] Expected (UEP) serial# [] Added (new) <NONE> Deleted (rogue): <NONE> 2013-08-08 21:19:06,241 [INFO] @repolib.py:158 - repos updated: 0 2013-08-08 21:19:06,241 [INFO] @facts.py:73 - Cache /var/lib/rhsm/facts/facts.json does not exit 2013-08-08 21:19:06,247 [DEBUG] @hwprobe.py:519 - cpu info: {'cpu.cpu(s)': 1, 'cpu.core(s)_per_socket': 1, 'cpu.thread(s)_per_core': 1, 'cpu.topology_source': 'kernel /sys cpu sibling lists', 'cpu.cpu_socket(s)': 1} 2013-08-08 21:19:06,276 [DEBUG] @injection.py:80 - Returning instance for feature PROD_DIR 2013-08-08 21:19:06,277 [DEBUG] @injection.py:72 - Initializing singleton for feature CERT_SORTER 2013-08-08 21:19:06,277 [DEBUG] @injection.py:80 - Returning instance for feature CP_PROVIDER 2013-08-08 21:19:06,277 [DEBUG] @injection.py:80 - Returning instance for feature PROD_DIR 2013-08-08 21:19:06,278 [DEBUG] @injection.py:80 - Returning instance for feature ENT_DIR 2013-08-08 21:19:06,278 [DEBUG] @injection.py:80 - Returning instance for feature IDENTITY 2013-08-08 21:19:06,278 [DEBUG] @injection.py:80 - Returning instance for feature PROD_DIR 2013-08-08 21:19:06,278 [INFO] @cache.py:168 - Checking current system info against cache: /var/lib/rhsm/cache/installed_products.json 2013-08-08 21:19:06,278 [INFO] @cache.py:398 - Cache does not exist 2013-08-08 21:19:06,278 [INFO] @cache.py:170 - System data has changed, updating server. 2013-08-08 21:19:06,278 [DEBUG] @connection.py:394 - Loading CA PEM certificates from: /etc/rhsm/ca/ 2013-08-08 21:19:06,279 [DEBUG] @connection.py:376 - Loading CA certificate: '/etc/rhsm/ca/redhat-uep.pem' 2013-08-08 21:19:06,279 [DEBUG] @connection.py:376 - Loading CA certificate: '/etc/rhsm/ca/candlepin-stage.pem' 2013-08-08 21:19:06,279 [DEBUG] @connection.py:376 - Loading CA certificate: '/etc/rhsm/ca/candlepin-local.pem' 2013-08-08 21:19:06,279 [DEBUG] @connection.py:415 - Making request: PUT /subscription/consumers/c84e976b-546c-47c7-a845-ebfc965c5f37 2013-08-08 21:19:06,370 [DEBUG] @connection.py:434 - Response status: 401 2013-08-08 21:19:06,370 [WARNING] @connection.py:438 - Clock skew detected, please check your system time 2013-08-08 21:19:06,370 [ERROR] @connection.py:455 - No JSON object could be decoded Traceback (most recent call last): File "/usr/lib/python2.4/site-packages/rhsm/connection.py", line 453, in validateResponse parsed = json.loads(response['content'], object_hook=self._decode_dict) File "/usr/lib/python2.4/site-packages/simplejson/__init__.py", line 318, in loads return cls(encoding=encoding, **kw).decode(s) File "/usr/lib/python2.4/site-packages/simplejson/decoder.py", line 335, in decode obj, end = self.raw_decode(s, idx=_w(s, 0).end()) File "/usr/lib/python2.4/site-packages/simplejson/decoder.py", line 353, in raw_decode raise ValueError("No JSON object could be decoded") ValueError: No JSON object could be decoded 2013-08-08 21:19:06,371 [ERROR] @connection.py:456 - Response: {'content': 'No Credentials provided', 'status': 401} 2013-08-08 21:19:06,371 [ERROR] @cache.py:180 - Error updating system data on the server 2013-08-08 21:19:06,371 [ERROR] @cache.py:181 - Network error code: 401 Traceback (most recent call last): File "/usr/share/rhsm/subscription_manager/cache.py", line 172, in update_check self._sync_with_server(uep, consumer_uuid) File "/usr/share/rhsm/subscription_manager/cache.py", line 421, in _sync_with_server installed_products=self.format_for_server()) File "/usr/lib/python2.4/site-packages/rhsm/connection.py", line 717, in updateConsumer ret = self.conn.request_put(method, params) File "/usr/lib/python2.4/site-packages/rhsm/connection.py", line 490, in request_put return self._request("PUT", method, params) File "/usr/lib/python2.4/site-packages/rhsm/connection.py", line 443, in _request self.validateResponse(result) File "/usr/lib/python2.4/site-packages/rhsm/connection.py", line 461, in validateResponse raise NetworkException(response['status']) NetworkException: Network error code: 401 2013-08-08 21:19:06,373 [ERROR] @managercli.py:148 - exception caught in subscription-manager 2013-08-08 21:19:06,373 [ERROR] @managercli.py:149 - Error updating system data on the server, see /var/log/rhsm/rhsm.log for more details. Traceback (most recent call last): File "/usr/sbin/subscription-manager", line 82, in ? sys.exit(abs(main() or 0)) File "/usr/sbin/subscription-manager", line 73, in main return managercli.ManagerCLI().main() File "/usr/share/rhsm/subscription_manager/managercli.py", line 2228, in main return CLI.main(self) File "/usr/share/rhsm/subscription_manager/cli.py", line 166, in main return cmd.main() File "/usr/share/rhsm/subscription_manager/managercli.py", line 438, in main return_code = self._do_command() File "/usr/share/rhsm/subscription_manager/managercli.py", line 1191, in _do_command self._request_validity_check() File "/usr/share/rhsm/subscription_manager/managercli.py", line 241, in _request_validity_check inj.require(inj.CERT_SORTER).force_cert_check() File "/usr/share/rhsm/subscription_manager/injection.py", line 103, in require return FEATURES.require(feature, *args, **kwargs) File "/usr/share/rhsm/subscription_manager/injection.py", line 74, in require self.providers[feature] = provider() File "/usr/share/rhsm/subscription_manager/cert_sorter.py", line 89, in __init__ self.update_product_manager() File "/usr/share/rhsm/subscription_manager/cert_sorter.py", line 100, in update_product_manager self.installed_mgr.update_check(self.cp_provider.get_consumer_auth_cp(), self.identity.uuid) File "/usr/share/rhsm/subscription_manager/cache.py", line 182, in update_check raise Exception(_("Error updating system data on the server, see /var/log/rhsm/rhsm.log " Exception: Error updating system data on the server, see /var/log/rhsm/rhsm.log for more details. 2013-08-08 21:19:08,350 [DEBUG] @injection.py:54 - Registering provider for feature IDENTITY: <class 'subscription_manager.identity.Identity'> 2013-08-08 21:19:08,350 [DEBUG] @injection.py:54 - Registering provider for feature PRODUCT_DATE_RANGE_CALCULATOR: <function factory at 0x8e54a3c> 2013-08-08 21:19:08,350 [DEBUG] @injection.py:54 - Registering provider for feature ENT_DIR: <class 'subscription_manager.certdirectory.EntitlementDirectory'> 2013-08-08 21:19:08,350 [DEBUG] @injection.py:54 - Registering provider for feature PROD_DIR: <class 'subscription_manager.certdirectory.ProductDirectory'> 2013-08-08 21:19:08,350 [DEBUG] @injection.py:54 - Registering provider for feature STATUS_CACHE: <class 'subscription_manager.cache.StatusCache'> 2013-08-08 21:19:08,350 [DEBUG] @injection.py:54 - Registering provider for feature PROD_STATUS_CACHE: <class 'subscription_manager.cache.ProductStatusCache'> 2013-08-08 21:19:08,350 [DEBUG] @injection.py:54 - Registering provider for feature CP_PROVIDER: <class 'subscription_manager.cp_provider.CPProvider'> 2013-08-08 21:19:08,350 [DEBUG] @injection.py:54 - Registering provider for feature CERT_SORTER: <class 'subscription_manager.cert_sorter.CertSorter'> 2013-08-08 21:19:08,350 [DEBUG] @injection.py:54 - Registering provider for feature PLUGIN_MANAGER: <class 'subscription_manager.plugins.PluginManager'> 2013-08-08 21:19:08,351 [DEBUG] @injection.py:54 - Registering provider for feature DBUS_IFACE: <class 'subscription_manager.dbus_interface.DbusIface'> 2013-08-08 21:19:08,353 [INFO] @rhsmd:192 - rhsmd started 2013-08-08 21:19:08,355 [INFO] @rhsmd:147 - D-Bus interface com.redhat.SubscriptionManager.EntitlementStatus.update_status called with status = 0 2013-08-08 21:19:08,387 [INFO] @rhsmd:115 - D-Bus signal com.redhat.SubscriptionManager.EntitlementStatus.entitlement_status_changed emitted