Description of problem: Registering with an activation key (containing many many pools) or registering with many many activation keys (containing individual pools) can lead to an SSL TimeoutError after one minute of real time. The problem is that after the timeout, the system remains unregistered with no entitlements attached to the system, yet on the server a consumer exists with entitlements attached. We now have a situation where the user of the system will unknowingly try again and again to use this large activation key. Unfortunately with every timeout, the entitlements available to the org are consequently depleted. Server-side action will be required to delete the orphaned consumers and restore the available entitlements, but the system user does not know that. Admittedly, this is an extreme case that only surfaces when the activation key has many many pools attached and the workaround is to reduce the number of pools attached to the activation key. This bug surfaced by an automated test that was simply attaching all available pools within the org to an activation key. Version-Release number of selected component (if applicable): [root@jsefler-7 ~]# subscription-manager version server type: Red Hat Subscription Management subscription management server: 0.8.34-1 subscription-manager: 1.10.8-1.el7 python-rhsm: 1.10.8-1.el7 How reproducible: Steps to Reproduce: Create an activation key and add one of every available pool to the key. (Not Shown) Then try to register with it... but before I register with it, let's just register without it and show the initially available quantities from the all available pools... [root@jsefler-7 ~]# subscription-manager register --org admin Username: testuser1 Password: The system has been registered with ID: aade10e6-4e5d-4802-ac79-dd17cac8f1ec [root@jsefler-7 ~]# subscription-manager list --all --available | grep Available | sort Available Subscriptions Available: 10 Available: 10 Available: 10 Available: 10 Available: 10 Available: 10 Available: 10 Available: 10 Available: 10 Available: 10 Available: 10 Available: 10 Available: 10 Available: 10 Available: 10 Available: 10 Available: 10 Available: 10 Available: 10 Available: 20 Available: 20 Available: 20 Available: 20 Available: 40 Available: 40 Available: 40 Available: 5 Available: 5 Available: 5 Available: 5 Available: 5 Available: 5 Available: 5 Available: 5 Available: 5 Available: 5 Available: 5 Available: 5 Available: 5 Available: 5 Available: 5 Available: 5 Available: 5 Available: 5 Available: 5 Available: 5 Available: 5 Available: 5 Available: 5 Available: 5 Available: 5 Available: 5 Available: 5 Available: 5 Available: 5 Available: 5 Available: 500 Available: Unlimited Available: Unlimited [root@jsefler-7 ~]# Now let's register with an activation key containing all the pools... [root@jsefler-7 ~]# time subscription-manager register --org=admin --activationkey=ActivationKey1386691261715WithMultiplePoolsForOrg_admin --force Network error, unable to connect to server. Please see /var/log/rhsm/rhsm.log for more information. real 1m4.718s user 0m1.233s sys 0m1.623s [root@jsefler-7 ~]# [root@jsefler-7 ~]# tail -f /var/log/rhsm/rhsm.log 2013-12-10 12:15:11,318 [DEBUG] subscription-manager @connection.py:444 - Making request: POST /candlepin/consumers?owner=admin&activation_keys=ActivationKey1386691261715WithMultiplePoolsForOrg_admin 2013-12-10 12:16:11,442 [ERROR] subscription-manager @managercli.py:156 - Error during registration: timed out 2013-12-10 12:16:11,443 [ERROR] subscription-manager @managercli.py:157 - timed out Traceback (most recent call last): File "/usr/share/rhsm/subscription_manager/managercli.py", line 1060, in _do_command installed_products=self.installed_mgr.format_for_server()) File "/usr/lib64/python2.7/site-packages/rhsm/connection.py", line 729, in registerConsumer return self.conn.request_post(url, params) File "/usr/lib64/python2.7/site-packages/rhsm/connection.py", line 551, in request_post return self._request("POST", method, params) File "/usr/lib64/python2.7/site-packages/rhsm/connection.py", line 458, in _request response = conn.getresponse() File "/usr/lib64/python2.7/httplib.py", line 1045, in getresponse response.begin() File "/usr/lib64/python2.7/httplib.py", line 409, in begin version, status, reason = self._read_status() File "/usr/lib64/python2.7/httplib.py", line 365, in _read_status line = self.fp.readline(_MAXLINE + 1) File "/usr/lib64/python2.7/socket.py", line 476, in readline data = self._sock.recv(self._rbufsize) File "/usr/lib64/python2.7/site-packages/M2Crypto/SSL/Connection.py", line 228, in read return self._read_bio(size) File "/usr/lib64/python2.7/site-packages/M2Crypto/SSL/Connection.py", line 213, in _read_bio return m2.ssl_read(self.ssl, size, self._timeout) SSLTimeoutError: timed out Now, let's register without the key again and list the available pool quantities... [root@jsefler-7 ~]# subscription-manager register --org admin Username: testuser1 Password: The system has been registered with ID: 17123bd5-e6d3-4410-98a0-fcd4266a4caf [root@jsefler-7 ~]# subscription-manager list --all --available | grep Available | sort Available Subscriptions Available: 19 Available: 19 Available: 19 Available: 19 Available: 3 Available: 39 Available: 39 Available: 39 Available: 4 Available: 4 Available: 4 Available: 4 Available: 4 Available: 4 Available: 4 Available: 4 Available: 4 Available: 4 Available: 4 Available: 4 Available: 4 Available: 4 Available: 4 Available: 4 Available: 4 Available: 4 Available: 4 Available: 4 Available: 4 Available: 4 Available: 4 Available: 4 Available: 4 Available: 4 Available: 4 Available: 4 Available: 4 Available: 499 Available: 9 Available: 9 Available: 9 Available: 9 Available: 9 Available: 9 Available: 9 Available: 9 Available: 9 Available: 9 Available: 9 Available: 9 Available: 9 Available: 9 Available: 9 Available: 9 Available: 9 Available: 9 Available: 9 Available: Unlimited Available: Unlimited [root@jsefler-7 ~]# BANG!: Notice that all of the available quantities have diminished from the failed registration that timed out.
commit 7d99792ef4d24207c7806559aee1ae4dd427dd1e Author: ckozak <ckozak> Date: Tue Feb 18 17:53:59 2014 -0500 1040101: Avoid repeating work and database lookups checking modifies Flatten out the algorithm, and only query the database once for entitlements and once for products
Verifying Version... [root@jsefler-7 ~]# subscription-manager version server type: This system is currently not registered. subscription management server: 0.9.4-1 subscription-manager: 1.10.14-3.el7 python-rhsm: 1.10.12-1.el7 Note: The fix that Carter has proposed in comment 1 is really a performance improvement. Let's test it... The activationkey used to demonstrate the problem in comment 0 contained 59 pools. To verify this bug, I use an activateion key with 98 pools. Let's see if the registration completes before the timeout... [root@jsefler-7 ~]# time subscription-manager register --org=admin --activationkey=ActivationKey1393875007416WithMultiplePoolsForOrg_admin The system has been registered with ID: f6cb9333-7ed5-4c39-8cb2-977ff2c148fd Installed Product Current Status: Product Name: Red Hat Enterprise Linux 7 Server High Touch Beta Status: Not Subscribed real 0m34.852s user 0m1.298s sys 0m0.379s [root@jsefler-7 ~]# subscription-manager list --consumed | grep "SKU" | wc -l 98 VERIFIED: An activation key containing many many (98) pools was successfully used to register (in 34 seconds) before the SSL timeout. Although this does NOT verify the "consequence of an SSLTimeoutError when registering with activation keys", it does verify a significant performance improvement with an highly unrealistic activation key containing nearly one hundred pools. Moving this test to VERIFIED. The automated tests that revealed this bug are now passing.
These bugs were fixed during 7.0 but not moved to CLOSED. They have been delivered