Bug 1305659

Summary: ospd-8 poodle 2016-02-04.1 tempest.api.object_storage.test_object_services.ObjectTest.test_update_object_metadata failing
Product: Red Hat OpenStack Reporter: Steve Linabery <slinaber>
Component: openstack-swiftAssignee: Pete Zaitcev <zaitcev>
Status: CLOSED WONTFIX QA Contact: nlevinki <nlevinki>
Severity: unspecified Docs Contact:
Priority: unspecified    
Version: 8.0 (Liberty)CC: derekh, sgotliv, yeylon, zaitcev
Target Milestone: gaKeywords: Automation, AutomationBlocker
Target Release: 8.0 (Liberty)   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2016-03-21 09:18:21 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:

Description Steve Linabery 2016-02-08 20:28:18 UTC 
Description of problem:
ospd-8 poodle 2016-02-04.1 tempest.api.object_storage.test_object_services.ObjectTest.test_update_object_metadata failing

Traceback (most recent call last):
testtools.testresult.real._StringException: Empty attachments:
  stderr
  stdout

pythonlogging:'': {{{
2016-02-08 12:37:13,471 26232 INFO     [tempest_lib.common.rest_client] Request (ObjectTest:test_update_object_metadata): 201 PUT http://172.16.23.110:8080/v1/AUTH_77fe649f61f641d5bdcaa4ddec37684c/tempest-TestContainer-1713534563/tempest-TestObject-1293458312 0.268s
2016-02-08 12:37:13,471 26232 DEBUG    [tempest_lib.common.rest_client] Request - Headers: {'Content-Type': 'application/json', 'Accept': 'application/json', 'X-Auth-Token': '<omitted>'}
        Body: test
    Response - Headers: {'status': '201', 'content-length': '0', 'last-modified': 'Mon, 08 Feb 2016 17:37:14 GMT', 'connection': 'close', 'etag': '098f6bcd4621d373cade4e832627b4f6', 'x-trans-id': 'txe4760bd3bec9490faca95-0056b8d249', 'date': 'Mon, 08 Feb 2016 17:37:13 GMT', 'content-type': 'text/html; charset=UTF-8'}
        Body: 
2016-02-08 12:37:13,537 26232 INFO     [tempest_lib.common.rest_client] Request (ObjectTest:test_update_object_metadata): 202 POST http://172.16.23.110:8080/v1/AUTH_77fe649f61f641d5bdcaa4ddec37684c/tempest-TestContainer-1713534563/tempest-TestObject-1293458312 0.065s
2016-02-08 12:37:13,537 26232 DEBUG    [tempest_lib.common.rest_client] Request - Headers: {'X-Object-Meta-test-meta': 'Meta', 'X-Auth-Token': '<omitted>'}
        Body: None
    Response - Headers: {'status': '202', 'content-length': '76', 'x-copied-from-last-modified': 'Mon, 08 Feb 2016 17:37:14 GMT', 'x-copied-from': 'tempest-TestContainer-1713534563/tempest-TestObject-1293458312', 'x-object-meta-test-meta': 'Meta', 'connection': 'close', 'x-trans-id': 'tx7e25733aea4c4392abe88-0056b8d248', 'date': 'Mon, 08 Feb 2016 17:37:12 GMT', 'x-copied-from-account': 'AUTH_77fe649f61f641d5bdcaa4ddec37684c', 'content-type': 'text/html; charset=UTF-8'}
        Body: <html><h1>Accepted</h1><p>The request is accepted for processing.</p></html>
2016-02-08 12:37:13,574 26232 INFO     [tempest_lib.common.rest_client] Request (ObjectTest:test_update_object_metadata): 200 HEAD http://172.16.23.110:8080/v1/AUTH_77fe649f61f641d5bdcaa4ddec37684c/tempest-TestContainer-1713534563/tempest-TestObject-1293458312 0.036s
2016-02-08 12:37:13,574 26232 DEBUG    [tempest_lib.common.rest_client] Request - Headers: {'Content-Type': 'application/json', 'Accept': 'application/json', 'X-Auth-Token': '<omitted>'}
        Body: None
    Response - Headers: {'status': '200', 'content-length': '4', 'content-location': 'http://172.16.23.110:8080/v1/AUTH_77fe649f61f641d5bdcaa4ddec37684c/tempest-TestContainer-1713534563/tempest-TestObject-1293458312', 'accept-ranges': 'bytes', 'last-modified': 'Mon, 08 Feb 2016 17:37:14 GMT', 'connection': 'close', 'etag': '098f6bcd4621d373cade4e832627b4f6', 'x-timestamp': '1454953033.21556', 'x-trans-id': 'tx4b7ef58e8725439faafe1-0056b8d249', 'date': 'Mon, 08 Feb 2016 17:37:13 GMT', 'content-type': 'application/json'}
        Body:
}}}

Traceback (most recent call last):
  File "/home/stack/tempest/tempest/api/object_storage/test_object_services.py", line 361, in test_update_object_metadata
    self.assertIn('x-object-meta-test-meta', resp)
  File "/usr/lib/python2.7/site-packages/testtools/testcase.py", line 356, in assertIn
    self.assertThat(haystack, Contains(needle), message)
  File "/usr/lib/python2.7/site-packages/testtools/testcase.py", line 435, in assertThat
    raise mismatch_error
testtools.matchers._impl.MismatchError: 'x-object-meta-test-meta' not in {'status': '200', 'content-length': '4', 'content-location': 'http://172.16.23.110:8080/v1/AUTH_77fe649f61f641d5bdcaa4ddec37684c/tempest-TestContainer-1713534563/tempest-TestObject-1293458312', 'accept-ranges': 'bytes', 'last-modified': 'Mon, 08 Feb 2016 17:37:14 GMT', 'connection': 'close', 'etag': '098f6bcd4621d373cade4e832627b4f6', 'x-timestamp': '1454953033.21556', 'x-trans-id': 'tx4b7ef58e8725439faafe1-0056b8d249', 'date': 'Mon, 08 Feb 2016 17:37:13 GMT', 'content-type': 'application/json'}
Comment 3 Pete Zaitcev 2016-02-16 20:00:17 UTC 
The problem appears to be that Tempest isn't getting the new headers
back until the copying is complete. For a complicated reason[1], Swift
defaults to post-as-copy: every POST request prompts copying of the
whole object. Thus, POST operation returns success to the user once
the copying is scheduled, but before it completes. In the meanwhile,
it's possible to fetch the old data. Tempest does that and fails
with a mismatch.

It's possible to configure a cluster to run so-called "fast-post"
by setting "object_post_as_copy = false" in proxy-server.conf.
But I'm sure the cluster is going to fail Tempest elsewhere too,
if it's too slow.

[1] https://review.openstack.org/135380