Merge pull request #1732 from fishtown-analytics/fix/dbt-cache-loggin…

…g-performance

disable dbt cache logging by default (#1725)

core/dbt/adapters/cache.py

@@ -1,7 +1,6 @@
 from collections import namedtuple
 import threading
 from copy import deepcopy
-import pprint
 from dbt.logger import CACHE_LOGGER as logger
 import dbt.exceptions
 
@@ -163,6 +162,12 @@ def dump_graph_entry(self):
         return [dot_separated(r) for r in self.referenced_by]
 
 
+def lazy_log(msg, func):
+    if logger.disabled:
+        return
+    logger.debug(msg.format(func()))
+
+
 class RelationsCache:
     """A cache of the relations known to dbt. Keeps track of relationships
     declared between tables and handles renames/drops as a real database would.
@@ -303,14 +308,13 @@ def add(self, relation):
         """
         cached = _CachedRelation(relation)
         logger.debug('Adding relation: {!s}'.format(cached))
-        logger.debug('before adding: {}'.format(
-            pprint.pformat(self.dump_graph()))
-        )
+
+        lazy_log('before adding: {!s}', self.dump_graph)
+
         with self.lock:
             self._setdefault(cached)
-        logger.debug('after adding: {}'.format(
-            pprint.pformat(self.dump_graph()))
-        )
+
+        lazy_log('after adding: {!s}', self.dump_graph)
 
     def _remove_refs(self, keys):
         """Removes all references to all entries in keys. This does not
@@ -431,21 +435,18 @@ def rename(self, old, new):
         old_key = _make_key(old)
         new_key = _make_key(new)
         logger.debug('Renaming relation {!s} to {!s}'.format(
-            old_key, new_key)
-        )
-        logger.debug('before rename: {}'.format(
-            pprint.pformat(self.dump_graph()))
-        )
+            old_key, new_key
+        ))
+
+        lazy_log('before rename: {!s}', self.dump_graph)
 
         with self.lock:
             if self._check_rename_constraints(old_key, new_key):
                 self._rename_relation(old_key, _CachedRelation(new))
             else:
                 self._setdefault(_CachedRelation(new))
 
-        logger.debug('after rename: {}'.format(
-            pprint.pformat(self.dump_graph()))
-        )
+        lazy_log('after rename: {!s}', self.dump_graph)
 
     def get_relations(self, database, schema):
         """Case-insensitively yield all relations matching the given schema.

core/dbt/config/profile.py

@@ -1,5 +1,4 @@
 import os
-import pprint
 
 from hologram import ValidationError
 
@@ -102,7 +101,7 @@ def to_profile_info(self, serialize_credentials=False):
         return result
 
     def __str__(self):
-        return pprint.pformat(self.to_profile_info())
+        return str(self.to_profile_info())
 
     def __eq__(self, other):
         if not (isinstance(other, self.__class__) and

core/dbt/config/project.py

@@ -1,7 +1,6 @@
 from copy import deepcopy
 import hashlib
 import os
-import pprint
 
 from dbt.clients.system import resolve_path_from_base
 from dbt.clients.system import path_exists
@@ -295,7 +294,7 @@ def from_project_config(cls, project_dict, packages_dict=None):
 
     def __str__(self):
         cfg = self.to_project_config(with_packages=True)
-        return pprint.pformat(cfg)
+        return str(cfg)
 
     def __eq__(self, other):
         if not (isinstance(other, self.__class__) and

core/dbt/config/runtime.py

@@ -1,6 +1,4 @@
-
 from copy import deepcopy
-import pprint
 
 from dbt.utils import parse_cli_vars
 from dbt.contracts.project import Configuration
@@ -148,7 +146,7 @@ def serialize(self):
         return result
 
     def __str__(self):
-        return pprint.pformat(self.serialize())
+        return str(self.serialize())
 
     def validate(self):
         """Validate the configuration against its contract.

core/dbt/logger.py

@@ -358,7 +358,9 @@ def set_output_stream(self, stream, error=None):
 def log_cache_events(flag):
     """Set the cache logger to propagate its messages based on the given flag.
     """
-    CACHE_LOGGER.disabled = True
+    # the flag is True if we should log, and False if we shouldn't, so disabled
+    # is the inverse.
+    CACHE_LOGGER.disabled = not flag
 
 
 GLOBAL_LOGGER = logger