2270529 – [rgw][s3-tests]: test_object_anon_put_write_access failed with "An error occurred (XAmzContentSHA256Mismatch) when calling the PutObject operation"

Bug 2270529 - [rgw][s3-tests]: test_object_anon_put_write_access failed with "An error occurred (XAmzContentSHA256Mismatch) when calling the PutObject operation"

Summary: [rgw][s3-tests]: test_object_anon_put_write_access failed with "An error occu...

Keywords:
Status:	CLOSED ERRATA
Alias:	None
Product:	Red Hat Ceph Storage
Classification:	Red Hat Storage
Component:	RGW
Sub Component:
Version:	7.0
Hardware:	Unspecified
OS:	Unspecified
Priority:	unspecified
Severity:	high
Target Milestone:	---
Target Release:	7.0z2
Assignee:	Matt Benjamin (redhat)
QA Contact:	Hemanth Sai
Docs Contact:	Disha Walvekar
URL:
Whiteboard:
Depends On:	2266411
Blocks:	2267614 2270485 2298578 2298579
TreeView+	depends on / blocked

Reported:	2024-03-20 19:56 UTC by Matt Benjamin (redhat)
Modified:	2024-11-16 04:25 UTC (History)
CC List:	8 users (show)
Fixed In Version:	ceph-18.2.0-190.el9cp
Doc Type:	Bug Fix
Doc Text:	Previously, one valid-form of 0-length trailing chunk boundary formatting was not handled. Due to this, RGW failed to correctly recognize the start of the trailing chunk, leading to the 403 error. With this fix, improved trailing chunk boundary detection is implemented and the unexpected 403 error in the anonymous access case no longer reproduces.
Clone Of:	2266411
Environment:
Last Closed:	2024-05-07 12:09:25 UTC
Embargoed:
Dependent Products:

Attachments	(Terms of Use)

Links
System	ID	Private	Priority	Status	Summary	Last Updated
Red Hat Issue Tracker	RHCEPH-8581	0	None	None	None	2024-03-20 19:57:19 UTC
Red Hat Product Errata	RHBA-2024:2743	0	None	None	None	2024-05-07 12:09:31 UTC

Description Matt Benjamin (redhat) 2024-03-20 19:56:45 UTC

+++ This bug was initially created as a clone of Bug #2266411 +++

Description of problem:
s3-tests: test_object_anon_put_write_access failed with "botocore.exceptions.ClientError: An error occurred (XAmzContentSHA256Mismatch) when calling the PutObject operation: None"


2024-02-12 14:07:14,339 (cephci.test_s3) [DEBUG] - cephci.Weekly.rgw.23.cephci.ceph.ceph.py:1528 - b'=================================== FAILURES ==================================='
2024-02-12 14:07:14,339 (cephci.test_s3) [DEBUG] - cephci.Weekly.rgw.23.cephci.ceph.ceph.py:1528 - b'______________________ test_object_anon_put_write_access _______________________'
2024-02-12 14:07:14,340 (cephci.test_s3) [DEBUG] - cephci.Weekly.rgw.23.cephci.ceph.ceph.py:1528 - b''
2024-02-12 14:07:14,340 (cephci.test_s3) [DEBUG] - cephci.Weekly.rgw.23.cephci.ceph.ceph.py:1528 - b'    def test_object_anon_put_write_access():'
2024-02-12 14:07:14,341 (cephci.test_s3) [DEBUG] - cephci.Weekly.rgw.23.cephci.ceph.ceph.py:1528 - b"        bucket_name = _setup_bucket_acl('public-read-write')"
2024-02-12 14:07:14,342 (cephci.test_s3) [DEBUG] - cephci.Weekly.rgw.23.cephci.ceph.ceph.py:1528 - b'        client = get_client()'
2024-02-12 14:07:14,342 (cephci.test_s3) [DEBUG] - cephci.Weekly.rgw.23.cephci.ceph.ceph.py:1528 - b"        client.put_object(Bucket=bucket_name, Key='foo')"
2024-02-12 14:07:14,343 (cephci.test_s3) [DEBUG] - cephci.Weekly.rgw.23.cephci.ceph.ceph.py:1528 - b'    '
2024-02-12 14:07:14,343 (cephci.test_s3) [DEBUG] - cephci.Weekly.rgw.23.cephci.ceph.ceph.py:1528 - b'        unauthenticated_client = get_unauthenticated_client()'
2024-02-12 14:07:14,344 (cephci.test_s3) [DEBUG] - cephci.Weekly.rgw.23.cephci.ceph.ceph.py:1528 - b'    '
2024-02-12 14:07:14,345 (cephci.test_s3) [DEBUG] - cephci.Weekly.rgw.23.cephci.ceph.ceph.py:1528 - b">       response = unauthenticated_client.put_object(Bucket=bucket_name, Key='foo', Body='foo')"
2024-02-12 14:07:14,345 (cephci.test_s3) [DEBUG] - cephci.Weekly.rgw.23.cephci.ceph.ceph.py:1528 - b''
2024-02-12 14:07:14,346 (cephci.test_s3) [DEBUG] - cephci.Weekly.rgw.23.cephci.ceph.ceph.py:1528 - b's3tests_boto3/functional/test_s3.py:3393: '
2024-02-12 14:07:14,346 (cephci.test_s3) [DEBUG] - cephci.Weekly.rgw.23.cephci.ceph.ceph.py:1528 - b'_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ '
2024-02-12 14:07:14,347 (cephci.test_s3) [DEBUG] - cephci.Weekly.rgw.23.cephci.ceph.ceph.py:1528 - b'.tox/py/lib/python3.9/site-packages/botocore/client.py:514: in _api_call'
2024-02-12 14:07:14,347 (cephci.test_s3) [DEBUG] - cephci.Weekly.rgw.23.cephci.ceph.ceph.py:1528 - b'    return self._make_api_call(operation_name, kwargs)'
2024-02-12 14:07:14,348 (cephci.test_s3) [DEBUG] - cephci.Weekly.rgw.23.cephci.ceph.ceph.py:1528 - b'_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ '
2024-02-12 14:07:14,349 (cephci.test_s3) [DEBUG] - cephci.Weekly.rgw.23.cephci.ceph.ceph.py:1528 - b''
2024-02-12 14:07:14,349 (cephci.test_s3) [DEBUG] - cephci.Weekly.rgw.23.cephci.ceph.ceph.py:1528 - b'self = <botocore.client.S3 object at 0x7ff88e413340>'
2024-02-12 14:07:14,350 (cephci.test_s3) [DEBUG] - cephci.Weekly.rgw.23.cephci.ceph.ceph.py:1528 - b"operation_name = 'PutObject'"
2024-02-12 14:07:14,351 (cephci.test_s3) [DEBUG] - cephci.Weekly.rgw.23.cephci.ceph.ceph.py:1528 - b"api_params = {'Body': <_io.BytesIO object at 0x7ff88d319540>, 'Bucket': 'test-v8m6qqm4dx2oyev5bjz3fzmo-217', 'Key': 'foo'}"
2024-02-12 14:07:14,352 (cephci.test_s3) [DEBUG] - cephci.Weekly.rgw.23.cephci.ceph.ceph.py:1528 - b''
2024-02-12 14:07:14,352 (cephci.test_s3) [DEBUG] - cephci.Weekly.rgw.23.cephci.ceph.ceph.py:1528 - b'    def _make_api_call(self, operation_name, api_params):'
2024-02-12 14:07:14,353 (cephci.test_s3) [DEBUG] - cephci.Weekly.rgw.23.cephci.ceph.ceph.py:1528 - b'        operation_model = self._service_model.operation_model(operation_name)'
2024-02-12 14:07:14,353 (cephci.test_s3) [DEBUG] - cephci.Weekly.rgw.23.cephci.ceph.ceph.py:1528 - b'        service_name = self._service_model.service_name'
2024-02-12 14:07:14,354 (cephci.test_s3) [DEBUG] - cephci.Weekly.rgw.23.cephci.ceph.ceph.py:1528 - b'        history_recorder.record('
2024-02-12 14:07:14,355 (cephci.test_s3) [DEBUG] - cephci.Weekly.rgw.23.cephci.ceph.ceph.py:1528 - b"            'API_CALL',"
2024-02-12 14:07:14,355 (cephci.test_s3) [DEBUG] - cephci.Weekly.rgw.23.cephci.ceph.ceph.py:1528 - b'            {'
2024-02-12 14:07:14,356 (cephci.test_s3) [DEBUG] - cephci.Weekly.rgw.23.cephci.ceph.ceph.py:1528 - b"                'service': service_name,"
2024-02-12 14:07:14,356 (cephci.test_s3) [DEBUG] - cephci.Weekly.rgw.23.cephci.ceph.ceph.py:1528 - b"                'operation': operation_name,"
2024-02-12 14:07:14,357 (cephci.test_s3) [DEBUG] - cephci.Weekly.rgw.23.cephci.ceph.ceph.py:1528 - b"                'params': api_params,"
2024-02-12 14:07:14,358 (cephci.test_s3) [DEBUG] - cephci.Weekly.rgw.23.cephci.ceph.ceph.py:1528 - b'            },'
2024-02-12 14:07:14,358 (cephci.test_s3) [DEBUG] - cephci.Weekly.rgw.23.cephci.ceph.ceph.py:1528 - b'        )'
2024-02-12 14:07:14,359 (cephci.test_s3) [DEBUG] - cephci.Weekly.rgw.23.cephci.ceph.ceph.py:1528 - b'        if operation_model.deprecated:'
2024-02-12 14:07:14,359 (cephci.test_s3) [DEBUG] - cephci.Weekly.rgw.23.cephci.ceph.ceph.py:1528 - b'            logger.debug('
2024-02-12 14:07:14,360 (cephci.test_s3) [DEBUG] - cephci.Weekly.rgw.23.cephci.ceph.ceph.py:1528 - b"                'Warning: %s.%s() is deprecated', service_name, operation_name"
2024-02-12 14:07:14,360 (cephci.test_s3) [DEBUG] - cephci.Weekly.rgw.23.cephci.ceph.ceph.py:1528 - b'            )'
2024-02-12 14:07:14,361 (cephci.test_s3) [DEBUG] - cephci.Weekly.rgw.23.cephci.ceph.ceph.py:1528 - b'        request_context = {'
2024-02-12 14:07:14,362 (cephci.test_s3) [DEBUG] - cephci.Weekly.rgw.23.cephci.ceph.ceph.py:1528 - b"            'client_region': self.meta.region_name,"
2024-02-12 14:07:14,362 (cephci.test_s3) [DEBUG] - cephci.Weekly.rgw.23.cephci.ceph.ceph.py:1528 - b"            'client_config': self.meta.config,"
2024-02-12 14:07:14,363 (cephci.test_s3) [DEBUG] - cephci.Weekly.rgw.23.cephci.ceph.ceph.py:1528 - b"            'has_streaming_input': operation_model.has_streaming_input,"
2024-02-12 14:07:14,363 (cephci.test_s3) [DEBUG] - cephci.Weekly.rgw.23.cephci.ceph.ceph.py:1528 - b"            'auth_type': operation_model.auth_type,"
2024-02-12 14:07:14,364 (cephci.test_s3) [DEBUG] - cephci.Weekly.rgw.23.cephci.ceph.ceph.py:1528 - b'        }'
2024-02-12 14:07:14,365 (cephci.test_s3) [DEBUG] - cephci.Weekly.rgw.23.cephci.ceph.ceph.py:1528 - b'        request_dict = self._convert_to_request_dict('
2024-02-12 14:07:14,365 (cephci.test_s3) [DEBUG] - cephci.Weekly.rgw.23.cephci.ceph.ceph.py:1528 - b'            api'
2024-02-12 14:07:14,366 (cephci.test_s3) [DEBUG] - cephci.Weekly.rgw.23.cephci.ceph.ceph.py:1528 - b'_params, operation_model, context=request_context'
2024-02-12 14:07:14,366 (cephci.test_s3) [DEBUG] - cephci.Weekly.rgw.23.cephci.ceph.ceph.py:1528 - b'        )'
2024-02-12 14:07:14,367 (cephci.test_s3) [DEBUG] - cephci.Weekly.rgw.23.cephci.ceph.ceph.py:1528 - b'        resolve_checksum_context(request_dict, operation_model, api_params)'
2024-02-12 14:07:14,368 (cephci.test_s3) [DEBUG] - cephci.Weekly.rgw.23.cephci.ceph.ceph.py:1528 - b'    '
2024-02-12 14:07:14,368 (cephci.test_s3) [DEBUG] - cephci.Weekly.rgw.23.cephci.ceph.ceph.py:1528 - b'        service_id = self._service_model.service_id.hyphenize()'
2024-02-12 14:07:14,369 (cephci.test_s3) [DEBUG] - cephci.Weekly.rgw.23.cephci.ceph.ceph.py:1528 - b'        handler, event_response = self.meta.events.emit_until_response('
2024-02-12 14:07:14,369 (cephci.test_s3) [DEBUG] - cephci.Weekly.rgw.23.cephci.ceph.ceph.py:1528 - b"            'before-call.{service_id}.{operation_name}'.format("
2024-02-12 14:07:14,370 (cephci.test_s3) [DEBUG] - cephci.Weekly.rgw.23.cephci.ceph.ceph.py:1528 - b'                service_id=service_id, operation_name=operation_name'
2024-02-12 14:07:14,370 (cephci.test_s3) [DEBUG] - cephci.Weekly.rgw.23.cephci.ceph.ceph.py:1528 - b'            ),'
2024-02-12 14:07:14,371 (cephci.test_s3) [DEBUG] - cephci.Weekly.rgw.23.cephci.ceph.ceph.py:1528 - b'            model=operation_model,'
2024-02-12 14:07:14,372 (cephci.test_s3) [DEBUG] - cephci.Weekly.rgw.23.cephci.ceph.ceph.py:1528 - b'            params=request_dict,'
2024-02-12 14:07:14,372 (cephci.test_s3) [DEBUG] - cephci.Weekly.rgw.23.cephci.ceph.ceph.py:1528 - b'            request_signer=self._request_signer,'
2024-02-12 14:07:14,373 (cephci.test_s3) [DEBUG] - cephci.Weekly.rgw.23.cephci.ceph.ceph.py:1528 - b'            context=request_context,'
2024-02-12 14:07:14,373 (cephci.test_s3) [DEBUG] - cephci.Weekly.rgw.23.cephci.ceph.ceph.py:1528 - b'        )'
2024-02-12 14:07:14,374 (cephci.test_s3) [DEBUG] - cephci.Weekly.rgw.23.cephci.ceph.ceph.py:1528 - b'    '
2024-02-12 14:07:14,375 (cephci.test_s3) [DEBUG] - cephci.Weekly.rgw.23.cephci.ceph.ceph.py:1528 - b'        if event_response is not None:'
2024-02-12 14:07:14,375 (cephci.test_s3) [DEBUG] - cephci.Weekly.rgw.23.cephci.ceph.ceph.py:1528 - b'            http, parsed_response = event_response'
2024-02-12 14:07:14,376 (cephci.test_s3) [DEBUG] - cephci.Weekly.rgw.23.cephci.ceph.ceph.py:1528 - b'        else:'
2024-02-12 14:07:14,376 (cephci.test_s3) [DEBUG] - cephci.Weekly.rgw.23.cephci.ceph.ceph.py:1528 - b'            apply_request_checksum(request_dict)'
2024-02-12 14:07:14,377 (cephci.test_s3) [DEBUG] - cephci.Weekly.rgw.23.cephci.ceph.ceph.py:1528 - b'            http, parsed_response = self._make_request('
2024-02-12 14:07:14,377 (cephci.test_s3) [DEBUG] - cephci.Weekly.rgw.23.cephci.ceph.ceph.py:1528 - b'                operation_model, request_dict, request_context'
2024-02-12 14:07:14,378 (cephci.test_s3) [DEBUG] - cephci.Weekly.rgw.23.cephci.ceph.ceph.py:1528 - b'            )'
2024-02-12 14:07:14,379 (cephci.test_s3) [DEBUG] - cephci.Weekly.rgw.23.cephci.ceph.ceph.py:1528 - b'    '
2024-02-12 14:07:14,379 (cephci.test_s3) [DEBUG] - cephci.Weekly.rgw.23.cephci.ceph.ceph.py:1528 - b'        self.meta.events.emit('
2024-02-12 14:07:14,380 (cephci.test_s3) [DEBUG] - cephci.Weekly.rgw.23.cephci.ceph.ceph.py:1528 - b"            'after-call.{service_id}.{operation_name}'.format("
2024-02-12 14:07:14,380 (cephci.test_s3) [DEBUG] - cephci.Weekly.rgw.23.cephci.ceph.ceph.py:1528 - b'                service_id=service_id, operat'
2024-02-12 14:07:14,381 (cephci.test_s3) [DEBUG] - cephci.Weekly.rgw.23.cephci.ceph.ceph.py:1528 - b'ion_name=operation_name'
2024-02-12 14:07:14,381 (cephci.test_s3) [DEBUG] - cephci.Weekly.rgw.23.cephci.ceph.ceph.py:1528 - b'            ),'
2024-02-12 14:07:14,382 (cephci.test_s3) [DEBUG] - cephci.Weekly.rgw.23.cephci.ceph.ceph.py:1528 - b'            http_response=http,'
2024-02-12 14:07:14,383 (cephci.test_s3) [DEBUG] - cephci.Weekly.rgw.23.cephci.ceph.ceph.py:1528 - b'            parsed=parsed_response,'
2024-02-12 14:07:14,383 (cephci.test_s3) [DEBUG] - cephci.Weekly.rgw.23.cephci.ceph.ceph.py:1528 - b'            model=operation_model,'
2024-02-12 14:07:14,384 (cephci.test_s3) [DEBUG] - cephci.Weekly.rgw.23.cephci.ceph.ceph.py:1528 - b'            context=request_context,'
2024-02-12 14:07:14,384 (cephci.test_s3) [DEBUG] - cephci.Weekly.rgw.23.cephci.ceph.ceph.py:1528 - b'        )'
2024-02-12 14:07:14,385 (cephci.test_s3) [DEBUG] - cephci.Weekly.rgw.23.cephci.ceph.ceph.py:1528 - b'    '
2024-02-12 14:07:14,386 (cephci.test_s3) [DEBUG] - cephci.Weekly.rgw.23.cephci.ceph.ceph.py:1528 - b'        if http.status_code >= 300:'
2024-02-12 14:07:14,387 (cephci.test_s3) [DEBUG] - cephci.Weekly.rgw.23.cephci.ceph.ceph.py:1528 - b'            error_code = parsed_response.get("Error", {}).get("Code")'
2024-02-12 14:07:14,387 (cephci.test_s3) [DEBUG] - cephci.Weekly.rgw.23.cephci.ceph.ceph.py:1528 - b'            error_class = self.exceptions.from_code(error_code)'
2024-02-12 14:07:14,388 (cephci.test_s3) [DEBUG] - cephci.Weekly.rgw.23.cephci.ceph.ceph.py:1528 - b'>           raise error_class(parsed_response, operation_name)'
2024-02-12 14:07:14,388 (cephci.test_s3) [DEBUG] - cephci.Weekly.rgw.23.cephci.ceph.ceph.py:1528 - b'E           botocore.exceptions.ClientError: An error occurred (XAmzContentSHA256Mismatch) when calling the PutObject operation: None'
2024-02-12 14:07:14,389 (cephci.test_s3) [DEBUG] - cephci.Weekly.rgw.23.cephci.ceph.ceph.py:1528 - b''
2024-02-12 14:07:14,390 (cephci.test_s3) [DEBUG] - cephci.Weekly.rgw.23.cephci.ceph.ceph.py:1528 - b'.tox/py/lib/python3.9/site-packages/botocore/client.py:938: ClientError'






failure logs on 7.0 and 7.1:

http://magna002.ceph.redhat.com/cephci-jenkins/test-runs/18.2.0-152/Weekly/rgw/25/sanity_rgw/execute_s3tests_0.log

http://magna006.ceph.redhat.com/cephci-jenkins/test-runs/18.2.1-11/Weekly/rgw/23/sanity_rgw/execute_s3tests_0.log



pass logs on pacific and quincy:

http://magna002.ceph.redhat.com/cephci-jenkins/test-runs/16.2.10-248/Weekly/rgw/11/tier-2_rgw_ssl_s3tests/execute_s3tests_0.log

http://magna002.ceph.redhat.com/cephci-jenkins/test-runs/16.2.10-248/Weekly/rgw/11/tier-2_rgw_regression/execute_s3tests_0.log

http://magna002.ceph.redhat.com/cephci-jenkins/test-runs/17.2.6-196/Weekly/rgw/24/tier-2_rgw_regression/execute_s3tests_0.log

http://magna002.ceph.redhat.com/cephci-jenkins/test-runs/17.2.6-196/Weekly/rgw/24/tier-2_rgw_ssl_s3tests/execute_s3tests_0.log


Version-Release number of selected component (if applicable):
ceph Version 18.2.0-152.el9cp

How reproducible:
always

Steps to Reproduce:
1.deploy rhcs cluster 7.0 with rgw daemon
2.clone and configure s3tests repo
3.execute s3tests

Actual results:
test_object_anon_put_write_access failed with XAmzContentSHA256Mismatch

Expected results:
expected the test passed

Additional info:

--- Additional comment from RHEL Program Management on 2024-02-27 19:00:07 UTC ---

This bug report has Keywords: Regression or TestBlocker.

Since no regressions or test blockers are allowed between releases, it is being proposed as a blocker for this release.

Please resolve \triage ASAP.

--- Additional comment from Matt Benjamin (redhat) on 2024-03-19 15:14:55 UTC ---

This should be retested with the most recent 7.1 baseline.

Matt

--- Additional comment from errata-xmlrpc on 2024-03-19 15:25:16 UTC ---

This bug has been added to advisory RHBA-2024:126567 by Thomas Serlin (tserlin)

--- Additional comment from errata-xmlrpc on 2024-03-19 15:25:17 UTC ---

Bug report changed to ON_QA status by Errata System.
A QE request has been submitted for advisory RHBA-2024:126567-01
https://errata.engineering.redhat.com/advisory/126567

--- Additional comment from errata-xmlrpc on 2024-03-19 15:25:29 UTC ---

This bug has been added to advisory RHBA-2024:126567 by Thomas Serlin (tserlin)

--- Additional comment from Matt Benjamin (redhat) on 2024-03-20 19:37:36 UTC ---

oops!

I completed this upstream but had not backported the fix for 7.1, so I'm updating here

commit 8d18a83ccc29de79b745bb103c891436059c498e (HEAD -> ceph-7.1-rhel-patches, rhgitlab/ceph-7.1-rhel-patches)
Author: matt benjamin <mbenjamin>
Date:   Sat Mar 2 13:49:52 2024 -0500

    rgw_sigv4: handle '0;' as trailer-chunk boundary
    
    https://tracker.ceph.com/issues/64676
    Resolves: rhbz#2266411
    
    Signed-off-by: matt benjamin <mbenjamin>
    (cherry picked from commit ef1111a17084f6672fd40e366f92f8168a09d0a0)

Comment 11 errata-xmlrpc 2024-05-07 12:09:25 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 (Red Hat Ceph Storage 7.0 Bug Fix 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-2024:2743

Comment 12 Red Hat Bugzilla 2024-11-16 04:25:32 UTC

The needinfo request[s] on this closed bug have been removed as they have been unresolved for 120 days

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