995292 – Error to unregister rhel 5.10 from SAM server

Bug 995292 - Error to unregister rhel 5.10 from SAM server

Summary: Error to unregister rhel 5.10 from SAM server

Keywords:
Status:	CLOSED WONTFIX
Alias:	None
Product:	Subscription Asset Manager
Classification:	Retired
Component:	katello
Sub Component:
Version:	1.3
Hardware:	Unspecified
OS:	Unspecified
Priority:	unspecified
Severity:	high
Target Milestone:	rc
Target Release:	---
Assignee:	Katello Bug Bin
QA Contact:	SAM QE List
Docs Contact:
URL:
Whiteboard:
Depends On:
Blocks:	sam20-tracker
TreeView+	depends on / blocked

Reported:	2013-08-09 01:39 UTC by gaoshang
Modified:	2017-06-26 20:31 UTC (History)
CC List:	9 users (show)
Fixed In Version:
Clone Of:
Environment:
Last Closed:	2017-06-26 20:31:59 UTC
Embargoed:

Attachments	(Terms of Use)
katello-debug log info attached (152.54 KB, application/x-gzip) 2013-08-09 03:19 UTC, gaoshang	no flags	Details
View All

Description gaoshang 2013-08-09 01:39:09 UTC

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

Comment 1 gaoshang 2013-08-09 03:19:59 UTC

Created attachment 784709 [details]
katello-debug log info attached

katello-debug log info

Comment 2 Tom McKay 2013-08-09 13:17:34 UTC

@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!

Comment 3 gaoshang 2013-08-12 03:04:56 UTC

(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

Comment 4 Adrian Likins 2013-08-16 14:08:47 UTC

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.

Comment 5 Alex Wood 2013-08-16 15:06:54 UTC

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.

Comment 6 Bryan Kearney 2013-08-29 19:07:22 UTC

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 ~]#

Comment 7 qianzhan 2013-08-30 03:37:29 UTC

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.

Comment 8 sthirugn@redhat.com 2013-08-30 19:22:28 UTC

Moving to Assigned as per Comment 7 above

Comment 9 Petr Janda 2013-09-09 11:42:57 UTC

According to my tests bug exists still in SAM-1.3-snapshot5

Comment 11 qianzhan 2014-04-22 03:18:21 UTC

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.

Comment 12 Bryan Kearney 2017-06-26 20:31:59 UTC

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!

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