Merge pull request #110 from Microsoft/dev

0.1.15 - logging fixes

vsts/setup.py

@@ -6,7 +6,7 @@
 from setuptools import setup, find_packages
 
 NAME = "vsts"
-VERSION = "0.1.14"
+VERSION = "0.1.15"
 
 # To install the library, run the following
 #

vsts/vsts/_file_cache.py

@@ -14,6 +14,9 @@
     import collections
 
 
+logger = logging.getLogger(__name__)
+
+
 class FileCache(collections.MutableMapping):
     """A simple dict-like class that is backed by a JSON file.
 
@@ -33,20 +36,20 @@ def load(self):
         try:
             if os.path.isfile(self.file_name):
                 if self.max_age > 0 and os.stat(self.file_name).st_mtime + self.max_age < time.clock():
-                    logging.debug('Cache file expired: %s', file=self.file_name)
+                    logger.debug('Cache file expired: %s', file=self.file_name)
                     os.remove(self.file_name)
                 else:
-                    logging.debug('Loading cache file: %s', self.file_name)
+                    logger.debug('Loading cache file: %s', self.file_name)
                     self.data = get_file_json(self.file_name, throw_on_empty=False) or {}
             else:
-                logging.debug('Cache file does not exist: %s', self.file_name)
+                logger.debug('Cache file does not exist: %s', self.file_name)
         except Exception as ex:
-            logging.exception(ex)
+            logger.debug(ex, exc_info=True)
             # file is missing or corrupt so attempt to delete it
             try:
                 os.remove(self.file_name)
             except Exception as ex2:
-                logging.exception(ex2)
+                logger.debug(ex2, exc_info=True)
         self.initial_load_occurred = True
 
     def save(self):
@@ -71,10 +74,10 @@ def save_with_retry(self, retries=5):
 
     def clear(self):
         if os.path.isfile(self.file_name):
-            logging.info("Deleting file: " + self.file_name)
+            logger.info("Deleting file: " + self.file_name)
             os.remove(self.file_name)
         else:
-            logging.info("File does not exist: " + self.file_name)
+            logger.info("File does not exist: " + self.file_name)
 
     def get(self, key, default=None):
         self._check_for_initial_load()
@@ -144,12 +147,12 @@ def read_file_content(file_path, allow_binary=False):
     for encoding in ['utf-8-sig', 'utf-8', 'utf-16', 'utf-16le', 'utf-16be']:
         try:
             with codecs_open(file_path, encoding=encoding) as f:
-                logging.debug("attempting to read file %s as %s", file_path, encoding)
+                logger.debug("attempting to read file %s as %s", file_path, encoding)
                 return f.read()
         except UnicodeDecodeError:
             if allow_binary:
                 with open(file_path, 'rb') as input_file:
-                    logging.debug("attempting to read file %s as binary", file_path)
+                    logger.debug("attempting to read file %s as binary", file_path)
                     return base64.b64encode(input_file.read()).decode("utf-8")
             else:
                 raise

vsts/vsts/exceptions.py

@@ -5,7 +5,6 @@
 
 from msrest.exceptions import (
     ClientException,
-    TokenExpiredError,
     ClientRequestError,
     AuthenticationError,
 )

vsts/vsts/version.py

@@ -3,4 +3,4 @@
 # Licensed under the MIT License. See License.txt in the project root for license information.
 # --------------------------------------------------------------------------------------------
 
-VERSION = "0.1.14"
+VERSION = "0.1.15"

vsts/vsts/vss_client.py

@@ -20,6 +20,9 @@
 from ._file_cache import OPTIONS_CACHE as OPTIONS_FILE_CACHE
 
 
+logger = logging.getLogger(__name__)
+
+
 class VssClient(object):
     """VssClient.
     :param str base_url: Service URL
@@ -50,11 +53,11 @@ def _send_request(self, request, headers=None, content=None, **operation_config)
         """
         if TRACE_ENV_VAR in os.environ and os.environ[TRACE_ENV_VAR] == 'true':
             print(request.method + ' ' + request.url)
-        logging.debug('%s %s', request.method, request.url)
-        logging.debug('Request content: %s', content)
+        logger.debug('%s %s', request.method, request.url)
+        logger.debug('Request content: %s', content)
         response = self._client.send(request=request, headers=headers,
                                      content=content, **operation_config)
-        logging.debug('Response content: %s', response.content)
+        logger.debug('Response content: %s', response.content)
         if response.status_code < 200 or response.status_code >= 300:
             self._handle_error(request, response)
         return response
@@ -71,11 +74,11 @@ def _send(self, http_method, location_id, version, route_values=None,
             version)
 
         if version != negotiated_version:
-            logging.info("Negotiated api version from '%s' down to '%s'. This means the client is newer than the server.",
-                         version,
-                         negotiated_version)
+            logger.info("Negotiated api version from '%s' down to '%s'. This means the client is newer than the server.",
+                        version,
+                        negotiated_version)
         else:
-            logging.debug("Api version '%s'", negotiated_version)
+            logger.debug("Api version '%s'", negotiated_version)
 
         # Construct headers
         headers = {'Content-Type': media_type + '; charset=utf-8',
@@ -112,7 +115,7 @@ def _create_request_message(self, http_method, location_id, route_values=None,
         route_values['resource'] = location.resource_name
         route_template = self._remove_optional_route_parameters(location.route_template,
                                                                 route_values)
-        logging.debug('Route template: %s', location.route_template)
+        logger.debug('Route template: %s', location.route_template)
         url = self._client.format_url(route_template, **route_values)
         request = ClientRequest()
         request.url = self._client.format_url(url)
@@ -150,14 +153,14 @@ def _get_resource_locations(self, all_host_types):
         # Next check for options cached on disk
         if not all_host_types and OPTIONS_FILE_CACHE[self.normalized_url]:
             try:
-                logging.debug('File cache hit for options on: %s', self.normalized_url)
+                logger.debug('File cache hit for options on: %s', self.normalized_url)
                 self._locations = self._base_deserialize.deserialize_data(OPTIONS_FILE_CACHE[self.normalized_url],
                                                                           '[ApiResourceLocation]')
                 return self._locations
             except DeserializationError as ex:
-                logging.exception(str(ex))
+                logger.debug(ex, exc_info=True)
         else:
-            logging.debug('File cache miss for options on: %s', self.normalized_url)
+            logger.debug('File cache miss for options on: %s', self.normalized_url)
 
         # Last resort, make the call to the server
         options_uri = self._combine_url(self.config.base_url, '_apis')
@@ -184,7 +187,7 @@ def _get_resource_locations(self, all_host_types):
             try:
                 OPTIONS_FILE_CACHE[self.normalized_url] = wrapper.value
             except SerializationError as ex:
-                logging.exception(str(ex))
+                logger.debug(ex, exc_info=True)
         return returned_locations
 
     @staticmethod

vsts/vsts/vss_connection.py

@@ -11,6 +11,8 @@
 from .location.v4_0.location_client import LocationClient
 from .vss_client_configuration import VssClientConfiguration
 
+logger = logging.getLogger(__name__)
+
 
 class VssConnection(object):
     """VssConnection.
@@ -77,14 +79,14 @@ def _get_resource_areas(self, force=False):
             location_client = LocationClient(self.base_url, self._creds)
             if not force and RESOURCE_FILE_CACHE[location_client.normalized_url]:
                 try:
-                    logging.debug('File cache hit for resources on: %s', location_client.normalized_url)
+                    logger.debug('File cache hit for resources on: %s', location_client.normalized_url)
                     self._resource_areas = location_client._base_deserialize.deserialize_data(RESOURCE_FILE_CACHE[location_client.normalized_url],
                                                                                               '[ResourceAreaInfo]')
                     return self._resource_areas
                 except Exception as ex:
-                    logging.exception(str(ex))
+                    logger.debug(ex, exc_info=True)
             elif not force:
-                logging.debug('File cache miss for resources on: %s', location_client.normalized_url)
+                logger.debug('File cache miss for resources on: %s', location_client.normalized_url)
             self._resource_areas = location_client.get_resource_areas()
             if self._resource_areas is None:
                 # For OnPrem environments we get an empty collection wrapper.
@@ -94,7 +96,7 @@ def _get_resource_areas(self, force=False):
                                                                             '[ResourceAreaInfo]')
                 RESOURCE_FILE_CACHE[location_client.normalized_url] = serialized
             except Exception as ex:
-                logging.exception(str(ex))
+                logger.debug(ex, exc_info=True)
         return self._resource_areas
 
     @staticmethod