diff --git a/codeflash-java-runtime/src/main/java/com/codeflash/Comparator.java b/codeflash-java-runtime/src/main/java/com/codeflash/Comparator.java index 32d9f6034..5416da469 100644 --- a/codeflash-java-runtime/src/main/java/com/codeflash/Comparator.java +++ b/codeflash-java-runtime/src/main/java/com/codeflash/Comparator.java @@ -144,8 +144,11 @@ private static Map readTestResults(String dbPath) throws Excepti try (Connection conn = DriverManager.getConnection(url); Statement stmt = conn.createStatement(); ResultSet rs = stmt.executeQuery( - "SELECT iteration_id, return_value FROM test_results WHERE loop_index = 1")) { + "SELECT test_module_path, test_class_name, test_function_name, iteration_id, return_value FROM test_results WHERE loop_index = 1")) { while (rs.next()) { + String testModulePath = rs.getString("test_module_path"); + String testClassName = rs.getString("test_class_name"); + String testFunctionName = rs.getString("test_function_name"); String iterationId = rs.getString("iteration_id"); byte[] returnValue = rs.getBytes("return_value"); // Strip the CODEFLASH_TEST_ITERATION suffix (e.g. "7_0" -> "7") @@ -155,7 +158,10 @@ private static Map readTestResults(String dbPath) throws Excepti if (lastUnderscore > 0) { iterationId = iterationId.substring(0, lastUnderscore); } - results.put(iterationId, returnValue); + // Use module:class:function:iteration as key to uniquely identify + // each invocation across different test files, classes, and methods + String key = testModulePath + ":" + testClassName + ":" + testFunctionName + "::" + iterationId; + results.put(key, returnValue); } } return results; diff --git a/codeflash/languages/java/instrumentation.py b/codeflash/languages/java/instrumentation.py index 4a2a0e0a9..a881aa208 100644 --- a/codeflash/languages/java/instrumentation.py +++ b/codeflash/languages/java/instrumentation.py @@ -1073,7 +1073,7 @@ def build_instrumented_body( timing_lines = [ f"{indent}for (int _cf_i{current_id} = 0; _cf_i{current_id} < _cf_innerIterations{current_id}; _cf_i{current_id}++) {{", f"{inner_indent}int _cf_loopId{current_id} = _cf_outerLoop{current_id} * _cf_maxInnerIterations{current_id} + _cf_i{current_id};", - f'{inner_indent}System.out.println("!$######" + _cf_mod{current_id} + ":" + _cf_cls{current_id} + "." + _cf_test{current_id} + ":" + _cf_fn{current_id} + ":" + _cf_loopId{current_id} + ":" + _cf_i{current_id} + "######$!");', + f'{inner_indent}System.out.println("!$######" + _cf_mod{current_id} + ":" + _cf_cls{current_id} + "." + _cf_test{current_id} + ":" + _cf_fn{current_id} + ":" + _cf_loopId{current_id} + ":" + "{current_id}" + "######$!");', f"{inner_indent}long _cf_end{current_id} = -1;", f"{inner_indent}long _cf_start{current_id} = 0;", f"{inner_indent}try {{", @@ -1083,7 +1083,7 @@ def build_instrumented_body( f"{inner_indent}}} finally {{", f"{inner_body_indent}long _cf_end{current_id}_finally = System.nanoTime();", f"{inner_body_indent}long _cf_dur{current_id} = (_cf_end{current_id} != -1 ? _cf_end{current_id} : _cf_end{current_id}_finally) - _cf_start{current_id};", - f'{inner_body_indent}System.out.println("!######" + _cf_mod{current_id} + ":" + _cf_cls{current_id} + "." + _cf_test{current_id} + ":" + _cf_fn{current_id} + ":" + _cf_loopId{current_id} + ":" + _cf_i{current_id} + ":" + _cf_dur{current_id} + "######!");', + f'{inner_body_indent}System.out.println("!######" + _cf_mod{current_id} + ":" + _cf_cls{current_id} + "." + _cf_test{current_id} + ":" + _cf_fn{current_id} + ":" + _cf_loopId{current_id} + ":" + "{current_id}" + ":" + _cf_dur{current_id} + "######!");', f"{inner_indent}}}", f"{indent}}}", ] @@ -1140,7 +1140,7 @@ def build_instrumented_body( timing_lines = [ f"{indent}for (int _cf_i{current_id} = 0; _cf_i{current_id} < _cf_innerIterations{current_id}; _cf_i{current_id}++) {{", f"{inner_indent}int _cf_loopId{current_id} = _cf_outerLoop{current_id} * _cf_maxInnerIterations{current_id} + _cf_i{current_id};", - f'{inner_indent}System.out.println("!$######" + _cf_mod{current_id} + ":" + _cf_cls{current_id} + "." + _cf_test{current_id} + ":" + _cf_fn{current_id} + ":" + _cf_loopId{current_id} + ":{current_id}_" + _cf_i{current_id} + "######$!");', + f'{inner_indent}System.out.println("!$######" + _cf_mod{current_id} + ":" + _cf_cls{current_id} + "." + _cf_test{current_id} + ":" + _cf_fn{current_id} + ":" + _cf_loopId{current_id} + ":{current_id}" + "######$!");', f"{inner_indent}long _cf_end{current_id} = -1;", f"{inner_indent}long _cf_start{current_id} = 0;", f"{inner_indent}try {{", @@ -1150,7 +1150,7 @@ def build_instrumented_body( f"{inner_indent}}} finally {{", f"{inner_body_indent}long _cf_end{current_id}_finally = System.nanoTime();", f"{inner_body_indent}long _cf_dur{current_id} = (_cf_end{current_id} != -1 ? _cf_end{current_id} : _cf_end{current_id}_finally) - _cf_start{current_id};", - f'{inner_body_indent}System.out.println("!######" + _cf_mod{current_id} + ":" + _cf_cls{current_id} + "." + _cf_test{current_id} + ":" + _cf_fn{current_id} + ":" + _cf_loopId{current_id} + ":{current_id}_" + _cf_i{current_id} + ":" + _cf_dur{current_id} + "######!");', + f'{inner_body_indent}System.out.println("!######" + _cf_mod{current_id} + ":" + _cf_cls{current_id} + "." + _cf_test{current_id} + ":" + _cf_fn{current_id} + ":" + _cf_loopId{current_id} + ":{current_id}" + ":" + _cf_dur{current_id} + "######!");', f"{inner_indent}}}", f"{indent}}}", ] diff --git a/codeflash/languages/java/resources/codeflash-runtime-1.0.0.jar b/codeflash/languages/java/resources/codeflash-runtime-1.0.0.jar index 848663294..479982784 100644 Binary files a/codeflash/languages/java/resources/codeflash-runtime-1.0.0.jar and b/codeflash/languages/java/resources/codeflash-runtime-1.0.0.jar differ diff --git a/codeflash/languages/python/context/unused_definition_remover.py b/codeflash/languages/python/context/unused_definition_remover.py index e70dcad29..3101c97ee 100644 --- a/codeflash/languages/python/context/unused_definition_remover.py +++ b/codeflash/languages/python/context/unused_definition_remover.py @@ -748,7 +748,6 @@ def detect_unused_helper_functions( """ # Skip this analysis for non-Python languages since we use Python's ast module if not is_python(): - logger.debug("Skipping unused helper function detection for non-Python languages") return [] if isinstance(optimized_code, CodeStringsMarkdown) and len(optimized_code.code_strings) > 0: diff --git a/codeflash/verification/parse_test_output.py b/codeflash/verification/parse_test_output.py index deb7d3a4b..d44a347fc 100644 --- a/codeflash/verification/parse_test_output.py +++ b/codeflash/verification/parse_test_output.py @@ -605,23 +605,16 @@ def parse_sqlite_test_results(sqlite_file_path: Path, test_files: TestFiles, tes else: # Try original_file_path first (for existing tests that were instrumented) test_type = test_files.get_test_type_by_original_file_path(test_file_path) - logger.debug(f"[PARSE-DEBUG] test_module={test_module_path}, test_file_path={test_file_path}") - logger.debug(f"[PARSE-DEBUG] by_original_file_path: {test_type}") # If not found, try instrumented_behavior_file_path (for generated tests) if test_type is None: test_type = test_files.get_test_type_by_instrumented_file_path(test_file_path) - logger.debug(f"[PARSE-DEBUG] by_instrumented_file_path: {test_type}") # Default to GENERATED_REGRESSION for Jest/Java tests when test type can't be determined if test_type is None and (is_jest or is_java_test): test_type = TestType.GENERATED_REGRESSION - logger.debug( - f"[PARSE-DEBUG] defaulting to GENERATED_REGRESSION ({'Jest' if is_jest else 'Java'})" - ) elif test_type is None: # Skip results where test type cannot be determined logger.debug(f"Skipping result for {test_function_name}: could not determine test type") continue - logger.debug(f"[PARSE-DEBUG] FINAL test_type={test_type}") # Deserialize return value # For Jest/Java: Store as serialized JSON - comparison happens via language-specific comparator @@ -699,10 +692,6 @@ def parse_test_xml( return test_results # Always use tests_project_rootdir since pytest is now the test runner for all frameworks base_dir = test_config.tests_project_rootdir - logger.debug(f"[PARSE-XML] base_dir for resolution: {base_dir}") - logger.debug( - f"[PARSE-XML] Registered test files: {[str(tf.instrumented_behavior_file_path) for tf in test_files.test_files]}" - ) # For Java: pre-parse fallback stdout once (not per testcase) to avoid O(n²) complexity java_fallback_stdout = None @@ -763,13 +752,9 @@ def parse_test_xml( if test_file_name is None: if test_class_path: # TODO : This might not be true if the test is organized under a class - logger.debug(f"[PARSE-XML] Resolving test_class_path={test_class_path} in base_dir={base_dir}") test_file_path = resolve_test_file_from_class_path(test_class_path, base_dir) if test_file_path is None: - logger.error( - f"[PARSE-XML] ERROR: Could not resolve test_class_path={test_class_path}, base_dir={base_dir}" - ) logger.warning(f"Could not find the test for file name - {test_class_path} ") continue else: @@ -782,15 +767,11 @@ def parse_test_xml( logger.warning(f"Could not find the test for file name - {test_file_path} ") continue # Try to match by instrumented file path first (for generated/instrumented tests) - logger.debug(f"[PARSE-XML] Looking up test_type by instrumented_file_path: {test_file_path}") test_type = test_files.get_test_type_by_instrumented_file_path(test_file_path) - logger.debug(f"[PARSE-XML] Lookup by instrumented path result: {test_type}") if test_type is None: # Fallback: try to match by original file path (for existing unit tests that were instrumented) # JUnit XML may reference the original class name, resolving to the original file path - logger.debug(f"[PARSE-XML] Looking up test_type by original_file_path: {test_file_path}") test_type = test_files.get_test_type_by_original_file_path(test_file_path) - logger.debug(f"[PARSE-XML] Lookup by original path result: {test_type}") if test_type is None: # Log registered paths for debugging registered_paths = [str(tf.instrumented_behavior_file_path) for tf in test_files.test_files] diff --git a/tests/test_languages/test_java/test_instrumentation.py b/tests/test_languages/test_java/test_instrumentation.py index 34d6da567..e0d6de086 100644 --- a/tests/test_languages/test_java/test_instrumentation.py +++ b/tests/test_languages/test_java/test_instrumentation.py @@ -504,7 +504,7 @@ def test_instrument_performance_mode_simple(self, tmp_path: Path): Calculator calc = new Calculator(); for (int _cf_i1 = 0; _cf_i1 < _cf_innerIterations1; _cf_i1++) { int _cf_loopId1 = _cf_outerLoop1 * _cf_maxInnerIterations1 + _cf_i1; - System.out.println("!$######" + _cf_mod1 + ":" + _cf_cls1 + "." + _cf_test1 + ":" + _cf_fn1 + ":" + _cf_loopId1 + ":" + _cf_i1 + "######$!"); + System.out.println("!$######" + _cf_mod1 + ":" + _cf_cls1 + "." + _cf_test1 + ":" + _cf_fn1 + ":" + _cf_loopId1 + ":" + "1" + "######$!"); long _cf_end1 = -1; long _cf_start1 = 0; try { @@ -514,7 +514,7 @@ def test_instrument_performance_mode_simple(self, tmp_path: Path): } finally { long _cf_end1_finally = System.nanoTime(); long _cf_dur1 = (_cf_end1 != -1 ? _cf_end1 : _cf_end1_finally) - _cf_start1; - System.out.println("!######" + _cf_mod1 + ":" + _cf_cls1 + "." + _cf_test1 + ":" + _cf_fn1 + ":" + _cf_loopId1 + ":" + _cf_i1 + ":" + _cf_dur1 + "######!"); + System.out.println("!######" + _cf_mod1 + ":" + _cf_cls1 + "." + _cf_test1 + ":" + _cf_fn1 + ":" + _cf_loopId1 + ":" + "1" + ":" + _cf_dur1 + "######!"); } } } @@ -575,7 +575,7 @@ def test_instrument_performance_mode_multiple_tests(self, tmp_path: Path): for (int _cf_i1 = 0; _cf_i1 < _cf_innerIterations1; _cf_i1++) { int _cf_loopId1 = _cf_outerLoop1 * _cf_maxInnerIterations1 + _cf_i1; - System.out.println("!$######" + _cf_mod1 + ":" + _cf_cls1 + "." + _cf_test1 + ":" + _cf_fn1 + ":" + _cf_loopId1 + ":" + _cf_i1 + "######$!"); + System.out.println("!$######" + _cf_mod1 + ":" + _cf_cls1 + "." + _cf_test1 + ":" + _cf_fn1 + ":" + _cf_loopId1 + ":" + "1" + "######$!"); long _cf_end1 = -1; long _cf_start1 = 0; try { @@ -585,7 +585,7 @@ def test_instrument_performance_mode_multiple_tests(self, tmp_path: Path): } finally { long _cf_end1_finally = System.nanoTime(); long _cf_dur1 = (_cf_end1 != -1 ? _cf_end1 : _cf_end1_finally) - _cf_start1; - System.out.println("!######" + _cf_mod1 + ":" + _cf_cls1 + "." + _cf_test1 + ":" + _cf_fn1 + ":" + _cf_loopId1 + ":" + _cf_i1 + ":" + _cf_dur1 + "######!"); + System.out.println("!######" + _cf_mod1 + ":" + _cf_cls1 + "." + _cf_test1 + ":" + _cf_fn1 + ":" + _cf_loopId1 + ":" + "1" + ":" + _cf_dur1 + "######!"); } } } @@ -603,7 +603,7 @@ def test_instrument_performance_mode_multiple_tests(self, tmp_path: Path): for (int _cf_i2 = 0; _cf_i2 < _cf_innerIterations2; _cf_i2++) { int _cf_loopId2 = _cf_outerLoop2 * _cf_maxInnerIterations2 + _cf_i2; - System.out.println("!$######" + _cf_mod2 + ":" + _cf_cls2 + "." + _cf_test2 + ":" + _cf_fn2 + ":" + _cf_loopId2 + ":" + _cf_i2 + "######$!"); + System.out.println("!$######" + _cf_mod2 + ":" + _cf_cls2 + "." + _cf_test2 + ":" + _cf_fn2 + ":" + _cf_loopId2 + ":" + "2" + "######$!"); long _cf_end2 = -1; long _cf_start2 = 0; try { @@ -613,7 +613,7 @@ def test_instrument_performance_mode_multiple_tests(self, tmp_path: Path): } finally { long _cf_end2_finally = System.nanoTime(); long _cf_dur2 = (_cf_end2 != -1 ? _cf_end2 : _cf_end2_finally) - _cf_start2; - System.out.println("!######" + _cf_mod2 + ":" + _cf_cls2 + "." + _cf_test2 + ":" + _cf_fn2 + ":" + _cf_loopId2 + ":" + _cf_i2 + ":" + _cf_dur2 + "######!"); + System.out.println("!######" + _cf_mod2 + ":" + _cf_cls2 + "." + _cf_test2 + ":" + _cf_fn2 + ":" + _cf_loopId2 + ":" + "2" + ":" + _cf_dur2 + "######!"); } } } @@ -681,7 +681,7 @@ def test_instrument_preserves_annotations(self, tmp_path: Path): for (int _cf_i1 = 0; _cf_i1 < _cf_innerIterations1; _cf_i1++) { int _cf_loopId1 = _cf_outerLoop1 * _cf_maxInnerIterations1 + _cf_i1; - System.out.println("!$######" + _cf_mod1 + ":" + _cf_cls1 + "." + _cf_test1 + ":" + _cf_fn1 + ":" + _cf_loopId1 + ":" + _cf_i1 + "######$!"); + System.out.println("!$######" + _cf_mod1 + ":" + _cf_cls1 + "." + _cf_test1 + ":" + _cf_fn1 + ":" + _cf_loopId1 + ":" + "1" + "######$!"); long _cf_end1 = -1; long _cf_start1 = 0; try { @@ -691,7 +691,7 @@ def test_instrument_preserves_annotations(self, tmp_path: Path): } finally { long _cf_end1_finally = System.nanoTime(); long _cf_dur1 = (_cf_end1 != -1 ? _cf_end1 : _cf_end1_finally) - _cf_start1; - System.out.println("!######" + _cf_mod1 + ":" + _cf_cls1 + "." + _cf_test1 + ":" + _cf_fn1 + ":" + _cf_loopId1 + ":" + _cf_i1 + ":" + _cf_dur1 + "######!"); + System.out.println("!######" + _cf_mod1 + ":" + _cf_cls1 + "." + _cf_test1 + ":" + _cf_fn1 + ":" + _cf_loopId1 + ":" + "1" + ":" + _cf_dur1 + "######!"); } } } @@ -823,7 +823,7 @@ class TestKryoSerializerUsage: for (int _cf_i1 = 0; _cf_i1 < _cf_innerIterations1; _cf_i1++) { int _cf_loopId1 = _cf_outerLoop1 * _cf_maxInnerIterations1 + _cf_i1; - System.out.println("!$######" + _cf_mod1 + ":" + _cf_cls1 + "." + _cf_test1 + ":" + _cf_fn1 + ":" + _cf_loopId1 + ":" + _cf_i1 + "######$!"); + System.out.println("!$######" + _cf_mod1 + ":" + _cf_cls1 + "." + _cf_test1 + ":" + _cf_fn1 + ":" + _cf_loopId1 + ":" + "1" + "######$!"); long _cf_end1 = -1; long _cf_start1 = 0; try { @@ -833,7 +833,7 @@ class TestKryoSerializerUsage: } finally { long _cf_end1_finally = System.nanoTime(); long _cf_dur1 = (_cf_end1 != -1 ? _cf_end1 : _cf_end1_finally) - _cf_start1; - System.out.println("!######" + _cf_mod1 + ":" + _cf_cls1 + "." + _cf_test1 + ":" + _cf_fn1 + ":" + _cf_loopId1 + ":" + _cf_i1 + ":" + _cf_dur1 + "######!"); + System.out.println("!######" + _cf_mod1 + ":" + _cf_cls1 + "." + _cf_test1 + ":" + _cf_fn1 + ":" + _cf_loopId1 + ":" + "1" + ":" + _cf_dur1 + "######!"); } } } @@ -899,7 +899,7 @@ def test_single_test_method(self): for (int _cf_i1 = 0; _cf_i1 < _cf_innerIterations1; _cf_i1++) { int _cf_loopId1 = _cf_outerLoop1 * _cf_maxInnerIterations1 + _cf_i1; - System.out.println("!$######" + _cf_mod1 + ":" + _cf_cls1 + "." + _cf_test1 + ":" + _cf_fn1 + ":" + _cf_loopId1 + ":" + _cf_i1 + "######$!"); + System.out.println("!$######" + _cf_mod1 + ":" + _cf_cls1 + "." + _cf_test1 + ":" + _cf_fn1 + ":" + _cf_loopId1 + ":" + "1" + "######$!"); long _cf_end1 = -1; long _cf_start1 = 0; try { @@ -909,7 +909,7 @@ def test_single_test_method(self): } finally { long _cf_end1_finally = System.nanoTime(); long _cf_dur1 = (_cf_end1 != -1 ? _cf_end1 : _cf_end1_finally) - _cf_start1; - System.out.println("!######" + _cf_mod1 + ":" + _cf_cls1 + "." + _cf_test1 + ":" + _cf_fn1 + ":" + _cf_loopId1 + ":" + _cf_i1 + ":" + _cf_dur1 + "######!"); + System.out.println("!######" + _cf_mod1 + ":" + _cf_cls1 + "." + _cf_test1 + ":" + _cf_fn1 + ":" + _cf_loopId1 + ":" + "1" + ":" + _cf_dur1 + "######!"); } } } @@ -948,7 +948,7 @@ def test_multiple_test_methods(self): for (int _cf_i1 = 0; _cf_i1 < _cf_innerIterations1; _cf_i1++) { int _cf_loopId1 = _cf_outerLoop1 * _cf_maxInnerIterations1 + _cf_i1; - System.out.println("!$######" + _cf_mod1 + ":" + _cf_cls1 + "." + _cf_test1 + ":" + _cf_fn1 + ":" + _cf_loopId1 + ":" + _cf_i1 + "######$!"); + System.out.println("!$######" + _cf_mod1 + ":" + _cf_cls1 + "." + _cf_test1 + ":" + _cf_fn1 + ":" + _cf_loopId1 + ":" + "1" + "######$!"); long _cf_end1 = -1; long _cf_start1 = 0; try { @@ -958,7 +958,7 @@ def test_multiple_test_methods(self): } finally { long _cf_end1_finally = System.nanoTime(); long _cf_dur1 = (_cf_end1 != -1 ? _cf_end1 : _cf_end1_finally) - _cf_start1; - System.out.println("!######" + _cf_mod1 + ":" + _cf_cls1 + "." + _cf_test1 + ":" + _cf_fn1 + ":" + _cf_loopId1 + ":" + _cf_i1 + ":" + _cf_dur1 + "######!"); + System.out.println("!######" + _cf_mod1 + ":" + _cf_cls1 + "." + _cf_test1 + ":" + _cf_fn1 + ":" + _cf_loopId1 + ":" + "1" + ":" + _cf_dur1 + "######!"); } } } @@ -977,7 +977,7 @@ def test_multiple_test_methods(self): second(); for (int _cf_i2 = 0; _cf_i2 < _cf_innerIterations2; _cf_i2++) { int _cf_loopId2 = _cf_outerLoop2 * _cf_maxInnerIterations2 + _cf_i2; - System.out.println("!$######" + _cf_mod2 + ":" + _cf_cls2 + "." + _cf_test2 + ":" + _cf_fn2 + ":" + _cf_loopId2 + ":" + _cf_i2 + "######$!"); + System.out.println("!$######" + _cf_mod2 + ":" + _cf_cls2 + "." + _cf_test2 + ":" + _cf_fn2 + ":" + _cf_loopId2 + ":" + "2" + "######$!"); long _cf_end2 = -1; long _cf_start2 = 0; try { @@ -987,7 +987,7 @@ def test_multiple_test_methods(self): } finally { long _cf_end2_finally = System.nanoTime(); long _cf_dur2 = (_cf_end2 != -1 ? _cf_end2 : _cf_end2_finally) - _cf_start2; - System.out.println("!######" + _cf_mod2 + ":" + _cf_cls2 + "." + _cf_test2 + ":" + _cf_fn2 + ":" + _cf_loopId2 + ":" + _cf_i2 + ":" + _cf_dur2 + "######!"); + System.out.println("!######" + _cf_mod2 + ":" + _cf_cls2 + "." + _cf_test2 + ":" + _cf_fn2 + ":" + _cf_loopId2 + ":" + "2" + ":" + _cf_dur2 + "######!"); } } } @@ -1039,7 +1039,7 @@ def test_multiple_target_calls_in_single_test_method(self): String _cf_fn1 = "target"; for (int _cf_i1 = 0; _cf_i1 < _cf_innerIterations1; _cf_i1++) { int _cf_loopId1 = _cf_outerLoop1 * _cf_maxInnerIterations1 + _cf_i1; - System.out.println("!$######" + _cf_mod1 + ":" + _cf_cls1 + "." + _cf_test1 + ":" + _cf_fn1 + ":" + _cf_loopId1 + ":1_" + _cf_i1 + "######$!"); + System.out.println("!$######" + _cf_mod1 + ":" + _cf_cls1 + "." + _cf_test1 + ":" + _cf_fn1 + ":" + _cf_loopId1 + ":1" + "######$!"); long _cf_end1 = -1; long _cf_start1 = 0; try { @@ -1049,7 +1049,7 @@ def test_multiple_target_calls_in_single_test_method(self): } finally { long _cf_end1_finally = System.nanoTime(); long _cf_dur1 = (_cf_end1 != -1 ? _cf_end1 : _cf_end1_finally) - _cf_start1; - System.out.println("!######" + _cf_mod1 + ":" + _cf_cls1 + "." + _cf_test1 + ":" + _cf_fn1 + ":" + _cf_loopId1 + ":1_" + _cf_i1 + ":" + _cf_dur1 + "######!"); + System.out.println("!######" + _cf_mod1 + ":" + _cf_cls1 + "." + _cf_test1 + ":" + _cf_fn1 + ":" + _cf_loopId1 + ":1" + ":" + _cf_dur1 + "######!"); } } helper(); @@ -1064,7 +1064,7 @@ def test_multiple_target_calls_in_single_test_method(self): String _cf_fn2 = "target"; for (int _cf_i2 = 0; _cf_i2 < _cf_innerIterations2; _cf_i2++) { int _cf_loopId2 = _cf_outerLoop2 * _cf_maxInnerIterations2 + _cf_i2; - System.out.println("!$######" + _cf_mod2 + ":" + _cf_cls2 + "." + _cf_test2 + ":" + _cf_fn2 + ":" + _cf_loopId2 + ":2_" + _cf_i2 + "######$!"); + System.out.println("!$######" + _cf_mod2 + ":" + _cf_cls2 + "." + _cf_test2 + ":" + _cf_fn2 + ":" + _cf_loopId2 + ":2" + "######$!"); long _cf_end2 = -1; long _cf_start2 = 0; try { @@ -1074,7 +1074,7 @@ def test_multiple_target_calls_in_single_test_method(self): } finally { long _cf_end2_finally = System.nanoTime(); long _cf_dur2 = (_cf_end2 != -1 ? _cf_end2 : _cf_end2_finally) - _cf_start2; - System.out.println("!######" + _cf_mod2 + ":" + _cf_cls2 + "." + _cf_test2 + ":" + _cf_fn2 + ":" + _cf_loopId2 + ":2_" + _cf_i2 + ":" + _cf_dur2 + "######!"); + System.out.println("!######" + _cf_mod2 + ":" + _cf_cls2 + "." + _cf_test2 + ":" + _cf_fn2 + ":" + _cf_loopId2 + ":2" + ":" + _cf_dur2 + "######!"); } } teardown(); @@ -1374,7 +1374,7 @@ def test_instrument_generated_test_performance_mode(self): for (int _cf_i1 = 0; _cf_i1 < _cf_innerIterations1; _cf_i1++) { int _cf_loopId1 = _cf_outerLoop1 * _cf_maxInnerIterations1 + _cf_i1; - System.out.println("!$######" + _cf_mod1 + ":" + _cf_cls1 + "." + _cf_test1 + ":" + _cf_fn1 + ":" + _cf_loopId1 + ":" + _cf_i1 + "######$!"); + System.out.println("!$######" + _cf_mod1 + ":" + _cf_cls1 + "." + _cf_test1 + ":" + _cf_fn1 + ":" + _cf_loopId1 + ":" + "1" + "######$!"); long _cf_end1 = -1; long _cf_start1 = 0; try { @@ -1384,7 +1384,7 @@ def test_instrument_generated_test_performance_mode(self): } finally { long _cf_end1_finally = System.nanoTime(); long _cf_dur1 = (_cf_end1 != -1 ? _cf_end1 : _cf_end1_finally) - _cf_start1; - System.out.println("!######" + _cf_mod1 + ":" + _cf_cls1 + "." + _cf_test1 + ":" + _cf_fn1 + ":" + _cf_loopId1 + ":" + _cf_i1 + ":" + _cf_dur1 + "######!"); + System.out.println("!######" + _cf_mod1 + ":" + _cf_cls1 + "." + _cf_test1 + ":" + _cf_fn1 + ":" + _cf_loopId1 + ":" + "1" + ":" + _cf_dur1 + "######!"); } } } @@ -1561,7 +1561,7 @@ def test_instrumented_code_has_balanced_braces(self, tmp_path: Path): for (int _cf_i2 = 0; _cf_i2 < _cf_innerIterations2; _cf_i2++) { int _cf_loopId2 = _cf_outerLoop2 * _cf_maxInnerIterations2 + _cf_i2; - System.out.println("!$######" + _cf_mod2 + ":" + _cf_cls2 + "." + _cf_test2 + ":" + _cf_fn2 + ":" + _cf_loopId2 + ":" + _cf_i2 + "######$!"); + System.out.println("!$######" + _cf_mod2 + ":" + _cf_cls2 + "." + _cf_test2 + ":" + _cf_fn2 + ":" + _cf_loopId2 + ":" + "2" + "######$!"); long _cf_end2 = -1; long _cf_start2 = 0; try { @@ -1573,7 +1573,7 @@ def test_instrumented_code_has_balanced_braces(self, tmp_path: Path): } finally { long _cf_end2_finally = System.nanoTime(); long _cf_dur2 = (_cf_end2 != -1 ? _cf_end2 : _cf_end2_finally) - _cf_start2; - System.out.println("!######" + _cf_mod2 + ":" + _cf_cls2 + "." + _cf_test2 + ":" + _cf_fn2 + ":" + _cf_loopId2 + ":" + _cf_i2 + ":" + _cf_dur2 + "######!"); + System.out.println("!######" + _cf_mod2 + ":" + _cf_cls2 + "." + _cf_test2 + ":" + _cf_fn2 + ":" + _cf_loopId2 + ":" + "2" + ":" + _cf_dur2 + "######!"); } } } @@ -1641,7 +1641,7 @@ def test_instrumented_code_preserves_imports(self, tmp_path: Path): List list = new ArrayList<>(); for (int _cf_i1 = 0; _cf_i1 < _cf_innerIterations1; _cf_i1++) { int _cf_loopId1 = _cf_outerLoop1 * _cf_maxInnerIterations1 + _cf_i1; - System.out.println("!$######" + _cf_mod1 + ":" + _cf_cls1 + "." + _cf_test1 + ":" + _cf_fn1 + ":" + _cf_loopId1 + ":" + _cf_i1 + "######$!"); + System.out.println("!$######" + _cf_mod1 + ":" + _cf_cls1 + "." + _cf_test1 + ":" + _cf_fn1 + ":" + _cf_loopId1 + ":" + "1" + "######$!"); long _cf_end1 = -1; long _cf_start1 = 0; try { @@ -1651,7 +1651,7 @@ def test_instrumented_code_preserves_imports(self, tmp_path: Path): } finally { long _cf_end1_finally = System.nanoTime(); long _cf_dur1 = (_cf_end1 != -1 ? _cf_end1 : _cf_end1_finally) - _cf_start1; - System.out.println("!######" + _cf_mod1 + ":" + _cf_cls1 + "." + _cf_test1 + ":" + _cf_fn1 + ":" + _cf_loopId1 + ":" + _cf_i1 + ":" + _cf_dur1 + "######!"); + System.out.println("!######" + _cf_mod1 + ":" + _cf_cls1 + "." + _cf_test1 + ":" + _cf_fn1 + ":" + _cf_loopId1 + ":" + "1" + ":" + _cf_dur1 + "######!"); } } } @@ -1758,7 +1758,7 @@ def test_test_with_nested_braces(self, tmp_path: Path): for (int _cf_i1 = 0; _cf_i1 < _cf_innerIterations1; _cf_i1++) { int _cf_loopId1 = _cf_outerLoop1 * _cf_maxInnerIterations1 + _cf_i1; - System.out.println("!$######" + _cf_mod1 + ":" + _cf_cls1 + "." + _cf_test1 + ":" + _cf_fn1 + ":" + _cf_loopId1 + ":" + _cf_i1 + "######$!"); + System.out.println("!$######" + _cf_mod1 + ":" + _cf_cls1 + "." + _cf_test1 + ":" + _cf_fn1 + ":" + _cf_loopId1 + ":" + "1" + "######$!"); long _cf_end1 = -1; long _cf_start1 = 0; try { @@ -1774,7 +1774,7 @@ def test_test_with_nested_braces(self, tmp_path: Path): } finally { long _cf_end1_finally = System.nanoTime(); long _cf_dur1 = (_cf_end1 != -1 ? _cf_end1 : _cf_end1_finally) - _cf_start1; - System.out.println("!######" + _cf_mod1 + ":" + _cf_cls1 + "." + _cf_test1 + ":" + _cf_fn1 + ":" + _cf_loopId1 + ":" + _cf_i1 + ":" + _cf_dur1 + "######!"); + System.out.println("!######" + _cf_mod1 + ":" + _cf_cls1 + "." + _cf_test1 + ":" + _cf_fn1 + ":" + _cf_loopId1 + ":" + "1" + ":" + _cf_dur1 + "######!"); } } } @@ -1908,7 +1908,7 @@ def test_instrument_with_cjk_in_string_literal(self, tmp_path: Path): ' String label = "\u30c6\u30b9\u30c8\u540d\u524d";\n' ' for (int _cf_i1 = 0; _cf_i1 < _cf_innerIterations1; _cf_i1++) {\n' ' int _cf_loopId1 = _cf_outerLoop1 * _cf_maxInnerIterations1 + _cf_i1;\n' - ' System.out.println("!$######" + _cf_mod1 + ":" + _cf_cls1 + "." + _cf_test1 + ":" + _cf_fn1 + ":" + _cf_loopId1 + ":" + _cf_i1 + "######$!");\n' + ' System.out.println("!$######" + _cf_mod1 + ":" + _cf_cls1 + "." + _cf_test1 + ":" + _cf_fn1 + ":" + _cf_loopId1 + ":" + "1" + "######$!");\n' ' long _cf_end1 = -1;\n' ' long _cf_start1 = 0;\n' ' try {\n' @@ -1918,7 +1918,7 @@ def test_instrument_with_cjk_in_string_literal(self, tmp_path: Path): ' } finally {\n' ' long _cf_end1_finally = System.nanoTime();\n' ' long _cf_dur1 = (_cf_end1 != -1 ? _cf_end1 : _cf_end1_finally) - _cf_start1;\n' - ' System.out.println("!######" + _cf_mod1 + ":" + _cf_cls1 + "." + _cf_test1 + ":" + _cf_fn1 + ":" + _cf_loopId1 + ":" + _cf_i1 + ":" + _cf_dur1 + "######!");\n' + ' System.out.println("!######" + _cf_mod1 + ":" + _cf_cls1 + "." + _cf_test1 + ":" + _cf_fn1 + ":" + _cf_loopId1 + ":" + "1" + ":" + _cf_dur1 + "######!");\n' ' }\n' ' }\n' ' }\n' @@ -1983,7 +1983,7 @@ def test_instrument_with_multibyte_in_comment(self, tmp_path: Path): ' String name = "caf\u00e9";\n' ' for (int _cf_i1 = 0; _cf_i1 < _cf_innerIterations1; _cf_i1++) {\n' ' int _cf_loopId1 = _cf_outerLoop1 * _cf_maxInnerIterations1 + _cf_i1;\n' - ' System.out.println("!$######" + _cf_mod1 + ":" + _cf_cls1 + "." + _cf_test1 + ":" + _cf_fn1 + ":" + _cf_loopId1 + ":" + _cf_i1 + "######$!");\n' + ' System.out.println("!$######" + _cf_mod1 + ":" + _cf_cls1 + "." + _cf_test1 + ":" + _cf_fn1 + ":" + _cf_loopId1 + ":" + "1" + "######$!");\n' ' long _cf_end1 = -1;\n' ' long _cf_start1 = 0;\n' ' try {\n' @@ -1993,7 +1993,7 @@ def test_instrument_with_multibyte_in_comment(self, tmp_path: Path): ' } finally {\n' ' long _cf_end1_finally = System.nanoTime();\n' ' long _cf_dur1 = (_cf_end1 != -1 ? _cf_end1 : _cf_end1_finally) - _cf_start1;\n' - ' System.out.println("!######" + _cf_mod1 + ":" + _cf_cls1 + "." + _cf_test1 + ":" + _cf_fn1 + ":" + _cf_loopId1 + ":" + _cf_i1 + ":" + _cf_dur1 + "######!");\n' + ' System.out.println("!######" + _cf_mod1 + ":" + _cf_cls1 + "." + _cf_test1 + ":" + _cf_fn1 + ":" + _cf_loopId1 + ":" + "1" + ":" + _cf_dur1 + "######!");\n' ' }\n' ' }\n' ' }\n' @@ -2280,7 +2280,7 @@ def test_run_and_parse_performance_mode(self, java_project): MathUtils math = new MathUtils(); for (int _cf_i1 = 0; _cf_i1 < _cf_innerIterations1; _cf_i1++) { int _cf_loopId1 = _cf_outerLoop1 * _cf_maxInnerIterations1 + _cf_i1; - System.out.println("!$######" + _cf_mod1 + ":" + _cf_cls1 + "." + _cf_test1 + ":" + _cf_fn1 + ":" + _cf_loopId1 + ":" + _cf_i1 + "######$!"); + System.out.println("!$######" + _cf_mod1 + ":" + _cf_cls1 + "." + _cf_test1 + ":" + _cf_fn1 + ":" + _cf_loopId1 + ":" + "1" + "######$!"); long _cf_end1 = -1; long _cf_start1 = 0; try { @@ -2290,7 +2290,7 @@ def test_run_and_parse_performance_mode(self, java_project): } finally { long _cf_end1_finally = System.nanoTime(); long _cf_dur1 = (_cf_end1 != -1 ? _cf_end1 : _cf_end1_finally) - _cf_start1; - System.out.println("!######" + _cf_mod1 + ":" + _cf_cls1 + "." + _cf_test1 + ":" + _cf_fn1 + ":" + _cf_loopId1 + ":" + _cf_i1 + ":" + _cf_dur1 + "######!"); + System.out.println("!######" + _cf_mod1 + ":" + _cf_cls1 + "." + _cf_test1 + ":" + _cf_fn1 + ":" + _cf_loopId1 + ":" + "1" + ":" + _cf_dur1 + "######!"); } } } @@ -2882,7 +2882,7 @@ def test_performance_mode_inner_loop_timing_markers(self, java_project): Fibonacci fib = new Fibonacci(); for (int _cf_i1 = 0; _cf_i1 < _cf_innerIterations1; _cf_i1++) { int _cf_loopId1 = _cf_outerLoop1 * _cf_maxInnerIterations1 + _cf_i1; - System.out.println("!$######" + _cf_mod1 + ":" + _cf_cls1 + "." + _cf_test1 + ":" + _cf_fn1 + ":" + _cf_loopId1 + ":" + _cf_i1 + "######$!"); + System.out.println("!$######" + _cf_mod1 + ":" + _cf_cls1 + "." + _cf_test1 + ":" + _cf_fn1 + ":" + _cf_loopId1 + ":" + "1" + "######$!"); long _cf_end1 = -1; long _cf_start1 = 0; try { @@ -2892,7 +2892,7 @@ def test_performance_mode_inner_loop_timing_markers(self, java_project): } finally { long _cf_end1_finally = System.nanoTime(); long _cf_dur1 = (_cf_end1 != -1 ? _cf_end1 : _cf_end1_finally) - _cf_start1; - System.out.println("!######" + _cf_mod1 + ":" + _cf_cls1 + "." + _cf_test1 + ":" + _cf_fn1 + ":" + _cf_loopId1 + ":" + _cf_i1 + ":" + _cf_dur1 + "######!"); + System.out.println("!######" + _cf_mod1 + ":" + _cf_cls1 + "." + _cf_test1 + ":" + _cf_fn1 + ":" + _cf_loopId1 + ":" + "1" + ":" + _cf_dur1 + "######!"); } } } @@ -2945,9 +2945,9 @@ def __init__(self, path): assert len(start_matches) == 2, f"Expected 2 start markers, got {len(start_matches)}: {start_matches}" assert len(end_matches) == 2, f"Expected 2 end markers, got {len(end_matches)}: {end_matches}" - # Verify invocation IDs are 0 and 1 (2 inner iterations, single call in test) + # Verify invocation IDs are constant (wrapper ID) across all inner iterations invocation_ids = [m[4] for m in start_matches] - assert set(invocation_ids) == {"0", "1"}, f"Expected invocation IDs 0 and 1, got: {invocation_ids}" + assert all(id == invocation_ids[0] for id in invocation_ids), f"Expected constant invocation IDs, got: {invocation_ids}" # Verify loop IDs are 2 and 3 (outerLoop=1, maxInner=2, inner=0,1 → 1*2+0=2, 1*2+1=3) loop_ids = [m[3] for m in start_matches] @@ -3153,7 +3153,7 @@ def test_time_correction_instrumentation(self, java_project): for (int _cf_i1 = 0; _cf_i1 < _cf_innerIterations1; _cf_i1++) { int _cf_loopId1 = _cf_outerLoop1 * _cf_maxInnerIterations1 + _cf_i1; - System.out.println("!$######" + _cf_mod1 + ":" + _cf_cls1 + "." + _cf_test1 + ":" + _cf_fn1 + ":" + _cf_loopId1 + ":" + _cf_i1 + "######$!"); + System.out.println("!$######" + _cf_mod1 + ":" + _cf_cls1 + "." + _cf_test1 + ":" + _cf_fn1 + ":" + _cf_loopId1 + ":" + "1" + "######$!"); long _cf_end1 = -1; long _cf_start1 = 0; try { @@ -3163,7 +3163,7 @@ def test_time_correction_instrumentation(self, java_project): } finally { long _cf_end1_finally = System.nanoTime(); long _cf_dur1 = (_cf_end1 != -1 ? _cf_end1 : _cf_end1_finally) - _cf_start1; - System.out.println("!######" + _cf_mod1 + ":" + _cf_cls1 + "." + _cf_test1 + ":" + _cf_fn1 + ":" + _cf_loopId1 + ":" + _cf_i1 + ":" + _cf_dur1 + "######!"); + System.out.println("!######" + _cf_mod1 + ":" + _cf_cls1 + "." + _cf_test1 + ":" + _cf_fn1 + ":" + _cf_loopId1 + ":" + "1" + ":" + _cf_dur1 + "######!"); } } } @@ -3181,7 +3181,7 @@ def test_time_correction_instrumentation(self, java_project): for (int _cf_i2 = 0; _cf_i2 < _cf_innerIterations2; _cf_i2++) { int _cf_loopId2 = _cf_outerLoop2 * _cf_maxInnerIterations2 + _cf_i2; - System.out.println("!$######" + _cf_mod2 + ":" + _cf_cls2 + "." + _cf_test2 + ":" + _cf_fn2 + ":" + _cf_loopId2 + ":" + _cf_i2 + "######$!"); + System.out.println("!$######" + _cf_mod2 + ":" + _cf_cls2 + "." + _cf_test2 + ":" + _cf_fn2 + ":" + _cf_loopId2 + ":" + "2" + "######$!"); long _cf_end2 = -1; long _cf_start2 = 0; try { @@ -3191,7 +3191,7 @@ def test_time_correction_instrumentation(self, java_project): } finally { long _cf_end2_finally = System.nanoTime(); long _cf_dur2 = (_cf_end2 != -1 ? _cf_end2 : _cf_end2_finally) - _cf_start2; - System.out.println("!######" + _cf_mod2 + ":" + _cf_cls2 + "." + _cf_test2 + ":" + _cf_fn2 + ":" + _cf_loopId2 + ":" + _cf_i2 + ":" + _cf_dur2 + "######!"); + System.out.println("!######" + _cf_mod2 + ":" + _cf_cls2 + "." + _cf_test2 + ":" + _cf_fn2 + ":" + _cf_loopId2 + ":" + "2" + ":" + _cf_dur2 + "######!"); } } } diff --git a/tests/test_languages/test_java/test_run_and_parse.py b/tests/test_languages/test_java/test_run_and_parse.py index 67c03b8da..35c644a48 100644 --- a/tests/test_languages/test_java/test_run_and_parse.py +++ b/tests/test_languages/test_java/test_run_and_parse.py @@ -537,29 +537,28 @@ def test_performance_inner_loop_count_and_timing(self, java_project): ) # Verify total_passed_runtime sums minimum runtime per test case - # InvocationId includes iteration_id, so each inner iteration is a separate "test case" - # With 2 inner iterations: 2 test cases (iteration_id=0 and iteration_id=1) - # total = min(outer loop runtimes for iter 0) + min(outer loop runtimes for iter 1) ≈ 20ms + # iteration_id is now constant (wrapper ID) across inner iterations, + # so all 4 runtimes (2 outer × 2 inner) group under 1 InvocationId key total_runtime = test_results.total_passed_runtime() runtime_by_test = test_results.usable_runtime_data_by_test_case() - # Should have 2 test cases (one per inner iteration) - assert len(runtime_by_test) == 2, ( - f"Expected 2 test cases (iteration_id=0 and 1), got {len(runtime_by_test)}" + # Should have 1 test case (constant iteration_id per call site) + assert len(runtime_by_test) == 1, ( + f"Expected 1 test case (constant iteration_id), got {len(runtime_by_test)}" ) - # Each test case should have 2 runtimes (2 outer loops) + # The single test case should have 4 runtimes (2 outer loops × 2 inner iterations) for test_id, test_runtimes in runtime_by_test.items(): - assert len(test_runtimes) == 2, ( - f"Expected 2 runtimes (2 outer loops) for {test_id.iteration_id}, got {len(test_runtimes)}" + assert len(test_runtimes) == 4, ( + f"Expected 4 runtimes (2 outer × 2 inner) for {test_id.iteration_id}, got {len(test_runtimes)}" ) - # Total should be sum of 2 minimums (one per inner iteration) ≈ 20ms + # Total should be min of all runtimes ≈ 10ms # Minimums filter out JIT warmup, so use tighter ±3% tolerance - expected_total_ns = 2 * expected_ns + expected_total_ns = expected_ns assert expected_total_ns * 0.97 <= total_runtime <= expected_total_ns * 1.03, ( f"total_passed_runtime {total_runtime / 1_000_000:.3f}ms not close to expected " - f"{expected_total_ns / 1_000_000:.1f}ms (2 inner iterations × 10ms each, ±3%)" + f"{expected_total_ns / 1_000_000:.1f}ms (min of 4 runtimes × 10ms each, ±3%)" ) def test_performance_multiple_test_methods_inner_loop(self, java_project): @@ -630,27 +629,27 @@ def test_performance_multiple_test_methods_inner_loop(self, java_project): ) # Verify total_passed_runtime sums minimum runtime per test case - # InvocationId includes iteration_id, so: 2 test methods × 2 inner iterations = 4 "test cases" - # total = sum of 4 minimums (each test method × inner iteration gets min of 2 outer loops) ≈ 40ms + # iteration_id is now constant (wrapper ID) per call site, so: + # 2 test methods = 2 InvocationId keys, each with 4 runtimes (2 outer × 2 inner) total_runtime = test_results.total_passed_runtime() runtime_by_test = test_results.usable_runtime_data_by_test_case() - # Should have 4 test cases (2 test methods × 2 inner iterations) - assert len(runtime_by_test) == 4, ( - f"Expected 4 test cases (2 methods × 2 iterations), got {len(runtime_by_test)}" + # Should have 2 test cases (one per test method, constant iteration_id) + assert len(runtime_by_test) == 2, ( + f"Expected 2 test cases (2 methods × constant iteration_id), got {len(runtime_by_test)}" ) - # Each test case should have 2 runtimes (2 outer loops) + # Each test case should have 4 runtimes (2 outer loops × 2 inner iterations) for test_id, test_runtimes in runtime_by_test.items(): - assert len(test_runtimes) == 2, ( - f"Expected 2 runtimes (2 outer loops) for {test_id.test_function_name}:{test_id.iteration_id}, " + assert len(test_runtimes) == 4, ( + f"Expected 4 runtimes (2 outer × 2 inner) for {test_id.test_function_name}:{test_id.iteration_id}, " f"got {len(test_runtimes)}" ) - # Total should be sum of 4 minimums ≈ 40ms + # Total should be sum of 2 minimums ≈ 20ms # Minimums filter out JIT warmup, so use tighter ±3% tolerance - expected_total_ns = 4 * expected_ns # 4 test cases × 10ms each + expected_total_ns = 2 * expected_ns # 2 test cases × 10ms each assert expected_total_ns * 0.97 <= total_runtime <= expected_total_ns * 1.03, ( f"total_passed_runtime {total_runtime / 1_000_000:.3f}ms not close to expected " - f"{expected_total_ns / 1_000_000:.1f}ms (2 methods × 2 inner iterations × 10ms, ±3%)" + f"{expected_total_ns / 1_000_000:.1f}ms (2 methods × min of 4 runtimes × 10ms, ±3%)" )