Use specific loggers instead of root

docker_test_tools/environment.py

@@ -10,6 +10,8 @@
 
 SEPARATOR = '|'
 
+log = logging.getLogger(__name__)
+
 
 class EnvironmentController(object):
     """Utility for managing environment operations."""
@@ -44,7 +46,7 @@ def get_services(self):
 
         :return dict: of format {'service-name': check_callback}
         """
-        logging.debug("Getting environment services, using docker compose: %s", self.compose_path)
+        log.debug("Getting environment services, using docker compose: %s", self.compose_path)
         try:
             services_output = subprocess.check_output(
                 ['docker-compose', '-f', self.compose_path, '-p', self.project_name, 'config', '--services'],
@@ -62,12 +64,12 @@ def setup(self):
         Should be called once before *all* the tests start.
         """
         try:
-            logging.debug("Setting up the environment")
+            log.debug("Setting up the environment")
             self.cleanup()
             self.run_containers()
             self.start_log_collection()
         except:
-            logging.exception("Setup failure, tearing down the test environment")
+            log.exception("Setup failure, tearing down the test environment")
             self.teardown()
             raise
 
@@ -76,7 +78,7 @@ def teardown(self):
 
         Should be called once after *all* the tests finish.
         """
-        logging.debug("Tearing down the environment")
+        log.debug("Tearing down the environment")
         try:
             self.stop_log_collection()
         finally:
@@ -88,15 +90,15 @@ def cleanup(self):
         Kills and removes the environment containers.
         """
         if self.reuse_containers:
-            logging.warning("Container reuse enabled: Skipping environment cleanup")
+            log.warning("Container reuse enabled: Skipping environment cleanup")
             return
 
         self.kill_containers()
         self.remove_containers()
 
     def run_containers(self):
         """Run environment containers."""
-        logging.debug("Running environment containers, using docker compose: %s", self.compose_path)
+        log.debug("Running environment containers, using docker compose: %s", self.compose_path)
         try:
             subprocess.check_output(
                 ['docker-compose', '-f', self.compose_path, '-p', self.project_name, 'up', '--build', '-d'],
@@ -107,7 +109,7 @@ def run_containers(self):
 
     def start_log_collection(self):
         """Start a log collection process which writes docker-compose logs into a file."""
-        logging.debug("Starting logs collection from environment containers")
+        log.debug("Starting logs collection from environment containers")
         self.logs_file = open(self.log_path, 'w')
         self.logs_process = subprocess.Popen(
             ['docker-compose', '-f', self.compose_path, '-p', self.project_name, 'logs', '--no-color', '-f', '-t'],
@@ -116,7 +118,7 @@ def start_log_collection(self):
 
     def stop_log_collection(self):
         """Stop the log collection process and close the log file."""
-        logging.debug("Stopping logs collection from environment containers")
+        log.debug("Stopping logs collection from environment containers")
         if self.logs_process:
             self.logs_process.kill()
             self.logs_process.wait()
@@ -131,7 +133,7 @@ def split_logs(self):
         Each line in the collected log file is in a format of: 'service.name_number  | message'
         This method writes each line to it's service log file amd keeps only the message.
         """
-        logging.debug("Splitting log file into separated files per service")
+        log.debug("Splitting log file into separated files per service")
         services_log_files = {}
         log_dir = os.path.dirname(self.log_path)
         try:
@@ -151,7 +153,7 @@ def split_logs(self):
 
     def remove_containers(self):
         """Remove the environment containers."""
-        logging.debug("Removing environment containers, using docker compose: %s", self.compose_path)
+        log.debug("Removing environment containers, using docker compose: %s", self.compose_path)
         try:
             subprocess.check_output(
                 ['docker-compose', '-f', self.compose_path, '-p', self.project_name, 'rm', '-f'],
@@ -162,7 +164,7 @@ def remove_containers(self):
 
     def kill_containers(self):
         """Kill the environment containers."""
-        logging.debug("Killing environment containers, using docker compose: %s", self.compose_path)
+        log.debug("Killing environment containers, using docker compose: %s", self.compose_path)
         try:
             subprocess.check_output(
                 ['docker-compose', '-f', self.compose_path, '-p', self.project_name, 'kill'],
@@ -177,7 +179,7 @@ def kill_container(self, name):
         :param str name: container name as it appears in the docker compose file.
         """
         self.validate_service_name(name)
-        logging.debug("Killing %s container", name)
+        log.debug("Killing %s container", name)
         try:
             subprocess.check_output(
                 ['docker-compose', '-f', self.compose_path, '-p', self.project_name, 'kill', name],
@@ -192,7 +194,7 @@ def restart_container(self, name):
         :param str name: container name as it appears in the docker compose file.
         """
         self.validate_service_name(name)
-        logging.debug("Restarting container %s", name)
+        log.debug("Restarting container %s", name)
         try:
             subprocess.check_output(
                 ['docker-compose', '-f', self.compose_path, '-p', self.project_name, 'restart', name],
@@ -207,7 +209,7 @@ def pause_container(self, name):
         :param str name: container name as it appears in the docker compose file.
         """
         self.validate_service_name(name)
-        logging.debug("Pausing %s container", name)
+        log.debug("Pausing %s container", name)
         try:
             subprocess.check_output(
                 ['docker-compose', '-f', self.compose_path, '-p', self.project_name, 'pause', name],
@@ -222,7 +224,7 @@ def unpause_container(self, name):
         :param str name: container name as it appears in the docker compose file.
         """
         self.validate_service_name(name)
-        logging.debug("Unpausing %s container", name)
+        log.debug("Unpausing %s container", name)
         try:
             subprocess.check_output(
                 ['docker-compose', '-f', self.compose_path, '-p', self.project_name, 'unpause', name],
@@ -237,7 +239,7 @@ def stop_container(self, name):
         :param str name: container name as it appears in the docker compose file.
         """
         self.validate_service_name(name)
-        logging.debug("Stopping %s container", name)
+        log.debug("Stopping %s container", name)
         try:
             subprocess.check_output(
                 ['docker-compose', '-f', self.compose_path, '-p', self.project_name, 'stop', name],
@@ -252,7 +254,7 @@ def start_container(self, name):
         :param str name: container name as it appears in the docker compose file.
         """
         self.validate_service_name(name)
-        logging.debug("Starting %s container", name)
+        log.debug("Starting %s container", name)
         try:
             subprocess.check_output(
                 ['docker-compose', '-f', self.compose_path, '-p', self.project_name, 'start', name],
@@ -284,7 +286,7 @@ def is_container_ready(self, name):
         :param str name: container name as it appears in the docker compose file.
         """
         self.validate_service_name(name)
-        logging.debug("Getting %s container state", name)
+        log.debug("Getting %s container state", name)
         container_id = self.get_container_id(name)
         try:
             status_output = subprocess.check_output(
@@ -293,15 +295,15 @@ def is_container_ready(self, name):
             )
 
         except subprocess.CalledProcessError as error:
-            logging.warning("Failed getting container %s state, reason: %s", name, error.output)
+            log.warning("Failed getting container %s state, reason: %s", name, error.output)
             return False
 
         if '"Health":' in status_output:
             is_ready = '"Status":"healthy"' in status_output
         else:
             is_ready = '"Status":"running"' in status_output
 
-        logging.debug("Container %s ready: %s", name, is_ready)
+        log.debug("Container %s ready: %s", name, is_ready)
         return is_ready
 
     def wait_for_services(self, services=None, interval=1, timeout=60):
@@ -311,19 +313,19 @@ def wait_for_services(self, services=None, interval=1, timeout=60):
         If it doesn't the method will wait for a 'running' state.
         """
         services = services if services else self.services
-        logging.info('Waiting for %s to reach the required state', services)
+        log.info('Waiting for %s to reach the required state', services)
 
         def service_checks():
             """Return True if services checks pass."""
             return all([self.is_container_ready(name) for name in services])
 
         try:
             waiting.wait(service_checks, sleep_seconds=interval, timeout_seconds=timeout)
-            logging.info('Services %s reached the required state', services)
+            log.info('Services %s reached the required state', services)
             return True
 
         except waiting.TimeoutExpired:
-            logging.error('%s failed to to reach the required state', services)
+            log.error('%s failed to to reach the required state', services)
             return False
 
     @contextmanager
@@ -415,7 +417,7 @@ def wait_for_health(self, name, health_check=None, interval=1, timeout=60):
         :param int interval: interval (in seconds) between checks.
         :param int timeout: timeout (in seconds) for all checks to pass.
         """
-        logging.debug("Waiting for %s container to be healthy", name)
+        log.debug("Waiting for %s container to be healthy", name)
         health_check = health_check if health_check else lambda: self.is_container_ready(name)
         waiting.wait(health_check, sleep_seconds=interval, timeout_seconds=timeout)
 
@@ -427,7 +429,7 @@ def validate_service_name(self, name):
     def _get_environment_variables():
         """Set the compose api version according to the server's api version"""
         server_api_version = get_server_api_version()
-        logging.debug("docker server api version is %s, updating environment_variables", server_api_version)
+        log.debug("docker server api version is %s, updating environment_variables", server_api_version)
         env = os.environ.copy()
         env['COMPOSE_API_VERSION'] = env['DOCKER_API_VERSION'] = server_api_version
         return env

docker_test_tools/plugin.py

@@ -1,17 +1,12 @@
 # pylint: disable=unused-argument
-import logging
-
 from nose2.events import Plugin
 
 from docker_test_tools.config import Config
 from docker_test_tools.environment import EnvironmentController
 
-log = logging.getLogger('nose2.plugins.docker_test_tools')
-
 
 class EnvironmentPlugin(Plugin):
     """Nose2 plugin, used for managing docker environment operations."""
-
     configSection = 'environment'
     commandLineSwitch = (None, 'environment', 'Enable docker test tools environment')
 

docker_test_tools/utils.py

@@ -4,6 +4,9 @@
 import waiting
 
 
+log = logging.getLogger(__name__)
+
+
 def run_health_checks(checks, interval=1, timeout=60):
     """Return True if all health checks pass (return True).
 
@@ -13,15 +16,15 @@ def run_health_checks(checks, interval=1, timeout=60):
 
     :raise bool: True is all the services are healthy, False otherwise.
     """
-    logging.info('Waiting for the required health checks to pass...')
+    log.info('Waiting for the required health checks to pass...')
     try:
         waiting.wait(lambda: all([health_check() for health_check in checks]),
                      sleep_seconds=interval, timeout_seconds=timeout)
 
         return True
 
     except waiting.TimeoutExpired:
-        logging.error("Required health checks didn't pass within timeout")
+        log.error("Required health checks didn't pass within timeout")
         return False
 
 
@@ -42,12 +45,12 @@ def get_curl_health_check(service_name, url):
 
     :return function: function used to determine if the given service is responsive.
     """
-    logging.debug('Defining a CURL based health check for service: %s at: %s', service_name, url)
+    log.debug('Defining a CURL based health check for service: %s at: %s', service_name, url)
 
     def curl_health_check():
         """Return True if the service is responsive."""
         is_ready = is_curl_responsive(url)
-        logging.debug('Service %s ready: %s', service_name, is_ready)
+        log.debug('Service %s ready: %s', service_name, is_ready)
         return is_ready
 
     return curl_health_check

docker_test_tools/wiremock.py

@@ -10,6 +10,8 @@
 
 import requests
 
+log = logging.getLogger(__name__)
+
 
 class WiremockError(Exception):
     """Raised on wiremock controller failures."""
@@ -42,7 +44,7 @@ def set_mapping_from_dir(self, dir_path):
 
         :param str dir_path: directory path to scan - should contain json mapping files.
         """
-        logging.debug('Setting service %s wiremock mapping using directory %s', self.url, dir_path)
+        log.debug('Setting service %s wiremock mapping using directory %s', self.url, dir_path)
         if not os.path.isdir(dir_path):
             raise ValueError("'%s' is not a valid dir" % dir_path)
 
@@ -62,7 +64,7 @@ def set_mapping_from_file(self, json_path):
 
         :param str json_path: json stub file path.
         """
-        logging.debug('Setting service %s wiremock mapping using file %s', self.url, json_path)
+        log.debug('Setting service %s wiremock mapping using file %s', self.url, json_path)
         with open(json_path, 'r') as json_file:
             json_object = json.load(json_file)
         self.set_mapping_from_json(json_object)
@@ -73,23 +75,23 @@ def set_mapping_from_json(self, json_object):
         :param json_object: json data of mapping stub.
         :raise WiremockError: on failure to configure service.
         """
-        logging.debug('Setting service %s wiremock mapping using json: %s', self.url, json_object)
+        log.debug('Setting service %s wiremock mapping using json: %s', self.url, json_object)
         try:
             requests.post(self.admin_mapping_url, json=json_object).raise_for_status()
         except:
-            logging.exception("Failed setting service %s wiremock mapping using json: %s", self.url, json_object)
+            log.exception("Failed setting service %s wiremock mapping using json: %s", self.url, json_object)
             raise WiremockError("Failed setting service %s wiremock mapping using json: %s" % (self.url, json_object))
 
     def reset_mapping(self):
         """Reset wiremock service mapping.
 
         :raise WiremockError: on failure to reset service mapping.
         """
-        logging.debug('Resetting %s wiremock mapping', self.url)
+        log.debug('Resetting %s wiremock mapping', self.url)
         try:
             requests.post(self.mapping_reset_url).raise_for_status()
         except:
-            logging.exception('Failed resetting %s wiremock mapping', self.url)
+            log.exception('Failed resetting %s wiremock mapping', self.url)
             raise WiremockError('Failed resetting %s wiremock mapping' % self.url)
 
     def get_request_journal(self):