[impala] 04/04: IMPALA-10304: Fix log level and format for pytests

[jo...@apache.org]

This is an automated email from the ASF dual-hosted git repository.

joemcdonnell pushed a commit to branch master
in repository https://gitbox.apache.org/repos/asf/impala.git

commit 2357958e734b0da36b908030f8a3d45c048cf16f
Author: Joe McDonnell <jo...@cloudera.com>
AuthorDate: Thu Oct 29 14:36:07 2020 -0700

    IMPALA-10304: Fix log level and format for pytests
    
    Recent testing showed that the pytests are not
    respecting the log level and format set in
    conftest.py's configure_logging(). It is using
    the default log level of WARNING and the
    default formatter.
    
    The issue is that logging.basicConfig() is only
    effective the first time it is called. The code
    in lib/python/impala_py_lib/helpers.py does a
    call to logging.basicConfig() at the global
    level, and conftest.py imports that file. This
    renders the call in configure_logging()
    ineffective.
    
    To avoid this type of confusion, logging.basicConfig()
    should only be called from the main() functions for
    libraries. This removes the call in lib/python/impala_py_lib
    (as it is not needed for a library without a main function).
    It also fixes up various other locations to move the
    logging.basicConfig() call to the main() function.
    
    Testing:
     - Ran the end to end tests and custom cluster tests
     - Confirmed the logging format
     - Added an assert in configure_logging() to test that
       the INFO log level is applied to the root logger.
    
    Change-Id: I5d91b7f910b3606c50bcba4579179a0bc8c20588
    Reviewed-on: http://gerrit.cloudera.org:8080/16679
    Reviewed-by: Tim Armstrong <ta...@cloudera.com>
    Tested-by: Impala Public Jenkins <im...@cloudera.com>
---
 bin/dump_breakpad_symbols.py                | 3 +--
 bin/run-workload.py                         | 2 +-
 bin/start-impala-cluster.py                 | 4 ++--
 lib/python/impala_py_lib/helpers.py         | 1 -
 tests/conftest.py                           | 9 +++++++++
 tests/shell/util.py                         | 1 -
 tests/stress/query_retries_stress_runner.py | 2 +-
 7 files changed, 14 insertions(+), 8 deletions(-)

diff --git a/bin/dump_breakpad_symbols.py b/bin/dump_breakpad_symbols.py
index f263676..3a6f02e 100755
--- a/bin/dump_breakpad_symbols.py
+++ b/bin/dump_breakpad_symbols.py
@@ -66,8 +66,6 @@ import tempfile
 from argparse import ArgumentParser
 from collections import namedtuple
 
-logging.basicConfig(level=logging.INFO)
-
 BinarySymbolInfo = namedtuple('BinarySymbolInfo', 'path, debug_path')
 
 
@@ -283,6 +281,7 @@ def process_binary(dump_syms, binary, out_dir):
 
 
 def main():
+  logging.basicConfig(level=logging.INFO)
   args = parse_args()
   dump_syms = args.dump_syms or find_dump_syms_binary()
   assert dump_syms
diff --git a/bin/run-workload.py b/bin/run-workload.py
index d21dfe4..d406627 100755
--- a/bin/run-workload.py
+++ b/bin/run-workload.py
@@ -119,7 +119,6 @@ if options.get_password:
   options.password = getpass.getpass()
   options.get_password = None
 
-logging.basicConfig(level=logging.INFO, format='[%(name)s]: %(message)s')
 LOG = logging.getLogger('run-workload')
 
 
@@ -239,6 +238,7 @@ def _validate_options():
       raise RuntimeError("Impalads must be of the form host:port or host.")
 
 if __name__ == "__main__":
+  logging.basicConfig(level=logging.INFO, format='[%(name)s]: %(message)s')
   # Check for badly formed user options.
   _validate_options()
 
diff --git a/bin/start-impala-cluster.py b/bin/start-impala-cluster.py
index 452700c..0edee2c 100755
--- a/bin/start-impala-cluster.py
+++ b/bin/start-impala-cluster.py
@@ -42,8 +42,6 @@ from tests.common.impala_cluster import (ImpalaCluster, DEFAULT_BEESWAX_PORT,
     DEFAULT_CATALOGD_JVM_DEBUG_PORT, DEFAULT_IMPALAD_JVM_DEBUG_PORT,
     find_user_processes, run_daemon)
 
-logging.basicConfig(level=logging.ERROR, format="%(asctime)s %(threadName)s: %(message)s",
-    datefmt="%H:%M:%S")
 LOG = logging.getLogger(os.path.splitext(os.path.basename(__file__))[0])
 LOG.setLevel(level=logging.DEBUG)
 
@@ -718,6 +716,8 @@ def validate_options():
 
 
 if __name__ == "__main__":
+  logging.basicConfig(level=logging.ERROR, format="%(asctime)s %(threadName)s: %(message)s",
+    datefmt="%H:%M:%S")
   validate_options()
   if options.docker_network is None:
     cluster_ops = MiniClusterOperations()
diff --git a/lib/python/impala_py_lib/helpers.py b/lib/python/impala_py_lib/helpers.py
index a6c68d8..9631ba7 100644
--- a/lib/python/impala_py_lib/helpers.py
+++ b/lib/python/impala_py_lib/helpers.py
@@ -21,7 +21,6 @@ import os
 import re
 import subprocess
 
-logging.basicConfig()
 LOG = logging.getLogger('impala_lib_python_helpers')
 
 
diff --git a/tests/conftest.py b/tests/conftest.py
index f8c98f6..ac6a8c3 100644
--- a/tests/conftest.py
+++ b/tests/conftest.py
@@ -68,8 +68,17 @@ 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.
+  #
+  # This call only takes effect if it is the first call to logging.basicConfig().
+  # For example, if some other library calls logging.basicConfig() at the global
+  # level, then importing that library can render this call ineffective.
   logging.basicConfig(level=logging.INFO, format=LOG_FORMAT)
 
+  # Verify that the logging level is set to the correct value.
+  rootLoggerLevel = logging.getLogger().getEffectiveLevel()
+  print("rootLoggerLevel = {0}".format(logging.getLevelName(rootLoggerLevel)))
+  assert(rootLoggerLevel == logging.INFO)
+
 
 def pytest_addoption(parser):
   """Adds a new command line options to py.test"""
diff --git a/tests/shell/util.py b/tests/shell/util.py
index 5e6e9bc..b8e8a91 100755
--- a/tests/shell/util.py
+++ b/tests/shell/util.py
@@ -37,7 +37,6 @@ from tests.common.impala_service import ImpaladService
 from tests.common.impala_test_suite import (IMPALAD_BEESWAX_HOST_PORT,
     IMPALAD_HS2_HOST_PORT, IMPALAD_HS2_HTTP_HOST_PORT)
 
-logging.basicConfig()
 LOG = logging.getLogger('tests/shell/util.py')
 LOG.addHandler(logging.StreamHandler())
 
diff --git a/tests/stress/query_retries_stress_runner.py b/tests/stress/query_retries_stress_runner.py
index a2ec1e2..f0876e1 100755
--- a/tests/stress/query_retries_stress_runner.py
+++ b/tests/stress/query_retries_stress_runner.py
@@ -44,7 +44,6 @@ from tests.util.test_file_parser import load_tpc_queries
 
 IMPALA_HOME = os.environ["IMPALA_HOME"]
 
-logging.basicConfig(level=logging.INFO, format='[%(name)s][%(threadName)s]: %(message)s')
 LOG = logging.getLogger('query_retries_stress_test')
 
 
@@ -293,6 +292,7 @@ def parse_args(parser):
 
 
 def main():
+  logging.basicConfig(level=logging.INFO, format='[%(name)s][%(threadName)s]: %(message)s')
   # Parse the command line args.
   parser = ArgumentParser(description="""
 Runs a stress test for transparent query retries. Starts an impala cluster with a