From 44dade45ba976748acafd1c02604ebdb28338b4b Mon Sep 17 00:00:00 2001 From: Julien Marrec Date: Wed, 5 Apr 2023 09:48:29 +0200 Subject: [PATCH 1/4] Add ctests for #4847 via a python script calling the CLI on a ruby/python file --- src/cli/CMakeLists.txt | 12 +++++++ src/cli/test/logger_test.py | 23 +++++++++++++ src/cli/test/logger_test.rb | 15 +++++++++ src/cli/test/run_test_logger.py | 57 +++++++++++++++++++++++++++++++++ 4 files changed, 107 insertions(+) create mode 100644 src/cli/test/logger_test.py create mode 100644 src/cli/test/logger_test.rb create mode 100644 src/cli/test/run_test_logger.py diff --git a/src/cli/CMakeLists.txt b/src/cli/CMakeLists.txt index 21edfa17ec..970157554b 100644 --- a/src/cli/CMakeLists.txt +++ b/src/cli/CMakeLists.txt @@ -230,6 +230,18 @@ if(BUILD_TESTING) ) set_tests_properties(OpenStudioCLI.Labs.Run_RubyPython PROPERTIES RESOURCE_LOCK "compact_osw") + add_test(NAME OpenStudioCLI.test_logger_rb + COMMAND ${Python_EXECUTABLE} "${CMAKE_CURRENT_SOURCE_DIR}/test/run_test_logger.py" $ ${CMAKE_CURRENT_SOURCE_DIR}/test/logger_test.rb + ) + + add_test(NAME OpenStudioCLI.Labs.test_logger_rb + COMMAND ${Python_EXECUTABLE} "${CMAKE_CURRENT_SOURCE_DIR}/test/run_test_logger.py" $ --labs ${CMAKE_CURRENT_SOURCE_DIR}/test/logger_test.rb + ) + + add_test(NAME OpenStudioCLI.Labs.test_logger_py + COMMAND ${Python_EXECUTABLE} "${CMAKE_CURRENT_SOURCE_DIR}/test/run_test_logger.py" $ --labs ${CMAKE_CURRENT_SOURCE_DIR}/test/logger_test.py + ) + # ============ #4856 - Forward a Path properly no matter the slashes employed ============ diff --git a/src/cli/test/logger_test.py b/src/cli/test/logger_test.py new file mode 100644 index 0000000000..ffa0ccdf60 --- /dev/null +++ b/src/cli/test/logger_test.py @@ -0,0 +1,23 @@ +import logging +import openstudio +import sys + +# Root logger +logger = logging.getLogger() +logger.setLevel(logging.WARNING) + +formatter = logging.Formatter('LOGGER - %(message)s') +handler = logging.StreamHandler(sys.stdout) +handler.setLevel(logging.WARNING) +handler.setFormatter(formatter) +logger.addHandler(handler) + +openstudio.Logger_instance().standardOutLogger().setLogLevel(openstudio.Error) + +logger.info("STDOUT Info") +logger.warning("STDOUT Warn") +logger.error("STDOUT Error") + +openstudio.logFree(openstudio.Info, "test", "Info") +openstudio.logFree(openstudio.Warn, "test", "Warn") +openstudio.logFree(openstudio.Error, "test", "Error") diff --git a/src/cli/test/logger_test.rb b/src/cli/test/logger_test.rb new file mode 100644 index 0000000000..efbbc25247 --- /dev/null +++ b/src/cli/test/logger_test.rb @@ -0,0 +1,15 @@ +$logger = Logger.new(STDOUT) +$logger.level = Logger::WARN +$logger.formatter = proc do |severity, datetime, progname, msg| + "LOGGER - #{msg}\n" +end + +OpenStudio::Logger.instance.standardOutLogger.setLogLevel(OpenStudio::Error) + +$logger.info "STDOUT Info" +$logger.warn "STDOUT Warn" +$logger.error "STDOUT Error" + +OpenStudio::logFree(OpenStudio::Info, "test", "Info") +OpenStudio::logFree(OpenStudio::Warn, "test", "Warn") +OpenStudio::logFree(OpenStudio::Error, "test", "Error") diff --git a/src/cli/test/run_test_logger.py b/src/cli/test/run_test_logger.py new file mode 100644 index 0000000000..7275323ee7 --- /dev/null +++ b/src/cli/test/run_test_logger.py @@ -0,0 +1,57 @@ +import argparse +from pathlib import Path +import subprocess + + +def validate_file(arg): + if (filepath := Path(arg)).is_file(): + return filepath + else: + raise FileNotFoundError(arg) + +if __name__ == "__main__": + + parser = argparse.ArgumentParser(description="Run a logger test.") + parser.add_argument( + "os_cli_path", type=validate_file, help="Path to the OS CLI" + ) + parser.add_argument('--labs', action='store_true') + parser.add_argument( + "logger_file", type=validate_file, help="Path to the logger test file to run" + ) + args = parser.parse_args() + print(args) + + command = [str(args.os_cli_path)] + if args.labs: + command.append("labs") + if (ext := args.logger_file.suffix) == '.py': + if not args.labs: + raise ValueError("When supplying a .py file, you must pass --labs") + command.append("execute_python_script") + elif ext == '.rb': + command.append("execute_ruby_script") + else: + raise ValueError(f"logger_file should have a .rb or .py extension, not {ext}") + + command.append(str(args.logger_file)) + print(f"Running: {' '.join(command)}") + r = subprocess.check_output(command).decode() + lines = r.splitlines() + for i, line in enumerate(lines): + print(i, line) + + # Pop the labs box + i_warn = 0 + for i, line in enumerate(lines): + if "The `labs` command is experimental - Do not use in production" in line: + i_warn = i + break + lines = lines[:(i_warn - 1)] + lines[(i_warn + 2):] + + if (n := len(lines)) != 3: + raise IOError(f"Expected 3 lines, got {n}") + + # Ruby when called this way has the openstudio logger messages first instead of last, so just sort + lines.sort() + assert lines == ['LOGGER - STDOUT Error', 'LOGGER - STDOUT Warn', '[test] <1> Error'] From e6e7dd27b555484186efd77ab7bcc903d65a747c Mon Sep 17 00:00:00 2001 From: Julien Marrec Date: Wed, 5 Apr 2023 10:59:16 +0200 Subject: [PATCH 2/4] Windows on Jenkins throws a charmap encoding error (I don't get the error locally...), try forcing encoding to utf-8 --- src/cli/test/run_test_logger.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/cli/test/run_test_logger.py b/src/cli/test/run_test_logger.py index 7275323ee7..e5b037de98 100644 --- a/src/cli/test/run_test_logger.py +++ b/src/cli/test/run_test_logger.py @@ -36,7 +36,7 @@ def validate_file(arg): command.append(str(args.logger_file)) print(f"Running: {' '.join(command)}") - r = subprocess.check_output(command).decode() + r = subprocess.check_output(command, encoding='utf-8') lines = r.splitlines() for i, line in enumerate(lines): print(i, line) From ce93b9a181d414688f7ce2d1700876da1cda147a Mon Sep 17 00:00:00 2001 From: Julien Marrec Date: Wed, 5 Apr 2023 11:50:37 +0200 Subject: [PATCH 3/4] Ok just don't try to print out the labs warning.... Whatever --- src/cli/test/run_test_logger.py | 5 +++-- 1 file changed, 3 insertions(+), 2 deletions(-) diff --git a/src/cli/test/run_test_logger.py b/src/cli/test/run_test_logger.py index e5b037de98..141b02259d 100644 --- a/src/cli/test/run_test_logger.py +++ b/src/cli/test/run_test_logger.py @@ -38,8 +38,6 @@ def validate_file(arg): print(f"Running: {' '.join(command)}") r = subprocess.check_output(command, encoding='utf-8') lines = r.splitlines() - for i, line in enumerate(lines): - print(i, line) # Pop the labs box i_warn = 0 @@ -49,6 +47,9 @@ def validate_file(arg): break lines = lines[:(i_warn - 1)] + lines[(i_warn + 2):] + for i, line in enumerate(lines): + print(i, line) + if (n := len(lines)) != 3: raise IOError(f"Expected 3 lines, got {n}") From 83015445b16e5032289600c2b723d4d0ce0f415a Mon Sep 17 00:00:00 2001 From: Julien Marrec Date: Tue, 4 Apr 2023 13:44:16 +0200 Subject: [PATCH 4/4] Workaround for #4847 - Disable the libopenstudiolib logger since the ruby shared lib has a duplicated one... --- src/cli/main.cpp | 9 +++++++++ 1 file changed, 9 insertions(+) diff --git a/src/cli/main.cpp b/src/cli/main.cpp index 74be9e37cb..b3d87ac570 100644 --- a/src/cli/main.cpp +++ b/src/cli/main.cpp @@ -4,6 +4,7 @@ #include "../workflow/OSWorkflow.hpp" #include "../utilities/core/ASCIIStrings.hpp" #include "../utilities/core/Logger.hpp" +#include "../utilities/core/StringStreamLogSink.hpp" #include "../utilities/bcl/BCLMeasure.hpp" #include "../measure/ModelMeasure.hpp" #include "../measure/EnergyPlusMeasure.hpp" @@ -306,6 +307,14 @@ int main(int argc, char* argv[]) { // fmt::print("gemPathDirs={}\n", fmt::join(gemPathDirs, ",")); // fmt::print("gemHomeDir={}\n", gemHomeDir); } else { +#if defined _WIN32 + // Poor man's hack #4847 + // Disable this logger, we have a duplicate in the ruby shared lib + openstudio::Logger::instance().standardOutLogger().disable(); + openstudio::Logger::instance().standardErrLogger().disable(); + // Avoid getting some messages during getOpenStudioModule() when we locate the DLL + openstudio::StringStreamLogSink sink; +#endif result = openstudio::rubyCLI(rubyEngine); }