Fix refresh_token parsing, use named logger

Fixes #23 and #25.

AUTHORS.md

@@ -13,5 +13,6 @@ The following wonderful people contributed directly or indirectly to this projec
 - Josh Mandel <https://github.com/jmandel>
 - Nikolai Schwertner <https://github.com/nschwertner>
 - Pascal Pfiffner <https://github.com/p2>
+- Trinadh Baranika <https://github.com/bktrinadh>
 
 Please add yourself here alphabetically when you submit your first pull request.

fhir-parser-resources/fhirabstractbase.py

@@ -6,6 +6,8 @@
 import sys
 import logging
 
+logger = logging.getLogger(__name__)
+
 
 class FHIRValidationError(Exception):
     """ Exception raised when one or more errors occurred during model
@@ -46,7 +48,7 @@ class FHIRAbstractBase(object):
 
     def __init__(self, jsondict=None, strict=True):
         """ Initializer. If strict is true, raises on errors, otherwise uses
-        `logging.warning()`.
+        `logger.warning()`.
         
         :raises: FHIRValidationError on validation errors, unless strict is False
         :param dict jsondict: A JSON dictionary to use for initialization
@@ -67,7 +69,7 @@ def __init__(self, jsondict=None, strict=True):
                     self.update_with_json(jsondict)
                 except FHIRValidationError as e:
                     for err in e.errors:
-                        logging.warning(err)
+                        logger.warning(err)
 
 
     # MARK: Instantiation from JSON

fhir-parser-resources/fhirdate.py

@@ -9,6 +9,8 @@
 import isodate
 import datetime
 
+logger = logging.getLogger(__name__)
+
 
 class FHIRDate(object):
     """ Facilitate working with dates.
@@ -31,7 +33,7 @@ def __init__(self, jsonval=None):
                 else:
                     self.date = isodate.parse_date(jsonval)
             except Exception as e:
-                logging.warning("Failed to initialize FHIRDate from \"{}\": {}"
+                logger.warning("Failed to initialize FHIRDate from \"{}\": {}"
                     .format(jsonval, e))
 
         self.origval = jsonval

fhir-parser-resources/fhirreference.py

@@ -6,6 +6,8 @@
 import logging
 from . import reference
 
+logger = logging.getLogger(__name__)
+
 
 class FHIRReference(reference.Reference):
     """ Subclassing FHIR's `Reference` resource to add resolving capabilities.
@@ -27,15 +29,15 @@ def resolved(self, klass):
 
         refid = self.processedReferenceIdentifier()
         if not refid:
-            logging.warning("No `reference` set, cannot resolve")
+            logger.warning("No `reference` set, cannot resolve")
             return None
 
         # already resolved and cached?
         resolved = owning_resource.resolvedReference(refid)
         if resolved is not None:
             if isinstance(resolved, klass):
                 return resolved
-            logging.warning("Referenced resource {} is not a {} but a {}".format(refid, klass, resolved.__class__))
+            logger.warning("Referenced resource {} is not a {} but a {}".format(refid, klass, resolved.__class__))
             return None
 
         # not yet resolved, see if it's a contained resource
@@ -45,7 +47,7 @@ def resolved(self, klass):
                     owning_resource.didResolveReference(refid, contained)
                     if isinstance(contained, klass):
                         return contained
-                    logging.warning("Contained resource {} is not a {} but a {}".format(refid, klass, contained.__class__))
+                    logger.warning("Contained resource {} is not a {} but a {}".format(refid, klass, contained.__class__))
                     return None
 
         # are we in a bundle?
@@ -65,7 +67,7 @@ def resolved(self, klass):
                         found = entry.resource
                         if isinstance(found, klass):
                             return found
-                        logging.warning("Bundled resource {} is not a {} but a {}".format(refid, klass, found.__class__))
+                        logger.warning("Bundled resource {} is not a {} but a {}".format(refid, klass, found.__class__))
                         return None
             bundle = bundle.owningBundle()
 
@@ -76,7 +78,7 @@ def resolved(self, klass):
 
         # TODO: instantiate server for absolute resource
         if server is None:
-            logging.warning("Not implemented: resolving absolute reference to resource {}"
+            logger.warning("Not implemented: resolving absolute reference to resource {}"
                 .format(self.reference))
             return None
 

fhirclient/auth.py

@@ -9,6 +9,7 @@
     import urllib.parse as urlparse
     from urllib.parse import urlencode
 
+logger = logging.getLogger(__name__)
 
 class FHIRAuth(object):
     """ Superclass to handle authorization flow and state.
@@ -53,7 +54,7 @@ def from_capability_security(cls, security, state=None):
                                 state['registration_uri'] = ee.valueUri
                         break
                     else:
-                        logging.warning("SMART AUTH: invalid `http://fhir-registry.smarthealthit.org/StructureDefinition/oauth-uris` extension: needs to include sub-extensions to define OAuth2 endpoints but there are none")
+                        logger.warning("SMART AUTH: invalid `http://fhir-registry.smarthealthit.org/StructureDefinition/oauth-uris` extension: needs to include sub-extensions to define OAuth2 endpoints but there are none")
 
                 # fallback to old extension URLs  
                 elif "http://fhir-registry.smarthealthit.org/StructureDefinition/oauth-uris#register" == e.url:
@@ -182,7 +183,7 @@ def authorize_uri(self, server):
         stored.
         """
         auth_params = self._authorize_params(server)
-        logging.debug("SMART AUTH: Will use parameters for `authorize_uri`: {0}".format(auth_params))
+        logger.debug("SMART AUTH: Will use parameters for `authorize_uri`: {0}".format(auth_params))
 
         # the authorize uri may have params, make sure to not lose them
         parts = list(urlparse.urlsplit(self._authorize_uri))
@@ -223,7 +224,7 @@ def handle_callback(self, url, server):
         :param server: The Server instance to use
         :returns: The launch context dictionary
         """
-        logging.debug("SMART AUTH: Handling callback URL")
+        logger.debug("SMART AUTH: Handling callback URL")
         if url is None:
             raise Exception("No callback URL received")
         try:
@@ -270,7 +271,7 @@ def _request_access_token(self, server, params):
         if server is None:
             raise Exception("I need a server to request an access token")
 
-        logging.debug("SMART AUTH: Requesting access token from {0}".format(self._token_uri))
+        logger.debug("SMART AUTH: Requesting access token from {0}".format(self._token_uri))
         auth = None
         if self.app_secret:
             auth = (self.app_id, self.app_secret)
@@ -280,14 +281,19 @@ def _request_access_token(self, server, params):
         if self.access_token is None:
             raise Exception("No access token received")
         del ret_params['access_token']
+
         if 'expires_in' in ret_params:
             del ret_params['expires_in']
 
-        self.refresh_token = ret_params.get('refresh_token')
-        if self.refresh_token is not None:
+        # The refresh token issued by the authorization server. If present, the
+        # app should discard any previous refresh_token associated with this
+        # launch, replacing it with this new value.
+        refresh_token = ret_params.get('refresh_token')
+        if refresh_token is not None:
+            self.refresh_token = refresh_token
             del ret_params['refresh_token']
 
-        logging.debug("SMART AUTH: Received access token: {0}, refresh token: {1}"
+        logger.debug("SMART AUTH: Received access token: {0}, refresh token: {1}"
             .format(self.access_token is not None, self.refresh_token is not None))
         return ret_params
 
@@ -301,10 +307,10 @@ def reauthorize(self, server):
         :returns: The launch context dictionary, or None on failure
         """
         if self.refresh_token is None:
-            logging.debug("SMART AUTH: Cannot reauthorize without refresh token")
+            logger.debug("SMART AUTH: Cannot reauthorize without refresh token")
             return None
 
-        logging.debug("SMART AUTH: Refreshing token")
+        logger.debug("SMART AUTH: Refreshing token")
         reauth = self._reauthorize_params()
         return self._request_access_token(server, reauth)
 

fhirclient/client.py

@@ -13,6 +13,9 @@
 scope_haslaunch = 'launch'
 scope_patientlaunch = 'launch/patient'
 
+logger = logging.getLogger(__name__)
+
+
 class FHIRClient(object):
     """ Instances of this class handle authorizing and talking to SMART on FHIR
     servers.
@@ -139,12 +142,12 @@ def reauthorize(self):
         return self.launch_context is not None
 
     def _handle_launch_context(self, ctx):
-        logging.debug("SMART: Handling launch context: {0}".format(ctx))
+        logger.debug("SMART: Handling launch context: {0}".format(ctx))
         if 'patient' in ctx:
             #print('Patient id was {0}, row context is {1}'.format(self.patient_id, ctx))
             self.patient_id = ctx['patient']        # TODO: TEST THIS!
         if 'id_token' in ctx:
-            logging.warning("SMART: Received an id_token, ignoring")
+            logger.warning("SMART: Received an id_token, ignoring")
         self.launch_context = ctx
         self.save_state()
 
@@ -156,15 +159,15 @@ def patient(self):
         if self._patient is None and self.patient_id is not None and self.ready:
             import models.patient
             try:
-                logging.debug("SMART: Attempting to read Patient {0}".format(self.patient_id))
+                logger.debug("SMART: Attempting to read Patient {0}".format(self.patient_id))
                 self._patient = models.patient.Patient.read(self.patient_id, self.server)
             except FHIRUnauthorizedException as e:
                 if self.reauthorize():
-                    logging.debug("SMART: Attempting to read Patient {0} after reauthorizing"
+                    logger.debug("SMART: Attempting to read Patient {0} after reauthorizing"
                         .format(self.patient_id))
                     self._patient = models.patient.Patient.read(self.patient_id, self.server)
             except FHIRNotFoundException as e:
-                logging.warning("SMART: Patient with id {0} not found".format(self.patient_id))
+                logger.warning("SMART: Patient with id {0} not found".format(self.patient_id))
                 self.patient_id = None
             self.save_state()
 

fhirclient/models/fhirabstractbase.py

@@ -6,6 +6,8 @@
 import sys
 import logging
 
+logger = logging.getLogger(__name__)
+
 
 class FHIRValidationError(Exception):
     """ Exception raised when one or more errors occurred during model
@@ -46,7 +48,7 @@ class FHIRAbstractBase(object):
 
     def __init__(self, jsondict=None, strict=True):
         """ Initializer. If strict is true, raises on errors, otherwise uses
-        `logging.warning()`.
+        `logger.warning()`.
         
         :raises: FHIRValidationError on validation errors, unless strict is False
         :param dict jsondict: A JSON dictionary to use for initialization
@@ -67,7 +69,7 @@ def __init__(self, jsondict=None, strict=True):
                     self.update_with_json(jsondict)
                 except FHIRValidationError as e:
                     for err in e.errors:
-                        logging.warning(err)
+                        logger.warning(err)
 
 
     # MARK: Instantiation from JSON

fhirclient/models/fhirdate.py

@@ -9,6 +9,8 @@
 import isodate
 import datetime
 
+logger = logging.getLogger(__name__)
+
 
 class FHIRDate(object):
     """ Facilitate working with dates.
@@ -31,7 +33,7 @@ def __init__(self, jsonval=None):
                 else:
                     self.date = isodate.parse_date(jsonval)
             except Exception as e:
-                logging.warning("Failed to initialize FHIRDate from \"{}\": {}"
+                logger.warning("Failed to initialize FHIRDate from \"{}\": {}"
                     .format(jsonval, e))
 
         self.origval = jsonval

fhirclient/models/fhirreference.py

@@ -6,6 +6,8 @@
 import logging
 from . import reference
 
+logger = logging.getLogger(__name__)
+
 
 class FHIRReference(reference.Reference):
     """ Subclassing FHIR's `Reference` resource to add resolving capabilities.
@@ -27,15 +29,15 @@ def resolved(self, klass):
 
         refid = self.processedReferenceIdentifier()
         if not refid:
-            logging.warning("No `reference` set, cannot resolve")
+            logger.warning("No `reference` set, cannot resolve")
             return None
 
         # already resolved and cached?
         resolved = owning_resource.resolvedReference(refid)
         if resolved is not None:
             if isinstance(resolved, klass):
                 return resolved
-            logging.warning("Referenced resource {} is not a {} but a {}".format(refid, klass, resolved.__class__))
+            logger.warning("Referenced resource {} is not a {} but a {}".format(refid, klass, resolved.__class__))
             return None
 
         # not yet resolved, see if it's a contained resource
@@ -45,7 +47,7 @@ def resolved(self, klass):
                     owning_resource.didResolveReference(refid, contained)
                     if isinstance(contained, klass):
                         return contained
-                    logging.warning("Contained resource {} is not a {} but a {}".format(refid, klass, contained.__class__))
+                    logger.warning("Contained resource {} is not a {} but a {}".format(refid, klass, contained.__class__))
                     return None
 
         # are we in a bundle?
@@ -65,7 +67,7 @@ def resolved(self, klass):
                         found = entry.resource
                         if isinstance(found, klass):
                             return found
-                        logging.warning("Bundled resource {} is not a {} but a {}".format(refid, klass, found.__class__))
+                        logger.warning("Bundled resource {} is not a {} but a {}".format(refid, klass, found.__class__))
                         return None
             bundle = bundle.owningBundle()
 
@@ -76,7 +78,7 @@ def resolved(self, klass):
 
         # TODO: instantiate server for absolute resource
         if server is None:
-            logging.warning("Not implemented: resolving absolute reference to resource {}"
+            logger.warning("Not implemented: resolving absolute reference to resource {}"
                 .format(self.reference))
             return None
 

fhirclient/server.py

@@ -13,6 +13,8 @@
 
 FHIRJSONMimeType = 'application/fhir+json'
 
+logger = logging.getLogger(__name__)
+
 
 class FHIRUnauthorizedException(Exception):
     """ Indicating a 401 response.
@@ -75,7 +77,7 @@ def get_capability(self, force=False):
         or forced.
         """
         if self._capability is None or force:
-            logging.info('Fetching CapabilityStatement from {0}'.format(self.base_uri))
+            logger.info('Fetching CapabilityStatement from {0}'.format(self.base_uri))
             from models import capabilitystatement
             conf = capabilitystatement.CapabilityStatement.read_from('metadata', self)
             self._capability = conf
@@ -84,7 +86,7 @@ def get_capability(self, force=False):
             try:
                 security = conf.rest[0].security
             except Exception as e:
-                logging.info("No REST security statement found in server capability statement")
+                logger.info("No REST security statement found in server capability statement")
 
             settings = {
                 'aud': self.base_uri,