From 0443645a01c70466eda0535536bd7840ecdf5a02 Mon Sep 17 00:00:00 2001 From: Kurt Biery Date: Thu, 26 Mar 2026 16:50:34 -0500 Subject: [PATCH 01/15] Initial ideas for integtest verbosity levels --- src/integrationtest/data_classes.py | 8 +++ src/integrationtest/data_file_checks.py | 4 +- .../integrationtest_commandline.py | 7 +++ src/integrationtest/integrationtest_drunc.py | 62 ++++++++++++++++--- 4 files changed, 70 insertions(+), 11 deletions(-) diff --git a/src/integrationtest/data_classes.py b/src/integrationtest/data_classes.py index cb6e9d6..60c7148 100755 --- a/src/integrationtest/data_classes.py +++ b/src/integrationtest/data_classes.py @@ -78,3 +78,11 @@ class CreateConfigResult: data_dirs: list[str] tpstream_data_dirs: list[str] trmon_data_dirs: list[str] + +@dataclass +class IntegtestVerbosityLevels: + most_concise: int = 1 # shows just errors and warnings + test_results: int = 2 # shows validation check successes as well as failures + drunc_transitions: int = 3 # shows drunc transitions plus test results + resource_check_debug_info: int = 4 # shows ResourceValidation debug info plus test results, drunc transitions + most_verbose: int = 5 # shows everything diff --git a/src/integrationtest/data_file_checks.py b/src/integrationtest/data_file_checks.py index aed2ecd..ba40c2b 100644 --- a/src/integrationtest/data_file_checks.py +++ b/src/integrationtest/data_file_checks.py @@ -141,9 +141,9 @@ 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") + print(f"\N{WHITE HEAVY CHECK MARK} All Attribute tests passed for file {base_filename}") return passed def check_event_count(datafile, expected_value, tolerance): diff --git a/src/integrationtest/integrationtest_commandline.py b/src/integrationtest/integrationtest_commandline.py index 023a7d1..de54b38 100755 --- a/src/integrationtest/integrationtest_commandline.py +++ b/src/integrationtest/integrationtest_commandline.py @@ -42,6 +42,13 @@ 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=5, + help="The volume of messages that are printed out by the integration test infrastructure", + 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 65bfc5a..f024331 100755 --- a/src/integrationtest/integrationtest_drunc.py +++ b/src/integrationtest/integrationtest_drunc.py @@ -3,6 +3,8 @@ import pathlib import getpass import os +import sys +from io import StringIO import conffwk from integrationtest.integrationtest_commandline import file_exists from integrationtest.resource_validation import ResourceValidator @@ -13,6 +15,7 @@ relationship_substitution, list_element_substitution, list_element_addition, + IntegtestVerbosityLevels, ) from daqconf.generate_hwmap import generate_hwmap from daqconf.generate import ( @@ -178,6 +181,16 @@ def create_config_files(request, tmp_path_factory, check_system_resources): "--skip-resource-checks" ) + # 26-Mar-2026, KAB: suppress output messages, if requested + integtest_verbosity_level = int(request.config.getoption("--integtest-verbosity")) + original_stdout = sys.stdout + if integtest_verbosity_level < IntegtestVerbosityLevels.most_verbose: + if integtest_verbosity_level >= (IntegtestVerbosityLevels.most_verbose / 2): + print("\n----------------------------------------", flush=True) + print("*** Messages related to configuration generation have been suppressed ***", 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" @@ -376,6 +389,9 @@ def apply_update(obj, substitution): trmon_data_dirs=trmon_dirs ) + # restore the usual stdout behavior, if needed + if integtest_verbosity_level < IntegtestVerbosityLevels.most_verbose: + sys.stdout = original_stdout yield result @@ -399,6 +415,7 @@ 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") @@ -438,9 +455,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.most_verbose: + print( + f"Starting Connectivity Service on port {create_config_files.config.connsvc_port}" + ) connsvc_env = os.environ.copy() connsvc_env["CONNECTION_FLASK_DEBUG"] = str( @@ -487,6 +505,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.most_verbose: + sys.stdout = catcher = StringIO() + for path in rawdata_paths: rawdata_dir = pathlib.Path(path) if rawdata_dir not in rawdata_dirs: @@ -548,9 +571,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.most_verbose: + 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 @@ -571,10 +595,27 @@ 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 + number_of_lines_printed_to_the_console = 0 full_output = "" for line in rc_process.stdout: - print(line, end='', flush=True) + should_be_printed = False + if integtest_verbosity_level < IntegtestVerbosityLevels.most_verbose: + if "error" in line.lower() or "warning" in line.lower(): + should_be_printed = True + else: + should_be_printed = True + 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 + if should_be_printed: + if number_of_lines_printed_to_the_console == 0: + print( + "++++++++++ DRUNC Run 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() @@ -640,5 +681,8 @@ 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) + if number_of_lines_printed_to_the_console > 0: + print("---------- DRUNC Run END ----------", flush=True) + else: + print("", flush=True) yield result From f5530286518b8fa009d09140b0a21cbb532c449c Mon Sep 17 00:00:00 2001 From: Kurt Biery Date: Sat, 28 Mar 2026 20:52:45 -0500 Subject: [PATCH 02/15] Changed the meaning of several verbosity levels; added verbosity control for another message type. --- src/integrationtest/data_classes.py | 9 +++-- .../integrationtest_commandline.py | 2 +- src/integrationtest/integrationtest_drunc.py | 38 ++++++++++++------- src/integrationtest/resource_validation.py | 2 - 4 files changed, 31 insertions(+), 20 deletions(-) diff --git a/src/integrationtest/data_classes.py b/src/integrationtest/data_classes.py index 60c7148..1996f18 100755 --- a/src/integrationtest/data_classes.py +++ b/src/integrationtest/data_classes.py @@ -81,8 +81,9 @@ class CreateConfigResult: @dataclass class IntegtestVerbosityLevels: - most_concise: int = 1 # shows just errors and warnings - test_results: int = 2 # shows validation check successes as well as failures + just_errors_and_warnings: int = 1 # shows just errors and warnings + drunc_boot_terminate: int = 2 # shows validation check successes as well as failures drunc_transitions: int = 3 # shows drunc transitions plus test results - resource_check_debug_info: int = 4 # shows ResourceValidation debug info plus test results, drunc transitions - most_verbose: int = 5 # shows everything + integtest_debug: int = 4 # shows ResourceValidation debug info plus test results, drunc transitions + full_output: int = 5 # shows everything + drunc_debug: int = 6 # includes drunc debug messages diff --git a/src/integrationtest/integrationtest_commandline.py b/src/integrationtest/integrationtest_commandline.py index de54b38..190490d 100755 --- a/src/integrationtest/integrationtest_commandline.py +++ b/src/integrationtest/integrationtest_commandline.py @@ -45,7 +45,7 @@ def pytest_addoption(parser): parser.addoption( "--integtest-verbosity", action="store", - default=5, + default=3, help="The volume of messages that are printed out by the integration test infrastructure", required=False ) diff --git a/src/integrationtest/integrationtest_drunc.py b/src/integrationtest/integrationtest_drunc.py index f024331..1af552a 100755 --- a/src/integrationtest/integrationtest_drunc.py +++ b/src/integrationtest/integrationtest_drunc.py @@ -136,8 +136,14 @@ 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")) 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}") @@ -147,16 +153,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): @@ -184,8 +192,8 @@ def create_config_files(request, tmp_path_factory, check_system_resources): # 26-Mar-2026, KAB: suppress output messages, if requested integtest_verbosity_level = int(request.config.getoption("--integtest-verbosity")) original_stdout = sys.stdout - if integtest_verbosity_level < IntegtestVerbosityLevels.most_verbose: - if integtest_verbosity_level >= (IntegtestVerbosityLevels.most_verbose / 2): + if integtest_verbosity_level < IntegtestVerbosityLevels.full_output: + if integtest_verbosity_level >= IntegtestVerbosityLevels.integtest_debug: print("\n----------------------------------------", flush=True) print("*** Messages related to configuration generation have been suppressed ***", flush=True) print("----------------------------------------", flush=True) @@ -390,7 +398,7 @@ def apply_update(obj, substitution): ) # restore the usual stdout behavior, if needed - if integtest_verbosity_level < IntegtestVerbosityLevels.most_verbose: + if integtest_verbosity_level < IntegtestVerbosityLevels.full_output: sys.stdout = original_stdout yield result @@ -455,7 +463,7 @@ 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 - if integtest_verbosity_level >= IntegtestVerbosityLevels.most_verbose: + if integtest_verbosity_level >= IntegtestVerbosityLevels.full_output: print( f"Starting Connectivity Service on port {create_config_files.config.connsvc_port}" ) @@ -507,7 +515,7 @@ class RunResult: # suppress output, if requested original_stdout = sys.stdout - if integtest_verbosity_level < IntegtestVerbosityLevels.most_verbose: + if integtest_verbosity_level < IntegtestVerbosityLevels.full_output: sys.stdout = catcher = StringIO() for path in rawdata_paths: @@ -572,7 +580,7 @@ class RunResult: file_obj.unlink(True) # missing is OK # restore the usual stdout behavior, if needed - if integtest_verbosity_level < IntegtestVerbosityLevels.most_verbose: + if integtest_verbosity_level < IntegtestVerbosityLevels.full_output: sys.stdout = original_stdout result = RunResult() @@ -600,11 +608,15 @@ class RunResult: full_output = "" for line in rc_process.stdout: should_be_printed = False - if integtest_verbosity_level < IntegtestVerbosityLevels.most_verbose: - if "error" in line.lower() or "warning" in line.lower(): + if integtest_verbosity_level < IntegtestVerbosityLevels.full_output: + if ("error" in line.lower() and not " In error " in line) or "warning" in line.lower(): should_be_printed = True else: should_be_printed = True + 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 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: @@ -612,7 +624,7 @@ class RunResult: if should_be_printed: if number_of_lines_printed_to_the_console == 0: print( - "++++++++++ DRUNC Run BEGIN ++++++++++", flush=True + "\n++++++++++ DRUNC Run BEGIN ++++++++++", flush=True ) # Apparently need to flush before subprocess.run print(line, end='', flush=True) number_of_lines_printed_to_the_console += 1 diff --git a/src/integrationtest/resource_validation.py b/src/integrationtest/resource_validation.py index 02482bf..5968ac0 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 From da0813c5b6c28c45043de8eaf99b7abf2f6a9747 Mon Sep 17 00:00:00 2001 From: Kurt Biery Date: Tue, 31 Mar 2026 14:00:30 -0500 Subject: [PATCH 03/15] added verbosity level checking to the validation functions --- src/integrationtest/data_classes.py | 9 ----- src/integrationtest/data_file_checks.py | 40 +++++++++++++------- src/integrationtest/integrationtest_drunc.py | 6 ++- src/integrationtest/log_file_checks.py | 2 +- src/integrationtest/opmon_metric_checks.py | 22 ++++++++--- src/integrationtest/verbosity_helper.py | 25 ++++++++++++ 6 files changed, 74 insertions(+), 30 deletions(-) create mode 100644 src/integrationtest/verbosity_helper.py diff --git a/src/integrationtest/data_classes.py b/src/integrationtest/data_classes.py index 1996f18..cb6e9d6 100755 --- a/src/integrationtest/data_classes.py +++ b/src/integrationtest/data_classes.py @@ -78,12 +78,3 @@ class CreateConfigResult: data_dirs: list[str] tpstream_data_dirs: list[str] trmon_data_dirs: list[str] - -@dataclass -class IntegtestVerbosityLevels: - just_errors_and_warnings: int = 1 # shows just errors and warnings - drunc_boot_terminate: int = 2 # shows validation check successes as well as failures - drunc_transitions: int = 3 # shows drunc transitions plus test results - integtest_debug: int = 4 # shows ResourceValidation debug info plus test results, drunc transitions - full_output: int = 5 # shows everything - drunc_debug: int = 6 # includes drunc debug messages diff --git a/src/integrationtest/data_file_checks.py b/src/integrationtest/data_file_checks.py index ba40c2b..e7460b5 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(): @@ -143,7 +151,8 @@ def check_file_attributes(datafile, was_test_run="true"): 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}) in file {base_filename} \N{POLICE CARS REVOLVING LIGHT}") if passed: - print(f"\N{WHITE HEAVY CHECK MARK} All Attribute tests passed for file {base_filename}") + 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): @@ -407,7 +421,7 @@ def check_tr_type_multiplicity(datafile, multi_required): def trigger_sanity_checks(): all_ok = trigger_functions_checks() if all_ok: - print(f"\n\N{WHITE HEAVY CHECK MARK} All trigger sanity checks passed successfully.") + datafile.vrb_hlpr.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_drunc.py b/src/integrationtest/integrationtest_drunc.py index 1af552a..3708002 100755 --- a/src/integrationtest/integrationtest_drunc.py +++ b/src/integrationtest/integrationtest_drunc.py @@ -8,6 +8,10 @@ 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, @@ -15,7 +19,6 @@ relationship_substitution, list_element_substitution, list_element_addition, - IntegtestVerbosityLevels, ) from daqconf.generate_hwmap import generate_hwmap from daqconf.generate import ( @@ -693,6 +696,7 @@ 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 + result.verbosity_helper = VerbosityHelper(integtest_verbosity_level) if number_of_lines_printed_to_the_console > 0: print("---------- DRUNC Run END ----------", flush=True) else: diff --git a/src/integrationtest/log_file_checks.py b/src/integrationtest/log_file_checks.py index e25d64f..f0df4e0 100644 --- a/src/integrationtest/log_file_checks.py +++ b/src/integrationtest/log_file_checks.py @@ -92,7 +92,7 @@ def log_has_no_errors(log_file_name, print_logfilename_for_problems=True, exclud 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): all_ok=True - print("") # Clear potential dot from pytest + #print("") # Clear potential dot from pytest for log in log_file_names: exclusions=[] requireds=[] 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/verbosity_helper.py b/src/integrationtest/verbosity_helper.py new file mode 100644 index 0000000..17e5c37 --- /dev/null +++ b/src/integrationtest/verbosity_helper.py @@ -0,0 +1,25 @@ +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 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) From 726d796ae479017dc9d49992028c5e67e4e9d138 Mon Sep 17 00:00:00 2001 From: Kurt Biery Date: Wed, 1 Apr 2026 13:48:17 -0500 Subject: [PATCH 04/15] Additional changes to implement integtest-verbosity. --- src/integrationtest/data_file_checks.py | 6 +++--- src/integrationtest/integrationtest_drunc.py | 20 +++++++++++++++++--- src/integrationtest/log_file_checks.py | 17 +++++++++++++---- src/integrationtest/verbosity_helper.py | 3 +++ 4 files changed, 36 insertions(+), 10 deletions(-) diff --git a/src/integrationtest/data_file_checks.py b/src/integrationtest/data_file_checks.py index e7460b5..3c667e8 100644 --- a/src/integrationtest/data_file_checks.py +++ b/src/integrationtest/data_file_checks.py @@ -418,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: - datafile.vrb_hlpr.lvl_print(IntegtestVerbosityLevels.drunc_transitions, - 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_drunc.py b/src/integrationtest/integrationtest_drunc.py index 3708002..509153a 100755 --- a/src/integrationtest/integrationtest_drunc.py +++ b/src/integrationtest/integrationtest_drunc.py @@ -3,6 +3,7 @@ import pathlib import getpass import os +import re import sys from io import StringIO import conffwk @@ -430,6 +431,13 @@ def run_dunerc(request, create_config_files, process_manager_type, tmp_path_fact run_dir = tmp_path_factory.mktemp("run") + 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"\n\n-> {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 @@ -614,6 +622,12 @@ class RunResult: if integtest_verbosity_level < IntegtestVerbosityLevels.full_output: if ("error" in line.lower() and not " In error " in line) or "warning" in line.lower(): should_be_printed = True + # 01-Apr-2026, KAB: special debugging for rare problem + if "Process manager did not exit in time, terminating forcefully" in line: + print("\n\n====================") + print(full_output) + print(line) + print("====================") else: should_be_printed = True if integtest_verbosity_level >= IntegtestVerbosityLevels.drunc_boot_terminate: @@ -627,7 +641,7 @@ class RunResult: if should_be_printed: if number_of_lines_printed_to_the_console == 0: print( - "\n++++++++++ DRUNC Run BEGIN ++++++++++", flush=True + "++++++++++ 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 @@ -698,7 +712,7 @@ class RunResult: result.daq_session_overall_time = time_after - time_before result.verbosity_helper = VerbosityHelper(integtest_verbosity_level) if number_of_lines_printed_to_the_console > 0: - print("---------- DRUNC Run END ----------", flush=True) - else: + print("---------- DRUNC Session END ----------", 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 f0df4e0..963787e 100644 --- a/src/integrationtest/log_file_checks.py +++ b/src/integrationtest/log_file_checks.py @@ -1,11 +1,17 @@ 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} @@ -55,7 +61,8 @@ def log_has_no_errors(log_file_name, print_logfilename_for_problems=True, exclud 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(): @@ -90,7 +97,8 @@ 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)): all_ok=True #print("") # Clear potential dot from pytest for log in log_file_names: @@ -108,7 +116,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/verbosity_helper.py b/src/integrationtest/verbosity_helper.py index 17e5c37..ebea7d2 100644 --- a/src/integrationtest/verbosity_helper.py +++ b/src/integrationtest/verbosity_helper.py @@ -17,6 +17,9 @@ class VerbosityHelper: 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) From 4a40922ee6ca66c64f33d4f2c902532dfaa15cd7 Mon Sep 17 00:00:00 2001 From: Kurt Biery Date: Mon, 6 Apr 2026 07:03:46 -0500 Subject: [PATCH 05/15] Updated the way that we open log files for reading in log_file_checks.py so that they reliably get closed. --- src/integrationtest/log_file_checks.py | 78 +++++++++++++------------- 1 file changed, 40 insertions(+), 38 deletions(-) diff --git a/src/integrationtest/log_file_checks.py b/src/integrationtest/log_file_checks.py index 963787e..a9f0981 100644 --- a/src/integrationtest/log_file_checks.py +++ b/src/integrationtest/log_file_checks.py @@ -15,51 +15,53 @@ def log_has_no_errors(log_file_name, print_logfilename_for_problems=True, exclud 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: 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}") From 8c4ba9e8795ee8d1781f2c1db1dccd88d18dc21c Mon Sep 17 00:00:00 2001 From: Kurt Biery Date: Mon, 6 Apr 2026 07:25:04 -0500 Subject: [PATCH 06/15] Added dunerc-fullprint-watch-string pytest option to trigger full run control output when a specified string is found in the RC output. --- .../integrationtest_commandline.py | 7 +++ src/integrationtest/integrationtest_drunc.py | 58 +++++++++++++------ 2 files changed, 47 insertions(+), 18 deletions(-) diff --git a/src/integrationtest/integrationtest_commandline.py b/src/integrationtest/integrationtest_commandline.py index 190490d..44625d9 100755 --- a/src/integrationtest/integrationtest_commandline.py +++ b/src/integrationtest/integrationtest_commandline.py @@ -49,6 +49,13 @@ def pytest_addoption(parser): 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 509153a..13d9b2d 100755 --- a/src/integrationtest/integrationtest_drunc.py +++ b/src/integrationtest/integrationtest_drunc.py @@ -615,29 +615,51 @@ class RunResult: # print out each line of captured output, as well as add it to the string that we # pass back to the user, subject to the verbosity level that the user has requested + full_printout_watch_string = request.config.getoption("--dunerc-fullprint-watch-string") + full_printout_activated = False number_of_lines_printed_to_the_console = 0 full_output = "" for line in rc_process.stdout: - should_be_printed = False - if integtest_verbosity_level < IntegtestVerbosityLevels.full_output: - if ("error" in line.lower() and not " In error " in line) or "warning" in line.lower(): - should_be_printed = True - # 01-Apr-2026, KAB: special debugging for rare problem - if "Process manager did not exit in time, terminating forcefully" in line: - print("\n\n====================") - print(full_output) - print(line) - print("====================") - else: - should_be_printed = True - 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 = 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 full_printout_watch_string in 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 - 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: + 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( From d9733770d1c09344c0f2627cbd0367e199bf7e2c Mon Sep 17 00:00:00 2001 From: Kurt Biery Date: Mon, 6 Apr 2026 20:15:43 -0500 Subject: [PATCH 07/15] Added a few blank lines to help with formatting when there are multiple confiugrations per pytest file (integtest) --- src/integrationtest/basic_checks.py | 29 ++++++++++++++ src/integrationtest/integrationtest_drunc.py | 40 +++++++++++++++++--- src/integrationtest/resource_validation.py | 2 +- 3 files changed, 65 insertions(+), 6 deletions(-) create mode 100644 src/integrationtest/basic_checks.py 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/integrationtest_drunc.py b/src/integrationtest/integrationtest_drunc.py index 13d9b2d..e53f5d1 100755 --- a/src/integrationtest/integrationtest_drunc.py +++ b/src/integrationtest/integrationtest_drunc.py @@ -46,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 @@ -124,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 @@ -142,11 +154,17 @@ def check_system_resources(request): 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) + print("", flush=True) if not resval.required_resources_are_present: resval_report_string = resval.get_required_resources_report() @@ -198,9 +216,10 @@ def create_config_files(request, tmp_path_factory, check_system_resources): original_stdout = sys.stdout if integtest_verbosity_level < IntegtestVerbosityLevels.full_output: if integtest_verbosity_level >= IntegtestVerbosityLevels.integtest_debug: - print("\n----------------------------------------", flush=True) + 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") @@ -220,7 +239,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) @@ -404,6 +423,8 @@ def apply_update(obj, substitution): # restore the usual stdout behavior, if needed if integtest_verbosity_level < IntegtestVerbosityLevels.full_output: sys.stdout = original_stdout + else: + print("", flush=True) yield result @@ -431,12 +452,20 @@ def run_dunerc(request, create_config_files, process_manager_type, tmp_path_fact run_dir = tmp_path_factory.mktemp("run") - if integtest_verbosity_level > IntegtestVerbosityLevels.just_errors_and_warnings: + global total_paramtrization_combinations + if total_paramtrization_combinations > 1 and integtest_verbosity_level > IntegtestVerbosityLevels.just_errors_and_warnings: + global parametrization_counter + parametrization_counter += 1 + if parametrization_counter > 1: + print("", flush=True) + print("", flush=True) + 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"\n\n-> {current_test} <-") + 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 @@ -735,6 +764,7 @@ class RunResult: 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/resource_validation.py b/src/integrationtest/resource_validation.py index 5968ac0..895d3ed 100644 --- a/src/integrationtest/resource_validation.py +++ b/src/integrationtest/resource_validation.py @@ -56,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: From 9d379dd2a8e6863b8b2adb797bad4cf8847beae6 Mon Sep 17 00:00:00 2001 From: Kurt Biery Date: Tue, 7 Apr 2026 07:46:49 -0500 Subject: [PATCH 08/15] Added some centrally-provided excluded substrings when DRUNC debugging is disabled, to prevent spurious complaints in that situation. --- src/integrationtest/log_file_checks.py | 8 +++++++- 1 file changed, 7 insertions(+), 1 deletion(-) diff --git a/src/integrationtest/log_file_checks.py b/src/integrationtest/log_file_checks.py index a9f0981..710d778 100644 --- a/src/integrationtest/log_file_checks.py +++ b/src/integrationtest/log_file_checks.py @@ -89,7 +89,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 @@ -101,6 +101,12 @@ def log_has_no_errors(log_file_name, print_logfilename_for_problems=True, exclud 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, 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 for log in log_file_names: From c075e3a568e03780697ee77e3d04ff639fb635ac Mon Sep 17 00:00:00 2001 From: Kurt Biery Date: Tue, 7 Apr 2026 07:47:12 -0500 Subject: [PATCH 09/15] More formatting tweaks. --- src/integrationtest/integrationtest_drunc.py | 11 +++++++---- 1 file changed, 7 insertions(+), 4 deletions(-) diff --git a/src/integrationtest/integrationtest_drunc.py b/src/integrationtest/integrationtest_drunc.py index e53f5d1..51bdb7a 100755 --- a/src/integrationtest/integrationtest_drunc.py +++ b/src/integrationtest/integrationtest_drunc.py @@ -164,7 +164,6 @@ def check_system_resources(request): if integtest_verbosity_level >= IntegtestVerbosityLevels.integtest_debug: resval_debug_string = resval.get_debug_string() print(resval_debug_string) - print("", flush=True) if not resval.required_resources_are_present: resval_report_string = resval.get_required_resources_report() @@ -213,6 +212,8 @@ def create_config_files(request, tmp_path_factory, check_system_resources): # 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: @@ -453,12 +454,14 @@ def run_dunerc(request, create_config_files, process_manager_type, tmp_path_fact run_dir = tmp_path_factory.mktemp("run") global total_paramtrization_combinations - if total_paramtrization_combinations > 1 and integtest_verbosity_level > IntegtestVerbosityLevels.just_errors_and_warnings: + if total_paramtrization_combinations > 1: global parametrization_counter parametrization_counter += 1 if parametrization_counter > 1: - print("", flush=True) - print("", flush=True) + if integtest_verbosity_level > IntegtestVerbosityLevels.just_errors_and_warnings and \ + integtest_verbosity_level < IntegtestVerbosityLevels.integtest_debug: + print("", flush=True) + print("", flush=True) current_test = os.environ.get("PYTEST_CURRENT_TEST") match_obj = re.search(r".*\[(.+)-run_.*rc.*\d].*", current_test) From 2809a93a587b1b1c14297061c44fae88f6c427b3 Mon Sep 17 00:00:00 2001 From: Kurt Biery Date: Tue, 7 Apr 2026 09:38:30 -0500 Subject: [PATCH 10/15] allow full_printout_watch_strings to be python regular expressions (to make it easier to deal with DRUNC message colorization) --- src/integrationtest/integrationtest_drunc.py | 5 +++-- 1 file changed, 3 insertions(+), 2 deletions(-) diff --git a/src/integrationtest/integrationtest_drunc.py b/src/integrationtest/integrationtest_drunc.py index 51bdb7a..4f5d6df 100755 --- a/src/integrationtest/integrationtest_drunc.py +++ b/src/integrationtest/integrationtest_drunc.py @@ -647,7 +647,8 @@ class RunResult: # print out each line of captured output, as well as add it to the string that we # pass back to the user, subject to the verbosity level that the user has requested - full_printout_watch_string = request.config.getoption("--dunerc-fullprint-watch-string") + 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 = "" @@ -658,7 +659,7 @@ class RunResult: # 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 full_printout_watch_string in line: + 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: From ca431e6124ed1d5f4e5f1d1edaaededb7aec4ca0 Mon Sep 17 00:00:00 2001 From: Kurt Biery Date: Wed, 8 Apr 2026 07:00:41 -0500 Subject: [PATCH 11/15] added verbosity checking to more print statements in log_file_checks.py --- src/integrationtest/log_file_checks.py | 6 ++++-- 1 file changed, 4 insertions(+), 2 deletions(-) diff --git a/src/integrationtest/log_file_checks.py b/src/integrationtest/log_file_checks.py index 710d778..795129d 100644 --- a/src/integrationtest/log_file_checks.py +++ b/src/integrationtest/log_file_checks.py @@ -72,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.integtest_debug): + 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.integtest_debug): + 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 From 8eaf6e0d2388c80485466f7f291eeb8565573c57 Mon Sep 17 00:00:00 2001 From: Kurt Biery Date: Wed, 8 Apr 2026 09:34:02 -0500 Subject: [PATCH 12/15] suppressed the pre-run-control printout of the test name when verbosity is 1 --- src/integrationtest/integrationtest_drunc.py | 11 ++++++----- 1 file changed, 6 insertions(+), 5 deletions(-) diff --git a/src/integrationtest/integrationtest_drunc.py b/src/integrationtest/integrationtest_drunc.py index 4f5d6df..4d4e53b 100755 --- a/src/integrationtest/integrationtest_drunc.py +++ b/src/integrationtest/integrationtest_drunc.py @@ -463,11 +463,12 @@ def run_dunerc(request, create_config_files, process_manager_type, tmp_path_fact print("", flush=True) print("", flush=True) - 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} <-") + 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 From 9ea0f862a4cde5a2a1dbd63d2020cbed4c5225ff Mon Sep 17 00:00:00 2001 From: Kurt Biery Date: Thu, 9 Apr 2026 07:56:51 -0500 Subject: [PATCH 13/15] Document to describe how trigger sources are selected and configured in integtests. --- docs/TriggerSourcesRatesAndReadoutWindows.md | 30 ++++++++++++++++++++ 1 file changed, 30 insertions(+) create mode 100644 docs/TriggerSourcesRatesAndReadoutWindows.md diff --git a/docs/TriggerSourcesRatesAndReadoutWindows.md b/docs/TriggerSourcesRatesAndReadoutWindows.md new file mode 100644 index 0000000..fba0f44 --- /dev/null +++ b/docs/TriggerSourcesRatesAndReadoutWindows.md @@ -0,0 +1,30 @@ +## Reference information + +As of April 2026, here are the trigger sources used by the available regression tests: + +crtmodules/crt_reader_test.py +daqsystemtest/3ru_1df_multirun_test.py +daqsystemtest/3ru_3df_multirun_test.py +daqsystemtest/example_system_test.py +daqsystemtest/fake_data_producer_test.py +daqsystemtest/long_window_readout_test.py +daqsystemtest/minimal_system_quick_test.py +daqsystemtest/readout_type_scan_test.py +daqsystemtest/sample_ehn1_multihost_test.py +daqsystemtest/small_footprint_quick_test.py +daqsystemtest/tpg_state_collection_test.py +daqsystemtest/tpreplay_test.py +daqsystemtest/tpstream_writing_test.py +daqsystemtest/trigger_bitwords_test.py +dfmodules/disabled_output_test.py +dfmodules/hdf5_compression_test.py +dfmodules/insufficient_disk_space_test.py +dfmodules/large_trigger_record_test.py +dfmodules/max_file_size_test.py +dfmodules/multiple_data_writers_test.py +dfmodules/offline_prod_run_test.py +dfmodules/trmonrequestor_test.py +hsilibs/iceberg_real_hsi_test.py +listrev/listrev_test.py +snbmodules/simple_transform_test.py +trigger/change_rate_test.py From d7f51dafdb54a5c97038335230442a8bf34d0aa5 Mon Sep 17 00:00:00 2001 From: Kurt Biery Date: Tue, 14 Apr 2026 08:41:43 -0500 Subject: [PATCH 14/15] Changed the verbosity level for required message printout in log_file_checks.py so that it appears at a slightly lower level. --- src/integrationtest/log_file_checks.py | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/src/integrationtest/log_file_checks.py b/src/integrationtest/log_file_checks.py index 795129d..e9f4802 100644 --- a/src/integrationtest/log_file_checks.py +++ b/src/integrationtest/log_file_checks.py @@ -72,13 +72,13 @@ 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: - if verbosity_helper.compare_level(IntegtestVerbosityLevels.integtest_debug): + 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: - if verbosity_helper.compare_level(IntegtestVerbosityLevels.integtest_debug): + 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 From 7aed6e01e6a174fe29278216842fe0839ce426d6 Mon Sep 17 00:00:00 2001 From: Kurt Biery Date: Tue, 14 Apr 2026 08:53:28 -0500 Subject: [PATCH 15/15] Removed the trigger-sources document --- docs/TriggerSourcesRatesAndReadoutWindows.md | 30 -------------------- 1 file changed, 30 deletions(-) delete mode 100644 docs/TriggerSourcesRatesAndReadoutWindows.md diff --git a/docs/TriggerSourcesRatesAndReadoutWindows.md b/docs/TriggerSourcesRatesAndReadoutWindows.md deleted file mode 100644 index fba0f44..0000000 --- a/docs/TriggerSourcesRatesAndReadoutWindows.md +++ /dev/null @@ -1,30 +0,0 @@ -## Reference information - -As of April 2026, here are the trigger sources used by the available regression tests: - -crtmodules/crt_reader_test.py -daqsystemtest/3ru_1df_multirun_test.py -daqsystemtest/3ru_3df_multirun_test.py -daqsystemtest/example_system_test.py -daqsystemtest/fake_data_producer_test.py -daqsystemtest/long_window_readout_test.py -daqsystemtest/minimal_system_quick_test.py -daqsystemtest/readout_type_scan_test.py -daqsystemtest/sample_ehn1_multihost_test.py -daqsystemtest/small_footprint_quick_test.py -daqsystemtest/tpg_state_collection_test.py -daqsystemtest/tpreplay_test.py -daqsystemtest/tpstream_writing_test.py -daqsystemtest/trigger_bitwords_test.py -dfmodules/disabled_output_test.py -dfmodules/hdf5_compression_test.py -dfmodules/insufficient_disk_space_test.py -dfmodules/large_trigger_record_test.py -dfmodules/max_file_size_test.py -dfmodules/multiple_data_writers_test.py -dfmodules/offline_prod_run_test.py -dfmodules/trmonrequestor_test.py -hsilibs/iceberg_real_hsi_test.py -listrev/listrev_test.py -snbmodules/simple_transform_test.py -trigger/change_rate_test.py