Valid V3 tokens reported as invalid

[Adam Young]

Use CURL to get an admin token and use it to perform list domains will result in a failure.

Get a scoped token:

$ cat token-request-admin.json
{
    "auth": {
        "identity": {
            "methods": [
                "password"
            ],
            "password": {
                "user": {
                    "domain": {
                        "name": "Default"
                    },
                    "name": "admin",
                    "password": "FreeIPA4All"
                }
            }
        },
        "scope": {
            "project": {
                "domain": {
                    "name": "Default"
                },
                "name": "demo"
            }
        }
    }
}

-sh-4.2$ export TOKEN=`curl -si -d @token-request-admin.json -H "Content-type: application/json" http://localhost:35357/v3/auth/tokens | awk '/X-Subject-Token/ {print $2}'`-sh-4.2$ echo $TOKEN
PKIZ_eJy9Wltz2kq3fJ9fcd537YoukISH70EgIUQ8owgLiZk3JDm6ji8fNkL69acHcLYhTgLZp46rXBhjadZa06u718h__42vseN67H8m9Fa9-ZtQz-PfLD7_8iC8YpsyK0gnD_hdEk4mrltPrMDZTUJrNs6X_7VzOnGryWT67LmT2yf31ktMYgfOzFrjlxvq5MX6w1031xLjuUlK76M325RJHGlrd1SnHd5PN2XqTvvUzLapDMrVbZsT736-Tdyo96qHPDY35ToOSr-0SmrMpXB5y6txzftcZ_YUr_XAj6eFqOaVHwc7P1zqRMS8vJlYZSKnz-IWq0zmDyKeaiuTaTxm_10ZIzORUefdaxsV0esCvp32wnVMIuzlgLqLmtm892NvKCpRU9vZYdWdCKeShen5AoVw9ceknI8OKchokLpNJ1bsG18dw6-sHZtorT_RdnQatLR66PHdstuBznpnSO1s7ZVt7t2PO5IYjw031YXjT55cbJN4-vhawNdwhRtJvoo22cTbIIIXHuuNqplXLxoi5FRPZkH5DeF4sqn3H1RUp8aiYXEw9GPa-_ZCsmpc0CormBsMREV7FgY9j5c7sg9FDoskXr6u9px085HKmxtTFHK3FfstfEaE0YuYjbfreKilx99hG6MumRyqn80WrV9-3tKw7m4qx_Angx2q_ULD9CNeTdqNerGaG-uYNWk3shN3hG085NWJOHtMjME-iqWM7tfx6CU0hs0hwuYlc6MO6VbHnWizeL5Zx7QkKtTXYjGJvF1Hp2HTHH4WDatqE-CpARzdt62dsMeSht6-ZkCtTlLZ7i9ezxZaaj9sb9Q2lYMdq3KEnptIxfSr3GQ93aZG1GWyqcSKboN48byOB4cI0mPI-x1o5o0wmm1Sj14QrkrvMblfNKkUBTcOhebHi9W15Ptehw6wDezLwOAx75ktCiE9vBalH2YNYGtghwrWB9_DV9GTPwrf2G0zLLyP4NrwFQawlUBje57CtGDhuGSVN6D2uGC2Y1K7KERIh6wKhtRlktlpRw2kEGnq5trdatyQ_coyqmh5WFHsQeVhu0RBDa5Tmxsi9jQmnc53gyHrl70fiho_7xheCSvPGmR_MwXl8bvQPUcu-RV0WTky6O1nNA6rRRjVftigjXJNVNit0DN5uKiJ7_Ke9kuNGtOG3l4Pa_IW129hTeWioiGrqEuRu9Mx2xrSqmhEVQ95DFYKPQPY6UFpzgkwLsMF32aVs0XkuIG71IWNu_Z0wFxuULWa4WjCLiTtKdiYYTWn_BnkyTWg-YfiVPi54duOQXjFNdBUhwqXPHRaVqVDIZkUttci_9-mR36V3yXpkV_ld0lLnzCSqKKSS96r1mZ2A7EB-0rPVMARknZICWyl0uTf-4Gohtivei-2ySx6fl3x2BMdQ7FYj2_DG4jQ0kS4HGIRNNUCzQdtpHKJPxLVjz3BHhPwYvqbviCXULoqKDQSxfVe6BmLkwtp_CioJ-lpPBxLQsOlgRSkj_w4quzviSXYCVdAZHMAJh2wyTGNd0SIvBcyC62WTtDK5aA9qPBxW8v9xbeH8IdfE7l83cY9ZCUMxXFHxjqXu0fevQ153nBFNlVT-LanC5cihXlD_Ji3LCxqoKxnfQQKTwe0-3nI5xGTa0M-j_hIqoeqw8Zsjrtw8AkSCIxF44NgVbigMPgEAAjIhIaaYHJlMKKCIy_vXs_U3bNZ0x637hFKhBs32t0pOsHUTYVWhujSAaHuUlN35FUGR4JGBmwpHIqADohzSyOfm7sVg48EXo6uDTZvWKfuSHXbd6-YreabwwWFls2sjzfdZ-gmUBjyAQo4YB1orn8YsD7VyI3J-2sL97Zu5IfCVdjfyjOpnMOZco1WC0ldPvBd9IMLlMZLoJNqYOxSpUFUHteEfB4xuTzkaZ3EzctZtDBZIYTTWJowEOC_RcV6dF4FYMUBEJo1tMfnvfhe9fNoyTXh_ttmgmfgJjccOFcOngR-0FwEnqgDx-2gd9A9GOswavzbgxP37hfD1D2ysDF6TmcRFjpGdawDekHUDMosKlh9u2ioHWgwVmjZAKt5ndJuXs1LDlo7t8WJHEGZ1B2PBfoTVJI3RTNQtO6mv9ypq4jI9RA-xcOBD6pgR1FRP56jG5s9qdIepIpIqL0c-m6kIuqopNo5HsgF8P1lauRnuV2aGvk1eDyYzBTYwKq2MhXoTggsj6cV7wsoNSsRQYo_ynV-ezkTv7WBhJa_9oG_s4HkAl08mgsgcHImNAaThMVT6ceQeOlogPEAbKvzyuqUuUbumGoxyXY_9kYmR5sMZEsg2eXp3ATqgi_BnqAfeIe5qfZtZTJEwyu626MSo7J_tEbkzUxcYWtqNdb935ntvdz9P5jt99zHUIDOMVwMOOZFWDsNxe15mA-FO5eQQ3yGgcN1NMLLPwDQm9TInwLoNTVyyXz8dptBbUPIwEAoIxrSlqATDWrn8MV0xyunhZzBqeYDZgQXzRHk1GgHygtebLSVz_6j2fntHHFqtl2-ozFWCjPQGeYIO4dSFxW1Uw2q3MHSVHDpDe_Td8y2ZNtkNdYzd3naG32x50pe5bhBrobyBsNXzWOvhcMzoUxzeKR8SKV3fl70kpii-J1mkAt8AfBAfyqy5HpPgHkBn4MTSyWJRJEIVVO7jZnEBsvE1KTwhOh342ee4G2k5NJQ_9CpAlBVVgnMTojUAMUZ6JOCKucaTwsolUFgFHRsj3lJuO9Fe724ngkQeaVoZkOF3HlD4VRYDB_YY4qxnZbaNawwGLtftr4Nnzg5Zej9zJT2py0Ld6JOKxFkUQgJZrItyFoD5sLMaIiSVcudsC1wh3XohTfo678PGxcw8k9nJt8-DiAXkCy5cMQDF2AUAOnsO9ZWNbJMH7YAdt_rIW0YoBQH0qG4kmTJNeG-J7zkfeX1sNfBjqPyPoyn8kYC4gtthM1XcxQsf7wA6dAdYVcbi9OIyZ8ehb7ihhwO4nJDnRX5IcQlzFBtBkQCNHZWsdCD2AfgySU-804O4o42j20SM6qFHHVJPNX27HxCIPAGmOzQdHBwDka-wGQVdksdpdsZTJaBldw55sBxc26m125UZBO9EnLwKjJNIhdtYiC1GVWn4Qm54gQLjRX8cMJD_vQE61V4yHvKg8GiTNymOq0FuLMP1LTSqhN-Fi4aEYMTMeYCwpYuqrz3Xdr6YT28hp2IMtTUttSAtbt2VlBsRv7NrHCcmVKD2bXB0JU09HZgXmgecjSQs_JHvTXc59wH7-oE-dWscElq5N_MChcIC1Jy0QuhaJihzhiDnYjVdjoD9M2QxbwDlAODhan2zhHINpXsQayYlsp3ekTSFvwwUAeSBoxCxzC1onDwROpIcIkP4ZlgKrmMivd75MAj5FL6fpdcQm9Ijmfq13Lhd-Ymbw_k0QtDeEUdcDYomBqqVMO5dqKKJFVp9l6LQb19ezh30XmiCvVnkZJrOXDv3CoPPsHCzWB1eZh28IPoSFQdwMAI3IATlYDqzPCuPVeuQazeVcfE5HfH4EzC0qjTzR4EAhKFPmL4qHdg65b2XCPqEQA30HXS-YGyUZNnHmfNKQIDGI5FJdxAZ2Gug1CCIbZswCUGq0qprwN-VKQ5L394EmjsikSCG46wFyu0M3C-t6535n51XT1P2r_v5nVi6IU6_j48zHyNAKkcn1Gez42OiEWRxbvDIcM_Iy56QzF0ig7k-_Ml5egBOOxciqErjNSJzUA9yWPd-fnhkcKON8S4pUOVT57NkpOHs-HZw9l-vka-I8q9cR5OJtZKU0_C25U9XtFg004CbpMoCOC95tGyd3xqta6lL52J1U6jeNiLVbCzK4uOcxaNrZSOo-gFNdJoMGhti9u49guxrShK7lmT2Q6nY76_gdW2XzMzM29khMFTbxN3-aJOsqzcGVMrdce3G99qvTW1NJe8PoS3A2dsBUtr7Hlj68tsuKSP34y01bRb52ZR3JW5cZPkT3fR8871k8H9aJazPPf-YmSDgebjt8-Txpw_fWweh5sb_d4LiqfJk_H08LRsfJnxu8w2W8u57Tdlf2O1mlfYi7mApfXkmNw7o9FdEn7S9O5ZluvGX_vRdnNXZ479wJr0r_rGvM9XyUP6afXp220c8S-beLv5Nh820YPrfv5APr_8lWsvvfkxHqyf3fBBFgbrVvfN3br4_NXQXfPRK26ah2L-ceanw0D_-Nlf3_ibm9nyORiX4zuSc5F7pqw_hRb3afCtcMxqNPHr1eOH1PbCeCDks-vo2V_PjzJ7-Tqb3mnh0_Iz_TQzWPChqskHf2Hf3saJ-bJOvu6m4ZcyHGqDZJ58eJrsnnotv9lmszbLdxX_D9n_04TD7H_-geJ_AcEXH5I=

curl -v -si -H"X-Auth-Token:$TOKEN" -H "Content-type: application/json" http://localhost:35357/v3/domains
(debugging removed)

* Connection #0 to host localhost left intact
{"error": {"message": "The request you have made requires authentication. (Disable debug mode to suppress these details.)", "code": 401, "title": "Unauthorized"}}

Put a debugging breakpoint

--- a/keystone/middleware/core.py
+++ b/keystone/middleware/core.py
@@ -253,6 +253,8 @@ class AuthContextMiddleware(wsgi.Middleware):
         context['environment'] = request.environ

         try:
+ from remote_pdb import RemotePdb
+ RemotePdb('0.0.0.0', 4444).set_trace()
             token_ref = self.token_api.get_token(token_id)
             # TODO(ayoung): These two functions return the token in different
             # formats instead of two calls, only make one. However, the call

Shows that the unique Id calculated inside self.token_api.get_token does not match what the token table has in it.
Its using the SQL provider, and that delegates to the new persistance API, which in turn gets the unique ID from the token_provider. Note that this should be calling the token_provider directly.

[Morgan Fainberg (mdrnstm)]

@Adam

You're using an UNSCOPED token to make a call to 'get_domains' or is that a typo? (it looks like a typo in your description here as your JSON has the project specified in the scope).

1. If unscoped, how is this unscoped token an admin token?
2. Is this on a new devstack (fresh stack)?
3. What roles are in the token (is the 'admin user' an admin in the demo project?)? This is relevant because get_domains (default policy) requires admin.

By default it looks like we create an admin role on demo tenant for admin user: https://github.com/openstack-dev/devstack/blob/4f3b66f538937cf0c7f9fdc97e5472f4c77bbe69/lib/keystone#L366

Obviously this is not hitting all cases where the ID is mis-matched otherwise this would not have been able to pass gate/check (tempest and unit) and all v3 tokens would be busted. The way we calculate the short/unique id of the token has not changed.

This is the previous .get_token in the token_api: https://github.com/openstack/keystone/blob/1c88ead7b143e746ef0a73f42ec43d66ae3e8341/keystone/token/core.py#L129-L141

This is the new get_token (persistence): https://github.com/openstack/keystone/blob/master/keystone/token/persistence/core.py#L68-L81

The unique ID code is still: return cms.cms_hash_token(token_id, mode=CONF.token.hash_algorithm)

Which you can see didn't change before it was moved to token_provider:
https://github.com/openstack/keystone/blob/1612cb416821f5b3463619fc5f0c3c00c780e884/keystone/token/core.py#L114-L124

Does this indicate we somehow broke the token hashing along the way (either in keystoneclient, or the hashing algorithms)?

The AuthContextMiddleware has not received an update to reference the token provider (see revocation events breaking on federated users not having domains).

I'll take a deeper dive once the week starts.

[Adam Young (ayoung)]

I just confirmed that the second time through the cms.hash_token code the token_id is one character longer. running token_id.strip() cuts it down to the length of the original token id. Looks like an error on marshalling, appending a bogus space or non-printing character at the end of the string.

[OpenStack Infra (hudson-openstack)]

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

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/113108
Committed: https://git.openstack.org/cgit/openstack/keystone/commit/?id=a9736aa8acaaffd5bcbd630af4c6a7b3c7007c03
Submitter: Jenkins
Branch: master

commit a9736aa8acaaffd5bcbd630af4c6a7b3c7007c03
Author: Adam Young <email address hidden>
Date: Sat Aug 9 23:56:41 2014 -0400

    Clean whitespace off token.

    A bogus, non-visible character may be appended to the token.
    If it is, the hash will not match the original, and the token
    will be incorrectly reported as invalid.

    Change-Id: I7b2c831b85818a8c07616f44c1d501701c9d72f8
    Closes-Bug: 1354765

[Dolph Mathews (dolph)]

What was the character that you were seeing?

[Dolph Mathews (dolph)]

This doesn't look like a critical issue, it looks like your CLI work is including a line break.