fix: consolidate logging setup (#541)

* fix: consolidate logging setup When switching autosynth to use synthtool's git module, we transitively load synthtool's logger setup which adds a log handler globally. This causes logs to be emitted twice (with 2 different styles). This consolidates the logging setup into a single helper and now both autosynth's and synthtool's logger instance use the same configuration (with different logger names). * fix: add the level name when the log isn't colorize
googleapis · May 12, 2020 · c585ac3 · c585ac3
1 parent 5b48b07
commit c585ac3
Show file tree

Hide file tree

Showing 16 changed files with 133 additions and 150 deletions.
diff --git a/autosynth/log.py b/autosynth/log.py
@@ -12,26 +12,7 @@
 # See the License for the specific language governing permissions and
 # limitations under the License.
 
-import logging
+from synthtool.log import configure_logger
 
 
-def _configure_logger():
-    """Create and configure the default logger for autosynth.
-
-    The logger will prefix the log message with the current time and the
-    log severity.
-    """
-    logger = logging.getLogger("autosynth")
-    logger.setLevel(logging.DEBUG)
-
-    handler = logging.StreamHandler()
-    handler.setLevel(logging.DEBUG)
-    formatter = logging.Formatter(
-        "%(asctime)s [%(levelname)s] %(message)s", datefmt="%Y-%m-%d %H:%M:%S"
-    )
-    handler.setFormatter(formatter)
-    logger.addHandler(handler)
-    return logger
-
-
-logger = _configure_logger()
+logger = configure_logger("autosynth")
diff --git a/synthtool/__init__.py b/synthtool/__init__.py
@@ -17,7 +17,7 @@
 import sys
 
 from synthtool.transforms import move, replace
-from synthtool import log
+from synthtool.log import logger
 
 copy = move
 
@@ -27,6 +27,6 @@
 # directly
 _main_module = sys.modules["__main__"]
 if hasattr(_main_module, "__file__") and "synthtool" not in _main_module.__file__:
-    log.critical(
+    logger.critical(
         "You are running the synthesis script directly, this will be disabled in a future release of Synthtool. Please use python3 -m synthtool instead."
     )
diff --git a/synthtool/__main__.py b/synthtool/__main__.py
@@ -19,7 +19,7 @@
 
 import click
 import pkg_resources
-import synthtool.log
+from synthtool.log import logger
 import synthtool.metadata
 from synthtool import preconfig
 
@@ -82,7 +82,7 @@ def main(synthfile: str, metadata: str, extra_args: Sequence[str]):
     synth_file = os.path.abspath(synthfile)
 
     if os.path.lexists(synth_file):
-        synthtool.log.debug(f"Executing {synth_file}.")
+        logger.debug(f"Executing {synth_file}.")
         # https://docs.python.org/3/library/importlib.html#importing-a-source-file-directly
         spec = importlib.util.spec_from_file_location("synth", synth_file)
         synth_module = importlib.util.module_from_spec(spec)
@@ -94,7 +94,7 @@ def main(synthfile: str, metadata: str, extra_args: Sequence[str]):
             spec.loader.exec_module(synth_module)  # type: ignore
 
     else:
-        synthtool.log.exception(f"{synth_file} not found.")
+        logger.exception(f"{synth_file} not found.")
         sys.exit(1)
 
 

diff --git a/synthtool/gcp/artman.py b/synthtool/gcp/artman.py
@@ -18,9 +18,8 @@
 import platform
 import tempfile
 
-from synthtool import log
-from synthtool import metadata
-from synthtool import shell
+from synthtool import metadata, shell
+from synthtool.log import logger
 
 ARTMAN_VERSION = os.environ.get("SYNTHTOOL_ARTMAN_VERSION", "latest")
 
@@ -143,7 +142,7 @@ def run(
         return output_dir
 
     def _ensure_dependencies_installed(self):
-        log.debug("Ensuring dependencies.")
+        logger.debug("Ensuring dependencies.")
 
         dependencies = ["docker", "git"]
         failed_dependencies = []
@@ -158,7 +157,7 @@ def _ensure_dependencies_installed(self):
             )
 
     def _install_artman(self):
-        log.debug("Pulling artman image.")
+        logger.debug("Pulling artman image.")
         shell.run(
             ["docker", "pull", f"googleapis/artman:{ARTMAN_VERSION}"], hide_output=False
         )

diff --git a/synthtool/gcp/common.py b/synthtool/gcp/common.py
@@ -19,10 +19,10 @@
 from pathlib import Path
 from typing import Dict, List, Optional
 
+from synthtool import _tracked_paths
 from synthtool.languages import node
+from synthtool.log import logger
 from synthtool.sources import git, templates
-from synthtool import _tracked_paths
-from synthtool import log
 
 
 TEMPLATES_URL: str = git.make_repo_clone_url("googleapis/synthtool")
@@ -33,7 +33,7 @@
 class CommonTemplates:
     def __init__(self):
         if LOCAL_TEMPLATES:
-            log.debug(f"Using local templates at {LOCAL_TEMPLATES}")
+            logger.debug(f"Using local templates at {LOCAL_TEMPLATES}")
             self._template_root = LOCAL_TEMPLATES
         else:
             templates_git = git.clone(TEMPLATES_URL)
@@ -68,7 +68,7 @@ def py_library(self, **kwargs) -> Path:
             kwargs["system_test_local_dependencies"] = kwargs[
                 "system_test_dependencies"
             ]
-            log.warning(
+            logger.warning(
                 "Template argument 'system_test_dependencies' is deprecated."
                 "Use 'system_test_local_dependencies' or 'system_test_external_dependencies'"
                 "instead."

diff --git a/synthtool/gcp/discogapic_generator.py b/synthtool/gcp/discogapic_generator.py
@@ -15,8 +15,8 @@
 from pathlib import Path
 
 from synthtool import _tracked_paths
-from synthtool import log
 from synthtool.gcp import artman
+from synthtool.log import logger
 from synthtool.sources import git
 
 DISCOVERY_ARTIFACT_MANAGER_URL: str = git.make_repo_clone_url(
@@ -90,7 +90,7 @@ def _generate_code(
                 f"Unable to find configuration yaml file: {config_path}."
             )
 
-        log.debug(f"Running generator for {config_path}.")
+        logger.debug(f"Running generator for {config_path}.")
         output_root = artman.Artman().run(
             f"googleapis/artman:{artman.ARTMAN_VERSION}",
             self.discovery_artifact_manager,
@@ -109,11 +109,11 @@ def _generate_code(
                 f"Unable to find generated output of artman: {genfiles}."
             )
 
-        log.success(f"Generated code into {genfiles}.")
+        logger.success(f"Generated code into {genfiles}.")
 
         _tracked_paths.add(genfiles)
         return genfiles
 
     def _clone_discovery_artifact_manager(self):
-        log.debug("Cloning discovery-artifact-manager.")
+        logger.debug("Cloning discovery-artifact-manager.")
         self.discovery_artifact_manager = git.clone(DISCOVERY_ARTIFACT_MANAGER_URL)
diff --git a/synthtool/gcp/gapic_bazel.py b/synthtool/gcp/gapic_bazel.py
@@ -17,10 +17,8 @@
 import shutil
 import tempfile
 
-from synthtool import _tracked_paths
-from synthtool import log
-from synthtool import metadata
-from synthtool import shell
+from synthtool import _tracked_paths, metadata, shell
+from synthtool.log import logger
 from synthtool.sources import git
 
 GOOGLEAPIS_URL: str = git.make_repo_clone_url("googleapis/googleapis")
@@ -173,7 +171,7 @@ def _generate_code(
 
         bazel_run_args = ["bazel", "build", bazel_target]
 
-        log.debug(f"Generating code for: {bazel_target}.")
+        logger.debug(f"Generating code for: {bazel_target}.")
         shell.run(bazel_run_args)
 
         # We've got tar file!
@@ -211,9 +209,9 @@ def _generate_code(
             os.makedirs(proto_output_path, exist_ok=True)
 
             for i in proto_files:
-                log.debug(f"Copy: {i} to {proto_output_path / i.name}")
+                logger.debug(f"Copy: {i} to {proto_output_path / i.name}")
                 shutil.copyfile(i, proto_output_path / i.name)
-            log.success(f"Placed proto files into {proto_output_path}.")
+            logger.success(f"Placed proto files into {proto_output_path}.")
 
         os.chdir(cwd)
 
@@ -225,7 +223,7 @@ def _generate_code(
             )
 
         # Huzzah, it worked.
-        log.success(f"Generated code into {output_dir}.")
+        logger.success(f"Generated code into {output_dir}.")
 
         # Record this in the synthtool metadata.
         metadata.add_client_destination(
@@ -245,10 +243,10 @@ def _clone_googleapis(self):
 
         if LOCAL_GOOGLEAPIS:
             self._googleapis = Path(LOCAL_GOOGLEAPIS).expanduser()
-            log.debug(f"Using local googleapis at {self._googleapis}")
+            logger.debug(f"Using local googleapis at {self._googleapis}")
 
         else:
-            log.debug("Cloning googleapis.")
+            logger.debug("Cloning googleapis.")
             self._googleapis = git.clone(GOOGLEAPIS_URL)
 
         return self._googleapis
@@ -259,12 +257,12 @@ def _clone_googleapis_private(self):
 
         if LOCAL_GOOGLEAPIS:
             self._googleapis_private = Path(LOCAL_GOOGLEAPIS).expanduser()
-            log.debug(
+            logger.debug(
                 f"Using local googleapis at {self._googleapis_private} for googleapis-private"
             )
 
         else:
-            log.debug("Cloning googleapis-private.")
+            logger.debug("Cloning googleapis-private.")
             self._googleapis_private = git.clone(GOOGLEAPIS_PRIVATE_URL)
 
         return self._googleapis_private
@@ -277,17 +275,17 @@ def _clone_discovery_artifact_manager(self):
             self._discovery_artifact_manager = Path(
                 LOCAL_DISCOVERY_ARTIFACT_MANAGER
             ).expanduser()
-            log.debug(
+            logger.debug(
                 f"Using local discovery_artifact_manager at {self._discovery_artifact_manager} for googleapis-private"
             )
         else:
-            log.debug("Cloning discovery-artifact-manager.")
+            logger.debug("Cloning discovery-artifact-manager.")
             self._discovery_artifact_manager = git.clone(DISCOVERY_ARTIFACT_MANAGER_URL)
 
         return self._discovery_artifact_manager
 
     def _ensure_dependencies_installed(self):
-        log.debug("Ensuring dependencies.")
+        logger.debug("Ensuring dependencies.")
 
         dependencies = ["bazel", "zip", "unzip", "tar"]
         failed_dependencies = []

diff --git a/synthtool/gcp/gapic_generator.py b/synthtool/gcp/gapic_generator.py
@@ -21,11 +21,9 @@
 from pathlib import Path
 from typing import Optional
 
-from synthtool import _tracked_paths
-from synthtool import log
-from synthtool import metadata
-from synthtool import shell
+from synthtool import _tracked_paths, metadata, shell
 from synthtool.gcp import artman
+from synthtool.log import logger
 from synthtool.sources import git
 
 GOOGLEAPIS_URL: str = git.make_repo_clone_url("googleapis/googleapis")
@@ -103,7 +101,7 @@ def _generate_code(
 
         generator_dir = LOCAL_GENERATOR
         if generator_dir is not None:
-            log.debug(f"Using local generator at {generator_dir}")
+            logger.debug(f"Using local generator at {generator_dir}")
 
         # Run the code generator.
         # $ artman --config path/to/artman_api.yaml generate python_gapic
@@ -121,7 +119,7 @@ def _generate_code(
                 f"Unable to find configuration yaml file: {(googleapis / config_path)}."
             )
 
-        log.debug(f"Running generator for {config_path}.")
+        logger.debug(f"Running generator for {config_path}.")
 
         if include_samples:
             if generator_args is None:
@@ -149,7 +147,7 @@ def _generate_code(
                 f"Unable to find generated output of artman: {genfiles}."
             )
 
-        log.success(f"Generated code into {genfiles}.")
+        logger.success(f"Generated code into {genfiles}.")
 
         # Get the *.protos files and put them in a protos dir in the output
         if include_protos:
@@ -165,9 +163,9 @@ def _generate_code(
             os.makedirs(proto_output_path, exist_ok=True)
 
             for i in proto_files:
-                log.debug(f"Copy: {i} to {proto_output_path / i.name}")
+                logger.debug(f"Copy: {i} to {proto_output_path / i.name}")
                 shutil.copyfile(i, proto_output_path / i.name)
-            log.success(f"Placed proto files into {proto_output_path}.")
+            logger.success(f"Placed proto files into {proto_output_path}.")
 
         if include_samples:
             samples_root_dir = None
@@ -209,10 +207,10 @@ def _clone_googleapis(self):
 
         if LOCAL_GOOGLEAPIS:
             self._googleapis = Path(LOCAL_GOOGLEAPIS).expanduser()
-            log.debug(f"Using local googleapis at {self._googleapis}")
+            logger.debug(f"Using local googleapis at {self._googleapis}")
 
         else:
-            log.debug("Cloning googleapis.")
+            logger.debug("Cloning googleapis.")
             self._googleapis = git.clone(GOOGLEAPIS_URL)
 
         return self._googleapis
@@ -223,12 +221,12 @@ def _clone_googleapis_private(self):
 
         if LOCAL_GOOGLEAPIS:
             self._googleapis_private = Path(LOCAL_GOOGLEAPIS).expanduser()
-            log.debug(
+            logger.debug(
                 f"Using local googleapis at {self._googleapis_private} for googleapis-private"
             )
 
         else:
-            log.debug("Cloning googleapis-private.")
+            logger.debug("Cloning googleapis-private.")
             self._googleapis_private = git.clone(GOOGLEAPIS_PRIVATE_URL)
 
         return self._googleapis_private
@@ -300,7 +298,7 @@ def _include_samples(
         test_files = googleapis_samples_dir.glob("**/*.test.yaml")
         os.makedirs(samples_test_dir, exist_ok=True)
         for i in test_files:
-            log.debug(f"Copy: {i} to {samples_test_dir / i.name}")
+            logger.debug(f"Copy: {i} to {samples_test_dir / i.name}")
             shutil.copyfile(i, samples_test_dir / i.name)
 
         # Download sample resources from sample_resources.yaml storage URIs.
@@ -321,7 +319,7 @@ def _include_samples(
                 response = requests.get(uri, allow_redirects=True)
                 download_path = samples_resources_dir / os.path.basename(uri)
                 os.makedirs(samples_resources_dir, exist_ok=True)
-                log.debug(f"Download {uri} to {download_path}")
+                logger.debug(f"Download {uri} to {download_path}")
                 with open(download_path, "wb") as output:  # type: ignore
                     output.write(response.content)
 
@@ -339,7 +337,7 @@ def _include_samples(
             "ruby": "bundle exec ruby",
         }
         if language not in LANGUAGE_EXECUTABLES:
-            log.info("skipping manifest gen")
+            logger.info("skipping manifest gen")
             return None
 
         manifest_arguments = [
@@ -355,7 +353,7 @@ def _include_samples(
             if os.path.isfile(code_sample):
                 manifest_arguments.append(sample_path)
         try:
-            log.debug(f"Writing samples manifest {manifest_arguments}")
+            logger.debug(f"Writing samples manifest {manifest_arguments}")
             shell.run(manifest_arguments, cwd=samples_root_dir)
         except (subprocess.CalledProcessError, FileNotFoundError):
-            log.warning("gen-manifest failed (sample-tester may not be installed)")
+            logger.warning("gen-manifest failed (sample-tester may not be installed)")