You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@impala.apache.org by jo...@apache.org on 2018/08/18 20:38:22 UTC

[3/7] impala git commit: tests: ensure consistent logging format across tests

tests: ensure consistent logging format across tests

Many of the test modules included calls to 'logging.basicConfig' at
global scope in their implementation. This meant that by just importing
one of these files, other tests would inherit their logging format. This
is typically a bad idea in Python -- modules should not have side
effects like this on import.

The format was additionally inconsistent. In some cases we had a "--"
prepended to the format, and in others we didn't. The "--" is very
useful since it lets developers copy-paste query-test output back into
the shell to reproduce an issue.

This patch fixes the above by centralizing the logging configuration in
a pytest hook that runs prior to all pytests. A few other non-pytest
related tools now configure logging in their "main" code which is only
triggered when the module is executed directly.

I tested that, with this change, logs still show up properly in the .xml
output files from 'run-tests.py' as well as when running tests manually
from impala-py.test

Change-Id: I55ef0214b43f87da2d71804913ba4caa964f789f
Reviewed-on: http://gerrit.cloudera.org:8080/11225
Reviewed-by: Philip Zeyliger <ph...@cloudera.com>
Tested-by: Impala Public Jenkins <im...@cloudera.com>


Project: http://git-wip-us.apache.org/repos/asf/impala/repo
Commit: http://git-wip-us.apache.org/repos/asf/impala/commit/30bb0b3d
Tree: http://git-wip-us.apache.org/repos/asf/impala/tree/30bb0b3d
Diff: http://git-wip-us.apache.org/repos/asf/impala/diff/30bb0b3d

Branch: refs/heads/master
Commit: 30bb0b3d897e165157dd682846f14b6b8106a87c
Parents: 1158883
Author: Todd Lipcon <to...@apache.org>
Authored: Tue Aug 14 16:38:55 2018 -0700
Committer: Todd Lipcon <to...@apache.org>
Committed: Sat Aug 18 04:21:00 2018 +0000

----------------------------------------------------------------------
 tests/common/impala_cluster.py            |  1 -
 tests/common/impala_service.py            |  2 --
 tests/common/impala_test_suite.py         |  1 -
 tests/common/test_result_verifier.py      |  1 -
 tests/conftest.py                         | 14 +++++++++++++-
 tests/metadata/test_hms_integration.py    |  5 -----
 tests/performance/query_exec_functions.py |  1 -
 tests/performance/query_executor.py       |  1 -
 tests/performance/scheduler.py            |  2 --
 tests/performance/workload_runner.py      |  2 --
 tests/run-tests.py                        |  3 +++
 tests/util/plugin_runner.py               |  1 -
 12 files changed, 16 insertions(+), 18 deletions(-)
----------------------------------------------------------------------


http://git-wip-us.apache.org/repos/asf/impala/blob/30bb0b3d/tests/common/impala_cluster.py
----------------------------------------------------------------------
diff --git a/tests/common/impala_cluster.py b/tests/common/impala_cluster.py
index d42c450..f04b4b9 100644
--- a/tests/common/impala_cluster.py
+++ b/tests/common/impala_cluster.py
@@ -32,7 +32,6 @@ from tests.common.impala_service import (
     StateStoredService)
 from tests.util.shell_util import exec_process, exec_process_async
 
-logging.basicConfig(level=logging.ERROR, format='%(threadName)s: %(message)s')
 LOG = logging.getLogger('impala_cluster')
 LOG.setLevel(level=logging.DEBUG)
 

http://git-wip-us.apache.org/repos/asf/impala/blob/30bb0b3d/tests/common/impala_service.py
----------------------------------------------------------------------
diff --git a/tests/common/impala_service.py b/tests/common/impala_service.py
index 0934f78..b738b8e 100644
--- a/tests/common/impala_service.py
+++ b/tests/common/impala_service.py
@@ -35,8 +35,6 @@ from RuntimeProfile.ttypes import TRuntimeProfileTree
 import base64
 import zlib
 
-logging.basicConfig(level=logging.ERROR, format='%(asctime)s %(threadName)s: %(message)s',
-    datefmt='%H:%M:%S')
 LOG = logging.getLogger('impala_service')
 LOG.setLevel(level=logging.DEBUG)
 

http://git-wip-us.apache.org/repos/asf/impala/blob/30bb0b3d/tests/common/impala_test_suite.py
----------------------------------------------------------------------
diff --git a/tests/common/impala_test_suite.py b/tests/common/impala_test_suite.py
index e7ac7b5..48a53f2 100644
--- a/tests/common/impala_test_suite.py
+++ b/tests/common/impala_test_suite.py
@@ -79,7 +79,6 @@ from thrift.protocol import TBinaryProtocol
 
 # Initializing the logger before conditional imports, since we will need it
 # for them.
-logging.basicConfig(level=logging.INFO, format='-- %(message)s')
 LOG = logging.getLogger('impala_test_suite')
 
 # The ADLS python client isn't downloaded when ADLS isn't the target FS, so do a

http://git-wip-us.apache.org/repos/asf/impala/blob/30bb0b3d/tests/common/test_result_verifier.py
----------------------------------------------------------------------
diff --git a/tests/common/test_result_verifier.py b/tests/common/test_result_verifier.py
index 2e8bbb1..f071e6b 100644
--- a/tests/common/test_result_verifier.py
+++ b/tests/common/test_result_verifier.py
@@ -26,7 +26,6 @@ from tests.util.test_file_parser import (join_section_lines, remove_comments,
     split_section_lines)
 from tests.util.hdfs_util import NAMENODE
 
-logging.basicConfig(level=logging.INFO, format='%(threadName)s: %(message)s')
 LOG = logging.getLogger('test_result_verfier')
 
 # Special prefix for column values that indicates the actual column value

http://git-wip-us.apache.org/repos/asf/impala/blob/30bb0b3d/tests/conftest.py
----------------------------------------------------------------------
diff --git a/tests/conftest.py b/tests/conftest.py
index 1d64b6b..f8ca1c7 100644
--- a/tests/conftest.py
+++ b/tests/conftest.py
@@ -32,8 +32,8 @@ from tests.common.patterns import is_valid_impala_identifier
 from tests.comparison.db_connection import ImpalaConnection
 from tests.util.filesystem_utils import FILESYSTEM, ISILON_WEBHDFS_PORT
 
-logging.basicConfig(level=logging.INFO, format='%(threadName)s: %(message)s')
 LOG = logging.getLogger('test_configuration')
+LOG_FORMAT = "-- %(asctime)s %(levelname)-8s %(threadName)s: %(message)s"
 
 DEFAULT_CONN_TIMEOUT = 45
 DEFAULT_EXPLORATION_STRATEGY = 'core'
@@ -50,6 +50,18 @@ if FILESYSTEM == 'isilon':
                                                  port=ISILON_WEBHDFS_PORT)
 
 
+def pytest_configure(config):
+  """ Hook startup of pytest to set up log format. """
+  configure_logging()
+
+
+def configure_logging():
+  # Use a "--" since most of our tests output SQL commands, and it's nice to
+  # be able to copy-paste directly from the test output back into a shell to
+  # try to reproduce a failure.
+  logging.basicConfig(level=logging.INFO, format=LOG_FORMAT)
+
+
 def pytest_addoption(parser):
   """Adds a new command line options to py.test"""
   parser.addoption("--exploration_strategy", default=DEFAULT_EXPLORATION_STRATEGY,

http://git-wip-us.apache.org/repos/asf/impala/blob/30bb0b3d/tests/metadata/test_hms_integration.py
----------------------------------------------------------------------
diff --git a/tests/metadata/test_hms_integration.py b/tests/metadata/test_hms_integration.py
index 0f085c4..3ac5cef 100644
--- a/tests/metadata/test_hms_integration.py
+++ b/tests/metadata/test_hms_integration.py
@@ -36,11 +36,6 @@ from tests.common.test_dimensions import (
     create_uncompressed_text_dimension)
 from tests.util.hive_utils import HiveDbWrapper, HiveTableWrapper
 
-import logging
-
-logging.basicConfig(level=logging.INFO, format='%(threadName)s: %(message)s')
-LOG = logging.getLogger('test_configuration')
-
 @SkipIfS3.hive
 @SkipIfADLS.hive
 @SkipIfIsilon.hive

http://git-wip-us.apache.org/repos/asf/impala/blob/30bb0b3d/tests/performance/query_exec_functions.py
----------------------------------------------------------------------
diff --git a/tests/performance/query_exec_functions.py b/tests/performance/query_exec_functions.py
index f7d00ec..0366291 100644
--- a/tests/performance/query_exec_functions.py
+++ b/tests/performance/query_exec_functions.py
@@ -31,7 +31,6 @@ DEFAULT_BEESWAX_PORT = 21000
 DEFAULT_HS2_PORT = 21050
 DEFAULT_HIVE_HS2_PORT = 10000
 
-logging.basicConfig(level=logging.INFO, format='[%(name)s] %(threadName)s: %(message)s')
 LOG = logging.getLogger('query_exec_functions')
 
 def get_hs2_hive_cursor(hiveserver, user=None, use_kerberos=False,

http://git-wip-us.apache.org/repos/asf/impala/blob/30bb0b3d/tests/performance/query_executor.py
----------------------------------------------------------------------
diff --git a/tests/performance/query_executor.py b/tests/performance/query_executor.py
index 1f4bec2..501f34a 100644
--- a/tests/performance/query_executor.py
+++ b/tests/performance/query_executor.py
@@ -36,7 +36,6 @@ import re
 from tests.performance.query import Query
 
 # Setup logging for this module.
-logging.basicConfig(level=logging.INFO, format='[%(name)s] %(threadName)s: %(message)s')
 LOG = logging.getLogger('query_executor')
 LOG.setLevel(level=logging.INFO)
 

http://git-wip-us.apache.org/repos/asf/impala/blob/30bb0b3d/tests/performance/scheduler.py
----------------------------------------------------------------------
diff --git a/tests/performance/scheduler.py b/tests/performance/scheduler.py
index 8a97dd4..760b331 100644
--- a/tests/performance/scheduler.py
+++ b/tests/performance/scheduler.py
@@ -28,11 +28,9 @@ from sys import exit
 from threading import Lock, Thread, Event
 import threading
 
-logging.basicConfig(level=logging.INFO, format='%(name)s %(threadName)s: %(message)s')
 LOG = logging.getLogger('scheduler')
 LOG.setLevel(level=logging.DEBUG)
 
-
 class Scheduler(object):
   """Schedules the submission of workloads across one of more clients.
 

http://git-wip-us.apache.org/repos/asf/impala/blob/30bb0b3d/tests/performance/workload_runner.py
----------------------------------------------------------------------
diff --git a/tests/performance/workload_runner.py b/tests/performance/workload_runner.py
index a50af9c..9cee7e0 100644
--- a/tests/performance/workload_runner.py
+++ b/tests/performance/workload_runner.py
@@ -34,8 +34,6 @@ from tests.performance.query_exec_functions import (
     execute_using_jdbc)
 from tests.performance.scheduler import Scheduler
 
-# Setup Logging
-logging.basicConfig(level=logging.INFO, format='[%(name)s]: %(message)s')
 LOG = logging.getLogger('workload_runner')
 
 

http://git-wip-us.apache.org/repos/asf/impala/blob/30bb0b3d/tests/run-tests.py
----------------------------------------------------------------------
diff --git a/tests/run-tests.py b/tests/run-tests.py
index b1a9fdd..78c152b 100755
--- a/tests/run-tests.py
+++ b/tests/run-tests.py
@@ -24,6 +24,7 @@
 # All additional command line options are passed to py.test.
 from tests.common.impala_cluster import ImpalaCluster
 from tests.common.impala_service import ImpaladService
+from tests.conftest import configure_logging
 import itertools
 import json
 import multiprocessing
@@ -224,6 +225,8 @@ def print_metrics(substring):
 
 
 if __name__ == "__main__":
+  # Ensure that logging is configured for the 'run-test.py' wrapper itself.
+  configure_logging()
   exit_on_error = '-x' in sys.argv or '--exitfirst' in sys.argv
   skip_serial = '--skip-serial' in sys.argv
   if skip_serial:

http://git-wip-us.apache.org/repos/asf/impala/blob/30bb0b3d/tests/util/plugin_runner.py
----------------------------------------------------------------------
diff --git a/tests/util/plugin_runner.py b/tests/util/plugin_runner.py
index 0bd8fe6..a0f0d90 100644
--- a/tests/util/plugin_runner.py
+++ b/tests/util/plugin_runner.py
@@ -22,7 +22,6 @@ import pkgutil
 PLUGIN_DIR = os.path.join(os.environ['IMPALA_HOME'], 'tests', 'benchmark', 'plugins')
 
 # Setup logging for this module.
-logging.basicConfig(level=logging.INFO, format='%(filename)s: %(message)s')
 LOG = logging.getLogger('plugin_runner')
 LOG.setLevel(level=logging.INFO)