Bug 2024589
| Summary: | client assumes SCA cert 'lastUpdate' date is in it's local timezone, then thinks it re-converts to UTC | |||
|---|---|---|---|---|
| Product: | Red Hat Enterprise Linux 8 | Reporter: | Nikos Moumoulidis <nmoumoul> | |
| Component: | subscription-manager | Assignee: | Pino Toscano <ptoscano> | |
| Status: | CLOSED ERRATA | QA Contact: | Red Hat subscription-manager QE Team <rhsm-qe> | |
| Severity: | high | Docs Contact: | ||
| Priority: | high | |||
| Version: | 8.4 | CC: | arpandey, cdonnell, redakkan | |
| Target Milestone: | rc | Keywords: | Triaged | |
| Target Release: | 8.6 | Flags: | pm-rhel:
mirror+
|
|
| Hardware: | Unspecified | |||
| OS: | Unspecified | |||
| Whiteboard: | ||||
| Fixed In Version: | subscription-manager-1.28.25-1.el8 | Doc Type: | If docs needed, set a value | |
| Doc Text: | Story Points: | --- | ||
| Clone Of: | ||||
| : | 2026320 (view as bug list) | Environment: | ||
| Last Closed: | 2022-05-10 15:22:58 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: | 2024573 | |||
| Bug Blocks: | 2026316, 2026320 | |||
pre-verification:
reproducer on subscription-manager-1.28.16-1.el8.x86_64
[root@kvm-01-guest11 ~]# rpm -qa subscription-manager
subscription-manager-1.28.16-1.el8.x86_64
[root@kvm-01-guest11 ~]#
[root@kvm-01-guest11 ~]# timedatectl set-timezone Europe/Paris <<<< can be set to any time zone east to UTC as mentioned in bug description
[root@kvm-01-guest11 ~]# subscription-manager register --username rhel9GA --password *****
Registering to: subscription.rhsm.stage.redhat.com:443/subscription
The system has been registered with ID: 32ee0e69-4e58-4920-926d-e391bf3382c7
The registered system name is: kvm-01-guest11.lab.eng.rdu2.redhat.com
[root@kvm-01-guest11 ~]#
[root@kvm-01-guest11 ~]# cut -d ',' -f1 /var/lib/rhsm/cache/content_access.json
{"lastUpdate": "2022-01-20T15:33:28+0000" <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<< date time present in cache
[root@kvm-01-guest11 ~]#
[root@kvm-01-guest11 ~]# export SUBMAN_DEBUG_PRINT_REQUEST=1 SUBMAN_DEBUG_PRINT_REQUEST_HEADER=1
[root@kvm-01-guest11 ~]#
[root@kvm-01-guest11 ~]# subscription-manager refresh
<output omitted>
Making request: subscription.rhsm.stage.redhat.com:443 GET /subscription/consumers/32ee0e69-4e58-4920-926d-e391bf3382c7/accessible_content {'Content-type': 'application/json', 'Accept': 'application/json', 'x-subscription-manager-version': '1.28.16-1.el8', 'X-Correlation-ID': '84db3ad06767417887632bfe79e6f4e6', 'Accept-Language': 'en-us', 'User-Agent': 'RHSM/1.0 (cmd=subscription-manager) subscription-manager/1.28.16-1.el8', 'Content-Length': '0', 'If-Modified-Since': 'Thu, 20 Jan 2022 14:33:28 GMT'}
^^^^---------.-----time difference, subman is sending the date to be 1 hour earlier than what the cache says,
<output omitted>
===============================================================================
preverifying on jenkins build- subscription-manager-1.28.25-1.git.9.941b9d3.el8.x86_64
[root@kvm-01-guest11 ~]#
[root@kvm-01-guest11 ~]# yum upgrade subscription-manager
Updating Subscription Management repositories.
Red Hat Enterprise Linux 8 for x86_64 - AppStream Beta (RPMs) 3.6 MB/s | 10 MB 00:02
Red Hat Enterprise Linux 8 for x86_64 - BaseOS Beta (RPMs) 2.4 MB/s | 4.1 MB 00:01
Jenkins CI builds of Red Hat Subscription Manager for RHEL 143 kB/s | 32 kB 00:00
:
<output omitted>
:
Verifying : subscription-manager-rhsm-certificates-1.28.25-1.git.9.941b9d3.el8.x86_64 11/12
Verifying : subscription-manager-rhsm-certificates-1.28.16-1.el8.x86_64 12/12
Installed products updated.
Upgraded:
dnf-plugin-subscription-manager-1.28.25-1.git.9.941b9d3.el8.x86_64 python3-cloud-what-1.28.25-1.git.9.941b9d3.el8.x86_64
python3-subscription-manager-rhsm-1.28.25-1.git.9.941b9d3.el8.x86_64 python3-syspurpose-1.28.25-1.git.9.941b9d3.el8.x86_64
subscription-manager-1.28.25-1.git.9.941b9d3.el8.x86_64 subscription-manager-rhsm-certificates-1.28.25-1.git.9.941b9d3.el8.x86_64
Complete!
[root@kvm-01-guest11 ~]#
[root@kvm-01-guest11 ~]#
[root@kvm-01-guest11 ~]# subscription-manager refresh
Making request: subscription.rhsm.stage.redhat.com:443 GET /subscription/consumers/32ee0e69-4e58-4920-926d-e391bf3382c7/certificates/serials {'Content-type': 'application/json', 'Accept': 'application/json', 'x-subscription-manager-version': '1.28.25-1.git.9.941b9d3.el8', 'X-Correlation-ID': '6b711c7ea1654ce684fe4db8768b5f5e', 'Accept-Language': 'en-us', 'User-Agent': 'RHSM/1.0 (cmd=subscription-manager) subscription-manager/1.28.25-1.git.9.941b9d3.el8', 'Content-Length': '0'}
Making request: subscription.rhsm.stage.redhat.com:443 GET /subscription/status {'Content-type': 'application/json', 'Accept': 'application/json', 'x-subscription-manager-version': '1.28.25-1.git.9.941b9d3.el8', 'X-Correlation-ID': '6b711c7ea1654ce684fe4db8768b5f5e', 'Accept-Language': 'en-us', 'User-Agent': 'RHSM/1.0 (cmd=subscription-manager) subscription-manager/1.28.25-1.git.9.941b9d3.el8', 'Content-Length': '0'}
Making request: subscription.rhsm.stage.redhat.com:443 GET /subscription/consumers/32ee0e69-4e58-4920-926d-e391bf3382c7/accessible_content {'Content-type': 'application/json', 'Accept': 'application/json', 'x-subscription-manager-version': '1.28.25-1.git.9.941b9d3.el8', 'X-Correlation-ID': '6b711c7ea1654ce684fe4db8768b5f5e', 'Accept-Language': 'en-us', 'User-Agent': 'RHSM/1.0 (cmd=subscription-manager) subscription-manager/1.28.25-1.git.9.941b9d3.el8', 'Content-Length': '0', 'If-Modified-Since': 'Thu, 20 Jan 2022 15:33:28 GMT'}
^^^^^^^ time matches the cache value
All local data refreshed
Making request: subscription.rhsm.stage.redhat.com:443 GET /subscription/consumers/32ee0e69-4e58-4920-926d-e391bf3382c7/compliance {'Content-type': 'application/json', 'Accept': 'application/json', 'x-subscription-manager-version': '1.28.25-1.git.9.941b9d3.el8', 'X-Correlation-ID': '6b711c7ea1654ce684fe4db8768b5f5e', 'Accept-Language': 'en-us', 'User-Agent': 'RHSM/1.0 (cmd=subscription-manager) subscription-manager/1.28.25-1.git.9.941b9d3.el8', 'Content-Length': '0'}
[root@kvm-01-guest11 ~]#
Actual Results and expected results are same here, subman is sending the date correct date time for refresh command.
Based on above observation setting verified field to tested.
Beaker Test information:
HOSTNAME=hpe-dl380pgen8-02-vm-16.hpe2.lab.eng.bos.redhat.com
JOBID=6324461
RECIPEID=11496978
RESULT_SERVER=
DISTRO=RHEL-8.6.0-20220220.3
ARCHITECTURE=x86_64
Steps to verify:
change system time anywhere east of UTC/GMT timezone
[root@hpe-dl380pgen8-02-vm-16 ~]#
[root@hpe-dl380pgen8-02-vm-16 ~]#
[root@hpe-dl380pgen8-02-vm-16 ~]# subscription-manager version
server type: Red Hat Subscription Management
subscription management server: 3.2.22-1
subscription management rules: 5.41
subscription-manager: 1.28.28-1.el8
[root@hpe-dl380pgen8-02-vm-16 ~]#
[root@hpe-dl380pgen8-02-vm-16 ~]# rpm -qa --changelog subscription-manager | grep 2024589
- 2024589: fix format of HTTP-date headers (ptoscano)
[root@hpe-dl380pgen8-02-vm-16 ~]#
[root@hpe-dl380pgen8-02-vm-16 ~]# subscription-manager register --username rhel9GA --password ******
Registering to: subscription.rhsm.stage.redhat.com:443/subscription
The system has been registered with ID: e02e7a1b-2e6b-40e1-9d96-5a3070c24cc1
The registered system name is: hpe-dl380pgen8-02-vm-16.hpe2.lab.eng.bos.redhat.com
[root@hpe-dl380pgen8-02-vm-16 ~]#
[root@hpe-dl380pgen8-02-vm-16 ~]#
[root@hpe-dl380pgen8-02-vm-16 ~]#
[root@hpe-dl380pgen8-02-vm-16 ~]# cut -d ',' -f1 /var/lib/rhsm/cache/content_access.json
{"lastUpdate": "2022-02-21T11:00:43+0000"
[root@hpe-dl380pgen8-02-vm-16 ~]# export SUBMAN_DEBUG_PRINT_REQUEST=1 SUBMAN_DEBUG_PRINT_REQUEST_HEADER=1
[root@hpe-dl380pgen8-02-vm-16 ~]#
[root@hpe-dl380pgen8-02-vm-16 ~]# subscription-manager refresh
Making request: subscription.rhsm.stage.redhat.com:443 GET /subscription/consumers/e02e7a1b-2e6b-40e1-9d96-5a3070c24cc1/certificates/serials {'Content-type': 'application/json', 'Accept': 'application/json', 'x-subscription-manager-version': '1.28.28-1.el8', 'X-Correlation-ID': '3f70973aff4943bf8cc1f707e6674f24', 'Accept-Language': 'en-us', 'User-Agent': 'RHSM/1.0 (cmd=subscription-manager) subscription-manager/1.28.28-1.el8', 'Content-Length': '0'}
Making request: subscription.rhsm.stage.redhat.com:443 GET /subscription/status {'Content-type': 'application/json', 'Accept': 'application/json', 'x-subscription-manager-version': '1.28.28-1.el8', 'X-Correlation-ID': '3f70973aff4943bf8cc1f707e6674f24', 'Accept-Language': 'en-us', 'User-Agent': 'RHSM/1.0 (cmd=subscription-manager) subscription-manager/1.28.28-1.el8', 'Content-Length': '0'}
Making request: subscription.rhsm.stage.redhat.com:443 GET /subscription/consumers/e02e7a1b-2e6b-40e1-9d96-5a3070c24cc1/accessible_content {'Content-type': 'application/json', 'Accept': 'application/json', 'x-subscription-manager-version': '1.28.28-1.el8', 'X-Correlation-ID': '3f70973aff4943bf8cc1f707e6674f24', 'Accept-Language': 'en-us', 'User-Agent': 'RHSM/1.0 (cmd=subscription-manager) subscription-manager/1.28.28-1.el8', 'Content-Length': '0', 'If-Modified-Since': 'Mon, 21 Feb 2022 11:00:43 GMT'}
^^^^^^^^^-----------------------header shows correct time
All local data refreshed
Actual Results:
'If-Modified-Since' and lastUpdate should show same datetime
Expected Results:
'If-Modified-Since' and lastUpdate shows same datetime
Verification : Passed
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 (subscription-manager bug fix and enhancement update), 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-2022:2047 |
Description of problem: subscription-manager assumes SCA cert's 'lastUpdate' date is in it's local timezone (wherever the client is), then thinks it is converting it to UTC, sending it back to Candlepin, and Candlepin thinks the client has an outdated version of the SCA cert, sending it back again (instead of sending back HTTP 304). Version-Release number of selected component (if applicable): 1.28.13-2.el8 1.29.18-1.fc33 How reproducible: 100% Note: Running this scenario with a client in any timezone other than UTC/GMT will lead to undesirable effects, but the exact effect I'm describing happens when you are anywhere east of UTC (so UTC+1, UTC+2..). Steps to Reproduce: 1. Make sure to run subscription-manager on a machine that is on anywhere east of UTC/GMT timezone. In this example, I am running this in UTC+1. 2. Register to an org with SCA mode 3. Validate that the /var/lib/rhsm/cache/content_access.json file is there, has content, and note the 'lastUpdate' in it, e.g. {"lastUpdate": "2021-11-18T11:12:49+0000"... This should be the date sent by Candlepin, which is in UTC/GMT (see the +0000 suffix which indicates that). 4. Run 'subman refresh' with the HTTP debug commands: SUBMAN_DEBUG_PRINT_REQUEST=1 SUBMAN_DEBUG_PRINT_REQUEST_HEADER=1 5. Check the HTTP debug output for the second call to /accessible_content, and specifically for the If-Modified-Since header value. Actual results: 'If-Modified-Since': 'Thu, 18 Nov 2021 10:12:49 GMT' (subman is sending the date to be 1 hour earlier than what the cache says) The actual effect is that the server will try to compare it to the date on the cert saved in the database (which should have been the same if the cert has not been regenerated), and server ends up thinking that it has a newer version of the cert, so it re-sends the cert back to the client, instead of sending back an HTTP 304 code. Expected results: 'If-Modified-Since': 'Thu, 18 Nov 2021 11:12:49 GMT' Additional info: Here is what I think happens: - Candlepin sends back SCA cert with lastUpdate set in UTC timezone (+0000) suffix. - subman saves that in the cache as-is. - Next time subman is calling /accessible_content, it reads the date from the cache, ignores the timezone suffix (+0000) and instead *assumes* it is local (to the client) time zone, tries to convert it to UTC, but in reality it just converts it to the wrong time. (in my case it shifts it down by 1 hour, because I am in UTC+1)