Bug 2026320

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 9 Reporter: Rehana <redakkan>
Component: subscription-managerAssignee: Pino Toscano <ptoscano>
Status: CLOSED ERRATA QA Contact: Red Hat subscription-manager QE Team <rhsm-qe>
Severity: high Docs Contact:
Priority: high    
Version: 9.0CC: arpandey, candlepin-bugs, cdonnell, nmoumoul, rhsm-qe
Target Milestone: rcKeywords: Triaged
Target Release: 9.0   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: subscription-manager-1.29.23-1.el9 Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: 2024589 Environment:
Last Closed: 2022-05-17 15:58:19 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: 2024589    
Bug Blocks:    
Deadline: 2022-01-11   

Description Rehana 2021-11-24 11:10:58 UTC 
+++ This bug was initially created as a clone of Bug #2024589 +++

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)
Comment 3 Archana Pandey 2022-01-17 17:27:50 UTC 
Pre-verification

Reproducing the issue on subscription-manager: 1.29.7-1.el9

[root@kvm-03-guest22 ~]# subscription-manager version
server type: This system is currently not registered.
subscription management server: 3.2.21-1
subscription management rules: 5.41
subscription-manager: 1.29.7-1.el9
[root@kvm-03-guest22 ~]# 
[root@kvm-03-guest22 ~]# subscription-manager register --username rhel9GA --password *******
Registering to: subscription.rhsm.stage.redhat.com:443/subscription
The system has been registered with ID: fcc3eadb-5aeb-4351-a674-ebaccb10fbc0
The registered system name is: kvm-03-guest22.lab.eng.rdu2.redhat.com

[root@kvm-03-guest22 ~]# cut -d ',' -f1 /var/lib/rhsm/cache/content_access.json
{"lastUpdate": "2022-01-17T16:50:32+0000"             <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<< remember the value for lastUpdate to verify with If-Modified-Since header

[root@kvm-03-guest22 ~]# 
[root@kvm-03-guest22 ~]# export SUBMAN_DEBUG_PRINT_REQUEST=1 SUBMAN_DEBUG_PRINT_REQUEST_HEADER=1
[root@kvm-03-guest22 ~]# 
[root@kvm-03-guest22 ~]# subscription-manager refresh
<output cropped>
Making request: subscription.rhsm.stage.redhat.com:443 GET /subscription/consumers/fcc3eadb-5aeb-4351-a674-ebaccb10fbc0/accessible_content {'Content-type': 'application/json', 'Accept': 'application/json', 'x-subscription-manager-version': '1.29.7-1.el9', 'X-Correlation-ID': 'e1cd5a2bcd1f49159a58676bdbf12dc4', 'Accept-Language': 'en-us', 'User-Agent': 'RHSM/1.0 (cmd=subscription-manager) subscription-manager/1.29.7-1.el9', 'Content-Length': '0', 'If-Modified-Since': 'Mon, 17 Jan 2022 15:50:32 GMT'}
                                                                                                                               ^^^^^ notice the time difference, subman is sending the date to be 1 hour earlier than what the cache says, 

============================================================

verifying issue on jenkins build of sub-man

[root@kvm-03-guest22 ~]# rpm -qa subscription-manager
subscription-manager-1.29.23-1.git.0.e927a6c.el9.x86_64
[root@kvm-03-guest22 ~]# subscription-manager refresh

Making request: subscription.rhsm.stage.redhat.com:443 GET /subscription/consumers/fcc3eadb-5aeb-4351-a674-ebaccb10fbc0/certificates/serials {'Content-type': 'application/json', 'Accept': 'application/json', 'x-subscription-manager-version': '1.29.23-1.git.0.e927a6c.el9', 'X-Correlation-ID': 'd974c339f0a54de186e1b8156969c769', 'Accept-Language': 'en-us', 'User-Agent': 'RHSM/1.0 (cmd=subscription-manager) subscription-manager/1.29.23-1.git.0.e927a6c.el9', '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.29.23-1.git.0.e927a6c.el9', 'X-Correlation-ID': 'd974c339f0a54de186e1b8156969c769', 'Accept-Language': 'en-us', 'User-Agent': 'RHSM/1.0 (cmd=subscription-manager) subscription-manager/1.29.23-1.git.0.e927a6c.el9', 'Content-Length': '0'}


Making request: subscription.rhsm.stage.redhat.com:443 GET /subscription/consumers/fcc3eadb-5aeb-4351-a674-ebaccb10fbc0/accessible_content {'Content-type': 'application/json', 'Accept': 'application/json', 'x-subscription-manager-version': '1.29.23-1.git.0.e927a6c.el9', 'X-Correlation-ID': 'd974c339f0a54de186e1b8156969c769', 'Accept-Language': 'en-us', 'User-Agent': 'RHSM/1.0 (cmd=subscription-manager) subscription-manager/1.29.23-1.git.0.e927a6c.el9', 'Content-Length': '0', 'If-Modified-Since': 'Mon, 17 Jan 2022 16:50:32 GMT'}
                                                                                                                                                       ^^^^^ correct time reported
All local data refreshed

<output cropped>

Actual Results and expected results are same here, subman is sending the date correct date time.

Based on above observation setting verified field to tested.
Comment 6 Archana Pandey 2022-01-31 08:01:58 UTC 
Verifying on nightly build  with sub-man version subscription-manager-1.29.23-1.el9.x86_64

Beaker Test information:
                         HOSTNAME=dell-per630-fc-01.dell2.lab.eng.bos.redhat.com
                            JOBID=6244150
                         RECIPEID=11377664
                    RESULT_SERVER=
                           DISTRO=RHEL-9.0.0-20220125.3
                     ARCHITECTURE=x86_64


[root@dell-per630-fc-01 ~]# subscription-manager version
server type: This system is currently not registered.
subscription management server: 3.2.22-1
subscription management rules: 5.41
subscription-manager: 1.29.23-1.el9

[root@dell-per630-fc-01 ~]# rpm -qa --changelog subscription-manager | grep 2026320
- 2026320: fix format of HTTP-date headers (ptoscano)
- 2026320: fix format of HTTP-date headers (ptoscano)
[root@dell-per630-fc-01 ~]# 


[root@dell-per630-fc-01 ~]# subscription-manager register --username rhel9GA --password *****
Registering to: subscription.rhsm.stage.redhat.com:443/subscription
The system has been registered with ID: 90f92978-3e21-4e51-bf3b-4018a01bbd5f
The registered system name is: dell-per630-fc-01.dell2.lab.eng.bos.redhat.com
[root@dell-per630-fc-01 ~]#

[root@dell-per630-fc-01 ~]# 
[root@dell-per630-fc-01 ~]# cut -d ',' -f1 /var/lib/rhsm/cache/content_access.json
{"lastUpdate": "2022-01-31T07:39:32+0000"

[root@dell-per630-fc-01 ~]# export SUBMAN_DEBUG_PRINT_REQUEST=1 SUBMAN_DEBUG_PRINT_REQUEST_HEADER=1
[root@dell-per630-fc-01 ~]# subscription-manager refresh

Making request: subscription.rhsm.stage.redhat.com:443 GET /subscription/consumers/90f92978-3e21-4e51-bf3b-4018a01bbd5f/certificates/serials {'Content-type': 'application/json', 'Accept': 'application/json', 'x-subscription-manager-version': '1.29.23-1.el9', 'X-Correlation-ID': '7d0e4acc739340c9816425a2fdf5664a', 'Accept-Language': 'en-us', 'User-Agent': 'RHSM/1.0 (cmd=subscription-manager) subscription-manager/1.29.23-1.el9', '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.29.23-1.el9', 'X-Correlation-ID': '7d0e4acc739340c9816425a2fdf5664a', 'Accept-Language': 'en-us', 'User-Agent': 'RHSM/1.0 (cmd=subscription-manager) subscription-manager/1.29.23-1.el9', 'Content-Length': '0'}


Making request: subscription.rhsm.stage.redhat.com:443 GET /subscription/consumers/90f92978-3e21-4e51-bf3b-4018a01bbd5f/accessible_content {'Content-type': 'application/json', 'Accept': 'application/json', 'x-subscription-manager-version': '1.29.23-1.el9', 'X-Correlation-ID': '7d0e4acc739340c9816425a2fdf5664a', 'Accept-Language': 'en-us', 'User-Agent': 'RHSM/1.0 (cmd=subscription-manager) subscription-manager/1.29.23-1.el9', 'Content-Length': '0', 'If-Modified-Since': 'Mon, 31 Jan 2022 07:39:32 GMT'}
                                                                                                        ^^^^^^^^^-------------------------------------header shows correct time
All local data refreshed

Making request: subscription.rhsm.stage.redhat.com:443 GET /subscription/consumers/90f92978-3e21-4e51-bf3b-4018a01bbd5f/compliance {'Content-type': 'application/json', 'Accept': 'application/json', 'x-subscription-manager-version': '1.29.23-1.el9', 'X-Correlation-ID': '7d0e4acc739340c9816425a2fdf5664a', 'Accept-Language': 'en-us', 'User-Agent': 'RHSM/1.0 (cmd=subscription-manager) subscription-manager/1.29.23-1.el9', 'Content-Length': '0'}


Making request: subscription.rhsm.stage.redhat.com:443 GET /subscription/consumers/90f92978-3e21-4e51-bf3b-4018a01bbd5f/compliance {'Content-type': 'application/json', 'Accept': 'application/json', 'x-subscription-manager-version': '1.29.23-1.el9', 'X-Correlation-ID': '7d0e4acc739340c9816425a2fdf5664a', 'Accept-Language': 'en-us', 'User-Agent': 'RHSM/1.0 (cmd=subscription-manager) subscription-manager/1.29.23-1.el9', 'Content-Length': '0'}


Making request: subscription.rhsm.stage.redhat.com:443 GET /subscription/consumers/90f92978-3e21-4e51-bf3b-4018a01bbd5f/compliance {'Content-type': 'application/json', 'Accept': 'application/json', 'x-subscription-manager-version': '1.29.23-1.el9', 'X-Correlation-ID': '7d0e4acc739340c9816425a2fdf5664a', 'Accept-Language': 'en-us', 'User-Agent': 'RHSM/1.0 (cmd=subscription-manager) subscription-manager/1.29.23-1.el9', 'Content-Length': '0'}


Making request: subscription.rhsm.stage.redhat.com:443 GET /subscription/consumers/90f92978-3e21-4e51-bf3b-4018a01bbd5f/compliance {'Content-type': 'application/json', 'Accept': 'application/json', 'x-subscription-manager-version': '1.29.23-1.el9', 'X-Correlation-ID': '7d0e4acc739340c9816425a2fdf5664a', 'Accept-Language': 'en-us', 'User-Agent': 'RHSM/1.0 (cmd=subscription-manager) subscription-manager/1.29.23-1.el9', 'Content-Length': '0'}

[root@dell-per630-fc-01 ~]# 

Actual Results:
'If-Modified-Since': 'Mon, 31 Jan 2022 07:39:32 GMT'

Expected Results:
'If-Modified-Since': 'Mon, 31 Jan 2022 07:39:32 GMT'

Verification : Passed
Comment 8 errata-xmlrpc 2022-05-17 15:58:19 UTC 
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 (new packages: subscription-manager), 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:3984