Updating logging output - simplifying output (#293)

* Updating logging output - simplifying * Remove incorrect updates
unicode-org · Aug 23, 2024 · e22373b · e22373b
1 parent f21de98
commit e22373b
Show file tree

Hide file tree

Showing 9 changed files with 51 additions and 57 deletions.
diff --git a/run_config.json b/run_config.json
@@ -11,7 +11,6 @@
       "test_type": [
         "collation_short",
         "datetime_fmt",
-        "lang_names",
         "likely_subtags",
         "list_fmt",
         "number_fmt",
@@ -32,7 +31,6 @@
       "test_type": [
         "collation_short",
         "datetime_fmt",
-        "lang_names",
         "likely_subtags",
         "list_fmt",
         "number_fmt",
@@ -113,7 +111,7 @@
     "prereq": {
       "name": "nvm 22..0, icu75.1",
       "version": "22.1.0",
-      "command": "nvm install 22.1.0;nvm use 22.1.0"
+      "command": "nvm install 22.1.0;nvm use 22.1.0 --silent"
     },
     "run": {
       "icu_version": "icu75",
@@ -135,7 +133,7 @@
     "prereq": {
       "name": "nvm",
       "version": "20.1.0",
-      "command": "nvm install 20.1.0;nvm use 20.1.0"
+      "command": "nvm install 20.1.0;nvm use 20.1.0 --silent"
     },
     "run": {
       "icu_version": "icu73",
@@ -153,7 +151,7 @@
     "prereq": {
       "name": "nvm 21.6.0, icu74.1",
       "version": "21.6.0",
-      "command": "nvm install 21.6.0;nvm use 21.6.0"
+      "command": "nvm install 21.6.0;nvm use 21.6.0 --silent"
     },
     "run": {
       "icu_version": "icu74",
@@ -175,7 +173,7 @@
     "prereq": {
       "name": "nvm",
       "version": "20.1.0",
-      "command": "nvm install 20.1.0;nvm use 20.1.0"
+      "command": "nvm install 20.1.0;nvm use 20.1.0 --silent"
     },
     "run": {
       "icu_version": "icu73",
@@ -197,7 +195,7 @@
     "prereq": {
       "name": "nvm",
       "version": "18.14.2",
-      "command": "nvm install 18.14.2;nvm use 18.14.2"
+      "command": "nvm install 18.14.2;nvm use 18.14.2 --silent"
     },
     "run": {
       "icu_version": "icu72",
@@ -207,7 +205,6 @@
         "datetime_fmt",
         "list_fmt",
         "number_fmt",
-        "lang_names",
         "likely_subtags",
         "rdt_fmt",
         "plural_rules"
@@ -219,7 +216,7 @@
     "prereq": {
       "name": "nvm",
       "version": "18.7.0",
-      "command": "nvm install 18.7.0;nvm use 18.7.0"
+      "command": "nvm install 18.7.0;nvm use 18.7.0 --silent"
     },
     "run": {
       "icu_version": "icu71",
@@ -239,7 +236,7 @@
     "prereq": {
       "name": "nvm",
       "version": "14.21.3",
-      "command": "nvm install 14.21.3;nvm use 14.21.3"
+      "command": "nvm install 14.21.3;nvm use 14.21.3 --silent"
     },
     "run": {
       "icu_version": "icu70",
@@ -255,7 +252,7 @@
     "prereq": {
       "name": "nvm",
       "version": "14.18.3",
-      "command": "nvm install 14.18.3;nvm use 14.18.3"
+      "command": "nvm install 14.18.3;nvm use 14.18.3 --silent"
     },
     "run": {
       "icu_version": "icu69",

diff --git a/schema/check_test_output.py b/schema/check_test_output.py
@@ -55,7 +55,7 @@ def main(args):
                 test_type = schema_files.TEST_FILE_TO_TEST_TYPE_MAP[test_file_prefix]
                 test_type_set.add(test_type)
             except BaseException as err:
-                logging.info('No file (%s) during schema check output: %s', file, err
+                logging.debug('No file (%s) during schema check output: %s', file, err
                               )
         for dir in icu_dirs:
             icu_version_set.add(os.path.basename(dir))

diff --git a/schema/schema_validator.py b/schema/schema_validator.py
@@ -27,7 +27,7 @@
 
 def parallel_validate_schema(validator, json_pairs):
         num_processors = mp.cpu_count()
-        loging.info('JSON validation: %s processors for %s plans' % num_processors, len(file_names))
+        logging.info('JSON validation: %s processors for %s plans' % num_processors, len(file_names))
 
         # How to get all the results
         processor_pool = mp.Pool(num_processors)
@@ -134,7 +134,7 @@ def validate_test_data_with_schema(self):
                 if file_path_pair:
                     schema_test_info.append(file_path_pair)
                 else:
-                    # logging.info('No data test file  %s for %s, %s', file_path_pair, test_type, icu_version)
+                    logging.debug('No data test file  %s for %s, %s', file_path_pair, test_type, icu_version)
                     pass
         results = self.parallel_check_test_data_schema(schema_test_info)
 
@@ -148,7 +148,7 @@ def validate_test_data_with_schema(self):
                 logging.warning('FAIL: Test data %s, %s. MSG=%s',
                                 test_type, icu_version, result_data['err_info'])
             else:
-                logging.info('Test data validated: %s %s', result_data['test_type'], result_data['icu_version'])
+                logging.debug('Test data validated: %s %s', result_data['test_type'], result_data['icu_version'])
             all_results.append(result_data)
         return all_results
 
@@ -207,7 +207,7 @@ def check_test_data_against_schema(self, schema_info):
 
     def check_test_data_schema(self, icu_version, test_type):
         # Check the generated test data for structure agains the schema
-        logging.info('Validating %s with %s', test_type, icu_version)
+        logging.debug('Validating %s with %s', test_type, icu_version)
 
         # Check test output vs. the test data schema
         schema_verify_file = os.path.join( self.schema_base, test_type, 'test_schema.json')
@@ -238,7 +238,7 @@ def check_test_data_schema(self, icu_version, test_type):
             test_result = result
         results['result'] = result
         if result:
-            logging.info('Test data %s validated successfully, with ICU %s', test_type, icu_version)
+            logging.debug('Test data %s validated successfully, with ICU %s', test_type, icu_version)
         else:
             logging.error('Test data %s FAILED with ICU %s: %s', test_type, icu_version, err_info)
 
@@ -265,7 +265,7 @@ def get_test_output_schema_plan(self, icu_version, test_type, executor):
 
     def check_test_output_schema(self, icu_version, test_type, executor):
         # Check the output of the tests for structure against the schema
-        logging.info('Validating test output: %s %s %s', executor , test_type, icu_version)
+        logging.debug('Validating test output: %s %s %s', executor , test_type, icu_version)
 
         # Check test output vs. the schema
         schema_file_name = SCHEMA_FILE_MAP[test_type]['result_data']['schema_file']

diff --git a/testdriver/testdriver.py b/testdriver/testdriver.py
@@ -51,7 +51,7 @@ def set_args(self, arg_options):
                 # Create a test plan based on data and options
                 test_data_info = ddt_data.testDatasets[test_type]
                 if self.debug:
-                    logging.info('$$$$$ test_type = %s test_data_info = %s',
+                    logging.debug('$$$$$ test_type = %s test_data_info = %s',
                                  test_type, test_data_info.testDataFilename)
 
                 for executor in arg_options.exec:
@@ -91,8 +91,7 @@ def parse_args(self, args):
 
         # Get all the arguments
         argparse = ddtargs.DdtArgs(args)
-        if self.debug:
-            logging.info('TestDriver OPTIONS: %s', argparse.getOptions())
+        logging.debug('TestDriver OPTIONS: %s', argparse.getOptions())
 
         # Now use the argparse.options to set the values in the driver
         self.set_args(argparse.getOptions())
@@ -105,13 +104,13 @@ def run_plans(self):
             plan.run_plan()
 
     def run_one(self, plan):
-        logging.info("Parallel of %s %s %s" % (plan.test_lang, plan.test_type, plan.icu_version))
+        logging.debug("Parallel of %s %s %s" % (plan.test_lang, plan.test_type, plan.icu_version))
         plan.run_plan()
 
     def run_plans_parallel(self):
         # Testing 15-Jan-2024
         num_processors = mp.cpu_count()
-        logging.info('There are %s processors for %s plans' % (num_processors, len(self.test_plans)))
+        logging.info('TestDriver: %s processors for %s plans' % (num_processors, len(self.test_plans)))
 
         processor_pool = mp.Pool(num_processors)
         with processor_pool as p:
@@ -125,6 +124,9 @@ def main(args):
     # print('ARGS = %s' % (args))
     driver.parse_args(args[1:])
 
+    logger = logging.Logger("TEST DRIVER LOGGER")
+    logger.setLevel(logging.INFO)
+
     if driver.run_serial:
         driver.run_plans()
     else:

diff --git a/testdriver/testplan.py b/testdriver/testplan.py
@@ -98,7 +98,7 @@ def run_plan(self):
             # Test data versions are given as "icu" + primary number, e.g., "73"
             # TODO: Consider sorting with possible dotted versions, e.g., 73.1.3
             newest_version = sorted(icu_test_dirs, reverse=True)[0]
-            logging.info('** Replacing proposed icu version of %s with version %s',
+            logging.warning('** Replacing proposed icu version of %s with version %s',
                          self.icu_version, newest_version)
             self.icu_version = newest_version
 
@@ -130,12 +130,10 @@ def run_plan(self):
 
         if self.options.run_limit:
             self.run_limit = int(self.options.run_limit)
-            if self.debug:
-                logging.debug('!!! RUN LIMIT SET: %d', self.run_limit)
+            logging.debug('!!! RUN LIMIT SET: %d', self.run_limit)
 
-        if self.debug:
-            logging.debug('Running plan %s on data %s',
-                self.exec_command, self.inputFilePath)
+        logging.debug('Running plan %s on data %s',
+                      self.exec_command, self.inputFilePath)
 
         if self.options.exec_mode == 'one_test':
             self.run_one_test_mode()
@@ -155,8 +153,7 @@ def request_executor_info(self):
             self.jsonOutput["platform error"] = self.run_error_message
             return None
         else:
-            if self.debug:
-                logging.debug('EXECUTOR INFO = %s', result)
+            logging.debug('EXECUTOR INFO = %s', result)
 
             try:
                 self.jsonOutput["platform"] = json.loads(result)
@@ -199,9 +196,8 @@ def request_executor_termination(self, terminate_args=None):
         if not result:
             self.jsonOutput["platform error"] = self.run_error_message
         else:
-            if self.debug:
-                logging.debug('TERMINATION INFO = %s', result)
-                self.jsonOutput["platform"] = json.loads(result)
+            logging.debug('TERMINATION INFO = %s', result)
+            self.jsonOutput["platform"] = json.loads(result)
 
     def generate_header(self):
         # TODO: Create JSON versions of each of these rather than printing
@@ -237,9 +233,8 @@ def complete_output_file(self, error_info):
             self.resultsFile.close()
 
     def run_one_test_mode(self):
-        if self.debug:
-            logging.debug('  Running OneTestMode %s on data %s',
-                  self.exec_command, self.inputFilePath)
+        logging.debug('  Running OneTestMode %s on data %s',
+                      self.exec_command, self.inputFilePath)
 
         # Set up calls for version data --> results
 
@@ -252,17 +247,15 @@ def run_one_test_mode(self):
             # The test data was not found. Skip this test.
             return None
 
-        if self.debug:
-            logging.info('@@@ %d tests found', len(tests))
+        logging.debug('@@@ %d tests found', len(tests))
 
         # Initialize JSON output headers --> results
 
         self.exec_list = self.exec_command.split()
         # TODO: get other things about the exec
-        if self.debug:
-            logging.info('EXEC info: exec_command %s, exec_list >%s<',
-                         self.exec_command,
-                         self.exec_list)
+        logging.debug('EXEC info: exec_command %s, exec_list >%s<',
+                     self.exec_command,
+                     self.exec_list)
 
         # Start the JSON output
         # Set up calls for version data --> results
@@ -284,9 +277,8 @@ def run_one_test_mode(self):
 
         # Create results file
         try:
-            if self.debug:
-                logging.debug('++++++ Results file path = %s', self.outputFilePath)
-                self.resultsFile = open(self.outputFilePath, encoding='utf-8', mode='w')
+            logging.debug('++++++ Results file path = %s', self.outputFilePath)
+            self.resultsFile = open(self.outputFilePath, encoding='utf-8', mode='w')
         except BaseException as error:
             logging.error('*** Cannot open results file at %s. Err = %s',
                   self.outputFilePath, error)
@@ -375,7 +367,7 @@ def run_all_single_tests(self, tests_per_execution=1):
 
             test_num += 1
             if self.run_limit and test_num > self.run_limit:
-                logging.info('** Stopped after %d tests', (test_num - 1))
+                logging.debug('** Stopped after %d tests', (test_num - 1))
                 break
 
         # PROCESS THE LAST BATCH, if any

diff --git a/testgen/generators/datetime_fmt.py b/testgen/generators/datetime_fmt.py
@@ -23,7 +23,7 @@ def process_test_data(self):
         }
 
         run_list = [
-            ['source ~/.nvm/nvm.sh; nvm install 21.6.0; nvm use 21.6.0'],
+            ['source ~/.nvm/nvm.sh; nvm install 21.6.0; nvm use 21.6.0 --silent'],
             ['node generators/datetime_gen.js'],
             ['mv datetime_fmt*.json icu74']
         ]
@@ -35,10 +35,10 @@ def process_test_data(self):
         # Set up Node version and call the generator
         # Add temporal to the package.
         nvm_version = icu_nvm_versions[self.icu_version]
-        generate_command = 'source ~/.nvm/nvm.sh; nvm install %s; nvm use %s; npm ci; node generators/datetime_gen.js %s %s' % (
+        generate_command = 'source ~/.nvm/nvm.sh; nvm install %s; nvm use %s --silent; npm ci; node generators/datetime_gen.js %s %s' % (
             nvm_version, nvm_version, '-run_limit', self.run_limit)
 
-        logging.info('Running this command: %s', generate_command)
+        logging.debug('Running this command: %s', generate_command)
         result = result = subprocess.run(generate_command, shell=True)
 
         # Move results to the right directory

diff --git a/testgen/generators/list_fmt.py b/testgen/generators/list_fmt.py
@@ -23,7 +23,7 @@ def process_test_data(self):
         }
 
         run_list = [
-            ['source ~/.nvm/nvm.sh; nvm install 21.6.0; nvm use 21.6.0'],
+            ['source ~/.nvm/nvm.sh; nvm install 21.6.0; nvm use 21.6.0 --silent'],
             ['node generators/list_fmt_gen.js'],
             ['mv list_fmt*.json icu74']
         ]
@@ -34,9 +34,9 @@ def process_test_data(self):
 
         # Set up Node version and call the generator
         nvm_version = icu_nvm_versions[self.icu_version]
-        generate_command = 'source ~/.nvm/nvm.sh; nvm install %s; nvm use %s; node generators/list_fmt_gen.js' % (nvm_version, nvm_version)
+        generate_command = 'source ~/.nvm/nvm.sh; nvm install %s; nvm use %s --silent; node generators/list_fmt_gen.js' % (nvm_version, nvm_version)
 
-        logging.info('Running this command: %s', generate_command)
+        logging.debug('Running this command: %s', generate_command)
         result = result = subprocess.run(generate_command, shell=True)
 
         # Move results to the right directory

diff --git a/testgen/generators/relativedatetime_fmt.py b/testgen/generators/relativedatetime_fmt.py
@@ -23,7 +23,7 @@ def process_test_data(self):
         }
 
         run_list = [
-            ['source ~/.nvm/nvm.sh; nvm install 21.6.0; nvm use 21.6.0'],
+            ['source ~/.nvm/nvm.sh; nvm install 21.6.0; nvm use 21.6.0 --silent'],
             ['node generators/rdt_gen.js'],
             ['mv rdt_fmt*.json icu74']
         ]
@@ -34,9 +34,9 @@ def process_test_data(self):
 
         # Set up Node version and call the generator
         nvm_version = icu_nvm_versions[self.icu_version]
-        generate_command = 'source ~/.nvm/nvm.sh; nvm install %s; nvm use %s; node generators/rdt_fmt_gen.js' % (nvm_version, nvm_version)
+        generate_command = 'source ~/.nvm/nvm.sh; nvm install %s; nvm use %s --silent; node generators/rdt_fmt_gen.js' % (nvm_version, nvm_version)
 
-        logging.info('Running this command: %s', generate_command)
+        logging.debug('Running this command: %s', generate_command)
         result = subprocess.run(generate_command, shell=True)
 
         # Move results to the right directory

diff --git a/verifier/verifier.py b/verifier/verifier.py
@@ -60,6 +60,9 @@ def __init__(self):
 
         logging.config.fileConfig("../logging.conf")
 
+        logger = logging.Logger("VERIFIER LOGGER")
+        logger.setLevel(logging.WARNING)
+
     def open_verify_files(self, vplan):
         # Get test data, verify data, and results for a case.
         try:
@@ -282,7 +285,7 @@ def analyze_failures(self):
     def setup_paths(self, executor, testfile, verify_file):
         base_dir = self.file_base
         if self.debug > 1:
-            logging.deubg('&&& FILE BASE = %s', base_dir)
+            logging.debug('&&& FILE BASE = %s', base_dir)
             # Check on the path defined here
             test_output_dir = 'testOutput'
             self.resultPath = os.path.join(