odd keystone behavior when X-Auth-Token ends with carriage return

Bug #1689468 reported by Matthew Edmonds
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
OpenStack Identity (keystone)
Invalid
Low
Gage Hugo
keystonemiddleware
Fix Released
Undecided
Matthew Edmonds

Bug Description

I had to root cause a very odd problem today, where a user complained that they had a token that worked with neutron but didn't work with keystone. E.g. they could list networks, but couldn't list projects. I thought there must be some mistake, but I was finally able to reproduce it and they were correct. Here's a script that shows the problem:

OPENSTACK=<my_ip_address>
AUTH_FILE=/root/auth.json

TOKEN=`curl -s -1 -k -i -X POST https://$OPENSTACK:5000/v3/auth/tokens -H "Accept:application/json" -H "Content-Type: application/json" -d @${AUTH_FILE} | grep X-Subject-Token | awk '{FS=":"; print $2}'`

echo 'neutron:'; curl -1 -k -X GET https://$OPENSTACK:9696/v2.0/networks -H "X-Auth-Token: $TOKEN" -H "Content-Type: application/json"; echo; echo

echo 'keystone:'; curl -1 -k -X GET https://$OPENSTACK:5000/v3/projects -H "X-Auth-Token: $TOKEN" -H "Accept: application/json"; echo; echo

With debug=True and insecure_debug=True and default_log_levels=keystonemiddleware=True, this yields something like:

neutron:
{"networks": []}

keystone:
{"error": {"message": "auth_context did not decode anything useful (Disable insecure_debug mode to suppress these details.)", "code": 401, "title": "Unauthorized"}}

I was finally able to figure out why... the awk command used to parse the token out of the X-Subject-Token header was leaving a \r on the end of the $TOKEN value, and apparently that's handled fine when you make the request to neutron (and presumably any non-keystone service), but not when you are talking to keystone directly. That makes some sense, since keystone has to do its own token validation differently.

Changing the following line in the script above (adding the gsub to trim the \r) fixed the issue:

TOKEN=`curl -s -1 -k -i -X POST https://$OPENSTACK:5000/v3/auth/tokens -H "Accept:application/json" -H "Content-Type: application/json" -d @${AUTH_FILE} | grep X-Subject-Token | awk '{FS=":"; gsub(/\r$/,"",$2); print $2}'`

We should fix this to be consistent with non-keystone token validation, to save someone else the trouble debugging this if nothing else. Keystone was doing weird things, where the debug logs would show that the context knew the user and roles, but had no token... leaving one to wonder how it figured out the user and roles if it didn't have a token?!? Not a good user experience for someone trying to write a script to our APIs.

Revision history for this message
Lance Bragstad (lbragstad) wrote :

Sounds like the fix here is to scrub the X-Subject-Token header manually within keystone?

Changed in keystone:
importance: Undecided → Low
status: New → Triaged
Revision history for this message
Matthew Edmonds (edmondsw) wrote :

Yes, that's what I was thinking.

Jaewoo Park (aselius)
Changed in keystone:
assignee: nobody → Jaewoo Park (aselius)
Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix proposed to keystone (master)

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

Changed in keystone:
status: Triaged → In Progress
Revision history for this message
Colleen Murphy (krinkle) wrote :

I had trouble reproducing this right away, I was seeing this:

$ curl -1 -k -X GET http://$OPENSTACK/identity/v3/projects -H "X-Auth-Token: $TOKEN" -H "Accept: application/json"
<!DOCTYPE HTML PUBLIC "-//IETF//DTD HTML 2.0//EN">
<html><head>
<title>503 Service Unavailable</title>
</head><body>
<h1>Service Unavailable</h1>
<p>The server is temporarily unable to service your
request due to maintenance downtime or capacity
problems. Please try again later.</p>
<hr>
<address>Apache/2.4.18 (Ubuntu) Server at 127.0.0.1 Port 80</address>
</body></html>

Devstack runs keystone under apache and I guess apache just doesn't accept malformed headers, as this happens with the default vhost too:

$ curl -1 -k -X GET http://$OPENSTACK -H "X-Header-I-Just-Made-Up: $TOKEN"
<!DOCTYPE HTML PUBLIC "-//IETF//DTD HTML 2.0//EN">
<html><head>
<title>400 Bad Request</title>
</head><body>
<h1>Bad Request</h1>
<p>Your browser sent a request that this server could not understand.<br />
</p>
<hr>
<address>Apache/2.4.18 (Ubuntu) Server at 127.0.0.1 Port 80</address>
</body></html>
$ curl -1 -k -X GET http://$OPENSTACK -H "X-Header-I-Just-Made-Up: $(echo $TOKEN | tr -d '\r')"
<the whole default index.html from apache>

If neutron-server was also run behind apache it probably would not have accepted the token. So this makes me wonder if keystone should really be trying to work around malformed tokens like this, when other webservers would consider it invalid?

Revision history for this message
Matthew Edmonds (edmondsw) wrote :

@Colleen, this was found with apache httpd (though not devstack).

Revision history for this message
Jaewoo Park (aselius) wrote :

The 400 bad request is sent by httpd apache itself, so im not sure if changing Keystone is the right way to do this.. if its just a 401 issue, then brushing up of the token on keystone would be the right way i think.

Revision history for this message
Matthew Edmonds (edmondsw) wrote :

Right, I think Colleen was looking at something entirely different from this issue. I'd like to keep this defect focused on the HTTP 401 in the description caused by the token ending with '\r'.

Changed in keystone:
assignee: Jaewoo Park (aselius) → Kelly Hall (kaerie)
Changed in keystone:
assignee: Kelly Hall (kaerie) → Aaron Thomas (aaron25mt)
Aaron Thomas (aaron25mt)
Changed in keystone:
assignee: Aaron Thomas (aaron25mt) → nobody
Changed in keystone:
assignee: nobody → Kelly Hall (kaerie)
Changed in keystone:
assignee: Kelly Hall (kaerie) → Gage Hugo (gagehugo)
Gage Hugo (gagehugo)
Changed in keystonemiddleware:
status: New → In Progress
Revision history for this message
Lance Bragstad (lbragstad) wrote :

The fix in review seems close, so targeting this for the Pike release.

Changed in keystone:
milestone: none → pike-rc1
Changed in keystonemiddleware:
assignee: nobody → Matthew Edmonds (edmondsw)
Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix merged to keystonemiddleware (master)

Reviewed: https://review.openstack.org/482971
Committed: https://git.openstack.org/cgit/openstack/keystonemiddleware/commit/?id=efb1fb99d87f754a008877f2e2d391221cb43721
Submitter: Jenkins
Branch: master

commit efb1fb99d87f754a008877f2e2d391221cb43721
Author: Matthew Edmonds <email address hidden>
Date: Wed Jul 12 09:45:59 2017 -0400

    strip whitespace from token

    This change strips whitespace from incoming tokens to prevent errors
    that are difficult for a caller to root cause.

    Change-Id: I4b3fd18314c3ca94beb3b0c8c17280451d6c8755
    Closes-Bug: #1689468

Changed in keystonemiddleware:
status: In Progress → Fix Released
Revision history for this message
Lance Bragstad (lbragstad) wrote :

This appears to be addressed by the keystonemiddleware patch. Marking this as invalid for keystone server. Please feel free to reopen if the issue resurfaces.

Changed in keystone:
status: In Progress → Invalid
Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Change abandoned on keystone (master)

Change abandoned by Jaewoo Park (<email address hidden>) on branch: master
Review: https://review.openstack.org/470425
Reason: resolved in https://review.openstack.org/#/c/482971/

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix included in openstack/keystonemiddleware 4.18.0

This issue was fixed in the openstack/keystonemiddleware 4.18.0 release.

To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.