Reduce debug noise for issue #336 #369

sven-oly · 2024-12-19T23:59:41Z

This removes excessive debug output from conformance test logs.

…ogs.

sffc · 2025-01-08T23:49:54Z

schema/check_generated_data.py

 from schema_files import ALL_TEST_TYPES

+logger = logging.Logger("Checking Test Data vs. Schemas LOGGER")
+logger.setLevel(logging.INFO)


Suggestion: often these libraries have a way to set the logging level from an environment variable or from the CLI, so that you can do something like DEBUG=* ./genData or ./genData -vv

Yes, that's possible. I'll take a look.

Also, I've removed lots of excessive logging in the latest commits.

One more thing: when executing in parallel, the individual threads cannot have a logger in their objects because a logger "cannot be pickled". That's a small complication / limit to logging.

I think don't pickle the logger; just make a new one for each thread

echeran · 2025-02-03T13:38:16Z

verifier/verifier.py


        # The following gets information from all the tests
        summary_report = SummaryReport(self.file_base)
+        summary_report.logger = logger


Why are you assigning the logger into a field of a SummaryReport instance? So far, we've made loggers as class/module-level global objects because they're just about capturing and printing information from noteworthy events in your code. They're not data that has inherent semantic meaning that needs to be stored, represented, passed around, etc. Also, the SummaryReport class doesn't have a logger field.

echeran · 2025-02-03T13:53:12Z

testdriver/testplan.py

        if self.options.run_limit:
            self.run_limit = int(self.options.run_limit)
-            logging.debug('!!! RUN LIMIT SET: %d', self.run_limit)
+            if self.debug:


To preface, I'm okay with using self.debug to conditionally run code because you regularly want to test and debug things differently locally vs. run things efficiently during a proper production run.

But using that debug field for conditional printing is an anti-pattern that we already replaced by using a logger, setting the logging level for each logging statement, and configuring the log levels appropriately for both the console output & what gets stored to a file.

There are a lot of instances throughout the PR with the pattern "if debug then print (via logging)". We should get rid of the "if debug" part in those places. That's not a loss because viewing the full debug level log output can be done via the file. It's easiest to view the log file in VS Code, which we've seen updates it's view of a file's contents in real time and nicely colorizes log file lines based on the log level of the line.

echeran · 2025-02-03T14:00:51Z

schema/schema_validator.py


    logger = logging.Logger("TEST_GENERATE LOGGER")
-    logger.setLevel(logging.INFO)
+    logger.setLevel(logging.WARNING)


By hard-coding the logger level for this file to be WARNING, and given that most of the logging statements here are either DEBUG or INFO, you're effectively turning off all of the logging happening in this module. Is that your intention?

Yes, I want to get rid of most of the non-urgent log results.

echeran · 2025-02-03T14:03:40Z

testdriver/testdriver.py

 from testplan import TestPlan

+logger = logging.Logger("TEST DRIVER LOGGER")
+logger.setLevel(logging.WARNING)


Unless there's a good reason, we should not manually (hardcode) the logger level in code. Instead, we should allow the logger level to be set by our existing config file. So here & other places in the PR, where you see logger.setLevel(...), we should remove those statements.

sffc

Seems fine

sffc · 2025-09-29T22:20:38Z

testgen/generators/datetime_fmt.py

            return result

-        # OK, there's no CLDR-based JSON data available.
-        run_list = [


Question: is this dead code?

sffc · 2025-09-29T22:20:47Z

testgen/generators/list_fmt.py

            exec_list.append('-run_limit')
            exec_list.append(str(self.run_limit))

-        run_list = [


Question: Is this dead code?

sffc · 2025-09-29T22:21:27Z

/gemini review

gemini-code-assist

Code Review

This pull request effectively reduces the debug log noise across several scripts by introducing named loggers and adjusting log levels. However, there are several critical issues that need to be addressed. The new loggers are created incorrectly using logging.Logger() instead of logging.getLogger(), which will prevent any log messages from being displayed. There are also a couple of logic errors introduced, such as making a run_limit feature dependent on a debug flag, and removing a necessary sys.exit() call. I've provided detailed comments and suggestions to fix these issues.

gemini-code-assist · 2025-09-29T22:24:10Z

schema/schema_validator.py

    logger = logging.Logger("TEST_GENERATE LOGGER")
-    logger.setLevel(logging.INFO)
+    logger.setLevel(logging.WARNING)


You should use logging.getLogger() instead of logging.Logger() to create or retrieve a logger. logging.getLogger() ensures that the logger is part of the logging hierarchy, allowing it to inherit configurations from parent loggers. Using logging.Logger() directly creates a standalone logger that won't have any handlers by default, so your log messages will not be processed or displayed.

Suggested change

logger = logging.Logger("TEST_GENERATE LOGGER")

logger.setLevel(logging.INFO)

logger.setLevel(logging.WARNING)

logger = logging.getLogger("TEST_GENERATE LOGGER")

logger.setLevel(logging.WARNING)

gemini-code-assist · 2025-09-29T22:24:10Z

testdriver/testdriver.py

+logger = logging.Logger("TEST DRIVER LOGGER")
+logger.setLevel(logging.WARNING)


You should use logging.getLogger() instead of logging.Logger() to create or retrieve a logger. logging.getLogger() ensures that the logger is part of the logging hierarchy, allowing it to inherit configurations from parent loggers. Using logging.Logger() directly creates a standalone logger that won't have any handlers by default, so your log messages will not be processed or displayed.

Suggested change

logger = logging.Logger("TEST DRIVER LOGGER")

logger.setLevel(logging.WARNING)

logger = logging.getLogger("TEST DRIVER LOGGER")

logger.setLevel(logging.WARNING)

gemini-code-assist · 2025-09-29T22:24:10Z

schema/check_schemas.py

    logger = logging.Logger("TEST SCHEMAS LOGGER")
-    logger.setLevel(logging.INFO)
+    logger.setLevel(logging.WARNING)


You should use logging.getLogger() instead of logging.Logger() to create or retrieve a logger. logging.getLogger() ensures that the logger is part of the logging hierarchy, allowing it to inherit configurations from parent loggers. Using logging.Logger() directly creates a standalone logger that won't have any handlers by default, so your log messages will not be processed or displayed.

Suggested change

logger = logging.Logger("TEST SCHEMAS LOGGER")

logger.setLevel(logging.INFO)

logger.setLevel(logging.WARNING)

logger = logging.getLogger("TEST SCHEMAS LOGGER")

logger.setLevel(logging.WARNING)

gemini-code-assist · 2025-09-29T22:24:10Z

schema/check_test_output.py


    logger = logging.Logger("Checking Test Data vs. Schemas LOGGER")
-    logger.setLevel(logging.INFO)
+    logger.setLevel(logging.WARNING)


You should use logging.getLogger() instead of logging.Logger() to create or retrieve a logger. logging.getLogger() ensures that the logger is part of the logging hierarchy, allowing it to inherit configurations from parent loggers. Using logging.Logger() directly creates a standalone logger that won't have any handlers by default, so your log messages will not be processed or displayed.

Suggested change

logger = logging.Logger("Checking Test Data vs. Schemas LOGGER")

logger.setLevel(logging.INFO)

logger.setLevel(logging.WARNING)

logger = logging.getLogger("Checking Test Data vs. Schemas LOGGER")

logger.setLevel(logging.WARNING)

gemini-code-assist · 2025-09-29T22:24:10Z

schema/check_test_output.py

        logging.fatal('Cannot create summary_json %s', error)
-        sys.exit(1)



This exception handler is missing a sys.exit(1) call that was present before. Removing it will cause the program to continue after a fatal error, likely leading to a NameError on the next line since summary_json would not have been created. Also, for consistency, logging.fatal should be changed to logger.fatal.

Suggested change

logging.fatal('Cannot create summary_json %s', error)

sys.exit(1)

logger.fatal('Cannot create summary_json %s', error)

sys.exit(1)

gemini-code-assist · 2025-09-29T22:24:11Z

testdriver/testdriver.py

    logger = logging.Logger("TEST DRIVER LOGGER")
-    logger.setLevel(logging.INFO)
+    logger.setLevel(logging.WARNING)
+
+    driver = TestDriver(logger)
+
+    logger.debug('ARGS = %s', args)
+    driver.parse_args(args[1:])


The --log argument added in ddtargs.py is not being used here to configure the logger's level; it's hardcoded to WARNING. To make the --log argument functional, you should parse the arguments before initializing the logger.

A possible refactoring of the main function:

import ddtargs def main(args): arg_parser = ddtargs.DdtArgs(args[1:]) options = arg_parser.getOptions() logger = logging.getLogger("TEST DRIVER LOGGER") log_level = getattr(logging, options.log.upper(), logging.WARNING) logger.setLevel(log_level) driver = TestDriver() driver.set_args(options) # Pass parsed options directly # ... rest of the function

This would require parse_args to not re-parse arguments.

gemini-code-assist · 2025-09-29T22:24:12Z

testdriver/testdriver.py


 class TestDriver:
-    def __init__(self):
+    def __init__(self, logger=None):


The logger parameter in the constructor is not used. The class uses the module-level logger instance instead. You should either use the passed logger by assigning it to an instance variable (e.g., self.logger = logger) and using it throughout the class, or remove the parameter for clarity. Since main is also modified, I suggest removing the parameter here and from the call site in main.

Suggested change

def __init__(self, logger=None):

def __init__(self):

gemini-code-assist · 2025-09-29T22:24:12Z

testdriver/testplan.py

        # Set up calls for version data --> results
        if not self.request_executor_info():
-            # TODO: Report problem with executor (somehow).
+            logging.error('Cannot get executor info');


This line ends with a semicolon, which is not standard Python style. Please remove it.

Suggested change

logging.error('Cannot get executor info');

logging.error('Cannot get executor info')

gemini-code-assist · 2025-09-29T22:24:12Z

schema/check_generated_data.py

+            logger.critical('  %s', failure)
        sys.exit(1)
    else:
        logging.info("All %d generated test data files match with schema", schema_count)


For consistency, you should use the logger instance defined at the module level instead of the root logging object. This ensures all logging in this module goes through the same configured logger.

Suggested change

logging.info("All %d generated test data files match with schema", schema_count)

logger.info("All %d generated test data files match with schema", schema_count)

gemini-code-assist · 2025-09-29T22:24:12Z

schema/schema_validator.py

 ch = logging.StreamHandler()
-ch.setLevel(logging.INFO)
+ch.setLevel(logging.WARNING)


The StreamHandler instance ch is created but never used. This appears to be dead code and should be removed.

sffc

Seems about right. Gemini has some feedback.

Craig added 3 commits November 12, 2024 16:56

Reducing lots of noise from debug statements and unneeded detail in l…

5ec198a

…ogs.

Merge remote-tracking branch 'upstream/main' into reduce_noise_336

0210a88

Turn off detailed progress in testdriver

9b0b024

sven-oly assigned echeran and sffc Dec 20, 2024

Craig added 2 commits January 8, 2025 14:51

Merge remote-tracking branch 'upstream/main' into reduce_noise_336

62e5f32

Merge remote-tracking branch 'upstream/main' into reduce_noise_336

e753cc4

sffc reviewed Jan 8, 2025

View reviewed changes

Craig added 3 commits January 9, 2025 10:37

Remove extra error info to logged output

fc4c295

remove unneeded debug detail

38ffe80

Merge remote-tracking branch 'upstream/main' into reduce_noise_336

81c542a

echeran reviewed Feb 3, 2025

View reviewed changes

sven-oly added 2 commits September 3, 2025 12:04

Merge remote-tracking branch 'upstream/main' into reduce_noise_336

59a17b8

Fix merge

fa4d5cb

sffc reviewed Sep 29, 2025

View reviewed changes

gemini-code-assist bot reviewed Sep 29, 2025

View reviewed changes

sffc approved these changes Oct 9, 2025

View reviewed changes

sven-oly merged commit f9d08ac into unicode-org:main Oct 10, 2025
10 checks passed

sven-oly deleted the reduce_noise_336 branch October 10, 2025 00:14

		logger = logging.Logger("TEST DRIVER LOGGER")
		logger.setLevel(logging.WARNING)

		logging.fatal('Cannot create summary_json %s', error)
		sys.exit(1)

	logging.error('Cannot get executor info');
	logging.error('Cannot get executor info')

	logging.info("All %d generated test data files match with schema", schema_count)
	logger.info("All %d generated test data files match with schema", schema_count)

Uh oh!

Reduce debug noise for issue #336 #369

Reduce debug noise for issue #336 #369

Uh oh!

Conversation

sven-oly commented Dec 19, 2024

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

sffc left a comment

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

sffc commented Sep 29, 2025

Uh oh!

gemini-code-assist bot left a comment

Choose a reason for hiding this comment

Code Review

Uh oh!

gemini-code-assist bot Sep 29, 2025

Choose a reason for hiding this comment

Uh oh!

gemini-code-assist bot Sep 29, 2025

Choose a reason for hiding this comment

Uh oh!

gemini-code-assist bot Sep 29, 2025

Choose a reason for hiding this comment

Uh oh!

gemini-code-assist bot Sep 29, 2025

Choose a reason for hiding this comment

Uh oh!

gemini-code-assist bot Sep 29, 2025

Choose a reason for hiding this comment

Uh oh!

gemini-code-assist bot Sep 29, 2025

Choose a reason for hiding this comment

Uh oh!

gemini-code-assist bot Sep 29, 2025

Choose a reason for hiding this comment

Uh oh!

gemini-code-assist bot Sep 29, 2025

Choose a reason for hiding this comment

Uh oh!

gemini-code-assist bot Sep 29, 2025

Choose a reason for hiding this comment

Uh oh!

gemini-code-assist bot Sep 29, 2025

Choose a reason for hiding this comment

Uh oh!

sffc left a comment

Choose a reason for hiding this comment

Uh oh!

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

3 participants