When uploading a file in swift using S3 api we get a stack trace in keystone

[Rodolphe Pineau]

OS Version : Ubuntu 12.04 beta 1
Keystone version : 2012.1
git commit version : 9feb00085f75ea2697fd2225e6003c2384904d08
Swift version is 1.4.8
When I'm uploading a file in swift using S3 API in Cyberduck , I get a stacktrace in keystone (the file get uploaded anyway) :

====================================================================================================
2012-03-22 13:12:42 DEBUG [keystone.common.wsgi] ******************** REQUEST ENVIRON ********************
2012-03-22 13:12:42 DEBUG [keystone.common.wsgi] SCRIPT_NAME = /v2.0
2012-03-22 13:12:42 DEBUG [keystone.common.wsgi] webob.adhoc_attrs = {'response': <Response at 0x36bff90 200 OK>}
2012-03-22 13:12:42 DEBUG [keystone.common.wsgi] REQUEST_METHOD = POST
2012-03-22 13:12:42 DEBUG [keystone.common.wsgi] PATH_INFO = /s3tokens
2012-03-22 13:12:42 DEBUG [keystone.common.wsgi] SERVER_PROTOCOL = HTTP/1.0
2012-03-22 13:12:42 DEBUG [keystone.common.wsgi] CONTENT_LENGTH = 315
2012-03-22 13:12:42 DEBUG [keystone.common.wsgi] eventlet.posthooks = []
2012-03-22 13:12:42 DEBUG [keystone.common.wsgi] SERVER_NAME = 192.168.244.27
2012-03-22 13:12:42 DEBUG [keystone.common.wsgi] REMOTE_ADDR = 192.168.240.13
2012-03-22 13:12:42 DEBUG [keystone.common.wsgi] eventlet.input = <eventlet.wsgi.Input object at 0x36bfa10>
2012-03-22 13:12:42 DEBUG [keystone.common.wsgi] wsgi.url_scheme = http
2012-03-22 13:12:42 DEBUG [keystone.common.wsgi] SERVER_PORT = 35357
2012-03-22 13:12:42 DEBUG [keystone.common.wsgi] wsgi.input = <_io.BytesIO object at 0x36afad0>
2012-03-22 13:12:42 DEBUG [keystone.common.wsgi] HTTP_HOST = 192.168.244.27:35357
2012-03-22 13:12:42 DEBUG [keystone.common.wsgi] wsgi.multithread = True
2012-03-22 13:12:42 DEBUG [keystone.common.wsgi] openstack.params = {u'credentials': {u'token': u'R0VUCgoKVGh1LCAyMiBNYXIgMjAxMiAyMToxMzoxMCBHTVQKL3Rlc3Qv', u'access': u'5126c1dd5ec341a1b0afa3f77cf12c7e', u'host': u'TEST-swift:8080', u'verb': u'GET', u'expire': u'Thu, 22 Mar 2012 21:13:10 GMT', u'signature': u'vASiSKg31WQnhsJg6kp2ZrSWxJo=', u'path': u'/v1/5126c1dd5ec341a1b0afa3f77cf12c7e/test'}}
2012-03-22 13:12:42 DEBUG [keystone.common.wsgi] wsgi.version = (1, 0)
2012-03-22 13:12:42 DEBUG [keystone.common.wsgi] openstack.context = {'token_id': None, 'is_admin': False}
2012-03-22 13:12:42 DEBUG [keystone.common.wsgi] GATEWAY_INTERFACE = CGI/1.1
2012-03-22 13:12:42 DEBUG [keystone.common.wsgi] wsgi.run_once = False
2012-03-22 13:12:42 DEBUG [keystone.common.wsgi] wsgi.errors = <open file '<stderr>', mode 'w' at 0x7f22e78cb270>
2012-03-22 13:12:42 DEBUG [keystone.common.wsgi] wsgi.multiprocess = False
2012-03-22 13:12:42 DEBUG [keystone.common.wsgi] webob.is_body_seekable = True
2012-03-22 13:12:42 DEBUG [keystone.common.wsgi] CONTENT_TYPE = application/json
2012-03-22 13:12:42 DEBUG [keystone.common.wsgi] HTTP_ACCEPT_ENCODING = identity
2012-03-22 13:12:42 DEBUG [keystone.common.wsgi]
2012-03-22 13:12:42 DEBUG [keystone.common.wsgi] ******************** REQUEST BODY ********************
2012-03-22 13:12:42 DEBUG [keystone.common.wsgi] {"credentials": {"host": "TEST-swift:8080", "access": "5126c1dd5ec341a1b0afa3f77cf12c7e", "token": "R0VUCgoKVGh1LCAyMiBNYXIgMjAxMiAyMToxMzoxMCBHTVQKL3Rlc3Qv", "verb": "GET", "expire": "Thu, 22 Mar 2012 21:13:10 GMT", "signature": "vASiSKg31WQnhsJg6kp2ZrSWxJo=", "path": "/v1/5126c1dd5ec341a1b0afa3f77cf12c7e/test"}}
2012-03-22 13:12:42 DEBUG [keystone.common.wsgi]
2012-03-22 13:12:42 DEBUG [routes.middleware] Matched POST /s3tokens
2012-03-22 13:12:42 DEBUG [routes.middleware] Route path: '{path_info:.*}', defaults: {'controller': <keystone.contrib.s3.core.S3Extension object at 0x31e8650>}
2012-03-22 13:12:42 DEBUG [routes.middleware] Match dict: {'controller': <keystone.contrib.s3.core.S3Extension object at 0x31e8650>, 'path_info': '/s3tokens'}
2012-03-22 13:12:42 DEBUG [routes.middleware] Matched POST /s3tokens
2012-03-22 13:12:42 DEBUG [routes.middleware] Route path: '/s3tokens', defaults: {'action': u'authenticate', 'controller': <keystone.contrib.s3.core.S3Controller object at 0x31e8750>}
2012-03-22 13:12:42 DEBUG [routes.middleware] Match dict: {'action': u'authenticate', 'controller': <keystone.contrib.s3.core.S3Controller object at 0x31e8750>}
2012-03-22 13:12:42 DEBUG [keystone.common.wsgi] arg_dict: {}
2012-03-22 13:12:42 ERROR [root] Not Authorized
Traceback (most recent call last):
  File "/usr/local/lib/python2.7/dist-packages/keystone-2012.1-py2.7.egg/keystone/common/wsgi.py", line 184, in __call__
    result = method(context, **params)
  File "/usr/local/lib/python2.7/dist-packages/keystone-2012.1-py2.7.egg/keystone/contrib/ec2/core.py", line 152, in authenticate
    self.check_signature(creds_ref, credentials)
  File "/usr/local/lib/python2.7/dist-packages/keystone-2012.1-py2.7.egg/keystone/contrib/s3/core.py", line 52, in check_signature
    raise Exception('Not Authorized')
Exception: Not Authorized
2012-03-22 13:12:42 DEBUG [keystone.common.wsgi] ******************** RESPONSE HEADERS ********************
2012-03-22 13:12:42 DEBUG [keystone.common.wsgi] Content-Type = application/json
2012-03-22 13:12:42 DEBUG [keystone.common.wsgi] Vary = X-Auth-Token
2012-03-22 13:12:42 DEBUG [keystone.common.wsgi] Content-Length = 158
2012-03-22 13:12:42 DEBUG [keystone.common.wsgi]
2012-03-22 13:12:42 DEBUG [keystone.common.wsgi] ******************** RESPONSE BODY ********************
2012-03-22 13:12:42 DEBUG [keystone.common.wsgi] {"error": {"message": "An unexpected error prevented the server from fulfilling your request. Not Authorized", "code": 500, "title": "Internal Server Error"}}
2012-03-22 13:12:42 DEBUG [eventlet.wsgi.server] 192.168.240.13 - - [22/Mar/2012 13:12:42] "POST /v2.0/s3tokens HTTP/1.1" 500 306 0.008429

this appears a few times for each upload.
In case this help here is the trace we then see in the swift logs :

====================================================================================================
Mar 22 14:23:59 swift-solo ?swift Connecting with tenant: 00a6a0c7cd5f4ab3909f374cf566f62b (txn: txcfd425d739ae4bb5b392268ed4c556ba)
Mar 22 14:23:59 swift-solo swift Using identity: {'roles': [u'Member', u'test'], 'user': u'tester', 'tenant': (u'00a6a0c7cd5f4ab3909f374cf566f62b', u'test')} (txn: txcfd425d739ae4bb5b392268ed4c556ba)
Mar 22 14:23:59 swift-solo swift allow user with role Member as account admin (txn: txcfd425d739ae4bb5b392268ed4c556ba) (client_ip: 192.168.240.10)
Mar 22 14:23:59 swift-solo account-server 192.168.240.13 - - [22/Mar/2012:21:23:59 +0000] "GET /sdb3/147724/AUTH_00a6a0c7cd5f4ab3909f374cf566f62b" 200 - "txcfd425d739ae4bb5b392268ed4c556ba" "-" "Cyberduck/4.2.1 (Mac OS X/10.6.8) (i386)" 0.0196 ""
Mar 22 14:23:59 swift-solo swift 192.168.240.10 192.168.240.10 22/Mar/2012/21/23/59 GET /v1/AUTH_00a6a0c7cd5f4ab3909f374cf566f62b%3Fformat%3Djson HTTP/1.0 200 - Cyberduck/4.2.1%20%28Mac%20OS%20X/10.6.8%29%20%28i386%29 a4614a8807c740d8a85f0215942922fb - 37 - txcfd425d739ae4bb5b392268ed4c556ba - 0.0803 -
Mar 22 14:23:59 swift-solo ?swift Connecting with tenant: 00a6a0c7cd5f4ab3909f374cf566f62b (txn: txcb9cb3623982490db348fafb04f10fc7) (client_ip: 192.168.240.10)
Mar 22 14:23:59 swift-solo swift Using identity: {'roles': [u'Member', u'test'], 'user': u'tester', 'tenant': (u'00a6a0c7cd5f4ab3909f374cf566f62b', u'test')} (txn: txcb9cb3623982490db348fafb04f10fc7) (client_ip: 192.168.240.10)
Mar 22 14:23:59 swift-solo swift allow user with role Member as account admin (txn: txcb9cb3623982490db348fafb04f10fc7) (client_ip: 192.168.240.10)
Mar 22 14:23:59 swift-solo account-server 192.168.240.13 - - [22/Mar/2012:21:23:59 +0000] "HEAD /sdb4/147724/AUTH_00a6a0c7cd5f4ab3909f374cf566f62b" 204 - "txcb9cb3623982490db348fafb04f10fc7" "-" "-" 0.0241 ""
Mar 22 14:23:59 swift-solo container-server 192.168.240.13 - - [22/Mar/2012:21:23:59 +0000] "GET /sdb4/76083/AUTH_00a6a0c7cd5f4ab3909f374cf566f62b/test" 200 - "txcb9cb3623982490db348fafb04f10fc7" "-" "Cyberduck/4.2.1 (Mac OS X/10.6.8) (i386)" 0.0851
Mar 22 14:24:00 swift-solo swift 192.168.240.10 192.168.240.10 22/Mar/2012/21/23/59 GET /v1/AUTH_00a6a0c7cd5f4ab3909f374cf566f62b/test%3Fformat%3Djson%26limit%3D1001%26prefix%3D%26delimiter%3D/ HTTP/1.0 200 - Cyberduck/4.2.1%20%28Mac%20OS%20X/10.6.8%29%20%28i386%29 1fe20b8208c44b34ac0a6efb7548e21e - 442 - txcb9cb3623982490db348fafb04f10fc7 - 0.1432 -
Mar 22 14:24:09 swift-solo ?swift Connecting with tenant: 00a6a0c7cd5f4ab3909f374cf566f62b (txn: txd7a50f6b873d4b04b2867b43846b35a4)
Mar 22 14:24:09 swift-solo swift Using identity: {'roles': [u'Member', u'test'], 'user': u'tester', 'tenant': (u'00a6a0c7cd5f4ab3909f374cf566f62b', u'test')} (txn: txd7a50f6b873d4b04b2867b43846b35a4)
Mar 22 14:24:09 swift-solo swift allow user with role Member as account admin (txn: txd7a50f6b873d4b04b2867b43846b35a4) (client_ip: 192.168.240.10)
Mar 22 14:24:09 swift-solo account-server 192.168.240.13 - - [22/Mar/2012:21:24:09 +0000] "GET /sdb4/147724/AUTH_00a6a0c7cd5f4ab3909f374cf566f62b" 200 - "txd7a50f6b873d4b04b2867b43846b35a4" "-" "Cyberduck/4.2.1 (Mac OS X/10.6.8) (i386)" 0.0061 ""
Mar 22 14:24:09 swift-solo swift 192.168.240.10 192.168.240.10 22/Mar/2012/21/24/09 GET /v1/AUTH_00a6a0c7cd5f4ab3909f374cf566f62b%3Fformat%3Djson HTTP/1.0 200 - Cyberduck/4.2.1%20%28Mac%20OS%20X/10.6.8%29%20%28i386%29 596d23a777c54d2e89377f3f77bf1e50 - 37 - txd7a50f6b873d4b04b2867b43846b35a4 - 0.0281 -
Mar 22 14:24:09 swift-solo ?swift Connecting with tenant: 00a6a0c7cd5f4ab3909f374cf566f62b (txn: txc50b9164372f48d29b091f39059c2e54) (client_ip: 192.168.240.10)
Mar 22 14:24:09 swift-solo swift Using identity: {'roles': [u'Member', u'test'], 'user': u'tester', 'tenant': (u'00a6a0c7cd5f4ab3909f374cf566f62b', u'test')} (txn: txc50b9164372f48d29b091f39059c2e54) (client_ip: 192.168.240.10)
Mar 22 14:24:09 swift-solo swift allow user with role Member as account admin (txn: txc50b9164372f48d29b091f39059c2e54) (client_ip: 192.168.240.10)
Mar 22 14:24:09 swift-solo container-server 192.168.240.13 - - [22/Mar/2012:21:24:09 +0000] "GET /sdb1/76083/AUTH_00a6a0c7cd5f4ab3909f374cf566f62b/test" 200 - "txc50b9164372f48d29b091f39059c2e54" "-" "Cyberduck/4.2.1 (Mac OS X/10.6.8) (i386)" 0.0370
Mar 22 14:24:09 swift-solo swift 192.168.240.10 192.168.240.10 22/Mar/2012/21/24/09 GET /v1/AUTH_00a6a0c7cd5f4ab3909f374cf566f62b/test%3Fformat%3Djson%26limit%3D1001%26prefix%3D%26delimiter%3D/ HTTP/1.0 200 - Cyberduck/4.2.1%20%28Mac%20OS%20X/10.6.8%29%20%28i386%29 86d94f5be1804a568fd4b97c07f83f32 - 442 - txc50b9164372f48d29b091f39059c2e54 - 0.0544 -
Mar 22 14:24:09 swift-solo ?catch_errors Error: Keystone reply error: status=500 reason=Internal Server Error: Traceback (most recent call last): File "/usr/local/lib/python2.7/dist-packages/swift-1.4.8-py2.7.egg/swift/common/middleware/catch_errors.py", line 47, in __call__ return self.app(env, my_start_response) File "/usr/local/lib/python2.7/dist-packages/swift-1.4.8-py2.7.egg/swift/common/middleware/memcache.py", line 47, in __call__ return self.app(env, start_response) File "/usr/local/lib/python2.7/dist-packages/swift-1.4.8-py2.7.egg/swift/common/middleware/swift3.py", line 479, in __call__ res = getattr(controller, req.method)(env, start_response) File "/usr/local/lib/python2.7/dist-packages/swift-1.4.8-py2.7.egg/swift/common/middleware/swift3.py", line 235, in GET body_iter = self.app(env, self.do_start_response) File "/usr/local/lib/python2.7/dist-packages/keystone-2012.1-py2.7.egg/keystone/middleware/s3_token.py", line 108, in __call__ resp.reason)) Exception: Keystone reply error: stat
Mar 22 14:24:09 swift-solo ?catch_errors Error: Keystone reply error: status=500 reason=Internal Server Error: Traceback (most recent call last): File "/usr/local/lib/python2.7/dist-packages/swift-1.4.8-py2.7.egg/swift/common/middleware/catch_errors.py", line 47, in __call__ return self.app(env, my_start_response) File "/usr/local/lib/python2.7/dist-packages/swift-1.4.8-py2.7.egg/swift/common/middleware/memcache.py", line 47, in __call__ return self.app(env, start_response) File "/usr/local/lib/python2.7/dist-packages/swift-1.4.8-py2.7.egg/swift/common/middleware/swift3.py", line 479, in __call__ res = getattr(controller, req.method)(env, start_response) File "/usr/local/lib/python2.7/dist-packages/swift-1.4.8-py2.7.egg/swift/common/middleware/swift3.py", line 235, in GET body_iter = self.app(env, self.do_start_response) File "/usr/local/lib/python2.7/dist-packages/keystone-2012.1-py2.7.egg/keystone/middleware/s3_token.py", line 108, in __call__ resp.reason)) Exception: Keystone reply error: stat
Mar 22 14:24:09 swift-solo ?catch_errors Error: Keystone reply error: status=500 reason=Internal Server Error: Traceback (most recent call last): File "/usr/local/lib/python2.7/dist-packages/swift-1.4.8-py2.7.egg/swift/common/middleware/catch_errors.py", line 47, in __call__ return self.app(env, my_start_response) File "/usr/local/lib/python2.7/dist-packages/swift-1.4.8-py2.7.egg/swift/common/middleware/memcache.py", line 47, in __call__ return self.app(env, start_response) File "/usr/local/lib/python2.7/dist-packages/swift-1.4.8-py2.7.egg/swift/common/middleware/swift3.py", line 479, in __call__ res = getattr(controller, req.method)(env, start_response) File "/usr/local/lib/python2.7/dist-packages/swift-1.4.8-py2.7.egg/swift/common/middleware/swift3.py", line 235, in GET body_iter = self.app(env, self.do_start_response) File "/usr/local/lib/python2.7/dist-packages/keystone-2012.1-py2.7.egg/keystone/middleware/s3_token.py", line 108, in __call__ resp.reason)) Exception: Keystone reply error: stat
Mar 22 14:24:10 swift-solo ?catch_errors Error: Keystone reply error: status=500 reason=Internal Server Error: Traceback (most recent call last): File "/usr/local/lib/python2.7/dist-packages/swift-1.4.8-py2.7.egg/swift/common/middleware/catch_errors.py", line 47, in __call__ return self.app(env, my_start_response) File "/usr/local/lib/python2.7/dist-packages/swift-1.4.8-py2.7.egg/swift/common/middleware/memcache.py", line 47, in __call__ return self.app(env, start_response) File "/usr/local/lib/python2.7/dist-packages/swift-1.4.8-py2.7.egg/swift/common/middleware/swift3.py", line 479, in __call__ res = getattr(controller, req.method)(env, start_response) File "/usr/local/lib/python2.7/dist-packages/swift-1.4.8-py2.7.egg/swift/common/middleware/swift3.py", line 235, in GET body_iter = self.app(env, self.do_start_response) File "/usr/local/lib/python2.7/dist-packages/keystone-2012.1-py2.7.egg/keystone/middleware/s3_token.py", line 108, in __call__ resp.reason)) Exception: Keystone reply error: stat
Mar 22 14:24:10 swift-solo ?catch_errors Error: Keystone reply error: status=500 reason=Internal Server Error: Traceback (most recent call last): File "/usr/local/lib/python2.7/dist-packages/swift-1.4.8-py2.7.egg/swift/common/middleware/catch_errors.py", line 47, in __call__ return self.app(env, my_start_response) File "/usr/local/lib/python2.7/dist-packages/swift-1.4.8-py2.7.egg/swift/common/middleware/memcache.py", line 47, in __call__ return self.app(env, start_response) File "/usr/local/lib/python2.7/dist-packages/swift-1.4.8-py2.7.egg/swift/common/middleware/swift3.py", line 479, in __call__ res = getattr(controller, req.method)(env, start_response) File "/usr/local/lib/python2.7/dist-packages/swift-1.4.8-py2.7.egg/swift/common/middleware/swift3.py", line 235, in GET body_iter = self.app(env, self.do_start_response) File "/usr/local/lib/python2.7/dist-packages/keystone-2012.1-py2.7.egg/keystone/middleware/s3_token.py", line 108, in __call__ resp.reason)) Exception: Keystone reply error: stat
Mar 22 14:24:12 swift-solo ?catch_errors Error: Keystone reply error: status=500 reason=Internal Server Error: Traceback (most recent call last): File "/usr/local/lib/python2.7/dist-packages/swift-1.4.8-py2.7.egg/swift/common/middleware/catch_errors.py", line 47, in __call__ return self.app(env, my_start_response) File "/usr/local/lib/python2.7/dist-packages/swift-1.4.8-py2.7.egg/swift/common/middleware/memcache.py", line 47, in __call__ return self.app(env, start_response) File "/usr/local/lib/python2.7/dist-packages/swift-1.4.8-py2.7.egg/swift/common/middleware/swift3.py", line 479, in __call__ res = getattr(controller, req.method)(env, start_response) File "/usr/local/lib/python2.7/dist-packages/swift-1.4.8-py2.7.egg/swift/common/middleware/swift3.py", line 235, in GET body_iter = self.app(env, self.do_start_response) File "/usr/local/lib/python2.7/dist-packages/keystone-2012.1-py2.7.egg/keystone/middleware/s3_token.py", line 108, in __call__ resp.reason)) Exception: Keystone reply error: stat
Mar 22 14:24:12 swift-solo ?swift Connecting with tenant: 00a6a0c7cd5f4ab3909f374cf566f62b (txn: txccb77000a9bd447e832e4f54e8b788b6)
Mar 22 14:24:12 swift-solo swift Using identity: {'roles': [u'Member', u'test'], 'user': u'tester', 'tenant': (u'00a6a0c7cd5f4ab3909f374cf566f62b', u'test')} (txn: txccb77000a9bd447e832e4f54e8b788b6)
Mar 22 14:24:12 swift-solo swift allow user with role Member as account admin (txn: txccb77000a9bd447e832e4f54e8b788b6) (client_ip: 192.168.240.10)
Mar 22 14:24:12 swift-solo container-server 192.168.240.13 - - [22/Mar/2012:21:24:12 +0000] "PUT /sdb1/76083/AUTH_00a6a0c7cd5f4ab3909f374cf566f62b/test/grub.txt" 201 - "txccb77000a9bd447e832e4f54e8b788b6" "-" "-" 0.0017
Mar 22 14:24:12 swift-solo object-server 192.168.240.13 - - [22/Mar/2012:21:24:12 +0000] "PUT /sdb1/253663/AUTH_00a6a0c7cd5f4ab3909f374cf566f62b/test/grub.txt" 201 - "-" "txccb77000a9bd447e832e4f54e8b788b6" "Cyberduck/4.2.1 (Mac OS X/10.6.8) (i386)" 0.4716
Mar 22 14:24:12 swift-solo container-server 192.168.240.13 - - [22/Mar/2012:21:24:12 +0000] "PUT /sdb2/76083/AUTH_00a6a0c7cd5f4ab3909f374cf566f62b/test/grub.txt" 201 - "txccb77000a9bd447e832e4f54e8b788b6" "-" "-" 0.0304
Mar 22 14:24:12 swift-solo object-server 192.168.240.13 - - [22/Mar/2012:21:24:12 +0000] "PUT /sdb3/253663/AUTH_00a6a0c7cd5f4ab3909f374cf566f62b/test/grub.txt" 201 - "-" "txccb77000a9bd447e832e4f54e8b788b6" "Cyberduck/4.2.1 (Mac OS X/10.6.8) (i386)" 0.6152
Mar 22 14:24:12 swift-solo container-server 192.168.240.13 - - [22/Mar/2012:21:24:13 +0000] "PUT /sdb4/76083/AUTH_00a6a0c7cd5f4ab3909f374cf566f62b/test/grub.txt" 201 - "txccb77000a9bd447e832e4f54e8b788b6" "-" "-" 0.0042
Mar 22 14:24:13 swift-solo object-server 192.168.240.13 - - [22/Mar/2012:21:24:13 +0000] "PUT /sdb2/253663/AUTH_00a6a0c7cd5f4ab3909f374cf566f62b/test/grub.txt" 201 - "-" "txccb77000a9bd447e832e4f54e8b788b6" "Cyberduck/4.2.1 (Mac OS X/10.6.8) (i386)" 0.6770
Mar 22 14:24:13 swift-solo swift 192.168.240.10 192.168.240.10 22/Mar/2012/21/24/13 PUT /v1/AUTH_00a6a0c7cd5f4ab3909f374cf566f62b/test/grub.txt HTTP/1.0 201 - Cyberduck/4.2.1%20%28Mac%20OS%20X/10.6.8%29%20%28i386%29 b148ac845aff48d785d4c9895dc728db 8702 - - txccb77000a9bd447e832e4f54e8b788b6 - 0.7471 -
Mar 22 14:24:13 swift-solo ?swift Connecting with tenant: 00a6a0c7cd5f4ab3909f374cf566f62b (txn: tx96596a8152084052ad9571392c0bfb90) (client_ip: 192.168.240.10)
Mar 22 14:24:13 swift-solo swift Using identity: {'roles': [u'Member', u'test'], 'user': u'tester', 'tenant': (u'00a6a0c7cd5f4ab3909f374cf566f62b', u'test')} (txn: tx96596a8152084052ad9571392c0bfb90) (client_ip: 192.168.240.10)
Mar 22 14:24:13 swift-solo swift allow user with role Member as account admin (txn: tx96596a8152084052ad9571392c0bfb90) (client_ip: 192.168.240.10)
Mar 22 14:24:13 swift-solo container-server 192.168.240.13 - - [22/Mar/2012:21:24:13 +0000] "GET /sdb1/76083/AUTH_00a6a0c7cd5f4ab3909f374cf566f62b/test" 200 - "tx96596a8152084052ad9571392c0bfb90" "-" "Cyberduck/4.2.1 (Mac OS X/10.6.8) (i386)" 0.0243
Mar 22 14:24:13 swift-solo swift 192.168.240.10 192.168.240.10 22/Mar/2012/21/24/13 GET /v1/AUTH_00a6a0c7cd5f4ab3909f374cf566f62b/test%3Fformat%3Djson%26limit%3D1001%26prefix%3D%26delimiter%3D/ HTTP/1.0 200 - Cyberduck/4.2.1%20%28Mac%20OS%20X/10.6.8%29%20%28i386%29 330ee2a9488a479a948cdc42072a3b7e - 591 - tx96596a8152084052ad9571392c0bfb90 - 0.0374 -

[Chmouel Boudjnah (chmouel)]

What signature:access are you using ? the one generated from keystone ec2-access-create --user user_id ?

[Rodolphe Pineau (rodolphe-cloudscaling)]

here how I generate the access key and secret key :

export OS_TENANT_NAME=test
export OS_USERNAME=tester
export OS_AUTH_URL=http://192.168.244.27:5000/v2.0
export OS_PASSWORD=testing

export EC2_URL=$(keystone catalog --service ec2 | awk '/ publicURL / { print $4 }')
export S3_URL=$(keystone catalog --service s3 | awk '/ publicURL / { print $4 }')
CREDS=$(keystone ec2-credentials-create)
export EC2_ACCESS_KEY=$(echo "$CREDS" | awk '/ access / { print $4 }')
export EC2_SECRET_KEY=$(echo "$CREDS" | awk '/ secret / { print $4 }')

echo -e "EC2_ACCESS_KEY = $EC2_ACCESS_KEY\nEC2_SECRET_KEY = $EC2_SECRET_KEY\n"

I then use these in Cyberduck with the S3 non SSL profile (pure HTTP) as in dev I don't have a SSL proxy

[Chmouel Boudjnah (chmouel)]

There was a full rewrite of the s3_token middleware merged this morning (Fri 23/03/12), it should be more robust and have plenty of bugs corrected (along more logging and unittests). Any chances to test again with this version? I unfortunately don't have a win or a mac with cyberduck handy to reproduce your problem.

[Rodolphe Pineau (rodolphe-cloudscaling)]

I'll test and report back.
Thanks.

[Rodolphe Pineau (rodolphe-cloudscaling)]

I retested and the stacktrace is still there :

2012-03-27 09:12:31 DEBUG [keystone.common.wsgi] ******************** REQUEST ENVIRON ********************
2012-03-27 09:12:31 DEBUG [keystone.common.wsgi] SCRIPT_NAME = /v2.0
2012-03-27 09:12:31 DEBUG [keystone.common.wsgi] webob.adhoc_attrs = {'response': <Response at 0x24bcd50 200 OK>}
2012-03-27 09:12:31 DEBUG [keystone.common.wsgi] REQUEST_METHOD = POST
2012-03-27 09:12:31 DEBUG [keystone.common.wsgi] PATH_INFO = /s3tokens
2012-03-27 09:12:31 DEBUG [keystone.common.wsgi] SERVER_PROTOCOL = HTTP/1.0
2012-03-27 09:12:31 DEBUG [keystone.common.wsgi] CONTENT_LENGTH = 315
2012-03-27 09:12:31 DEBUG [keystone.common.wsgi] eventlet.posthooks = []
2012-03-27 09:12:31 DEBUG [keystone.common.wsgi] SERVER_NAME = 192.168.244.27
2012-03-27 09:12:31 DEBUG [keystone.common.wsgi] REMOTE_ADDR = 192.168.240.13
2012-03-27 09:12:31 DEBUG [keystone.common.wsgi] eventlet.input = <eventlet.wsgi.Input object at 0x24bc150>
2012-03-27 09:12:31 DEBUG [keystone.common.wsgi] wsgi.url_scheme = http
2012-03-27 09:12:31 DEBUG [keystone.common.wsgi] SERVER_PORT = 35357
2012-03-27 09:12:31 DEBUG [keystone.common.wsgi] wsgi.input = <_io.BytesIO object at 0x24b1410>
2012-03-27 09:12:31 DEBUG [keystone.common.wsgi] HTTP_HOST = 192.168.244.27:35357
2012-03-27 09:12:31 DEBUG [keystone.common.wsgi] wsgi.multithread = True
2012-03-27 09:12:31 DEBUG [keystone.common.wsgi] openstack.params = {u'credentials': {u'token': u'R0VUCgoKVHVlLCAyNyBNYXIgMjAxMiAxNzoxMzowMSBHTVQKL3Rlc3Qv', u'access': u'a33d3faba9aa46bd813777c7fb06f953', u'host': u'roro-swift:8080', u'verb': u'GET', u'expire': u'Tue, 27 Mar 2012 17:13:01 GMT', u'signature': u'UP9gJ6iN/8/L734jZOq68h698po=', u'path': u'/v1/a33d3faba9aa46bd813777c7fb06f953/test'}}
2012-03-27 09:12:31 DEBUG [keystone.common.wsgi] wsgi.version = (1, 0)
2012-03-27 09:12:31 DEBUG [keystone.common.wsgi] openstack.context = {'token_id': None, 'is_admin': False}
2012-03-27 09:12:31 DEBUG [keystone.common.wsgi] GATEWAY_INTERFACE = CGI/1.1
2012-03-27 09:12:31 DEBUG [keystone.common.wsgi] wsgi.run_once = False
2012-03-27 09:12:31 DEBUG [keystone.common.wsgi] wsgi.errors = <open file '<stderr>', mode 'w' at 0x7f77e2823270>
2012-03-27 09:12:31 DEBUG [keystone.common.wsgi] wsgi.multiprocess = False
2012-03-27 09:12:31 DEBUG [keystone.common.wsgi] webob.is_body_seekable = True
2012-03-27 09:12:31 DEBUG [keystone.common.wsgi] CONTENT_TYPE = application/json
2012-03-27 09:12:31 DEBUG [keystone.common.wsgi] HTTP_ACCEPT_ENCODING = identity
2012-03-27 09:12:31 DEBUG [keystone.common.wsgi]
2012-03-27 09:12:31 DEBUG [keystone.common.wsgi] ******************** REQUEST BODY ********************
2012-03-27 09:12:31 DEBUG [keystone.common.wsgi] {"credentials": {"host": "roro-swift:8080", "access": "a33d3faba9aa46bd813777c7fb06f953", "token": "R0VUCgoKVHVlLCAyNyBNYXIgMjAxMiAxNzoxMzowMSBHTVQKL3Rlc3Qv", "verb": "GET", "expire": "Tue, 27 Mar 2012 17:13:01 GMT", "signature": "UP9gJ6iN/8/L734jZOq68h698po=", "path": "/v1/a33d3faba9aa46bd813777c7fb06f953/test"}}
2012-03-27 09:12:31 DEBUG [keystone.common.wsgi]
2012-03-27 09:12:31 DEBUG [...

[Chmouel Boudjnah (chmouel)]

Can you try this script :

http://p.chmouel.com/botoconnect.py

from the command line and let me know if this is working for you?

Make sure to define those env variable before :

S3_URL
EC2_SECRET_KEY
EC2_SECRET_KEY

For example this is what I have on my devstack install :

S3_URL=http://localhost:8080
EC2_ACCESS_KEY=32645fdeaaed45d698edd97bbbd29644
EC2_SECRET_KEY=ee80c73c8eef4b28874d8798341aebd7

[OpenStack Infra (hudson-openstack)]

Fix proposed to branch: master
Review: https://review.openstack.org/5870

[Rodolphe Pineau (rodolphe-cloudscaling)]

I ran the script :

./botoconnect.py
ParseResult(scheme='http', netloc='roro-swift:8080', path='/', params='', query='', fragment='')
Creating bucket: cont_s3
uploading: uploaded_from_s3.txt key
modifying: uploaded_from_s3.txt key

and did not see any stacktrace in keystone logs.

but If I upload a file in the same bucket from Cyberduck I get the stacktrace. So Cyberduck is doing something different from what boto is doing and triggers the error.

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/5870
Committed: http://github.com/openstack/keystone/commit/7c053df8e37906c95dc78222a33f4ec91712774e
Submitter: Jenkins
Branch: master

commit 7c053df8e37906c95dc78222a33f4ec91712774e
Author: Dolph Mathews <email address hidden>
Date: Tue Mar 27 10:57:04 2012 -0700

    Raise keystone.exception for HTTP 401 (bug 962563)

    Change-Id: I22e3b6769c69ef5917028980007d3295fed99fb7

[OpenStack Infra (hudson-openstack)]

Fix proposed to branch: milestone-proposed
Review: https://review.openstack.org/6163

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/6163
Committed: http://github.com/openstack/keystone/commit/1b7aa15ae425e68c15588ba738e9b701b62d995a
Submitter: Jenkins
Branch: milestone-proposed

commit 1b7aa15ae425e68c15588ba738e9b701b62d995a
Author: Dolph Mathews <email address hidden>
Date: Tue Mar 27 10:57:04 2012 -0700

    Raise keystone.exception for HTTP 401 (bug 962563)

    Change-Id: I22e3b6769c69ef5917028980007d3295fed99fb7