Add logging configuration and setup to qiskit-neko tests

This commit logging options to the configuration file to set the log
level globally and per module, adjust the log message format, and
store the logs to a file in addition to the attachments in the
test result stream.
This commit is contained in:
Matthew Treinish 2022-01-07 13:07:36 -05:00
parent 0932909ff7
commit b1afc1f33a
No known key found for this signature in database
GPG Key ID: FD12A0F214C9E177
3 changed files with 113 additions and 11 deletions

View File

@ -21,12 +21,19 @@ import yaml
LOG = logging.getLogger(__name__)
LOG_LEVEL_VALIDATOR = vol.Any("DEBUG", "INFO", "WARNING", "ERROR", "CRITICAL")
schema = vol.Schema(
{
vol.Optional("test_timeout", default=-1): float,
vol.Optional("test_timeout"): vol.Coerce(float),
vol.Optional("backend_plugin", default="aer"): str,
vol.Optional("backend_selection", default=""): str,
vol.Optional("backend_script", default=""): str,
vol.Optional("backend_selection"): str,
vol.Optional("backend_script"): str,
vol.Optional("default_log_level", default="INFO"): LOG_LEVEL_VALIDATOR,
vol.Optional("module_log_level"): {vol.Extra: LOG_LEVEL_VALIDATOR},
vol.Optional("log_format"): str,
vol.Optional("log_file"): str,
}
)

View File

@ -243,14 +243,29 @@ def enforce_subclasses_call(methods, attr="_enforce_subclasses_call_cache"):
return decorator
def _iter_loggers():
"""Iterate on existing loggers."""
# Sadly, Logger.manager and Manager.loggerDict are not documented,
# but there is no logging public function to iterate on all loggers.
# The root logger is not part of loggerDict.
yield logging.getLogger()
manager = logging.Logger.manager
for logger in manager.loggerDict.values():
if isinstance(logger, logging.PlaceHolder):
continue
yield logger
@enforce_subclasses_call(["setUp", "setUpClass", "tearDown", "tearDownClass"])
class BaseTestCase(testtools.testcase.WithAttributes, testtools.TestCase):
log_format = "%(asctime)s %(process)d %(levelname)-8s [%(name)s] %(message)s"
def __init__(self, *args, **kwargs):
super().__init__(*args, **kwargs)
self.__setup_called = False
self.__teardown_called = False
self.log_format = "%(asctime)s %(process)d %(levelname)-8s [%(name)s] %(message)s"
def setUp(self):
super().setUp()
@ -267,12 +282,36 @@ class BaseTestCase(testtools.testcase.WithAttributes, testtools.TestCase):
self.useFixture(fixtures.MonkeyPatch("sys.stdout", stdout))
stderr = self.useFixture(fixtures.StringStream("stderr")).stream
self.useFixture(fixtures.MonkeyPatch("sys.stderr", stderr))
self.useFixture(
fixtures.LoggerFixture(nuke_handlers=False, format=self.log_format, level=None)
)
# Load configuration and set backends
# Load configuration
self.config = None
self.find_config_file()
# Configure logging
default_log_level = None
module_log_levels = None
if self.config:
default_log_level = self.config.config.get("default_log_level", None)
self.log_format = self.config.config.get("log_format", self.log_format)
module_log_levels = self.config.config.get("module_log_level", {})
log_file = self.config.config.get("log_file", None)
if log_file:
file_handler = logging.FileHandler(log_file)
formatter = logging.Formatter(self.log_format)
file_handler.setFormatter(formatter)
if default_log_level:
file_handler.setLevel(default_log_level)
logging.getLogger("").addHandler(file_handler)
self.useFixture(
fixtures.LoggerFixture(
nuke_handlers=False, format=self.log_format, level=default_log_level
)
)
if module_log_levels:
for mod, level in module_log_levels.items():
logger = logging.getLogger(mod)
logger.setLevel(level)
# Set backend
self.plugin_manager = backend_plugin.BackendPluginManager()
if self.config:
backend_script_path = self.config.config.get("backend_script", None)
@ -287,7 +326,7 @@ class BaseTestCase(testtools.testcase.WithAttributes, testtools.TestCase):
else:
self.backends = backend_plugin.BackendPluginManager().get_plugin_backends()
self.backend = self.backends["aer"]
# set test timeout
# Set test timeout
test_timeout = os.environ.get("NEKO_TEST_TIMEOUT", 0)
try:
test_timeout = int(test_timeout)

View File

@ -28,10 +28,14 @@ class TestConfig(unittest.TestCase):
def test_load_config_fully_populated(self):
data = """---
test_timeout: 60.0
test_timeout: 60
backend_plugin: ibmq
backend_selection: brooklyn
backend_script: /tmp/script.py
default_log_level: WARNING
module_log_level:
qiskit: DEBUG
numpy: ERROR
"""
mock_open = unittest.mock.mock_open(read_data=data)
with unittest.mock.patch("qiskit_neko.config.open", mock_open):
@ -41,12 +45,64 @@ backend_script: /tmp/script.py
"backend_plugin": "ibmq",
"backend_selection": "brooklyn",
"backend_script": "/tmp/script.py",
"default_log_level": "WARNING",
"module_log_level": {"qiskit": "DEBUG", "numpy": "ERROR"},
}
self.assertEqual(expected, config_obj.config)
def test_load_config_invalid_timeout_type(self):
data = """---
test_timeout: 60 seconds
"""
mock_open = unittest.mock.mock_open(read_data=data)
with unittest.mock.patch("qiskit_neko.config.open", mock_open):
with self.assertRaises(vol.MultipleInvalid):
config.NekoConfig("fake_path")
def test_load_config_change_default_log_level(self):
data = """---
default_log_level: DEBUG
"""
expected = {
"backend_plugin": "aer",
"default_log_level": "DEBUG",
}
mock_open = unittest.mock.mock_open(read_data=data)
with unittest.mock.patch("qiskit_neko.config.open", mock_open):
config_obj = config.NekoConfig("fake_path")
self.assertEqual(config_obj.config, expected)
def test_load_config_invalid_default_log_level(self):
data = """---
default_log_level: DOUBLE_WARNING
"""
mock_open = unittest.mock.mock_open(read_data=data)
with unittest.mock.patch("qiskit_neko.config.open", mock_open):
with self.assertRaises(vol.MultipleInvalid):
config.NekoConfig("fake_path")
def test_load_config_module_log_level(self):
data = """---
module_log_level:
qiskit: DEBUG
numpy: ERROR
"""
expected = {
"backend_plugin": "aer",
"default_log_level": "INFO",
"module_log_level": {"qiskit": "DEBUG", "numpy": "ERROR"},
}
mock_open = unittest.mock.mock_open(read_data=data)
with unittest.mock.patch("qiskit_neko.config.open", mock_open):
config_obj = config.NekoConfig("fake_path")
self.assertEqual(config_obj.config, expected)
def test_load_config_module_log_level_one_invalid_level(self):
data = """---
module_log_level:
qiskit: DEBUG
numpy: TRUE_ERROR
"""
mock_open = unittest.mock.mock_open(read_data=data)
with unittest.mock.patch("qiskit_neko.config.open", mock_open):