nova is still broken with boto==2.35*

[Matt Riedemann]

Bug 1408987 fixed one auth issue with the signature handling:

https://review.openstack.org/#/c/146124/

But when trying to uncap the requirement on master we hit two new failures when trying to create a security group, we get auth failures (401 failures to be exact).

Copied from comment 14 of bug 1408987:

This is still broken on master, when I tried to uncap the boto version on master I get new auth failures:

http://logs.openstack.org/92/146592/1/check/check-tempest-dsvm-full/7c375f8/console.html#_2015-01-12_19_11_36_102

2015-01-12 19:11:36.102 | tempest.thirdparty.boto.test_ec2_security_groups.EC2SecurityGroupTest.test_create_authorize_security_group
2015-01-12 19:11:36.102 | ----------------------------------------------------------------------------------------------------------
2015-01-12 19:11:36.102 |
2015-01-12 19:11:36.102 | Captured traceback:
2015-01-12 19:11:36.102 | ~~~~~~~~~~~~~~~~~~~
2015-01-12 19:11:36.103 | Traceback (most recent call last):
2015-01-12 19:11:36.103 | _StringException: Empty attachments:
2015-01-12 19:11:36.103 | stderr
2015-01-12 19:11:36.103 | stdout
2015-01-12 19:11:36.103 |
2015-01-12 19:11:36.103 | pythonlogging:'': {{{
2015-01-12 19:11:36.103 | 2015-01-12 19:07:12,279 27381 DEBUG [keystoneclient.auth.identity.v2] Making authentication request to http://127.0.0.1:5000/v2.0/tokens
2015-01-12 19:11:36.103 | 2015-01-12 19:07:13,359 27381 ERROR [boto] 401 Unauthorized
2015-01-12 19:11:36.103 | 2015-01-12 19:07:13,359 27381 ERROR [boto] <?xml version="1.0"?>
2015-01-12 19:11:36.103 | <Response><Errors><Error><Code>AuthFailure</Code><Message>Unauthorized</Message></Error></Errors><RequestID>req-81391f74-7caf-42a6-a3b8-ccd2c7d1cbdf</RequestID></Response>
2015-01-12 19:11:36.104 | }}}
2015-01-12 19:11:36.104 |
2015-01-12 19:11:36.104 | Traceback (most recent call last):
2015-01-12 19:11:36.104 | File "tempest/thirdparty/boto/test_ec2_security_groups.py", line 32, in test_create_authorize_security_group
2015-01-12 19:11:36.104 | group_description)
2015-01-12 19:11:36.104 | File "tempest/services/botoclients.py", line 84, in func
2015-01-12 19:11:36.104 | return getattr(conn, name)(*args, **kwargs)
2015-01-12 19:11:36.104 | File "/usr/local/lib/python2.7/dist-packages/boto/ec2/connection.py", line 3003, in create_security_group
2015-01-12 19:11:36.104 | SecurityGroup, verb='POST')
2015-01-12 19:11:36.105 | File "/usr/local/lib/python2.7/dist-packages/boto/connection.py", line 1207, in get_object
2015-01-12 19:11:36.105 | raise self.ResponseError(response.status, response.reason, body)
2015-01-12 19:11:36.105 | EC2ResponseError: EC2ResponseError: 401 Unauthorized
2015-01-12 19:11:36.105 | <?xml version="1.0"?>
2015-01-12 19:11:36.105 | <Response><Errors><Error><Code>AuthFailure</Code><Message>Unauthorized</Message></Error></Errors><RequestID>req-81391f74-7caf-42a6-a3b8-ccd2c7d1cbdf</RequestID></Response>

It's something to do with security groups this time.

http://logs.openstack.org/92/146592/1/check/check-tempest-dsvm-full/7c375f8/logs/screen-n-api.txt.gz#_2015-01-12_19_07_13_357

2015-01-12 19:07:13.357 24624 DEBUG nova.api.ec2.faults [-] EC2 error response: AuthFailure: Unauthorized ec2_error_response /opt/stack/new/nova/nova/api/ec2/faults.py:29

[Matt Riedemann (mriedem)]

The keystone log has a warning for the same failures:

http://logstash.openstack.org/#eyJzZWFyY2giOiJtZXNzYWdlOlwiQXV0aG9yaXphdGlvbiBmYWlsZWQuIEVDMiBzaWduYXR1cmUgbm90IHN1cHBsaWVkXCIgQU5EIHRhZ3M6XCJzY3JlZW4ta2V5LnR4dFwiIiwiZmllbGRzIjpbXSwib2Zmc2V0IjowLCJ0aW1lZnJhbWUiOiI2MDQ4MDAiLCJncmFwaG1vZGUiOiJjb3VudCIsInRpbWUiOnsidXNlcl9pbnRlcnZhbCI6MH0sInN0YW1wIjoxNDIxMjA1ODE5MDkwLCJtb2RlIjoiIiwiYW5hbHl6ZV9maWVsZCI6IiJ9

So those actually show up in logstash. They only hit on the change to uncap the version:

https://review.openstack.org/#/c/146592/

[OpenStack Infra (hudson-openstack)]

Related fix proposed to branch: master
Review: https://review.openstack.org/147058

[Matt Riedemann (mriedem)]

Debug patch: https://review.openstack.org/#/c/147058/

[Davanum Srinivas (DIMS) (dims-v)]

Matt, is the 401 intermittent? 147058 did not seem to repro it. trying a recheck

[Matt Riedemann (mriedem)]

@dims, it shouldn't be intermittent, and it looks like your recheck was lost somewhere so I just rechecked it again.

[Matt Riedemann (mriedem)]

A debug change in devstack to run tempest without boto capped < 2.35 and also with the nova change that adds extra debug info to the ec2 fault create code.

https://review.openstack.org/#/c/147601/

[Matt Riedemann (mriedem)]

There are two places in keystone where we can get "EC2 signature not supplied", one is if the access entry isn't in the credentials dict and the other is if the signature isn't there, but since the error message is the same and there is no stacktrace, it's hard to tell which we're hitting, so I'm going to push a keystone patch to change those error messages slighty (one for access, one for signature).

[Matt Riedemann (mriedem)]

Have some keystone debug output here, the access key is in the credentials dict in keystone, it's the signature check that fails:

http://logs.openstack.org/01/147601/3/check/check-tempest-dsvm-full/96bb05e/logs/apache/keystone.txt.gz#_2015-01-15_22_00_27_046

2015-01-15 22:00:27.046880 26075 ERROR keystone.contrib.ec2.controllers [-] signature check failed; creds_ref: {'access': u'3da5e55bb5234719862d308c72b7c5e2', 'tenant_id': u'f8e946fd1293453eb9c98c266a03d386', 'secret': u'd53885bfa7ce4c57bcad80c9d30d1b71', 'user_id': u'37e655b3cc844a64b5665976127b28a5', 'trust_id': None}; credentials: {u'body_hash': u'915db51f333ae4d2bda6502c2c69278dc9ee90a117fbc0def065c1f7e1724c05', u'access': u'3da5e55bb5234719862d308c72b7c5e2', u'headers': {u'Content-Length': u'150', u'Accept-Encoding': u'identity', u'User-Agent': u'Boto/2.35.1 Python/2.7.6 Linux/3.13.0-44-generic', u'Host': u'127.0.0.1:8773', u'X-Amz-Date': u'20150115T220027Z', u'Content-Type': u'application/x-www-form-urlencoded; charset=UTF-8', u'Authorization': u'AWS4-HMAC-SHA256 Credential=3da5e55bb5234719862d308c72b7c5e2/20150115/0/127/aws4_request,SignedHeaders=host;x-amz-date,Signature=1c314a588a431c92d83b00ca7450195c461857fb78018147065e43089af10788'}, u'host': u'127.0.0.1:8773', u'verb': u'POST', u'params': {u'Action': u'CreateSecurityGroup', u'GroupName': u'securty_group--505956668', u'Version': u'2014-10-01', u'GroupDescription': u'securty_group--505956668 security group description '}, u'signature': u'1c314a588a431c92d83b00ca7450195c461857fb78018147065e43089af10788', u'path': u'/services/Cloud/'}; generated signature: 8189a643a8669802f5e9e09bc835558cc8521b7edebb43d166e6b60469509d11

[Matt Riedemann (mriedem)]

Aha, the signature nova is passing to keystone:

1c314a588a431c92d83b00ca7450195c461857fb78018147065e43089af10788

is different from the generated signature in the keystone code:

8189a643a8669802f5e9e09bc835558cc8521b7edebb43d166e6b60469509d11

[Steve Martinelli (stevemar)]

Matt, how does nova generate it's signature?

Seems like in keystone it's all done here: https://github.com/openstack/python-keystoneclient/blob/master/keystoneclient/contrib/ec2/utils.py#L75-L99

That function is called with:
  signer = ec2_utils.Ec2Signer(creds_ref['secret'])
  signature = signer.generate(credentials)

Looks like it's using the v4 version of signature generation, which means all these params need to be the same on both ends:
  credentials['params'],
  credentials['verb'],
  credentials['host'],
  credentials['path'],
  credentials['headers'],
  credentials['body_hash']

Which I've added below for completeness,

{
    u'body_hash': u'915db51f333ae4d2bda6502c2c69278dc9ee90a117fbc0def065c1f7e1724c05',
    u'host': u'127.0.0.1: 8773',
    u'verb': u'POST',
    u'params': {
        u'Action': u'CreateSecurityGroup',
        u'GroupName': u'securty_group--505956668',
        u'Version': u'2014-10-01',
        u'GroupDescription': u'securty_group--505956668securitygroupdescription'
    },
    u'path': u'/services/Cloud/'
    u'headers': {
        u'Content-Length': u'150',
        u'Accept-Encoding': u'identity',
        u'User-Agent': u'Boto/2.35.1Python/2.7.6Linux/3.13.0-44-generic',
        u'Host': u'127.0.0.1: 8773',
        u'X-Amz-Date': u'20150115T220027Z',
        u'Content-Type': u'application/x-www-form-urlencoded;charset=UTF-8',
        u'Authorization': u'AWS4-HMAC-SHA256Credential=3da5e55bb5234719862d308c72b7c5e2/20150115/0/127/aws4_request,
        SignedHeaders=host;x-amz-date,
        Signature=1c314a588a431c92d83b00ca7450195c461857fb78018147065e43089af10788'
    },
}

Maybe apache could be eating up a header? IIRC mod_wsgi eats up the Authorization header by default, but I think I changed devstack to allow for that now. Maybe hostnames are being used instead of ip?

[Matt Riedemann (mriedem)]

This is the nova code that generates the creds:

https://review.openstack.org/#/c/146124/

I found in the ec2-api project in stackforge that they fixed this differently (it's quite a bit more code):

https://github.com/stackforge/ec2-api/commit/e4c4463ab10ebf6e21d84f9b3369494b0055f963

I haven't yet gone through the differences in detail.

[Matt Riedemann (mriedem)]

I'm going to see if I can import the keystoneclient code into nova and re-use that rather than copying something else into nova, that way keystoneclient and nova could be using the same code and then we could look at making heat use keystoneclient too, since it sounds like heat has it's own copy of this ec2 signature generation code. I smell a new oslo library in the making!

[Andrey Pavlov (apavlov-e)]

it happens with 'euca-add-group' as well if description has trailing space. Like in tempest test -

(0):~$ euca-add-group securty_group-123124 -d 'security_group-123124 security group description '
AuthFailure: Unauthorized
(1):~$

[Andrey Pavlov (apavlov-e)]

May be I am wrong.
euca-add-group gets failure if description has spaces in any place...

But 'aws' tool works well .

[Andrey Pavlov (apavlov-e)]

So.
It happens because boto sends '%20' instead of spaces. But webob/wsgi modules converts it to '+' sign in body.
And then it calculates different body hash than boto and keystone uses this incorrect body hash for calculating signature.

Does anybody knows how to get raw body from post?

[Andrey Pavlov (apavlov-e)]

first call to 'req.params' rewrites Request.body_file member and i didn't find a way to get original body.

so it can be fix as a hack in nova/ec2 code - just save body before accessing any other field in request
or add ability to get original body to webob.Request class.

[Andrey Pavlov (apavlov-e)]

something from webob bug tracker - https://github.com/Pylons/webob/issues/149

[Andrey Pavlov (apavlov-e)]

@stevemar Nova doesn't generate signature. It takes signature from request and passes it to keystone.

[OpenStack Infra (hudson-openstack)]

Related fix proposed to branch: master
Review: https://review.openstack.org/152112

[OpenStack Infra (hudson-openstack)]

Change abandoned by Matt Riedemann (<email address hidden>) on branch: master
Review: https://review.openstack.org/147663
Reason: Looks like we have a winner:

https://review.openstack.org/#/c/152112/

[OpenStack Infra (hudson-openstack)]

Change abandoned by Matt Riedemann (<email address hidden>) on branch: master
Review: https://review.openstack.org/147058

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/152112
Committed: https://git.openstack.org/cgit/openstack/nova/commit/?id=fb588f87db65f28823f9e07a9900c34c7b3576a2
Submitter: Jenkins
Branch: master

commit fb588f87db65f28823f9e07a9900c34c7b3576a2
Author: Andrey Pavlov <email address hidden>
Date: Mon Feb 2 16:32:24 2015 +0300

    Make code compatible with v4 auth and workaround webob bug.

    Webob library has a bug https://github.com/Pylons/webob/issues/149
    which causes modification of req.body after first access. So it's
    critical to calculate the body hash before any other access is made.

    auth_params should be empty for v4 auth algorythm.

    Related-Bug: #1410622

    Change-Id: I06d798a125b700d9b4670448804d6be27f978d75

[OpenStack Infra (hudson-openstack)]

Related fix proposed to branch: stable/juno
Review: https://review.openstack.org/156921

[OpenStack Infra (hudson-openstack)]

Change abandoned by Matt Riedemann (<email address hidden>) on branch: master
Review: https://review.openstack.org/147639
Reason: meh

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/156921
Committed: https://git.openstack.org/cgit/openstack/nova/commit/?id=ae0c898c67b4926c8fd99fdab2b83fc1b38e1c70
Submitter: Jenkins
Branch: stable/juno

commit ae0c898c67b4926c8fd99fdab2b83fc1b38e1c70
Author: Andrey Pavlov <email address hidden>
Date: Mon Feb 2 16:32:24 2015 +0300

    Make code compatible with v4 auth and workaround webob bug.

    Webob library has a bug https://github.com/Pylons/webob/issues/149
    which causes modification of req.body after first access. So it's
    critical to calculate the body hash before any other access is made.

    auth_params should be empty for v4 auth algorythm.

    Related-Bug: #1410622

    Conflicts:
     nova/api/ec2/__init__.py

    Change-Id: I06d798a125b700d9b4670448804d6be27f978d75
    (cherry picked from commit fb588f87db65f28823f9e07a9900c34c7b3576a2)

[Bert JW Regeer (bertjwregeer)]

Hello,

I am the new maintainer for WebOb, and I tracked down this bug and squashed it. See: https://github.com/Pylons/webob/pull/192. I will be releasing a new version of WebOb 1.4.x that will contain the fix a little later today.

I've also got some changes that are going to be in WebOb 1.5, what is the best way to get in touch with the OpenStack developers to make sure you guys get a heads-up ahead of time, and to make sure that there is a good channel of communication. My email address is <email address hidden>.

Thanks,
Bert