diff --git a/src/integrationtest/basic_checks.py b/src/integrationtest/basic_checks.py new file mode 100644 index 0000000..5209872 --- /dev/null +++ b/src/integrationtest/basic_checks.py @@ -0,0 +1,29 @@ +import pytest +import os +import re +from integrationtest.verbosity_helper import IntegtestVerbosityLevels + +def basic_checks(run_dunerc, caplog, print_test_name: bool = True): + + # print out the name of the current test, if requested + if print_test_name and run_dunerc.verbosity_helper.compare_level(IntegtestVerbosityLevels.drunc_transitions): + # print the name of the current test + current_test = os.environ.get("PYTEST_CURRENT_TEST") + match_obj = re.search(r".*\[(.+)-run_.*rc.*\d].*", current_test) + if match_obj: + current_test = match_obj.group(1) + banner_line = re.sub(".", "=", current_test) + print(banner_line) + print(current_test) + print(banner_line) + + # Check that dunerc completed correctly + if run_dunerc.completed_process.returncode != 0: + fail_msg = f"The run control session returned a non-zero status code ({run_dunerc.completed_process.returncode})." + pytest.fail(fail_msg, pytrace=False) + + # Check that there weren't any warnings or errors during setup + setup_logs = caplog.get_records("setup") + if len(setup_logs) > 0: + fail_msg = f"One or more problems were encountered during the setup of the pytest: {setup_logs}" + pytest.fail(fail_msg, pytrace=False) diff --git a/src/integrationtest/data_file_checks.py b/src/integrationtest/data_file_checks.py index aed2ecd..3c667e8 100644 --- a/src/integrationtest/data_file_checks.py +++ b/src/integrationtest/data_file_checks.py @@ -19,23 +19,29 @@ check_multi_TR_type, record_ordinal_string_all_tests, trigger_functions_checks - ) +) +from integrationtest.verbosity_helper import ( + IntegtestVerbosityLevels, + VerbosityHelper +) # 21-May-2025, KAB: tweak the print() statement default behavior so that it always flushes the output. import functools print = functools.partial(print, flush=True) class DataFile: - def __init__(self, filename): + def __init__(self, filename, verbosity_helper: VerbosityHelper = VerbosityHelper(99)): self.h5file=h5py.File(filename, 'r') self.events=self.h5file.keys() self.name=str(filename) + self.vrb_hlpr = verbosity_helper def sanity_check(datafile): "Very basic sanity checks on file" passed=True base_filename = os.path.basename(datafile.h5file.filename) - print("") # Clear potential dot from pytest + if datafile.vrb_hlpr.compare_level(IntegtestVerbosityLevels.drunc_transitions): + print("") # Clear potential dot from pytest # execute unit tests for local function(s) # (this is probably not the best place for these...) @@ -72,7 +78,8 @@ def sanity_check(datafile): passed=False if passed: - print(f"\N{WHITE HEAVY CHECK MARK} Sanity-check passed for file {base_filename}") + datafile.vrb_hlpr.lvl_print(IntegtestVerbosityLevels.drunc_transitions, + f"\N{WHITE HEAVY CHECK MARK} Sanity-check passed for file {base_filename}") else: print(f"\N{POLICE CARS REVOLVING LIGHT} One or more sanity-checks failed for file {base_filename} \N{POLICE CARS REVOLVING LIGHT}") return passed @@ -86,7 +93,8 @@ def check_file_attributes(datafile, was_test_run="true"): passed=True base_filename = os.path.basename(datafile.h5file.filename) if "tp" in base_filename: - print("") # Clear potential dot from pytest + if datafile.vrb_hlpr.compare_level(IntegtestVerbosityLevels.drunc_transitions): + print("") # Clear potential dot from pytest expected_attribute_names = ["application_name", "closing_timestamp", "creation_timestamp", "file_index", "filelayout_params", "filelayout_version", "offline_data_stream", "operational_environment", "record_type", "recorded_size", "run_number", "run_was_for_test_purposes", "source_id_geo_id_map"] for expected_attr_name in expected_attribute_names: if expected_attr_name not in datafile.h5file.attrs.keys(): @@ -141,9 +149,10 @@ def check_file_attributes(datafile, was_test_run="true"): attr_value = datafile.h5file.attrs.get(expected_attr_name) if attr_value != was_test_run: passed=False - print(f"\N{POLICE CARS REVOLVING LIGHT} The value in HDF5 File Attribute '{expected_attr_name}' ({attr_value}) does not match the expected value ({was_test_run}) \N{POLICE CARS REVOLVING LIGHT}") + print(f"\N{POLICE CARS REVOLVING LIGHT} The value in HDF5 File Attribute '{expected_attr_name}' ({attr_value}) does not match the expected value ({was_test_run}) in file {base_filename} \N{POLICE CARS REVOLVING LIGHT}") if passed: - print(f"\N{WHITE HEAVY CHECK MARK} All Attribute tests passed") + datafile.vrb_hlpr.lvl_print(IntegtestVerbosityLevels.drunc_transitions, + f"\N{WHITE HEAVY CHECK MARK} All Attribute tests passed for file {base_filename}") return passed def check_event_count(datafile, expected_value, tolerance): @@ -156,7 +165,8 @@ def check_event_count(datafile, expected_value, tolerance): passed=False print(f"\N{POLICE CARS REVOLVING LIGHT} Record count {event_count} is outside the tolerance of {tolerance} from an expected value of {expected_value} \N{POLICE CARS REVOLVING LIGHT}") if passed: - print(f"\N{WHITE HEAVY CHECK MARK} Record count {event_count} is within a tolerance of {tolerance} from an expected value of {expected_value}") + datafile.vrb_hlpr.lvl_print(IntegtestVerbosityLevels.drunc_transitions, + f"\N{WHITE HEAVY CHECK MARK} Record count {event_count} is within a tolerance of {tolerance} from an expected value of {expected_value}") return passed # 18-Aug-2021, KAB: General-purposed test for fragment count. The idea behind this test @@ -207,9 +217,11 @@ def check_fragment_count(datafile, params): min_count_list.sort() max_count_list.sort() if len(min_count_list) > 1 or len(max_count_list) > 1 or min_count_list[0] != max_count_list[0]: - print(f"\N{WHITE HEAVY CHECK MARK} {params['fragment_type_description']} fragment count in range {min_count_list} to {max_count_list} confirmed in all {len(records)} records") + datafile.vrb_hlpr.lvl_print(IntegtestVerbosityLevels.drunc_transitions, + f"\N{WHITE HEAVY CHECK MARK} {params['fragment_type_description']} fragment count in range {min_count_list} to {max_count_list} confirmed in all {len(records)} records") else: - print(f"\N{WHITE HEAVY CHECK MARK} {params['fragment_type_description']} fragment count of {min_count_list[0]} confirmed in all {len(records)} records") + datafile.vrb_hlpr.lvl_print(IntegtestVerbosityLevels.drunc_transitions, + f"\N{WHITE HEAVY CHECK MARK} {params['fragment_type_description']} fragment count of {min_count_list[0]} confirmed in all {len(records)} records") return passed # 18-Aug-2021, KAB: general-purposed test for fragment sizes. The idea behind this test @@ -264,7 +276,8 @@ def check_fragment_sizes(datafile, params): if passed: min_size_list.sort() max_size_list.sort() - print(f"\N{WHITE HEAVY CHECK MARK} All {params['fragment_type_description']} fragments in {len(records)} records have sizes between {min_size_list[0] if len(min_size_list) == 1 else min_size_list} and {max_size_list[0] if len(max_size_list) == 1 else max_size_list}") + datafile.vrb_hlpr.lvl_print(IntegtestVerbosityLevels.drunc_transitions, + f"\N{WHITE HEAVY CHECK MARK} All {params['fragment_type_description']} fragments in {len(records)} records have sizes between {min_size_list[0] if len(min_size_list) == 1 else min_size_list} and {max_size_list[0] if len(max_size_list) == 1 else max_size_list}") return passed # 07-Jan-2025, ELF: test for fragment error flags. The idea behind this test @@ -314,7 +327,8 @@ def check_fragment_error_flags(datafile, params): print(f" \N{POLICE CARS REVOLVING LIGHT} {params['fragment_type_description']} fragment for SrcID {src_id.to_string()} in record {rec} has the following unmasked error flags set: {get_set_status_bit_names(status_bits & status_bitmask)} \N{POLICE CARS REVOLVING LIGHT}") if passed: error_mask_list.sort() - print(f"\N{WHITE HEAVY CHECK MARK} All {params['fragment_type_description']} fragments in {len(records)} records have no error flags set (after applying bitmasks)") + datafile.vrb_hlpr.lvl_print(IntegtestVerbosityLevels.drunc_transitions, + f"\N{WHITE HEAVY CHECK MARK} All {params['fragment_type_description']} fragments in {len(records)} records have no error flags set (after applying bitmasks)") return passed def check_n_unique_sids(datafile, expected_sids_tp, expected_sids_ta, expected_sids_tc): @@ -404,10 +418,10 @@ def check_tr_type_multiplicity(datafile, multi_required): return True -def trigger_sanity_checks(): +def trigger_sanity_checks(verbosity_helper: VerbosityHelper = VerbosityHelper(99)): all_ok = trigger_functions_checks() if all_ok: - print(f"\n\N{WHITE HEAVY CHECK MARK} All trigger sanity checks passed successfully.") + verbosity_helper.lvl_print(IntegtestVerbosityLevels.drunc_transitions, + f"\n\N{WHITE HEAVY CHECK MARK} All trigger sanity checks passed successfully.") else: print(f"\n\N{POLICE CARS REVOLVING LIGHT} Some trigger sanity checks FAILED. Please review the errors above.") - diff --git a/src/integrationtest/integrationtest_commandline.py b/src/integrationtest/integrationtest_commandline.py index 023a7d1..44625d9 100755 --- a/src/integrationtest/integrationtest_commandline.py +++ b/src/integrationtest/integrationtest_commandline.py @@ -42,6 +42,20 @@ def pytest_addoption(parser): help="The run control process manager type to use for this test, e.g. ssh-standalone", required=False ) + parser.addoption( + "--integtest-verbosity", + action="store", + default=3, + help="The volume of messages that are printed out by the integration test infrastructure", + required=False + ) + parser.addoption( + "--dunerc-fullprint-watch-string", + action="store", + default="", + help="A phrase that, if found in run control messages, will trigger the printout of all RC messages", + required=False + ) def pytest_configure(config): for opt in ("--dunerc-path",): diff --git a/src/integrationtest/integrationtest_drunc.py b/src/integrationtest/integrationtest_drunc.py index 1a9fc9d..406af21 100755 --- a/src/integrationtest/integrationtest_drunc.py +++ b/src/integrationtest/integrationtest_drunc.py @@ -3,9 +3,16 @@ import pathlib import getpass import os +import re +import sys +from io import StringIO import conffwk from integrationtest.integrationtest_commandline import file_exists from integrationtest.resource_validation import ResourceValidator +from integrationtest.verbosity_helper import ( + VerbosityHelper, + IntegtestVerbosityLevels, +) from integrationtest.data_classes import ( CreateConfigResult, config_substitution, @@ -39,6 +46,11 @@ import json +# keep track of the number of parametrizations (for various display uses) +total_paramtrization_combinations = 0 +parametrization_counter = 0 + + def parametrize_fixture_with_items(metafunc, fixture, itemsname): """Parametrize a fixture using the contents of variable `listname` from module scope. We want to distinguish between the cases where @@ -117,8 +129,15 @@ def pytest_generate_tests(metafunc): if "run_dunerc" in metafunc.fixturenames: parametrize_fixture_with_items(metafunc, "run_dunerc", "dunerc_command_list") + # determine the number of different parametrizations + # (recall that this fixture is called once per pytest function in each integtest) + # (we only need to calculate this value once, so we check the initial value of zero) + global total_paramtrization_combinations + if total_paramtrization_combinations == 0: + total_paramtrization_combinations = len(metafunc.module.confgen_arguments) * len(metafunc.module.process_manager_choices) + if type(metafunc.module.dunerc_command_list) is dict: + total_paramtrization_combinations *= len(metafunc.module.dunerc_command_list) -# 29-Dec-2025, KAB: added fixture to handle different process manager choices @pytest.fixture(scope="module") def process_manager_type(request, tmp_path_factory): yield request.param @@ -133,8 +152,19 @@ def check_system_resources(request): the recommended resources are not present, then a warning is printed """ skip_resource_checks = request.config.getoption("--skip-resource-checks") + integtest_verbosity_level = int(request.config.getoption("--integtest-verbosity")) + + # print out a couple of blank lines to help with formatting + if integtest_verbosity_level > IntegtestVerbosityLevels.just_errors_and_warnings: + print("", flush=True) + print("", flush=True) resval = getattr(request.module, "resource_validator", ResourceValidator()) + + if integtest_verbosity_level >= IntegtestVerbosityLevels.integtest_debug: + resval_debug_string = resval.get_debug_string() + print(resval_debug_string) + if not resval.required_resources_are_present: resval_report_string = resval.get_required_resources_report() print(f"\n\N{LARGE YELLOW CIRCLE} {resval_report_string}") @@ -144,16 +174,18 @@ def check_system_resources(request): del request.session.items[1:] pytest.skip(f"\n\N{LARGE YELLOW CIRCLE} {resval_report_string}") if not resval.recommended_resources_are_present: - resval_report_string = resval.get_recommended_resources_report() - print(f"\n*** Note: {resval_report_string}") + if integtest_verbosity_level >= IntegtestVerbosityLevels.integtest_debug: + resval_report_string = resval.get_recommended_resources_report() + print(f"\n*** Note: {resval_report_string}") yield True # 16-Feb-2026, KAB: added a printout for recommended resources after the "yield" # statement so that it gets printed out at the end of the output that the user sees. if not resval.recommended_resources_are_present: - resval_report_string = resval.get_recommended_resources_report() - print(f"\n*** Note: {resval_report_string}") + if integtest_verbosity_level >= IntegtestVerbosityLevels.integtest_debug: + resval_report_string = resval.get_recommended_resources_report() + print(f"\n*** Note: {resval_report_string}") @pytest.fixture(scope="module") def create_config_files(request, tmp_path_factory, check_system_resources): @@ -183,6 +215,19 @@ def create_config_files(request, tmp_path_factory, check_system_resources): if not drunc_config.daq_session_name: drunc_config.daq_session_name = drunc_config.config_session_name + # 26-Mar-2026, KAB: suppress output messages, if requested + integtest_verbosity_level = int(request.config.getoption("--integtest-verbosity")) + if integtest_verbosity_level >= IntegtestVerbosityLevels.integtest_debug: + print("", flush=True) + original_stdout = sys.stdout + if integtest_verbosity_level < IntegtestVerbosityLevels.full_output: + if integtest_verbosity_level >= IntegtestVerbosityLevels.integtest_debug: + print("----------------------------------------", flush=True) + print("*** Messages related to configuration generation have been suppressed ***", flush=True) + print("----------------------------------------", flush=True) + print("", flush=True) + sys.stdout = catcher = StringIO() + config_dir = tmp_path_factory.mktemp("config") boot_file = config_dir / "boot.json" configfile = config_dir / "config.json" @@ -200,7 +245,7 @@ def create_config_files(request, tmp_path_factory, check_system_resources): object_databases = getattr(request.module, "object_databases", []) local_object_databases = copy_configuration(config_dir, object_databases) - print() # Blank line + #print() # Blank line if file_exists(integtest_conf): print(f"Integtest preconfigured config file: {integtest_conf}") consolidate_files(str(temp_config_db), integtest_conf, *local_object_databases) @@ -381,6 +426,11 @@ def apply_update(obj, substitution): trmon_data_dirs=trmon_dirs ) + # restore the usual stdout behavior, if needed + if integtest_verbosity_level < IntegtestVerbosityLevels.full_output: + sys.stdout = original_stdout + else: + print("", flush=True) yield result @@ -404,9 +454,28 @@ def run_dunerc(request, create_config_files, process_manager_type, tmp_path_fact disable_connectivity_service = request.config.getoption( "--disable-connectivity-service" ) + integtest_verbosity_level = int(request.config.getoption("--integtest-verbosity")) run_dir = tmp_path_factory.mktemp("run") + global total_paramtrization_combinations + if total_paramtrization_combinations > 1: + global parametrization_counter + parametrization_counter += 1 + if parametrization_counter > 1: + if integtest_verbosity_level > IntegtestVerbosityLevels.just_errors_and_warnings and \ + integtest_verbosity_level < IntegtestVerbosityLevels.integtest_debug: + print("", flush=True) + print("", flush=True) + + if integtest_verbosity_level > IntegtestVerbosityLevels.just_errors_and_warnings: + current_test = os.environ.get("PYTEST_CURRENT_TEST") + match_obj = re.search(r".*\[(.+)-run_.*rc.*\d].*", current_test) + if match_obj: + current_test = match_obj.group(1) + print(f"-> {current_test} <-") + + # 15-Dec-2025, KAB: if one of our integtest bundle scripts has provided information # about itself in the execution environment of the currently running test, use that # information to create a file in the 'run' directory of the test. This is used by the @@ -443,9 +512,10 @@ def run_dunerc(request, create_config_files, process_manager_type, tmp_path_fact and create_config_files.config.connsvc_port is not None ): # start connsvc - print( - f"Starting Connectivity Service on port {create_config_files.config.connsvc_port}" - ) + if integtest_verbosity_level >= IntegtestVerbosityLevels.full_output: + print( + f"Starting Connectivity Service on port {create_config_files.config.connsvc_port}" + ) connsvc_env = os.environ.copy() connsvc_env["CONNECTION_FLASK_DEBUG"] = str( @@ -492,6 +562,11 @@ class RunResult: trmon_dirs = [run_dir] trmon_paths = create_config_files.trmon_data_dirs + # suppress output, if requested + original_stdout = sys.stdout + if integtest_verbosity_level < IntegtestVerbosityLevels.full_output: + sys.stdout = catcher = StringIO() + for path in rawdata_paths: rawdata_dir = pathlib.Path(path) if rawdata_dir not in rawdata_dirs: @@ -553,9 +628,10 @@ class RunResult: print(f"Deleting TRMon data file from earlier test: {str(file_obj)}") file_obj.unlink(True) # missing is OK - print( - "++++++++++ DRUNC Run BEGIN ++++++++++", flush=True - ) # Apparently need to flush before subprocess.run + # restore the usual stdout behavior, if needed + if integtest_verbosity_level < IntegtestVerbosityLevels.full_output: + sys.stdout = original_stdout + result = RunResult() time_before = time.time() # 25-Mar-2026, KAB: use subprocess.Popen to manage the run control session so that we can @@ -573,10 +649,60 @@ class RunResult: ) # print out each line of captured output, as well as add it to the string that we - # pass back to the user + # pass back to the user, subject to the verbosity level that the user has requested + tmp_string = request.config.getoption("--dunerc-fullprint-watch-string") + full_printout_watch_string = tmp_string.replace("_SPC_", " ") + full_printout_activated = False + number_of_lines_printed_to_the_console = 0 full_output = "" for line in rc_process.stdout: - print(line, end='', flush=True) + should_be_printed = integtest_verbosity_level >= IntegtestVerbosityLevels.full_output or \ + full_printout_activated + + # check for a user-specified string that triggers full printout + # (this check needs to come first so that it sees the initial value of "should_be_printed") + if should_be_printed == False and len(full_printout_watch_string) > 0: + if re.search(full_printout_watch_string, line): + if number_of_lines_printed_to_the_console == 0: + print("\n++++++++++ DRUNC Session BEGIN ++++++++++", flush=True) + else: + print("++++++++++ Switching to full DRUNC output mode ++++++++++", flush=True) + print( + f"+++ Displaying all DRUNC messages based on the presence of phrase \"{full_printout_watch_string}\" +++", + flush=True + ) + print(full_output) # messages captured so far + full_printout_activated = True + should_be_printed = True + number_of_lines_printed_to_the_console = 1 # probably more, but good enough + + # check for errors and warnings for all verbosity levels + if should_be_printed == False: + if ("error" in line.lower() and not " In error " in line) or "warning" in line.lower(): + should_be_printed = True + + # check for basic transition messages, if that level of verbosity is requested + if should_be_printed == False: + if integtest_verbosity_level >= IntegtestVerbosityLevels.drunc_boot_terminate: + if "Booting session" in line or \ + ("Current FSM status is " in line and ("initial" in line or "running" in line)): + should_be_printed = True + + # check for all transition messages, if that level of verbosity is requested + if should_be_printed == False: + if integtest_verbosity_level >= IntegtestVerbosityLevels.drunc_transitions: + if "Booting session" in line or "Running transition" in line \ + or ("wait" in line and "running" in line) or "exit code" in line: + should_be_printed = True + + # actually do the printout + if should_be_printed: + if number_of_lines_printed_to_the_console == 0: + print( + "++++++++++ DRUNC Session BEGIN ++++++++++", flush=True + ) # Apparently need to flush before subprocess.run + print(line, end='', flush=True) + number_of_lines_printed_to_the_console += 1 full_output += line rc_process.communicate() @@ -636,5 +762,10 @@ class RunResult: # 10-Dec-2025, KAB: added the DAQ session overall time so that we can use this # information in fine-tuning the allowed ranges in time-based checking of test results. result.daq_session_overall_time = time_after - time_before - print("---------- DRUNC Run END ----------", flush=True) + result.verbosity_helper = VerbosityHelper(integtest_verbosity_level) + if number_of_lines_printed_to_the_console > 0: + print("---------- DRUNC Session END ----------", flush=True) + print("", flush=True) + elif integtest_verbosity_level >= IntegtestVerbosityLevels.drunc_boot_terminate: + print("", flush=True) yield result diff --git a/src/integrationtest/log_file_checks.py b/src/integrationtest/log_file_checks.py index e25d64f..e9f4802 100644 --- a/src/integrationtest/log_file_checks.py +++ b/src/integrationtest/log_file_checks.py @@ -1,61 +1,70 @@ from glob import glob import re +from integrationtest.verbosity_helper import ( + IntegtestVerbosityLevels, + VerbosityHelper +) # 21-May-2025, KAB: tweak the print() statement default behavior so that it always flushes the output. import functools print = functools.partial(print, flush=True) -def log_has_no_errors(log_file_name, print_logfilename_for_problems=True, excluded_substring_list=[], required_substring_list=[], print_required_message_report=False): +def log_has_no_errors(log_file_name, print_logfilename_for_problems=True, excluded_substring_list=[], + required_substring_list=[], print_required_message_report=False, + verbosity_helper: VerbosityHelper = VerbosityHelper(99)): ok=True ignored_problem_count=0 required_counts={ss:0 for ss in required_substring_list} - for line in open(log_file_name, errors='ignore').readlines(): + with open(log_file_name, errors='ignore') as file_handle: + for line in file_handle.readlines(): - # First check if the line appears to be in the standard format of messages produced with our logging package - # For lines produced with our logging package, the first two words in the line are the date and time, then the severity + # First check if the line appears to be in the standard format of messages produced with our logging package + # For lines produced with our logging package, the first two words in the line are the date and time, then the severity - bad_line=False - match_logline_prefix = re.search(r"^20[0-9][0-9]-[A-Z][a-z][a-z]-[0-9]+\s+[0-9:,]+\s+([A-Z]+)", line) - if match_logline_prefix: - severity=match_logline_prefix.group(1) - if severity in ("WARNING", "ERROR", "FATAL"): - bad_line=True - else: # This line's not produced with our logging package, so let's just look for bad words - if "WARN" in line or "Warn" in line or "warn" in line or \ - "ERROR" in line or "Error" in line or "error" in line or \ - "FATAL" in line or "Fatal" in line or "fatal" in line or \ - "egmentation fault" in line: - bad_line=True + bad_line=False + match_logline_prefix = re.search(r"^20[0-9][0-9]-[A-Z][a-z][a-z]-[0-9]+\s+[0-9:,]+\s+([A-Z]+)", line) + if match_logline_prefix: + severity=match_logline_prefix.group(1) + if severity in ("WARNING", "ERROR", "FATAL"): + bad_line=True + else: # This line's not produced with our logging package, so let's just look for bad words + if "WARN" in line or "Warn" in line or "warn" in line or \ + "ERROR" in line or "Error" in line or "error" in line or \ + "FATAL" in line or "Fatal" in line or "fatal" in line or \ + "egmentation fault" in line: + bad_line=True + + if bad_line: + ignore_this_problem=False + for excluded_substring in excluded_substring_list: + match_obj = re.search(excluded_substring, line) + if match_obj: + ignore_this_problem=True + break + if ignore_this_problem: + bad_line=False + ignored_problem_count+=1 + if bad_line: + for substr in required_substring_list: + match_obj = re.search(substr, line) + if match_obj: + bad_line=False + break + if bad_line: + if ok and print_logfilename_for_problems: + print("----------") + print(f"\N{POLICE CARS REVOLVING LIGHT} Problem(s) found in logfile {log_file_name}:") + print(line) + ok=False - if bad_line: - ignore_this_problem=False - for excluded_substring in excluded_substring_list: - match_obj = re.search(excluded_substring, line) - if match_obj: - ignore_this_problem=True - break - if ignore_this_problem: - bad_line=False - ignored_problem_count+=1 - if bad_line: for substr in required_substring_list: match_obj = re.search(substr, line) if match_obj: - bad_line=False - break - if bad_line: - if ok and print_logfilename_for_problems: - print("----------") - print(f"\N{POLICE CARS REVOLVING LIGHT} Problem(s) found in logfile {log_file_name}:") - print(line) - ok=False + required_counts[substr] += 1 - for substr in required_substring_list: - match_obj = re.search(substr, line) - if match_obj: - required_counts[substr] += 1 if ignored_problem_count > 0: - print(f"\N{CONSTRUCTION SIGN} Note: problems found in {ignored_problem_count} lines in {log_file_name} were ignored based on {len(excluded_substring_list)} phrase(s). \N{CONSTRUCTION SIGN}") + if verbosity_helper.compare_level(IntegtestVerbosityLevels.integtest_debug): + print(f"\N{CONSTRUCTION SIGN} Note: problems found in {ignored_problem_count} lines in {log_file_name} were ignored based on {len(excluded_substring_list)} phrase(s). \N{CONSTRUCTION SIGN}") overall_required_message_count = 0 found_message_count = 0 for (substr,count) in required_counts.items(): @@ -63,12 +72,14 @@ def log_has_no_errors(log_file_name, print_logfilename_for_problems=True, exclud print(f"\N{POLICE CARS REVOLVING LIGHT} Failure: Required log message \"{substr}\" was not found in {log_file_name} \N{POLICE CARS REVOLVING LIGHT}") ok=False elif print_required_message_report: - print(f"\N{WHITE HEAVY CHECK MARK} Required log message \"{substr}\" occurred {count} times in {log_file_name}") + if verbosity_helper.compare_level(IntegtestVerbosityLevels.drunc_transitions): + print(f"\N{WHITE HEAVY CHECK MARK} Required log message \"{substr}\" occurred {count} times in {log_file_name}") overall_required_message_count += count if count > 0: found_message_count += 1 if overall_required_message_count > 0: - print(f"\N{WHITE HEAVY CHECK MARK} Note: required log messages were found in {overall_required_message_count} lines in {log_file_name} based on {found_message_count} required messages (of a total of {len(required_substring_list)} required messages).") + if verbosity_helper.compare_level(IntegtestVerbosityLevels.drunc_transitions): + print(f"\N{WHITE HEAVY CHECK MARK} Note: required log messages were found in {overall_required_message_count} lines in {log_file_name} based on {found_message_count} required messages (of a total of {len(required_substring_list)} required messages).") return ok # 23-Nov-2021, KAB: added the ability for users to specify sets of excluded substrings, to @@ -80,7 +91,7 @@ def log_has_no_errors(log_file_name, print_logfilename_for_problems=True, exclud # stops as soon as one file with problems is found (default is to check them all) # * a flag to control whether the logfile name is printed to the console when an a problem # is first found in that logfile (default is printout) -# * the sets of excluded substrings. This goal of this argument is to allow certain +# * the sets of excluded substrings. The goal of this argument is to allow certain # select messages to be ignored so that overall checking of logfiles can remain enabled # without being distracted by 'expected' problems. This argument is expected to be a # dictionary keyed by strings that might appear in the logfile name and having values @@ -90,9 +101,16 @@ def log_has_no_errors(log_file_name, print_logfilename_for_problems=True, exclud # ex_sub_map = {"ruemu": ["expected problem phrase 1", "expected problem phrase 2"]} # ex_sub_map = {"ruemu": [r"expected problem phrase \d+"]} def logs_are_error_free(log_file_names, show_all_problems=True, print_logfilename_for_problems=True, - excluded_substring_map={}, required_substring_map={}, print_required_message_report=False): + excluded_substring_map={}, required_substring_map={}, print_required_message_report=False, + verbosity_helper: VerbosityHelper = VerbosityHelper(99)): + + # 06-Apr-2026, KAB: if the verbosity level is set to enable DRUNC debug messages, add + # some strings to the excluded substring map so we don't trigger on those debug messages + if verbosity_helper.compare_level(IntegtestVerbosityLevels.drunc_debug): + excluded_substring_map["SSH_SHELL_process_manager"] = ["RAN:", "LogLevel=error"] + all_ok=True - print("") # Clear potential dot from pytest + #print("") # Clear potential dot from pytest for log in log_file_names: exclusions=[] requireds=[] @@ -108,7 +126,8 @@ def logs_are_error_free(log_file_names, show_all_problems=True, print_logfilenam requireds += required_substring_map[required_key] break - single_ok=log_has_no_errors(log, print_logfilename_for_problems, exclusions, requireds, print_required_message_report) + single_ok=log_has_no_errors(log, print_logfilename_for_problems, exclusions, requireds, + print_required_message_report, verbosity_helper) if not single_ok: all_ok=False diff --git a/src/integrationtest/opmon_metric_checks.py b/src/integrationtest/opmon_metric_checks.py index 0c37905..47351f9 100644 --- a/src/integrationtest/opmon_metric_checks.py +++ b/src/integrationtest/opmon_metric_checks.py @@ -1,4 +1,8 @@ from opmonlib.info_file_collator import collate_info_files +from integrationtest.verbosity_helper import ( + IntegtestVerbosityLevels, + VerbosityHelper +) # modify the print() statement default behavior so that it always flushes the output. import functools @@ -19,7 +23,8 @@ def collate_opmon_data_from_files(json_files: list) -> dict: # So, the default behavior of this function is to check that there is at least one sample. # Returns False if a problem is encountered (e.g. parsing the collated JSON metric data) # or the sample count is out of the requested range. True otherwise. -def check_metric_sample_count(collated_opmon_data: dict, dict_key_list: list, min_count=1, max_count=-1): +def check_metric_sample_count(collated_opmon_data: dict, dict_key_list: list, min_count=1, max_count=-1, + verbosity_helper: VerbosityHelper = VerbosityHelper(99)): full_key_path = dict_key_list[0] for key_name in dict_key_list[1:]: full_key_path += "/" + str(key_name) @@ -57,14 +62,16 @@ def check_metric_sample_count(collated_opmon_data: dict, dict_key_list: list, mi print(f"\N{POLICE CARS REVOLVING LIGHT} The number of metric samples for key \"{full_key_path}\" ({number_of_samples}) is outside the expected range ({min_count}..unbounded). \N{POLICE CARS REVOLVING LIGHT}") return False else: - print(f"\N{WHITE HEAVY CHECK MARK} The number of metric samples for key \"{full_key_path}\" ({number_of_samples}) is within the expected range ({min_count}..unbounded).") + verbosity_helper.lvl_print(IntegtestVerbosityLevels.drunc_transitions, + f"\N{WHITE HEAVY CHECK MARK} The number of metric samples for key \"{full_key_path}\" ({number_of_samples}) is within the expected range ({min_count}..unbounded).") return True else: if number_of_samples < min_count or number_of_samples > max_count: print(f"\N{POLICE CARS REVOLVING LIGHT} The number of metric samples for key \"{full_key_path}\" ({number_of_samples}) is outside the expected range ({min_count}..{max_count}). \N{POLICE CARS REVOLVING LIGHT}") return False else: - print(f"\N{WHITE HEAVY CHECK MARK} The number of metric samples for key \"{full_key_path}\" ({number_of_samples}) is within the expected range ({min_count}..{max_count}).") + verbosity_helper.lvl_print(IntegtestVerbosityLevels.drunc_transitions, + f"\N{WHITE HEAVY CHECK MARK} The number of metric samples for key \"{full_key_path}\" ({number_of_samples}) is within the expected range ({min_count}..{max_count}).") return True @@ -77,7 +84,8 @@ def check_metric_sample_count(collated_opmon_data: dict, dict_key_list: list, mi # So, the default behavior of this function is to check that there is at least one non-zero metric value. # Returns False if a problem is encountered (e.g. parsing the collated JSON metric data) # or the value sum is out of the requested range. True otherwise. -def check_metric_value_sum(collated_opmon_data: dict, dict_key_list: list, min_value_sum=1, max_value_sum=-1): +def check_metric_value_sum(collated_opmon_data: dict, dict_key_list: list, min_value_sum=1, max_value_sum=-1, + verbosity_helper: VerbosityHelper = VerbosityHelper(99)): full_key_path = dict_key_list[0] for key_name in dict_key_list[1:]: full_key_path += "/" + str(key_name) @@ -117,12 +125,14 @@ def check_metric_value_sum(collated_opmon_data: dict, dict_key_list: list, min_v print(f"\N{POLICE CARS REVOLVING LIGHT} The sum of metric values for key \"{full_key_path}\" ({value_sum}) is outside the expected range ({min_value_sum}..unbounded). \N{POLICE CARS REVOLVING LIGHT}") return False else: - print(f"\N{WHITE HEAVY CHECK MARK} The sum of metric values for key \"{full_key_path}\" ({value_sum}) is within the expected range ({min_value_sum}..unbounded).") + verbosity_helper.lvl_print(IntegtestVerbosityLevels.drunc_transitions, + f"\N{WHITE HEAVY CHECK MARK} The sum of metric values for key \"{full_key_path}\" ({value_sum}) is within the expected range ({min_value_sum}..unbounded).") return True else: if value_sum < min_value_sum or value_sum > max_value_sum: print(f"\N{POLICE CARS REVOLVING LIGHT} The sum of metric values for key \"{full_key_path}\" ({value_sum}) is outside the expected range ({min_value_sum}..{max_value_sum}). \N{POLICE CARS REVOLVING LIGHT}") return False else: - print(f"\N{WHITE HEAVY CHECK MARK} The sum of metric values for key \"{full_key_path}\" ({value_sum}) is within the expected range ({min_value_sum}..{max_value_sum}).") + verbosity_helper.lvl_print(IntegtestVerbosityLevels.drunc_transitions, + f"\N{WHITE HEAVY CHECK MARK} The sum of metric values for key \"{full_key_path}\" ({value_sum}) is within the expected range ({min_value_sum}..{max_value_sum}).") return True diff --git a/src/integrationtest/resource_validation.py b/src/integrationtest/resource_validation.py index 02482bf..895d3ed 100644 --- a/src/integrationtest/resource_validation.py +++ b/src/integrationtest/resource_validation.py @@ -20,8 +20,6 @@ # resource_validator.cpu_count_needs(32, 64) # resource_validator.free_memory_needs(28) # # set other minimum values, if desired -# resval_debug_string = resource_validator.get_debug_string() -# print(f"{resval_debug_string}") # # The check_system_resources fixture will check that the system has the required resources import os @@ -58,7 +56,7 @@ def require_cpu_count(self, minimum_cpu_count): # method to specify the number of CPUs that is needed def cpu_count_needs(self, required_count=-1, recommended_count=-1): cpu_count = os.cpu_count() - self.debug_string += f"\nDEBUG: CPU count is {cpu_count}" + self.debug_string += f"DEBUG: CPU count is {cpu_count}" if required_count >= 0: self.debug_string += f", required number is {required_count}" if recommended_count >= 0: diff --git a/src/integrationtest/verbosity_helper.py b/src/integrationtest/verbosity_helper.py new file mode 100644 index 0000000..ebea7d2 --- /dev/null +++ b/src/integrationtest/verbosity_helper.py @@ -0,0 +1,28 @@ +from dataclasses import dataclass +#import pytest + +@dataclass +class IntegtestVerbosityLevels: + just_errors_and_warnings: int = 1 # shows just errors and warnings + drunc_boot_terminate: int = 2 # adds a small subset of drunc transitions + drunc_transitions: int = 3 # adds all drunc transitions plus validation check results + integtest_debug: int = 4 # adds ResourceValidation debug info and any other integtest debug + full_output: int = 5 # shows everything + drunc_debug: int = 6 # enables drunc debug messages + +class VerbosityHelper: + #def __init__(self, request): + # self.requested_verbosity = int(request.config.getoption("--integtest-verbosity")) + + def __init__(self, verbosity_level): + self.requested_verbosity = int(verbosity_level) + + def get_requested_verbosity_level(self) -> int: + return self.requested_verbosity + + def compare_level(self, comparison_level) -> bool: + return self.requested_verbosity >= int(comparison_level) + + def lvl_print(self, comparison_level: int, text: str): + if self.requested_verbosity >= comparison_level: + print(text, flush=True)