test: log to stdout

4 files changed, 49 insertions, 81 deletions

diff --git a/test/cavp.py b/test/cavp.py
index 1e6ebb8..e2ad7bf 100644
--- a/test/cavp.py
+++ b/test/cavp.py
@@ -103,7 +103,7 @@ class TestFile:
         return TestExitCode.SUCCESS
 
     def run_encryption_tests(self, tools, use_boxes=False):
-        logging.info('Running encryption tests...')
+        logging.debug('Running encryption tests...')
         if not self.recognized():
             return TestExitCode.SKIPPED
         try:
@@ -116,7 +116,7 @@ class TestFile:
             return TestExitCode.ERROR
 
     def run_decryption_tests(self, tools, use_boxes=False):
-        logging.info('Running decryption tests...')
+        logging.debug('Running decryption tests...')
         if not self.recognized():
             return TestExitCode.SKIPPED
         try:
@@ -129,7 +129,7 @@ class TestFile:
             return TestExitCode.ERROR
 
     def _parse_path(self):
-        logging.info('Trying to parse test file path \'%s\'...', self._path)
+        logging.debug('Trying to parse test file path \'%s\'...', self._path)
         stub = self._strip_extension(os.path.basename(self._path))
         if not stub: return
         stub = self._strip_algorithm(stub)
@@ -156,7 +156,7 @@ class TestFile:
         if self._algorithm is None:
             logging.warning('Unknown or unsupported algorithm: %s', self._path)
             return None
-        logging.info('\tAlgorithm: %s', self._algorithm)
+        logging.debug('\tAlgorithm: %s', self._algorithm)
         return stub[0:-3]
 
     _RECOGNIZED_METHODS = ('GFSbox', 'KeySbox', 'VarKey', 'VarTxt')
@@ -164,7 +164,7 @@ class TestFile:
     def _strip_method(self, stub):
         for method in self._RECOGNIZED_METHODS:
             if stub.endswith(method):
-                logging.info('\tMethod: %s', method)
+                logging.debug('\tMethod: %s', method)
                 return stub[0:len(stub) - len(method)]
         logging.warning('Unknown or unsupported method: %s', self._path)
         return None
@@ -174,7 +174,7 @@ class TestFile:
         if self._mode is None:
             logging.warning('Unknown or unsupported mode: %s', self._path)
             return None
-        logging.info('\tMode: %s', self._mode)
+        logging.debug('\tMode: %s', self._mode)
         return self._mode
 
 
@@ -189,27 +189,17 @@ class TestArchive(zipfile.ZipFile):
 
 
 _script_dir = os.path.dirname(__file__)
-_script_name = os.path.splitext(os.path.basename(__file__))[0]
 
 
-def _build_default_log_path():
-    timestamp = datetime.now().strftime('%Y-%m-%d_%H-%M-%S')
-    fn = '{}_{}.log'.format(_script_name, timestamp)
-    return os.path.join(_script_dir, fn)
-
-
-def _setup_logging(log_path=None):
-    if log_path is None:
-        log_path = _build_default_log_path()
-
+def _setup_logging(verbose=False):
+    level = logging.DEBUG if verbose else logging.INFO
     logging.basicConfig(
-        filename=log_path,
         format='%(asctime)s | %(module)s | %(levelname)s | %(message)s',
-        level=logging.DEBUG)
+        level=level)
 
 
-def run_tests(archive_path, tools_path=(), use_sde=False, use_boxes=False, log_path=None):
-    _setup_logging(log_path)
+def run_tests(archive_path, tools_path=(), use_sde=False, use_boxes=False, verbose=False):
+    _setup_logging(verbose)
     tools = Tools(tools_path, use_sde=use_sde)
     archive = TestArchive(archive_path)
     exit_codes = []
@@ -245,8 +235,8 @@ def _parse_args(args=None):
     parser.add_argument('--archive', '-a', dest='archive_path', metavar='PATH',
                         default=os.path.join(_script_dir, 'data/KAT_AES.zip'),
                         help='set test vectors archive file path')
-    parser.add_argument('--log', '-l', dest='log_path', metavar='PATH',
-                        help='set log file path')
+    parser.add_argument('--verbose', '-v', action='store_true',
+                        help='verbose log output')
     return parser.parse_args(args)
 
 
diff --git a/test/file.py b/test/file.py
index b6d685d..bdf0f48 100644
--- a/test/file.py
+++ b/test/file.py
@@ -89,14 +89,14 @@ def _make_output_file():
 
 def run_encryption_test(tools, algorithm, mode, key, plaintext_path,
                         ciphertext_path, iv=None, force=False):
-    logging.info('Running encryption test...')
-    logging.info('\tPlaintext file path: %s', plaintext_path)
-    logging.info('\tExpected ciphertext file path: %s', ciphertext_path)
-    logging.info('\tAlgorithm: %s', algorithm)
-    logging.info('\tMode: %s', mode)
+    logging.debug('Running encryption test...')
+    logging.debug('\tPlaintext file path: %s', plaintext_path)
+    logging.debug('\tExpected ciphertext file path: %s', ciphertext_path)
+    logging.debug('\tAlgorithm: %s', algorithm)
+    logging.debug('\tMode: %s', mode)
 
     with _make_output_file() as tmp_path:
-        logging.info('\tEncrypted file path: %s', tmp_path)
+        logging.debug('\tEncrypted file path: %s', tmp_path)
 
         try:
             tools.run_encrypt_file(algorithm, mode, key, plaintext_path,
@@ -117,14 +117,14 @@ def run_encryption_test(tools, algorithm, mode, key, plaintext_path,
 
 def run_decryption_test(tools, algorithm, mode, key, plaintext_path,
                         ciphertext_path, iv=None):
-    logging.info('Running decryption test...')
-    logging.info('\tCiphertext file path: %s', ciphertext_path)
-    logging.info('\tExpected plaintext file path: %s', plaintext_path)
-    logging.info('\tAlgorithm: %s', algorithm)
-    logging.info('\tMode: %s', mode)
+    logging.debug('Running decryption test...')
+    logging.debug('\tCiphertext file path: %s', ciphertext_path)
+    logging.debug('\tExpected plaintext file path: %s', plaintext_path)
+    logging.debug('\tAlgorithm: %s', algorithm)
+    logging.debug('\tMode: %s', mode)
 
     with _make_output_file() as tmp_path:
-        logging.info('\tDecrypted file path: %s', tmp_path)
+        logging.debug('\tDecrypted file path: %s', tmp_path)
 
         try:
             tools.run_decrypt_file(algorithm, mode, key, ciphertext_path,
@@ -158,9 +158,9 @@ def enum_tests(suite_dir):
             mode = maybe_mode
             for key_path in _list_keys(mode_dir):
                 key = _read_key(key_path)
-                logging.info('Key: %s', key)
+                logging.debug('Key: %s', key)
                 test_name = _extract_test_name(key_path)
-                logging.info('Test name: %s', test_name)
+                logging.debug('Test name: %s', test_name)
                 iv = None
                 if mode.requires_init_vector():
                     iv_path = _extract_iv_path(key_path)
@@ -174,24 +174,15 @@ _script_dir = os.path.dirname(__file__)
 _script_name = os.path.splitext(os.path.basename(__file__))[0]
 
 
-def _build_default_log_path():
-    timestamp = datetime.now().strftime('%Y-%m-%d_%H-%M-%S')
-    fn = '{}_{}.log'.format(_script_name, timestamp)
-    return os.path.join(_script_dir, fn)
-
-
-def _setup_logging(log_path=None):
-    if log_path is None:
-        log_path = _build_default_log_path()
-
+def _setup_logging(verbose=False):
+    level = logging.DEBUG if verbose else logging.INFO
     logging.basicConfig(
-        filename=log_path,
         format='%(asctime)s | %(module)s | %(levelname)s | %(message)s',
-        level=logging.DEBUG)
+        level=level)
 
 
-def run_tests(suite_path, tools_path=(), log_path=None, use_sde=False, force=False):
-    _setup_logging(log_path)
+def run_tests(suite_path, tools_path=(), verbose=False, use_sde=False, force=False):
+    _setup_logging(verbose)
     tools = Tools(tools_path, use_sde=use_sde)
     exit_codes = []
 
@@ -221,8 +212,8 @@ def _parse_args(args=None):
                         help='set file encryption utilities directory path')
     parser.add_argument('--sde', '-e', dest='use_sde', action='store_true',
                         help='use Intel SDE to run the utilities')
-    parser.add_argument('--log', '-l', dest='log_path', metavar='PATH',
-                        help='set log file path')
+    parser.add_argument('--verbose', '-v', action='store_true',
+                        help='verbose log output')
     parser.add_argument('--force', '-f', action='store_true',
                         help='overwrite ciphertext files')
     parser.add_argument('--suite', '-s', dest='suite_path',
diff --git a/test/nist.py b/test/nist.py
index 9448a6d..21aab5a 100644
--- a/test/nist.py
+++ b/test/nist.py
@@ -182,9 +182,9 @@ class TestExitCode(Enum):
 
 
 def run_encryption_test(tools, algorithm, mode, use_boxes=False):
-    logging.info('Running encryption test...')
-    logging.info('Algorithm: %s', algorithm)
-    logging.info('Mode: %s', mode)
+    logging.debug('Running encryption test...')
+    logging.debug('Algorithm: %s', algorithm)
+    logging.debug('Mode: %s', mode)
 
     try:
         plaintexts = get_test_plaintexts(algorithm, mode)
@@ -204,9 +204,9 @@ def run_encryption_test(tools, algorithm, mode, use_boxes=False):
 
 
 def run_decryption_test(tools, algorithm, mode, use_boxes=False):
-    logging.info('Running decryption test...')
-    logging.info('Algorithm: %s', algorithm)
-    logging.info('Mode: %s', mode)
+    logging.debug('Running decryption test...')
+    logging.debug('Algorithm: %s', algorithm)
+    logging.debug('Mode: %s', mode)
 
     try:
         ciphertexts = get_test_ciphertexts(algorithm, mode)
@@ -225,28 +225,15 @@ def run_decryption_test(tools, algorithm, mode, use_boxes=False):
         return TestExitCode.ERROR
 
 
-_script_dir = os.path.dirname(__file__)
-_script_name = os.path.splitext(os.path.basename(__file__))[0]
-
-
-def _build_default_log_path():
-    timestamp = datetime.now().strftime('%Y-%m-%d_%H-%M-%S')
-    fn = '{}_{}.log'.format(_script_name, timestamp)
-    return os.path.join(_script_dir, fn)
-
-
-def _setup_logging(log_path=None):
-    if log_path is None:
-        log_path = _build_default_log_path()
-
+def _setup_logging(verbose=False):
+    level = logging.DEBUG if verbose else logging.INFO
     logging.basicConfig(
-        filename=log_path,
         format='%(asctime)s | %(module)s | %(levelname)s | %(message)s',
-        level=logging.DEBUG)
+        level=level)
 
 
-def run_tests(tools_path=(), use_sde=False, use_boxes=False, log_path=None):
-    _setup_logging(log_path)
+def run_tests(tools_path=(), use_sde=False, use_boxes=False, verbose=False):
+    _setup_logging(verbose)
     tools = Tools(tools_path, use_sde=use_sde)
 
     exit_codes = []
@@ -280,8 +267,8 @@ def _parse_args(args=None):
                         help='use Intel SDE to run the utilities')
     parser.add_argument('--boxes', '-b', action='store_true', dest='use_boxes',
                         help='use the "boxes" interface')
-    parser.add_argument('--log', '-l', dest='log_path', metavar='PATH',
-                        help='set log file path')
+    parser.add_argument('--verbose', '-v', action='store_true',
+                        help='verbose log output')
     return parser.parse_args(args)
 
 
diff --git a/test/toolkit.py b/test/toolkit.py
index 4abdbf4..103dc9d 100644
--- a/test/toolkit.py
+++ b/test/toolkit.py
@@ -85,14 +85,14 @@ class Tools:
     def run(self, tool_path, args):
         cmd_list = ['sde', '--', tool_path] if self._use_sde else [tool_path]
         cmd_list.extend(args)
-        logging.info('Trying to execute: %s', subprocess.list2cmdline(cmd_list))
+        logging.debug('Trying to execute: %s', subprocess.list2cmdline(cmd_list))
         try:
             output = subprocess.check_output(
                 cmd_list, universal_newlines=True, stderr=subprocess.STDOUT)
         except subprocess.CalledProcessError as e:
             logging.error('Output:\n%s', e.output)
             raise
-        logging.info('Output:\n%s', output)
+        logging.debug('Output:\n%s', output)
         return output.split()
 
     @staticmethod