search

CMSgov / bluebutton-web-server

Blue Button API
https://sandbox.bluebutton.cms.gov
Other
40 stars 24 forks source link

Oauth flow completes, but not authorized to access resource #510

Closed sverchdotgov closed 6 years ago

sverchdotgov commented 6 years ago

I'm trying to set up the environment locally with a small test client, but I can't seem to authenticate. The same code authenticates against the sandbox environment, so I suspect I missed some steps.

I'm working off current master: * 7d711ac (origin/master, master) Merge pull request #497 from CMSgov/develop.

I looked at https://github.com/CMSgov/bluebutton-web-server#setup, but it references a file that doesn't seem to exist (hhs_oauth_server/settings/local_sample.txt), so I'm guessing things have changed since that was written.

Steps I took to set the local instance up:

Test client code:

from requests_oauthlib import OAuth2Session
from flask import Flask, request, redirect, session, url_for
from flask.json import jsonify
import os

app = Flask(__name__)

# https://stackoverflow.com/questions/27785375/testing-flask-oauthlib-locally-without-https
os.environ['OAUTHLIB_INSECURE_TRANSPORT'] = '1'

# This information is obtained upon registration of a new GitHub OAuth
# application here: https://github.com/settings/applications/new
client_id = "R7wsHFuiUzLBvVBkCrViLfQL2vRcyc0LmSuuBpX4"
client_secret = "XXXXX"
authorization_base_url = 'http://localhost:8000/v1/o/authorize/'
token_url = 'http://localhost:8000/v1/o/token/'
redirect_uri = "http://localhost:5000/callback"

#client_id = "Vx5H94QUhKhTd7j2ZeTIgv2WJdZhoshwiod5kiKd"
#client_secret = "XXXXX"
#authorization_base_url = 'https://sandbox.bluebutton.cms.gov/v1/o/authorize/'
#token_url = 'https://sandbox.bluebutton.cms.gov/v1/o/token/'
#redirect_uri = "http://localhost:5000/callback"

@app.route("/")
def demo():
    """Step 1: User Authorization.

    Redirect the user/resource owner to the OAuth provider (i.e. Github)
    using an URL with a few key OAuth parameters.
    """
    app.logger.debug("Step 1: User Authorization.")
    github = OAuth2Session(client_id, redirect_uri=redirect_uri)
    authorization_url, state = github.authorization_url(authorization_base_url)
    app.logger.debug("Authorization URL: %s", authorization_url)

    # State is used to prevent CSRF, keep this for later.
    session['oauth_state'] = state
    app.logger.debug("OAuth State: %s", session['oauth_state'])
    return redirect(authorization_url)

# Step 2: User authorization, this happens on the provider.

@app.route("/callback", methods=["GET"])
def callback():
    """ Step 3: Retrieving an access token.

    The user has been redirected back from the provider to your registered
    callback URL. With this redirection comes an authorization code included
    in the redirect URL. We will use that to obtain an access token.
    """
    app.logger.debug("Step 1: Retrieving Access Token.")
    github = OAuth2Session(client_id, state=session['oauth_state'], redirect_uri=redirect_uri)
    app.logger.debug("Authorization Response: %s", request.url)
    app.logger.debug("Token URL: %s", token_url)
    token = github.fetch_token(token_url, client_secret=client_secret,
                               authorization_response=request.url)

    # At this point you can fetch protected resources but lets save
    # the token and show how this is done from a persisted token
    # in /profile.
    session['oauth_token'] = token
    app.logger.debug("Token: %s", session['oauth_token'])
    print session['oauth_token']

    return redirect(url_for('.profile'))

@app.route("/profile", methods=["GET"])
def profile():
    """Fetching a protected resource using an OAuth 2 token.
    """
    resource_url = 'https://sandbox.bluebutton.cms.gov/v1/connect/userinfo'
    app.logger.debug("Fetching URL: %s with token %s", resource_url, session['oauth_token'])
    github = OAuth2Session(client_id, token=session['oauth_token'], redirect_uri=redirect_uri)
    res = github.get(resource_url)
    app.logger.debug("Resource response code: %s", res.status_code)
    return jsonify(res.json())

if __name__ == "__main__":
    # This allows us to use a plain HTTP callback
    os.environ['DEBUG'] = "1"

    app.secret_key = os.urandom(24)
    app.run(debug=True)

Running invocation and log output:

$ python test_oauth_client.py 
 * Running on http://127.0.0.1:5000/ (Press CTRL+C to quit)
 * Restarting with stat
 * Debugger is active!
 * Debugger PIN: 780-654-211
--------------------------------------------------------------------------------
DEBUG in test_oauth_client [test_oauth_client.py:34]:
Step 1: User Authorization.
--------------------------------------------------------------------------------
--------------------------------------------------------------------------------
DEBUG in test_oauth_client [test_oauth_client.py:37]:
Authorization URL: http://localhost:8000/v1/o/authorize/?response_type=code&client_id=R7wsHFuiUzLBvVBkCrViLfQL2vRcyc0LmSuuBpX4&redirect_uri=http%3A%2F%2Flocalhost%3A5000%2Fcallback&state=MPvElFptoZKWRajVcNJ4pivLYK3Trw
--------------------------------------------------------------------------------
--------------------------------------------------------------------------------
DEBUG in test_oauth_client [test_oauth_client.py:41]:
OAuth State: MPvElFptoZKWRajVcNJ4pivLYK3Trw
--------------------------------------------------------------------------------
127.0.0.1 - - [15/Feb/2018 11:14:28] "GET / HTTP/1.1" 302 -
--------------------------------------------------------------------------------
DEBUG in test_oauth_client [test_oauth_client.py:55]:
Step 1: Retrieving Access Token.
--------------------------------------------------------------------------------
--------------------------------------------------------------------------------
DEBUG in test_oauth_client [test_oauth_client.py:57]:
Authorization Response: http://localhost:5000/callback?code=aHZ1qCYcHzNjTWf9yJys4GjfL4v5ss&state=MPvElFptoZKWRajVcNJ4pivLYK3Trw
--------------------------------------------------------------------------------
--------------------------------------------------------------------------------
DEBUG in test_oauth_client [test_oauth_client.py:58]:
Token URL: http://localhost:8000/v1/o/token/
--------------------------------------------------------------------------------
--------------------------------------------------------------------------------
DEBUG in test_oauth_client [test_oauth_client.py:66]:
Token: {u'token_type': u'Bearer', u'patient': u'20140000008325', u'refresh_token': u'lWijMeqxMaxtXPal49oKOiDUp1abV6', u'access_token': u'sample-token-string', u'scope': [u'profile', u'patient/Patient.read', u'patient/ExplanationOfBenefit.read', u'patient/Coverage.read'], u'expires_in': 86219.14765, u'expires_at': 1518797488.542184}
--------------------------------------------------------------------------------
{u'token_type': u'Bearer', u'patient': u'20140000008325', u'refresh_token': u'lWijMeqxMaxtXPal49oKOiDUp1abV6', u'access_token': u'sample-token-string', u'scope': [u'profile', u'patient/Patient.read', u'patient/ExplanationOfBenefit.read', u'patient/Coverage.read'], u'expires_in': 86219.14765, u'expires_at': 1518797488.542184}
127.0.0.1 - - [15/Feb/2018 11:14:29] "GET /callback?code=aHZ1qCYcHzNjTWf9yJys4GjfL4v5ss&state=MPvElFptoZKWRajVcNJ4pivLYK3Trw HTTP/1.1" 302 -
--------------------------------------------------------------------------------
DEBUG in test_oauth_client [test_oauth_client.py:77]:
Fetching URL: https://sandbox.bluebutton.cms.gov/v1/connect/userinfo with token {u'patient': u'20140000008325', u'access_token': u'sample-token-string', u'expires_in': 86219.14765, u'expires_at': 1518797488.542184, u'token_type': u'Bearer', u'scope': [u'profile', u'patient/Patient.read', u'patient/ExplanationOfBenefit.read', u'patient/Coverage.read'], u'refresh_token': u'lWijMeqxMaxtXPal49oKOiDUp1abV6'}
--------------------------------------------------------------------------------
--------------------------------------------------------------------------------
DEBUG in test_oauth_client [test_oauth_client.py:80]:
Resource response code: 403
--------------------------------------------------------------------------------
127.0.0.1 - - [15/Feb/2018 11:14:29] "GET /profile HTTP/1.1" 500 -
Traceback (most recent call last):
  File "/home/sverch/USDS/HHS/repos/bluebutton-web-server/env/lib/python2.7/site-packages/flask/app.py", line 1997, in __call__
    return self.wsgi_app(environ, start_response)
  File "/home/sverch/USDS/HHS/repos/bluebutton-web-server/env/lib/python2.7/site-packages/flask/app.py", line 1985, in wsgi_app
    response = self.handle_exception(e)
  File "/home/sverch/USDS/HHS/repos/bluebutton-web-server/env/lib/python2.7/site-packages/flask/app.py", line 1540, in handle_exception
    reraise(exc_type, exc_value, tb)
  File "/home/sverch/USDS/HHS/repos/bluebutton-web-server/env/lib/python2.7/site-packages/flask/app.py", line 1982, in wsgi_app
    response = self.full_dispatch_request()
  File "/home/sverch/USDS/HHS/repos/bluebutton-web-server/env/lib/python2.7/site-packages/flask/app.py", line 1614, in full_dispatch_request
    rv = self.handle_user_exception(e)
  File "/home/sverch/USDS/HHS/repos/bluebutton-web-server/env/lib/python2.7/site-packages/flask/app.py", line 1517, in handle_user_exception
    reraise(exc_type, exc_value, tb)
  File "/home/sverch/USDS/HHS/repos/bluebutton-web-server/env/lib/python2.7/site-packages/flask/app.py", line 1612, in full_dispatch_request
    rv = self.dispatch_request()
  File "/home/sverch/USDS/HHS/repos/bluebutton-web-server/env/lib/python2.7/site-packages/flask/app.py", line 1598, in dispatch_request
    return self.view_functions[rule.endpoint](**req.view_args)
  File "/home/sverch/USDS/HHS/repos/bluebutton-web-server/test_oauth_client.py", line 81, in profile
    return jsonify(res.json())
  File "/home/sverch/USDS/HHS/repos/bluebutton-web-server/env/lib/python2.7/site-packages/requests/models.py", line 892, in json
    return complexjson.loads(self.text, **kwargs)
  File "/usr/lib64/python2.7/json/__init__.py", line 339, in loads
    return _default_decoder.decode(s)
  File "/usr/lib64/python2.7/json/decoder.py", line 364, in decode
    obj, end = self.raw_decode(s, idx=_w(s, 0).end())
  File "/usr/lib64/python2.7/json/decoder.py", line 382, in raw_decode
    raise ValueError("No JSON object could be decoded")
ValueError: No JSON object could be decoded
127.0.0.1 - - [15/Feb/2018 11:14:29] "GET /profile?__debugger__=yes&cmd=resource&f=style.css HTTP/1.1" 200 -
127.0.0.1 - - [15/Feb/2018 11:14:29] "GET /profile?__debugger__=yes&cmd=resource&f=jquery.js HTTP/1.1" 200 -
127.0.0.1 - - [15/Feb/2018 11:14:29] "GET /profile?__debugger__=yes&cmd=resource&f=debugger.js HTTP/1.1" 200 -
127.0.0.1 - - [15/Feb/2018 11:14:29] "GET /profile?__debugger__=yes&cmd=resource&f=console.png HTTP/1.1" 200 -
127.0.0.1 - - [15/Feb/2018 11:14:29] "GET /profile?__debugger__=yes&cmd=resource&f=console.png HTTP/1.1" 200 -

Log output from local server:

web_1  | 2018-02-15 16:13:34,751 INFO [10] performance.hhs_oauth_server.request_logging line:64 2018-02-15T16:13:34.750845 request    2c38a8e0-126b-11e8-9a1f-0242ac120003  1 /v1/o/applications/1/update/ +0:00:00 
web_1  | 2018-02-15 16:13:34,752 INFO [10] performance.hhs_oauth_server.request_logging line:64 2018-02-15T16:13:34.752321 response   2c38a8e0-126b-11e8-9a1f-0242ac120003  2 /v1/o/applications/1/update/ +0:00:00.001476 302 => /v1/accounts/mfa/login?next=/v1/o/applications/1/update/
web_1  | [15/Feb/2018 16:13:34] "GET /v1/o/applications/1/update/ HTTP/1.1" 302 0
web_1  | 2018-02-15 16:13:34,763 INFO [10] performance.hhs_oauth_server.request_logging line:64 2018-02-15T16:13:34.763667 request    2c3a96f0-126b-11e8-b547-0242ac120003  1 /v1/accounts/mfa/login +0:00:00 
web_1  | 2018-02-15 16:13:34,786 INFO [10] performance.hhs_oauth_server.request_logging line:64 2018-02-15T16:13:34.786530 response   2c3a96f0-126b-11e8-b547-0242ac120003  2 /v1/accounts/mfa/login +0:00:00.022863 200 (7630b)
web_1  | [15/Feb/2018 16:13:34] "GET /v1/accounts/mfa/login?next=/v1/o/applications/1/update/ HTTP/1.1" 200 7630
web_1  | 2018-02-15 16:13:45,374 INFO [10] performance.hhs_oauth_server.request_logging line:64 2018-02-15T16:13:45.374379 request    328dabc8-126b-11e8-9d99-0242ac120003  1 /v1/accounts/mfa/login +0:00:00 
web_1  | 2018-02-15 16:13:45,429 INFO [10] hhs_oauth_server.accounts line:129 Successful login from 172.18.0.1
web_1  | 2018-02-15 16:13:45,429 INFO [10] performance.hhs_oauth_server.request_logging line:64 2018-02-15T16:13:45.429487 response   328dabc8-126b-11e8-9d99-0242ac120003  2 /v1/accounts/mfa/login +0:00:00.055108 302 => /v1/o/applications/1/update/
web_1  | [15/Feb/2018 16:13:45] "POST /v1/accounts/mfa/login?next=/v1/o/applications/1/update/ HTTP/1.1" 302 0
web_1  | 2018-02-15 16:13:45,434 INFO [10] performance.hhs_oauth_server.request_logging line:64 2018-02-15T16:13:45.434474 request    3296d1e4-126b-11e8-b0a7-0242ac120003  1 /v1/o/applications/1/update/ +0:00:00 
web_1  | 2018-02-15 16:13:45,473 INFO [10] performance.hhs_oauth_server.request_logging line:64 2018-02-15T16:13:45.473164 response   3296d1e4-126b-11e8-b0a7-0242ac120003  2 /v1/o/applications/1/update/ +0:00:00.038690 200 (13375b)
web_1  | [15/Feb/2018 16:13:45] "GET /v1/o/applications/1/update/ HTTP/1.1" 200 13375
web_1  | 2018-02-15 16:13:54,055 INFO [10] performance.hhs_oauth_server.request_logging line:64 2018-02-15T16:13:54.054953 request    37ba3814-126b-11e8-b9f4-0242ac120003  1 /v1/o/applications/1/update/ +0:00:00 
web_1  | 2018-02-15 16:13:54,071 INFO [10] hhs_server.apps.dot_ext.models line:57 fred agreed to https://cmsgov.github.io/bluebutton-developer-help/api-terms-of-use.html for the application TestApp on 2018-02-15 16:13:54.068875+00:00
web_1  | 2018-02-15 16:13:54,073 INFO [10] performance.hhs_oauth_server.request_logging line:64 2018-02-15T16:13:54.073842 response   37ba3814-126b-11e8-b9f4-0242ac120003  2 /v1/o/applications/1/update/ +0:00:00.018889 302 => /v1/o/applications/1/
web_1  | [15/Feb/2018 16:13:54] "POST /v1/o/applications/1/update/ HTTP/1.1" 302 0
web_1  | 2018-02-15 16:13:54,076 INFO [10] performance.hhs_oauth_server.request_logging line:64 2018-02-15T16:13:54.076671 request    37bd82d0-126b-11e8-a86b-0242ac120003  1 /v1/o/applications/1/ +0:00:00 
web_1  | 2018-02-15 16:13:54,097 INFO [10] performance.hhs_oauth_server.request_logging line:64 2018-02-15T16:13:54.097223 response   37bd82d0-126b-11e8-a86b-0242ac120003  2 /v1/o/applications/1/ +0:00:00.020552 200 (10032b)
web_1  | [15/Feb/2018 16:13:54] "GET /v1/o/applications/1/ HTTP/1.1" 200 10032
web_1  | 2018-02-15 16:14:03,619 INFO [10] performance.hhs_oauth_server.request_logging line:64 2018-02-15T16:14:03.619136 request    3d6d9936-126b-11e8-9096-0242ac120003  1 /v1/o/authorize/ +0:00:00 
web_1  | 2018-02-15 16:14:03,648 INFO [10] performance.hhs_oauth_server.request_logging line:64 2018-02-15T16:14:03.648802 response   3d6d9936-126b-11e8-9096-0242ac120003  2 /v1/o/authorize/ +0:00:00.029666 200 (4431b)
web_1  | [15/Feb/2018 16:14:03] "GET /v1/o/authorize/?response_type=code&client_id=R7wsHFuiUzLBvVBkCrViLfQL2vRcyc0LmSuuBpX4&redirect_uri=http%3A%2F%2Flocalhost%3A5000%2Fcallback&state=8OAUsepwyvKskuNvbyZdVQCq17bMC8 HTTP/1.1" 200 4431
web_1  | 2018-02-15 16:14:05,182 INFO [10] performance.hhs_oauth_server.request_logging line:64 2018-02-15T16:14:05.182018 request    3e5c1354-126b-11e8-8a94-0242ac120003  1 /v1/o/authorize/ +0:00:00 
web_1  | 2018-02-15 16:14:05,197 INFO [10] performance.hhs_oauth_server.request_logging line:64 2018-02-15T16:14:05.196985 response   3e5c1354-126b-11e8-8a94-0242ac120003  2 /v1/o/authorize/ +0:00:00.014967 302 => http://localhost:5000/callback?code=ejBtExTJjiCq9LXAsN8of3FEKVefAH&state=8OAUsepwyvKskuNvbyZdVQCq17bMC8
web_1  | [15/Feb/2018 16:14:05] "POST /v1/o/authorize/?response_type=code&client_id=R7wsHFuiUzLBvVBkCrViLfQL2vRcyc0LmSuuBpX4&redirect_uri=http%3A%2F%2Flocalhost%3A5000%2Fcallback&state=8OAUsepwyvKskuNvbyZdVQCq17bMC8 HTTP/1.1" 302 0
web_1  | 2018-02-15 16:14:05,204 INFO [10] performance.hhs_oauth_server.request_logging line:64 2018-02-15T16:14:05.204006 request    3e5f69c8-126b-11e8-a450-0242ac120003  1 /v1/o/token/ +0:00:00 
web_1  | 2018-02-15 16:14:05,226 INFO [10] performance.hhs_oauth_server.request_logging line:64 2018-02-15T16:14:05.226129 response   3e5f69c8-126b-11e8-a450-0242ac120003  2 /v1/o/token/ +0:00:00.022123 200 (268b)
web_1  | [15/Feb/2018 16:14:05] "POST /v1/o/token/ HTTP/1.1" 200 268
web_1  | 2018-02-15 16:14:28,202 INFO [10] performance.hhs_oauth_server.request_logging line:64 2018-02-15T16:14:28.202332 request    4c14b6b8-126b-11e8-aba2-0242ac120003  1 /v1/o/authorize/ +0:00:00 
web_1  | 2018-02-15 16:14:28,229 INFO [10] performance.hhs_oauth_server.request_logging line:64 2018-02-15T16:14:28.229411 response   4c14b6b8-126b-11e8-aba2-0242ac120003  2 /v1/o/authorize/ +0:00:00.027079 200 (4431b)
web_1  | [15/Feb/2018 16:14:28] "GET /v1/o/authorize/?response_type=code&client_id=R7wsHFuiUzLBvVBkCrViLfQL2vRcyc0LmSuuBpX4&redirect_uri=http%3A%2F%2Flocalhost%3A5000%2Fcallback&state=MPvElFptoZKWRajVcNJ4pivLYK3Trw HTTP/1.1" 200 4431
web_1  | 2018-02-15 16:14:29,462 INFO [10] performance.hhs_oauth_server.request_logging line:64 2018-02-15T16:14:29.462081 request    4cd4f874-126b-11e8-b971-0242ac120003  1 /v1/o/authorize/ +0:00:00 
web_1  | 2018-02-15 16:14:29,498 INFO [10] performance.hhs_oauth_server.request_logging line:64 2018-02-15T16:14:29.498174 response   4cd4f874-126b-11e8-b971-0242ac120003  2 /v1/o/authorize/ +0:00:00.036093 302 => http://localhost:5000/callback?code=aHZ1qCYcHzNjTWf9yJys4GjfL4v5ss&state=MPvElFptoZKWRajVcNJ4pivLYK3Trw
web_1  | [15/Feb/2018 16:14:29] "POST /v1/o/authorize/?response_type=code&client_id=R7wsHFuiUzLBvVBkCrViLfQL2vRcyc0LmSuuBpX4&redirect_uri=http%3A%2F%2Flocalhost%3A5000%2Fcallback&state=MPvElFptoZKWRajVcNJ4pivLYK3Trw HTTP/1.1" 302 0
web_1  | 2018-02-15 16:14:29,508 INFO [10] performance.hhs_oauth_server.request_logging line:64 2018-02-15T16:14:29.507863 request    4cdbe45e-126b-11e8-b3a2-0242ac120003  1 /v1/o/token/ +0:00:00 
web_1  | 2018-02-15 16:14:29,540 INFO [10] performance.hhs_oauth_server.request_logging line:64 2018-02-15T16:14:29.540167 response   4cdbe45e-126b-11e8-b3a2-0242ac120003  2 /v1/o/token/ +0:00:00.032304 200 (267b)
web_1  | [15/Feb/2018 16:14:29] "POST /v1/o/token/ HTTP/1.1" 200 267

Is there some step I missed to actually get the data from the backing provider? It's strange though, because I'm just trying to get the profile information.

aviars commented 6 years ago

@sverchdotgov Perhaps your app is not configured to use all the scopes? Double check that. By default, all scopes are selected unless you check otherwise.

sverchdotgov commented 6 years ago

@aviars I checked, and I do seem to have all the scopes selected in the account I'm authorizing with.

whytheplatypus commented 6 years ago

@sverchdotgov if you're running it locally and loging in with the root user that you created during setup that user probably doesn't have an associated Crosswalk