I think this RFE may have already been implemented then removed then enabled again.

The most recent record of it I have found is the following bug:
https://bugzilla.redhat.com/show_bug.cgi?id=1173139

As can be seen from Filip's comments it seems that this feature still exists.

I believe the only change necessary here is to ensure that python-rhsm logs the request uuid with every request.

I'm moving this to subscription-manager with an update that this header should always be logged with the request response. This value is being returned in the x-candlepin-request-uuid header.

This is implemented in upstream already. I think the only RFE here might be to log what method and handler were used in the request along with the request ID (in the same log message). The logic for this is there can be a lot being written to the rhsm.log at the same time. This makes it a bit hard to see what method and handler a particular request went with. Another potential change would be to reduce the log level from DEBUG to INFO on this particular log statement.


Other than the above there appears to be nothing to do for this RFE.

Demonstrating that on RHEL 73 , the rhsm.log didnot contain any request IDs 
==========================================================================

# subscription-manager version
server type: Red Hat Subscription Management
subscription management server: 0.9.51.21-1
subscription management rules: 5.15.1
subscription-manager: 1.17.15-1.el7
python-rhsm: 1.17.9-1.el7


[root@dhcp35-220 ~]# subscription-manager register
Registering to: subscription.rhn.stage.redhat.com:443/subscription
Username:stage_test_rhel74
Password: 

2017-05-09 13:31:21,090 [INFO] subscription-manager:27433:MainThread @managercli.py:384 - Client Versions: {'python-rhsm': '1.17.9-1.el7', 'subscription-manager': '1.17.15-1.el7'}
2017-05-09 13:31:21,091 [INFO] subscription-manager:27433:MainThread @connection.py:830 - Connection built: host=subscription.rhn.stage.redhat.com port=443 handler=/subscription auth=identity_cert ca_dir=/etc/rhsm/ca/ verify=False
2017-05-09 13:31:21,091 [INFO] subscription-manager:27433:MainThread @connection.py:830 - Connection built: host=subscription.rhn.stage.redhat.com port=443 handler=/subscription auth=none
2017-05-09 13:31:21,092 [INFO] subscription-manager:27433:MainThread @managercli.py:384 - Client Versions: {'python-rhsm': '1.17.9-1.el7', 'subscription-manager': '1.17.15-1.el7'}
2017-05-09 13:31:21,104 [INFO] subscription-manager:27433:MainThread @managercli.py:359 - Consumer Identity name=None uuid=None
2017-05-09 13:31:21,108 [INFO] subscription-manager:27433:MainThread @managercli.py:359 - Consumer Identity name=None uuid=None
2017-05-09 13:31:30,169 [INFO] subscription-manager:27433:MainThread @connection.py:830 - Connection built: host=subscription.rhn.stage.redhat.com port=443 handler=/subscription auth=basic username=stage_test_rhel74
2017-05-09 13:31:30,235 [INFO] subscription-manager:27433:MainThread @hwprobe.py:916 - collected virt facts: virt.is_guest=True, virt.host_type=kvm, virt.uuid=d5700f2b-0cf9-e976-f085-ee83f3510c31
The system has been registered with ID: fd6ecf3d-717e-42e4-a913-ce3124dcd282 
2017-05-09 13:31:38,240 [INFO] subscription-manager:27433:MainThread @managerlib.py:77 - Consumer created: {'consumer_name': 'dhcp35-220.lab.eng.blr.redhat.com', 'uuid': 'fd6ecf3d-717e-42e4-a913-ce3124dcd282'}
2017-05-09 13:31:38,243 [INFO] subscription-manager:27433:MainThread @connection.py:830 - Connection built: host=subscription.rhn.stage.redhat.com port=443 handler=/subscription auth=identity_cert ca_dir=/etc/rhsm/ca/ verify=False
2017-05-09 13:31:40,904 [INFO] subscription-manager:27433:MainThread @managercli.py:395 - Server Versions: {'rules-version': '5.15.1', 'candlepin': '0.9.51.21-1', 'server-type': 'Red Hat Subscription Management'}
2017-05-09 13:31:42,155 [INFO] rhsmd:27472:MainThread @rhsmd:261 - rhsmd started
2017-05-09 13:31:42,268 [INFO] rhsmd:27472:MainThread @connection.py:830 - Connection built: host=subscription.rhn.stage.redhat.com port=443 handler=/subscription auth=identity_cert ca_dir=/etc/rhsm/ca/ verify=False
2017-05-09 13:31:43,785 [INFO] rhsmd:27472:MainThread @cert_sorter.py:205 - Product status: valid_products= partial_products= expired_products= unentitled_producs=69 and 251 future_products= valid_until=None
2017-05-09 13:31:45,950 [INFO] subscription-manager:27433:MainThread @cert_sorter.py:205 - Product status: valid_products= partial_products= expired_products= unentitled_producs=69 and 251 future_products= valid_until=None
2017-05-09 13:31:46,084 [INFO] rhsmd:27485:MainThread @rhsmd:261 - rhsmd started
2017-05-09 13:31:46,134 [INFO] rhsmd:27485:MainThread @connection.py:830 - Connection built: host=subscription.rhn.stage.redhat.com port=443 handler=/subscription auth=identity_cert ca_dir=/etc/rhsm/ca/ verify=False
2017-05-09 13:31:47,640 [INFO] rhsmd:27485:MainThread @cert_sorter.py:205 - Product status: valid_products= partial_products= expired_products= unentitled_producs=69 and 251 future_products= valid_until=None

^^ No requestIDs displayed in the rhsm.log


Retesting with RHEL 74 
======================

# subscription-manager version
server type: Red Hat Subscription Management
subscription management server: 0.9.51.21-1
subscription management rules: 5.15.1
subscription-manager: 1.19.12-1.el7
python-rhsm: 1.19.6-1.el7


[root@dhcp151-211 ~]# subscription-manager register
Registering to: subscription.rhsm.stage.redhat.com:443/subscription
Username:stage_test_rhel74
Password: 

rhsm.log
=========
2017-05-09 03:59:20,450 [INFO] subscription-manager:28360:MainThread @managercli.py:522 - X-Correlation-ID: 3f7da34d4bf44b6d876b0c5e04548f21
2017-05-09 03:59:20,451 [INFO] subscription-manager:28360:MainThread @managercli.py:411 - Client Versions: {'python-rhsm': '1.19.6-1.el7', 'subscription-manager': '1.19.12-1.el7'}
2017-05-09 03:59:20,452 [INFO] subscription-manager:28360:MainThread @connection.py:780 - Connection built: host=subscription.rhsm.stage.redhat.com port=443 handler=/subscription auth=identity_cert ca_dir=/etc/rhsm/ca/ insecure=False
2017-05-09 03:59:20,453 [INFO] subscription-manager:28360:MainThread @connection.py:780 - Connection built: host=subscription.rhsm.stage.redhat.com port=443 handler=/subscription auth=none
2017-05-09 03:59:20,454 [INFO] subscription-manager:28360:MainThread @managercli.py:411 - Client Versions: {'python-rhsm': '1.19.6-1.el7', 'subscription-manager': '1.19.12-1.el7'}
2017-05-09 03:59:20,472 [INFO] subscription-manager:28360:MainThread @managercli.py:386 - Consumer Identity name=None uuid=None
2017-05-09 03:59:20,474 [INFO] subscription-manager:28360:MainThread @managercli.py:386 - Consumer Identity name=None uuid=None
2017-05-09 03:59:34,462 [INFO] subscription-manager:28360:MainThread @connection.py:780 - Connection built: host=subscription.rhsm.stage.redhat.com port=443 handler=/subscription auth=basic username=stage_test_rhel74
2017-05-09 03:59:34,497 [INFO] subscription-manager:28360:MainThread @dmiinfo.py:75 - Using dmidecode dump file: /dev/mem
2017-05-09 03:59:36,342 [INFO] subscription-manager:28360:MainThread @connection.py:520 - Response: status=200, requestUuid=4fbbd0ba-abd0-4c08-b1f5-304dd198434f, request="GET /subscription/users/stage_test_rhel74/owners"
2017-05-09 03:59:36,797 [INFO] subscription-manager:28360:MainThread @connection.py:520 - Response: status=200, request="GET /subscription/"
The system has been registered with ID: f4a4b498-4167-4535-aa3e-ca0f70692222 
2017-05-09 03:59:38,953 [INFO] subscription-manager:28360:MainThread @connection.py:520 - Response: status=200, requestUuid=73f957fc-556d-4365-b9a4-2da42c708692, request="POST /subscription/consumers?owner=10917755"
2017-05-09 03:59:38,958 [INFO] subscription-manager:28360:MainThread @managerlib.py:76 - Consumer created: {'consumer_name': u'dhcp151-211.mpc.lab.eng.bos.redhat.com', 'uuid': 'f4a4b498-4167-4535-aa3e-ca0f70692222'}
2017-05-09 03:59:38,960 [INFO] subscription-manager:28360:MainThread @connection.py:780 - Connection built: host=subscription.rhsm.stage.redhat.com port=443 handler=/subscription auth=identity_cert ca_dir=/etc/rhsm/ca/ insecure=False
2017-05-09 03:59:39,418 [INFO] subscription-manager:28360:MainThread @connection.py:520 - Response: status=200, request="GET /subscription/"
2017-05-09 03:59:39,992 [INFO] subscription-manager:28360:MainThread @connection.py:520 - Response: status=200, requestUuid=3aa6dee6-964c-4bf5-9a57-67f1152f1157, request="GET /subscription/status"
2017-05-09 03:59:39,993 [INFO] subscription-manager:28360:MainThread @managercli.py:422 - Server Versions: {'rules-version': u'5.15.1', 'candlepin': u'0.9.51.21-1', 'server-type': 'Red Hat Subscription Management'}
2017-05-09 03:59:40,451 [INFO] subscription-manager:28360:MainThread @connection.py:520 - Response: status=200, request="GET /subscription/"
2017-05-09 03:59:41,515 [INFO] subscription-manager:28360:MainThread @connection.py:520 - Response: status=204, request="PUT /subscription/consumers/f4a4b498-4167-4535-aa3e-ca0f70692222/packages"
2017-05-09 03:59:42,137 [INFO] subscription-manager:28360:MainThread @connection.py:520 - Response: status=200, requestUuid=64e7adbc-d378-40b2-8626-cce2e74682b1, request="GET /subscription/status"
2017-05-09 03:59:42,138 [INFO] subscription-manager:28360:MainThread @managercli.py:1260 - System registered, updating entitlements if needed
2017-05-09 03:59:42,762 [INFO] subscription-manager:28360:MainThread @connection.py:520 - Response: status=200, requestUuid=586db60a-d91c-4056-a51f-ed08e642b88f, request="GET /subscription/consumers/f4a4b498-4167-4535-aa3e-ca0f70692222/certificates/serials"
2017-05-09 03:59:42,763 [INFO] subscription-manager:28360:MainThread @entcertlib.py:130 - certs updated:
Total updates: 0
Found (local) serial# []
Expected (UEP) serial# []
Added (new)
  <NONE>
Deleted (rogue):
  <NONE>
2017-05-09 03:59:43,388 [INFO] subscription-manager:28360:MainThread @connection.py:520 - Response: status=200, requestUuid=8c61089a-215a-4b85-87d5-d7893750e312, request="GET /subscription/consumers/f4a4b498-4167-4535-aa3e-ca0f70692222/compliance"
2017-05-09 03:59:43,390 [INFO] subscription-manager:28360:MainThread @cert_sorter.py:205 - Product status: valid_products= partial_products= expired_products= unentitled_producs=69 future_products= valid_until=None
2017-05-09 03:59:43,905 [INFO] rhsmd:26295:MainThread @connection.py:780 - Connection built: host=subscription.rhsm.stage.redhat.com port=443 handler=/subscription auth=identity_cert ca_dir=/etc/rhsm/ca/ insecure=False
2017-05-09 03:59:44,532 [INFO] rhsmd:26295:MainThread @connection.py:520 - Response: status=200, requestUuid=15bb9d3f-f5c5-4144-abff-a225cde52c9e, request="GET /subscription/consumers/f4a4b498-4167-4535-aa3e-ca0f70692222/compliance"

^^ Observed that now request UUIDS are printed in the rhsm.log with "INFO" level

Moving the bug to Verified!!

Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory, and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://access.redhat.com/errata/RHBA-2017:2083