From 16c6d72bdbde95d5c00004beefc1e41f810c8f29 Mon Sep 17 00:00:00 2001 From: Robusta Runner Date: Fri, 22 Aug 2025 22:46:06 +0300 Subject: [PATCH 01/14] POC --- tests/llm/conftest.py | 56 +- tests/llm/test_ask_holmes.py | 38 +- tests/llm/test_investigate.py | 28 +- tests/llm/test_workload_health.py | 31 +- tests/llm/utils/reporting/github_reporter.py | 6 +- .../llm/utils/reporting/terminal_reporter.py | 478 +++++++++++++++--- tests/llm/utils/test_results.py | 33 +- 7 files changed, 552 insertions(+), 118 deletions(-) diff --git a/tests/llm/conftest.py b/tests/llm/conftest.py index 5b65c9770d..91a126d50a 100644 --- a/tests/llm/conftest.py +++ b/tests/llm/conftest.py @@ -475,6 +475,7 @@ def _collect_test_results_from_stats(terminalreporter): "mock_data_failure": False, "braintrust_span_id": None, "braintrust_root_span_id": None, + "clean_test_case_id": None, # Not available for skipped tests } continue elif when != "call": @@ -553,6 +554,8 @@ def _collect_test_results_from_stats(terminalreporter): "mock_data_failure": mock_data_failure, "user_prompt": user_props.get("user_prompt", ""), "is_setup_failure": user_props.get("is_setup_failure", False), + "model": user_props.get("model", "Unknown"), + "clean_test_case_id": user_props.get("clean_test_case_id"), "error_message": str(report.longrepr) if hasattr(report, "longrepr") and report.longrepr else None, @@ -560,37 +563,46 @@ def _collect_test_results_from_stats(terminalreporter): "braintrust_root_span_id": user_props.get("braintrust_root_span_id"), } - # Create TestResult objects to get test_id and test_name properties + # Extract test case names for all results results_with_ids = [] for result in test_results.values(): - # Create a temporary TestResult to extract IDs - temp_result = TestResult( - nodeid=result["nodeid"], - expected=result["expected"], - actual=result["actual"], - pass_fail="", # Will be set later - tools_called=result["tools_called"], - logs="", # Will be set later - test_type=result["test_type"], - execution_time=result["execution_time"], - expected_correctness_score=result["expected_correctness_score"], - user_prompt=result["user_prompt"], - actual_correctness_score=result["actual_correctness_score"], - mock_data_failure=result["mock_data_failure"], - ) + # If we have a clean test case ID from the test, use it + # This is set in test_ask_holmes.py, test_investigate.py, and test_workload_health.py + # via: request.node.user_properties.append(("clean_test_case_id", test_case.id)) + # It provides the clean test case ID without model suffixes that pytest adds when + # parameterizing with multiple models (e.g., "01_how_many_pods" instead of + # "01_how_many_pods-gpt-4o" or "01_how_many_pods-anthropic/claude-3-5-sonnet") + # Note: This won't be available for skipped tests (they never enter the test function body) + # or tests that fail during early setup before user_properties are set + if result.get("clean_test_case_id"): + result["test_case_name"] = result["clean_test_case_id"] + else: + # Fallback: Create a temporary TestResult to extract test case name from nodeid + temp_result = TestResult( + nodeid=result["nodeid"], + expected=result["expected"], + actual=result["actual"], + pass_fail="", # Will be set later + tools_called=result["tools_called"], + logs="", # Will be set later + test_type=result["test_type"], + execution_time=result["execution_time"], + expected_correctness_score=result["expected_correctness_score"], + user_prompt=result["user_prompt"], + actual_correctness_score=result["actual_correctness_score"], + mock_data_failure=result["mock_data_failure"], + ) + # Add extracted test case name to the result dict + result["test_case_name"] = temp_result.test_case_name - # Add extracted IDs to the result dict - result["test_id"] = temp_result.test_id - result["test_name"] = temp_result.test_name results_with_ids.append(result) - # Sort results by test_type then test_id for consistent ordering + # Sort results by test_type then test_case_name for consistent ordering sorted_results = sorted( results_with_ids, key=lambda r: ( r["test_type"], - int(r["test_id"]) if r["test_id"].isdigit() else 999, - r["test_name"], + r["test_case_name"], ), ) diff --git a/tests/llm/test_ask_holmes.py b/tests/llm/test_ask_holmes.py index 061bfc2287..68c69488ea 100644 --- a/tests/llm/test_ask_holmes.py +++ b/tests/llm/test_ask_holmes.py @@ -54,9 +54,17 @@ def get_ask_holmes_test_cases(): return get_test_cases(TEST_CASES_FOLDER) +def get_models(): + """Get list of models to test from MODELS env var.""" + models_str = os.environ.get("MODELS", "gpt-4o") + return models_str.split(",") + + @pytest.mark.llm +@pytest.mark.parametrize("model", get_models()) @pytest.mark.parametrize("test_case", get_ask_holmes_test_cases()) def test_ask_holmes( + model: str, test_case: AskHolmesTestCase, caplog, request, @@ -66,6 +74,11 @@ def test_ask_holmes( # Set initial properties early so they're available even if test fails set_initial_properties(request, test_case) + # Add model to user properties for reporting + request.node.user_properties.append(("model", model)) + # Add clean test case ID (without model suffix) + request.node.user_properties.append(("clean_test_case_id", test_case.id)) + # Check if test should be skipped check_and_skip_test(test_case) @@ -80,6 +93,7 @@ def test_ask_holmes( print( f" โ€ข Mode: {'โšช๏ธ MOCKED' if mock_generation_config.mode == MockMode.MOCK else '๐Ÿ”ฅ LIVE'}, Generate Mocks: {mock_generation_config.generate_mocks}" ) + print(f" โ€ข Model: {model}") print(f" โ€ข User Prompt: {test_case.user_prompt}") print(f" โ€ข Expected Output: {test_case.expected_output}") if test_case.before_test: @@ -99,13 +113,14 @@ def test_ask_holmes( print(f" โ€ข After Test: {test_case.after_test}") tracer = TracingFactory.create_tracer("braintrust") - tracer.start_experiment() + metadata = {"model": model} + tracer.start_experiment(additional_metadata=metadata) result: Optional[LLMResult] = None try: with tracer.start_trace( - name=test_case.id, span_type=SpanType.EVAL + name=f"{test_case.id}[{model}]", span_type=SpanType.EVAL ) as eval_span: # Store span info in user properties for conftest to access if hasattr(eval_span, "id"): @@ -132,6 +147,7 @@ def test_ask_holmes( with set_test_env_vars(test_case): result = ask_holmes( test_case=test_case, + model=model, tracer=tracer, eval_span=eval_span, mock_generation_config=mock_generation_config, @@ -141,6 +157,7 @@ def test_ask_holmes( with set_test_env_vars(test_case): result = ask_holmes( test_case=test_case, + model=model, tracer=tracer, eval_span=eval_span, mock_generation_config=mock_generation_config, @@ -151,13 +168,17 @@ def test_ask_holmes( # Log error to span if available try: if "eval_span" in locals(): + # Prepare tags with model + tags = (test_case.tags or []).copy() + tags.append(f"model:{model}") + eval_span.log( input=test_case.user_prompt, output=result.result if result else str(e), expected=test_case.expected_output, dataset_record_id=test_case.id, scores={}, - tags=test_case.tags or [], + tags=tags, ) except Exception: pass # Don't fail the test due to logging issues @@ -215,14 +236,18 @@ def test_ask_holmes( # Log evaluation results directly to the span if eval_span: + # Prepare tags with model + tags = (test_case.tags or []).copy() + tags.append(f"model:{model}") + eval_span.log( input=input, output=output or "", expected=str(expected), dataset_record_id=test_case.id, scores=scores, - metadata={"system_prompt": prompt}, - tags=test_case.tags or [], + metadata={"system_prompt": prompt, "model": model}, + tags=tags, ) # Print tool calls summary @@ -272,6 +297,7 @@ def test_ask_holmes( # TODO: can this call real ask_holmes so more of the logic is captured def ask_holmes( test_case: AskHolmesTestCase, + model: str, tracer, eval_span, mock_generation_config, @@ -297,7 +323,7 @@ def ask_holmes( ai = ToolCallingLLM( tool_executor=tool_executor, max_steps=40, - llm=DefaultLLM(os.environ.get("MODEL", "gpt-4o"), tracer=tracer), + llm=DefaultLLM(model, tracer=tracer), ) test_type = ( diff --git a/tests/llm/test_investigate.py b/tests/llm/test_investigate.py index 58f5637b9c..6047c7e25b 100644 --- a/tests/llm/test_investigate.py +++ b/tests/llm/test_investigate.py @@ -72,9 +72,17 @@ def get_investigate_test_cases(): return get_test_cases(TEST_CASES_FOLDER) +def get_models(): + """Get list of models to test from MODELS env var.""" + models_str = os.environ.get("MODELS", "gpt-4o") + return models_str.split(",") + + @pytest.mark.llm +@pytest.mark.parametrize("model", get_models()) @pytest.mark.parametrize("test_case", get_investigate_test_cases()) def test_investigate( + model: str, test_case: InvestigateTestCase, caplog, request, @@ -84,6 +92,11 @@ def test_investigate( # Set initial properties early so they're available even if test fails set_initial_properties(request, test_case) + # Add model to user properties for reporting + request.node.user_properties.append(("model", model)) + # Add clean test case ID (without model suffix) + request.node.user_properties.append(("clean_test_case_id", test_case.id)) + # Check if test should be skipped check_and_skip_test(test_case) @@ -95,8 +108,8 @@ def test_investigate( tracer = TracingFactory.create_tracer("braintrust") config = MockConfig(test_case, tracer, mock_generation_config) - config.model = os.environ.get("MODEL", "gpt-4o") - metadata = {"model": config.model or "Unknown"} + config.model = model + metadata = {"model": model} tracer.start_experiment(additional_metadata=metadata) mock_dal = MockSupabaseDal( @@ -118,7 +131,7 @@ def test_investigate( os.environ, {"HOLMES_STRUCTURED_OUTPUT_CONVERSION_FEATURE_FLAG": "False"} ): with tracer.start_trace( - name=test_case.id, span_type=SpanType.EVAL + name=f"{test_case.id}[{model}]", span_type=SpanType.EVAL ) as eval_span: # Store span info in user properties for conftest to access if hasattr(eval_span, "id"): @@ -156,6 +169,8 @@ def test_investigate( debug_expected = "\n- ".join(expected) + print(f"\n๐Ÿงช TEST: {test_case.id}") + print(f" โ€ข Model: {model}") print(f"** EXPECTED **\n- {debug_expected}") correctness_eval = evaluate_correctness( output=output, @@ -180,13 +195,18 @@ def test_investigate( # Log evaluation results directly to the span if eval_span: + # Prepare tags with model + tags = (test_case.tags or []).copy() + tags.append(f"model:{model}") + eval_span.log( input=input, output=output or "", expected=str(expected), dataset_record_id=test_case.id, scores=scores, - tags=test_case.tags, + metadata={"model": model}, + tags=tags, ) tools_called = [t.tool_name for t in result.tool_calls] print(f"\n** TOOLS CALLED **\n{tools_called}") diff --git a/tests/llm/test_workload_health.py b/tests/llm/test_workload_health.py index f62186a8c0..7e9789cb9b 100644 --- a/tests/llm/test_workload_health.py +++ b/tests/llm/test_workload_health.py @@ -63,9 +63,17 @@ def get_workload_health_test_cases(): return get_test_cases(TEST_CASES_FOLDER) +def get_models(): + """Get list of models to test from MODELS env var.""" + models_str = os.environ.get("MODELS", "gpt-4o") + return models_str.split(",") + + @pytest.mark.llm +@pytest.mark.parametrize("model", get_models()) @pytest.mark.parametrize("test_case", get_workload_health_test_cases()) def test_health_check( + model: str, test_case: HealthCheckTestCase, caplog, request, @@ -75,6 +83,11 @@ def test_health_check( # Set initial properties early so they're available even if test fails set_initial_properties(request, test_case) + # Add model to user properties for reporting + request.node.user_properties.append(("model", model)) + # Add clean test case ID (without model suffix) + request.node.user_properties.append(("clean_test_case_id", test_case.id)) + # Check if test should be skipped check_and_skip_test(test_case) @@ -85,10 +98,11 @@ def test_health_check( pytest.fail(f"Test setup failed: {setup_failures[test_case.id]}") tracer = TracingFactory.create_tracer("braintrust") - tracer.start_experiment() + metadata = {"model": model} + tracer.start_experiment(additional_metadata=metadata) config = MockConfig(test_case, tracer, mock_generation_config, request) - config.model = os.environ.get("MODEL", "gpt-4o") + config.model = model mock_dal = MockSupabaseDal( test_case_folder=Path(test_case.folder), @@ -100,7 +114,9 @@ def test_health_check( input = test_case.workload_health_request expected = test_case.expected_output - with tracer.start_trace(name=test_case.id, span_type=SpanType.EVAL) as eval_span: + with tracer.start_trace( + name=f"{test_case.id}[{model}]", span_type=SpanType.EVAL + ) as eval_span: # Store span info in user properties for conftest to access if hasattr(eval_span, "id"): request.node.user_properties.append( @@ -121,6 +137,8 @@ def test_health_check( assert result, "No result returned by workload_health_check()" # check that analysis is json parsable otherwise failed. + print(f"\n๐Ÿงช TEST: {test_case.id}") + print(f" โ€ข Model: {model}") print(f"** ANALYSIS **\n- {result.analysis}") json.loads(result.analysis) output = result.analysis @@ -143,13 +161,18 @@ def test_health_check( # Log evaluation results directly to the span if eval_span: + # Prepare tags with model + tags = (test_case.tags or []).copy() + tags.append(f"model:{model}") + eval_span.log( input=input, output=output or "", expected=str(expected), dataset_record_id=test_case.id, scores=scores, - metadata={"tags": test_case.tags}, + metadata={"model": model}, + tags=tags, ) tools_called = [t.tool_name for t in result.tool_calls] diff --git a/tests/llm/utils/reporting/github_reporter.py b/tests/llm/utils/reporting/github_reporter.py index 5a86cee881..bb9ab0d792 100644 --- a/tests/llm/utils/reporting/github_reporter.py +++ b/tests/llm/utils/reporting/github_reporter.py @@ -122,17 +122,17 @@ def generate_markdown_report(sorted_results: List[dict]) -> Tuple[str, List[dict for result in sorted_results: test_suite = result["test_type"] - test_name = f"{result['test_id']}_{result['test_name']}" + test_case_name = result["test_case_name"] braintrust_url = get_braintrust_url( result.get("braintrust_span_id"), result.get("braintrust_root_span_id"), ) if braintrust_url: - test_name = f"[{test_name}]({braintrust_url})" + test_case_name = f"[{test_case_name}]({braintrust_url})" status = TestStatus(result) - markdown += f"| {test_suite} | {test_name} | {status.markdown_symbol} |\n" + markdown += f"| {test_suite} | {test_case_name} | {status.markdown_symbol} |\n" markdown += "\n\n**Legend**\n" markdown += "\n- :white_check_mark: the test was successful" diff --git a/tests/llm/utils/reporting/terminal_reporter.py b/tests/llm/utils/reporting/terminal_reporter.py index ec54f0b7f0..60c2dcd404 100644 --- a/tests/llm/utils/reporting/terminal_reporter.py +++ b/tests/llm/utils/reporting/terminal_reporter.py @@ -1,7 +1,7 @@ """Terminal reporting functionality for test results.""" import textwrap -from typing import List, Dict +from typing import List, Dict, Optional, Any from collections import defaultdict from rich.console import Console @@ -10,11 +10,119 @@ from tests.llm.utils.test_results import TestStatus, TestResult +def _calculate_p90(times: List[float]) -> float: + """Calculate the 90th percentile of a list of times. + + Args: + times: List of execution times + + Returns: + P90 time value, or 0 if times is empty + """ + if not times: + return 0 + + sorted_times = sorted(times) + p90_index = int(len(sorted_times) * 0.9) + # Handle edge case for small sample sizes + if p90_index >= len(sorted_times): + p90_index = len(sorted_times) - 1 + return sorted_times[p90_index] + + +def _calculate_valid_runs(results: List[dict]) -> int: + """Calculate the number of valid test runs (excluding skipped and setup failures). + + Args: + results: List of test results + + Returns: + Number of valid runs + """ + setup_failures = sum(1 for r in results if r.get("is_setup_failure", False)) + skipped = sum(1 for r in results if r.get("status") == "skipped") + return len(results) - setup_failures - skipped + + +def _calculate_pass_percentage(passed: int, valid_runs: int) -> float: + """Calculate pass percentage from passed count and valid runs. + + Args: + passed: Number of passed tests + valid_runs: Number of valid test runs + + Returns: + Pass percentage (0-100) + """ + if valid_runs > 0: + return (passed / valid_runs) * 100 + return 0 + + +def _get_failure_indicators( + mock_failures: int, setup_failures: int, runs: Optional[int] = None +) -> str: + """Get emoji indicators for failure types. + + Args: + mock_failures: Number of mock data failures + setup_failures: Number of setup failures + runs: Total number of runs (optional, for partial setup failure detection) + + Returns: + String with emoji indicators (e.g., " ๐Ÿ“ฆ" or " ๐Ÿ”ง") + """ + indicators = "" + if mock_failures > 0: + indicators = " ๐Ÿ“ฆ" + elif setup_failures > 0: + # Only show setup indicator if it's partial (not all runs failed setup) + if runs is None or setup_failures < runs: + indicators = " ๐Ÿ”ง" + return indicators + + +def _parse_test_name(nodeid: str, remove_iteration: bool = True) -> str: + """Parse test name from nodeid, optionally removing iteration numbers. + + This function extracts the test case identifier from a pytest nodeid. + + Args: + nodeid: Full node ID from pytest (e.g., 'test_ask_holmes[01_how_many_pods0]') + remove_iteration: Whether to remove iteration numbers + + Returns: + Parsed test name (e.g., '01_how_many_pods') + """ + if "[" in nodeid and "]" in nodeid: + # Extract the parametrized part between brackets + test_case = nodeid.split("[")[1].split("]")[0] + + # Remove trailing iteration numbers if requested + if remove_iteration and test_case: + # Remove trailing digits (iteration numbers added by pytest) + # Iteration numbers are appended directly to the end without separator + while test_case and test_case[-1].isdigit(): + test_case = test_case[:-1] + + return test_case + else: + # No parameters, use the test function name + return nodeid.split("::")[-1] if "::" in nodeid else nodeid + + def handle_console_output(sorted_results: List[dict], terminalreporter=None) -> None: """Display Rich table and Braintrust links for developers.""" if not sorted_results: return + # Group results by test name to calculate P90 + test_time_groups = defaultdict(list) + for result in sorted_results: + test_key = result.get("nodeid", "") + if result.get("execution_time"): + test_time_groups[test_key].append(result.get("execution_time")) + # Create Rich table console = Console() table = Table( @@ -27,33 +135,14 @@ def handle_console_output(sorted_results: List[dict], terminalreporter=None) -> # Add columns with specific widths (reduced to fit terminal width) table.add_column("Test", style="cyan", width=12) table.add_column("Status", justify="center", width=13) - table.add_column("Time", justify="right", width=5) - table.add_column("User Prompt", style="white", width=22) - table.add_column("Expected", style="green", width=22) - table.add_column("Actual", style="yellow", width=22) + table.add_column("Time", justify="right", width=10) + table.add_column("User Prompt", style="white", width=20) + table.add_column("Expected", style="green", width=20) + table.add_column("Actual", style="yellow", width=20) # Add rows to table for result in sorted_results: status = TestStatus(result) - pass_fail = ( - "โœ… PASS" if status.passed else "โŒ FAIL" - ) # Still needed for TestResult - - # Create TestResult object for analysis function - test_result = TestResult( - nodeid=result.get("nodeid", ""), - expected=result["expected"], - actual=result["actual"], - pass_fail=pass_fail, - tools_called=result["tools_called"], - logs="", # We don't have logs in this context - test_type=result["test_type"], - error_message=None, - execution_time=result.get("execution_time"), - expected_correctness_score=result["expected_correctness_score"], - actual_correctness_score=result["actual_correctness_score"], - mock_data_failure=result.get("mock_data_failure", False), - ) # Wrap long content for table readability user_prompt_wrapped = ( @@ -72,19 +161,36 @@ def handle_console_output(sorted_results: List[dict], terminalreporter=None) -> else "" ) - # Combine test ID and name using TestResult properties - combined_test_name = ( - f"{test_result.test_id}_{test_result.test_name} ({result['test_type']})" - ) + # Use test_case_name and model that are already in the result dict + test_case_name = result["test_case_name"] + model = result.get("model", "") + if model: + combined_test_name = f"{test_case_name} ({model})" + else: + combined_test_name = f"{test_case_name} ({result['test_type']})" # Wrap test name to fit column test_name_wrapped = "\n".join(textwrap.wrap(combined_test_name, width=10)) - # Format execution time - time_str = ( - f"{result.get('execution_time'):.1f}s" - if result.get("execution_time") - else "N/A" - ) + # Format execution time with P90 if available + exec_time = result.get("execution_time") + if exec_time: + # Get the test case name to look up all times for this test + test_case_name = result["test_case_name"] + # Find all execution times for this specific test case (across all models) + test_times = [] + for r in sorted_results: + if r["test_case_name"] == test_case_name and r.get("execution_time"): + test_times.append(r["execution_time"]) + + # Calculate average time for multiple runs + if len(test_times) > 1: + avg_time = sum(test_times) / len(test_times) + p90 = _calculate_p90(test_times) + time_str = f"Avg: {avg_time:.1f}s\nP90: {p90:.1f}s" + else: + time_str = f"{exec_time:.1f}s" + else: + time_str = "N/A" # Disabled for now - get analysis for failed tests with openai # analysis = _get_analysis_for_result(test_result) @@ -136,7 +242,7 @@ def _get_llm_analysis(result: TestResult) -> str: prompt = textwrap.dedent(f"""\ Analyze this failed eval for an AIOps agent why it failed. - TEST: {result.test_name} + TEST: {result.test_case_name} EXPECTED: {result.expected} ACTUAL: {result.actual} TOOLS CALLED: {', '.join(result.tools_called)} @@ -168,26 +274,258 @@ def _get_llm_analysis(result: TestResult) -> str: return f"Analysis failed: {e}" +def _get_status_emoji( + pass_pct: float, setup_fail: bool = False, all_skipped: bool = False +) -> str: + """Get the appropriate emoji based on pass percentage and status. + + Args: + pass_pct: Pass percentage (0-100) + setup_fail: Whether all runs were setup failures + all_skipped: Whether all runs were skipped + + Returns: + Emoji string representing the status + """ + if all_skipped: + return "โญ๏ธ" + if setup_fail: + return "๐Ÿ”ง" + if pass_pct == 100.0: + return "โœ…" + elif pass_pct == 0.0: + return "โŒ" + else: + return "โš ๏ธ" + + +def _detect_multiple_models(sorted_results: List[dict]) -> bool: + """Detect if results contain multiple models. + + Args: + sorted_results: List of test results + + Returns: + True if multiple models are present + """ + models = set() + for result in sorted_results: + model = result.get("model", "Unknown") + models.add(model) + return len(models) > 1 + + +def _print_model_comparison_table(sorted_results: List[dict], console: Console) -> None: + """Print a model comparison table when multiple models are detected.""" + if not sorted_results: + return + + # Group results by test case and model + test_model_groups: Dict[str, Dict[str, List[dict]]] = defaultdict( + lambda: defaultdict(list) + ) + models = set() + + for result in sorted_results: + model = result.get("model", "Unknown") + models.add(model) + + # Use the test_case_name which is already clean + test_case = result["test_case_name"] + + test_model_groups[test_case][model].append(result) + + # Sort models for consistent column order + sorted_models = sorted(models) + + # Create comparison table + comparison_table = Table( + title="\n๐Ÿ“Š MODEL COMPARISON RESULTS", + show_header=True, + header_style="bold cyan", + show_lines=True, + padding=(0, 1), + ) + + # Add columns + comparison_table.add_column("Test Case", style="bright_blue", width=30) + for model in sorted_models: + comparison_table.add_column(model, justify="center", width=22) + + # Process each test case + model_totals: Dict[str, Dict[str, Any]] = { + model: { + "runs": 0, + "pass": 0, + "times": [], + "setup_fail": 0, + "mock_fail": 0, + "skip": 0, + } + for model in sorted_models + } + + for test_case in sorted(test_model_groups.keys()): + row_data = [test_case] + + for model in sorted_models: + results = test_model_groups[test_case].get(model, []) + + if not results: + row_data.append("โ€”") + continue + + # Calculate statistics for this test/model combination + runs = len(results) + passed = sum(1 for r in results if TestStatus(r).passed) + skipped = sum(1 for r in results if r.get("status") == "skipped") + setup_failures = sum(1 for r in results if r.get("is_setup_failure", False)) + mock_failures = sum(1 for r in results if r.get("mock_data_failure", False)) + + # Calculate times + times = [ + r.get("execution_time", 0) for r in results if r.get("execution_time") + ] + avg_time = sum(times) / len(times) if times else 0 + + # Update model totals + model_totals[model]["runs"] += runs + model_totals[model]["pass"] += passed + model_totals[model]["times"].extend(times) + model_totals[model]["setup_fail"] += setup_failures + model_totals[model]["mock_fail"] += mock_failures + model_totals[model]["skip"] += skipped + + # Determine display based on status + if skipped == runs: + cell_text = "[cyan]Skipped[/cyan]" + elif setup_failures == runs: + cell_text = "[magenta]Setup Fail[/magenta]" + else: + # Calculate pass percentage from valid runs + valid_runs = _calculate_valid_runs(results) + pass_pct = _calculate_pass_percentage(passed, valid_runs) + + # Choose color based on pass percentage + if pass_pct == 100: + color = "green" + elif pass_pct >= 50: + color = "yellow" + else: + color = "red" + + # Format as 3 lines: Score, Pass count, Avg time + cell_lines = [] + cell_lines.append(f"[{color}]{pass_pct:.0f}%[/{color}]") + cell_lines.append(f"{passed}/{valid_runs}") + if avg_time > 0: + cell_lines.append(f"Avg: {avg_time:.1f}s") + + cell_text = "\n".join(cell_lines) + + row_data.append(cell_text) + + comparison_table.add_row(*row_data) + + # Add separator + separator_row = ["โ”€" * 28] + ["โ”€" * 18] * len(sorted_models) + comparison_table.add_row(*separator_row, style="dim") + + # Add model average row + average_row = ["Model Average"] + for model in sorted_models: + totals = model_totals[model] + if totals["runs"] > 0: + # Calculate pass percentage from valid runs + valid_runs = totals["runs"] - totals["setup_fail"] - totals["skip"] + pass_pct = _calculate_pass_percentage(totals["pass"], valid_runs) + if valid_runs > 0: + # Choose color based on pass percentage + if pass_pct == 100: + color = "bold green" + elif pass_pct >= 50: + color = "bold yellow" + else: + color = "bold red" + average_row.append(f"[{color}]{pass_pct:.1f}%[/{color}]") + else: + average_row.append("โ€”") + else: + average_row.append("โ€”") + comparison_table.add_row(*average_row) + + # Add average time row + time_row = ["Average Time"] + for model in sorted_models: + times = model_totals[model]["times"] + if times: + avg_time = sum(times) / len(times) + time_row.append(f"{avg_time:.1f}s") + else: + time_row.append("โ€”") + comparison_table.add_row(*time_row) + + # Add P90 time row + p90_row = ["P90 Time"] + for model in sorted_models: + times = model_totals[model]["times"] + if times: + p90_time = _calculate_p90(times) + p90_row.append(f"{p90_time:.1f}s") + else: + p90_row.append("โ€”") + comparison_table.add_row(*p90_row) + + console.print(comparison_table) + + # Print summary + total_tests = len(test_model_groups) + console.print( + f"\n[dim]Compared {len(sorted_models)} models across {total_tests} test cases[/dim]" + ) + + # Find best performing model(s) + best_models = [] + best_pass_pct = 0.0 + for model in sorted_models: + totals = model_totals[model] + valid_runs = totals["runs"] - totals["setup_fail"] - totals["skip"] + pass_pct = _calculate_pass_percentage(totals["pass"], valid_runs) + if valid_runs > 0: + if pass_pct > best_pass_pct: + best_pass_pct = pass_pct + best_models = [model] + elif pass_pct == best_pass_pct: + best_models.append(model) + + if best_models: + if len(best_models) == 1: + console.print( + f"[bold green]Best performing model: {best_models[0]} ({best_pass_pct:.1f}% pass rate)[/bold green]" + ) + else: + models_str = ", ".join(best_models) + console.print( + f"[bold green]Best performing models: {models_str} ({best_pass_pct:.1f}% pass rate)[/bold green]" + ) + + def _print_summary_statistics(sorted_results: List[dict], console: Console) -> None: """Print a summary statistics table similar to pytest coverage reports.""" if not sorted_results: return + # Check if we should use model comparison view + if _detect_multiple_models(sorted_results): + _print_model_comparison_table(sorted_results, console) + return + # Group results by test name (without iteration number) test_groups: Dict[str, List[dict]] = defaultdict(list) for result in sorted_results: - # Extract test name without iteration number - nodeid = result.get("nodeid", "") - # Remove iteration suffix like "0", "1", etc. - if "[" in nodeid: - base_name = nodeid.split("[")[1].split("]")[0] - # Remove trailing numbers - if base_name and base_name[-1].isdigit(): - base_name = base_name.rstrip("0123456789") - else: - base_name = nodeid - + # Use test_case_name from result dict + base_name = result["test_case_name"] test_groups[base_name].append(result) # Create summary table @@ -208,6 +546,7 @@ def _print_summary_statistics(sorted_results: List[dict], console: Console) -> N summary_table.add_column("Mock Fail", justify="center", style="yellow", width=10) summary_table.add_column("Pass %", justify="right", width=8) summary_table.add_column("Avg Time", justify="right", width=10) + summary_table.add_column("P90 Time", justify="right", width=10) # Calculate statistics for each test total_runs = 0 @@ -240,15 +579,18 @@ def _print_summary_statistics(sorted_results: List[dict], console: Console) -> N and r.get("status") != "skipped" ) - # Calculate pass percentage - if runs > 0: - pass_pct = (passed / runs) * 100 - else: - pass_pct = 0 + # Determine pass percentage display + all_skipped = all(r.get("status") == "skipped" for r in results) + all_setup_fail = setup_failures == runs + + # Calculate pass percentage from valid runs + valid_runs = _calculate_valid_runs(results) + pass_pct = _calculate_pass_percentage(passed, valid_runs) - # Calculate average execution time + # Calculate average and P90 execution time times = [r.get("execution_time", 0) for r in results if r.get("execution_time")] avg_time = sum(times) / len(times) if times else 0 + p90_time = _calculate_p90(times) # Update totals total_runs += runs @@ -257,9 +599,18 @@ def _print_summary_statistics(sorted_results: List[dict], console: Console) -> N total_setup_fail += setup_failures total_mock_fail += mock_failures - # Format values - pass_pct_str = f"{pass_pct:.1f}%" + # Format pass percentage with emoji + if all_skipped: + pass_pct_str = "โญ๏ธ Skipped" + elif all_setup_fail: + pass_pct_str = "๐Ÿ”ง Setup Fail" + else: + emoji = _get_status_emoji(pass_pct) + indicators = _get_failure_indicators(mock_failures, setup_failures, runs) + pass_pct_str = f"{emoji} {pass_pct:.1f}%{indicators}" + avg_time_str = f"{avg_time:.1f}s" if avg_time > 0 else "N/A" + p90_time_str = f"{p90_time:.1f}s" if p90_time > 0 else "N/A" # Add row summary_table.add_row( @@ -271,6 +622,7 @@ def _print_summary_statistics(sorted_results: List[dict], console: Console) -> N str(mock_failures) if mock_failures > 0 else "-", pass_pct_str, avg_time_str, + p90_time_str, ) # Add separator @@ -283,14 +635,23 @@ def _print_summary_statistics(sorted_results: List[dict], console: Console) -> N "โ”€" * 8, "โ”€" * 6, "โ”€" * 8, + "โ”€" * 8, style="dim", ) # Add totals row total_actual_runs = total_runs - total_pass_pct = ( - (total_pass / total_actual_runs) * 100 if total_actual_runs > 0 else 0 - ) + total_pass_pct = _calculate_pass_percentage(total_pass, total_actual_runs) + + # Format total pass percentage with emoji + total_emoji = _get_status_emoji(total_pass_pct) + # For totals, always show indicators if any failures exist + total_indicators = "" + if total_mock_fail > 0: + total_indicators += " ๐Ÿ“ฆ" + if total_setup_fail > 0: + total_indicators += " ๐Ÿ”ง" + summary_table.add_row( "TOTAL", str(total_runs), @@ -298,7 +659,8 @@ def _print_summary_statistics(sorted_results: List[dict], console: Console) -> N str(total_fail), str(total_setup_fail), str(total_mock_fail), - f"{total_pass_pct:.1f}%", + f"{total_emoji} {total_pass_pct:.1f}%{total_indicators}", + "", "", style="bold", ) diff --git a/tests/llm/utils/test_results.py b/tests/llm/utils/test_results.py index 10747f6ef4..780a2dd994 100644 --- a/tests/llm/utils/test_results.py +++ b/tests/llm/utils/test_results.py @@ -21,31 +21,22 @@ class TestResult: mock_data_failure: bool = False @property - def test_id(self) -> str: - """Extract test ID from pytest nodeid. + def test_case_name(self) -> str: + """Extract full test case name from pytest nodeid. - Example: 'test_ask_holmes[01_how_many_pods]' -> '01' + Example: 'test_ask_holmes[01_how_many_pods]' -> '01_how_many_pods' + Example: 'test_ask_holmes[01_how_many_pods0]' -> '01_how_many_pods' (removes iteration) """ if "[" in self.nodeid and "]" in self.nodeid: test_case = self.nodeid.split("[")[1].split("]")[0] - # Extract number from start of test case name - return test_case.split("_")[0] if "_" in test_case else test_case - return "unknown" - - @property - def test_name(self) -> str: - """Extract readable test name from pytest nodeid. - - Example: 'test_ask_holmes[01_how_many_pods]' -> 'how_many_pods' - """ - try: - if "[" in self.nodeid and "]" in self.nodeid: - test_case = self.nodeid.split("[")[1].split("]")[0] - # Remove number prefix and convert underscores to spaces - parts = test_case.split("_")[1:] if "_" in test_case else [test_case] - return "_".join(parts) - except (IndexError, AttributeError): - pass + # Remove trailing digits (iteration numbers added by pytest) + while test_case and test_case[-1].isdigit(): + # But keep digits that are part of the test name (e.g., "113_" in "113_checkout") + # Check if removing this digit would leave us with underscore or nothing + if len(test_case) == 1 or test_case[-2] == "_": + break + test_case = test_case[:-1] + return test_case return self.nodeid.split("::")[-1] if "::" in self.nodeid else self.nodeid From 3f4605807339c7b1d3045485318f640de11483b2 Mon Sep 17 00:00:00 2001 From: Robusta Runner Date: Sat, 23 Aug 2025 10:54:33 +0300 Subject: [PATCH 02/14] more improvements --- docs/development/evals/index.md | 71 +- holmes/core/tool_calling_llm.py | 88 ++ holmes/main.py | 8 +- holmes/utils/console/logging.py | 7 +- tests/llm/conftest.py | 36 +- tests/llm/test_ask_holmes.py | 57 +- tests/llm/test_investigate.py | 130 ++- tests/llm/utils/braintrust.py | 136 +++ tests/llm/utils/property_manager.py | 50 +- .../llm/utils/reporting/terminal_reporter.py | 897 ++++++++++++++---- 10 files changed, 1203 insertions(+), 277 deletions(-) diff --git a/docs/development/evals/index.md b/docs/development/evals/index.md index 36a15fdda0..8921742ad7 100644 --- a/docs/development/evals/index.md +++ b/docs/development/evals/index.md @@ -64,6 +64,34 @@ RUN_LIVE=true MODEL=azure/your-deployment-name CLASSIFIER_MODEL=azure/your-deplo - For any model provider, ensure you have the necessary API keys and environment variables set (e.g., `OPENAI_API_KEY`, `ANTHROPIC_API_KEY`, `AZURE_API_KEY`) - The model specified here is passed directly to LiteLLM, so any model supported by LiteLLM can be used +### Multi-Model Benchmarking + +HolmesGPT supports running evaluations across multiple models simultaneously to compare their performance: + +```bash +# Test multiple models in a single run +# Models are specified as comma-separated list +RUN_LIVE=true MODELS=gpt-4o,anthropic/claude-3-5-sonnet-20241022,gpt-4o-mini \ + CLASSIFIER_MODEL=gpt-4o \ + poetry run pytest -m 'llm and easy' --no-cov + +# Run with multiple iterations for statistically significant results +RUN_LIVE=true ITERATIONS=10 \ + MODELS=gpt-4o,anthropic/claude-3-5-sonnet-20241022 \ + CLASSIFIER_MODEL=gpt-4o \ + poetry run pytest -m 'llm and easy' -n 10 + +# Test specific scenario across models +RUN_LIVE=true MODELS=gpt-4o,gpt-4o-mini \ + poetry run pytest tests/llm/test_ask_holmes.py -k "01_how_many_pods" +``` + +When running multi-model benchmarks: +- Results will show a **Model Comparison Table** with side-by-side performance metrics +- Each model's pass rate, execution times, and P90 percentiles are displayed +- Tests are parameterized by model, so you'll see separate results for each model/test combination +- Use `CLASSIFIER_MODEL` to ensure consistent scoring across all models + ### Running Evals with Multiple Iterations LLMs are non-deterministic - they produce different outputs for the same input. **10 iterations is a good rule of thumb** for reliable results. @@ -147,18 +175,53 @@ RUN_LIVE=true pytest -k "test" --skip-setup ## Model Comparison Workflow -Track performance across different models: +### Recommended: Multi-Model Testing (Single Run) + +**Use the `MODELS` environment variable to test multiple models in a single run:** ```bash +# Compare multiple models simultaneously - RECOMMENDED approach +RUN_LIVE=true ITERATIONS=10 \ + MODELS=gpt-4o,anthropic/claude-3-5-sonnet-20241022,gpt-4o-mini \ + CLASSIFIER_MODEL=gpt-4o \ + poetry run pytest -m 'llm and easy' -n 10 + +# This will generate a comparison table showing: +# - Side-by-side pass rates for each model +# - Execution time comparisons +# - Cost comparisons +# - Best performing models summary +``` + +### Alternative: Single-Model Testing (Separate Runs) + +For cases where you need separate experiments or different configurations per model: + +```bash +# Run separate experiments for each model +# Useful when you need different settings or want to track experiments separately + # 1. Baseline with GPT-4 RUN_LIVE=true ITERATIONS=10 EXPERIMENT_ID=baseline_gpt4o MODEL=gpt-4o pytest -n 10 tests/llm/ -# 2. Compare with Claude -RUN_LIVE=true ITERATIONS=10 EXPERIMENT_ID=claude35 MODEL=anthropic/claude-3-5-sonnet CLASSIFIER_MODEL=gpt-4o pytest -n 10 tests/llm/ +# 2. Compare with Claude (using GPT-4 as classifier since Anthropic models can't classify) +RUN_LIVE=true ITERATIONS=10 EXPERIMENT_ID=claude35 MODEL=anthropic/claude-3-5-sonnet-20241022 CLASSIFIER_MODEL=gpt-4o pytest -n 10 tests/llm/ + +# 3. Test a smaller model +RUN_LIVE=true ITERATIONS=10 EXPERIMENT_ID=gpt4o_mini MODEL=gpt-4o-mini pytest -n 10 tests/llm/ +``` -# 3. Results will be tracked if both BRAINTRUST_API_KEY and BRAINTRUST_ORG are set +### Braintrust Integration + +Results are automatically tracked if Braintrust is configured: + +```bash +# Set these once in your environment export BRAINTRUST_API_KEY=your-key export BRAINTRUST_ORG=your-org + +# Then run any evaluation command - results will be tracked automatically +RUN_LIVE=true MODELS=gpt-4o,anthropic/claude-3-5-sonnet-20241022 pytest -m 'llm and easy' ``` ## Test Markers diff --git a/holmes/core/tool_calling_llm.py b/holmes/core/tool_calling_llm.py index 5716697234..0e988966e0 100644 --- a/holmes/core/tool_calling_llm.py +++ b/holmes/core/tool_calling_llm.py @@ -43,6 +43,9 @@ get_todo_manager, ) +# Create a named logger for cost tracking +cost_logger = logging.getLogger("holmes.costs") + def format_tool_result_data(tool_result: StructuredToolResult) -> str: tool_response = tool_result.data @@ -194,6 +197,11 @@ class LLMResult(BaseModel): # TODO: clean up these two prompt: Optional[str] = None messages: Optional[List[dict]] = None + # Cost tracking + total_cost: float = 0.0 + total_tokens: int = 0 + prompt_tokens: int = 0 + completion_tokens: int = 0 def get_tool_usage_summary(self): return "AI used info from issue and " + ",".join( @@ -265,6 +273,11 @@ def call( # type: ignore perf_timing.measure("get_all_tools_openai_format") max_steps = self.max_steps i = 0 + # Initialize cost tracking + total_cost = 0.0 + total_tokens = 0 + prompt_tokens_total = 0 + completion_tokens_total = 0 while i < max_steps: i += 1 @@ -299,6 +312,36 @@ def call( # type: ignore ) logging.debug(f"got response {full_response.to_json()}") # type: ignore + # Log and accumulate cost information if available + try: + cost_value = ( + full_response._hidden_params.get("response_cost", 0) + if hasattr(full_response, "_hidden_params") + else 0 + ) + # Ensure cost is a float + cost = float(cost_value) if cost_value is not None else 0.0 + usage = getattr(full_response, "usage", {}) + if usage: + prompt_toks = usage.get("prompt_tokens", 0) + completion_toks = usage.get("completion_tokens", 0) + total_toks = usage.get("total_tokens", 0) + cost_logger.debug( + f"LLM call cost: ${cost:.6f} | Tokens: {prompt_toks} prompt + {completion_toks} completion = {total_toks} total" + ) + # Accumulate costs + total_cost += cost + prompt_tokens_total += prompt_toks + completion_tokens_total += completion_toks + total_tokens += total_toks + elif cost > 0: + cost_logger.debug( + f"LLM call cost: ${cost:.6f} | Token usage not available" + ) + total_cost += cost + except Exception as e: + logging.debug(f"Could not extract cost information: {e}") + perf_timing.measure("llm.completion") # catch a known error that occurs with Azure and replace the error message with something more obvious to the user except BadRequestError as e: @@ -365,6 +408,10 @@ def call( # type: ignore tool_calls=tool_calls, prompt=json.dumps(messages, indent=2), messages=messages, + total_cost=total_cost, + total_tokens=total_tokens, + prompt_tokens=prompt_tokens_total, + completion_tokens=completion_tokens_total, ) perf_timing.end(f"- completed in {i} iterations -") @@ -373,6 +420,10 @@ def call( # type: ignore tool_calls=tool_calls, prompt=json.dumps(messages, indent=2), messages=messages, + total_cost=total_cost, + total_tokens=total_tokens, + prompt_tokens=prompt_tokens_total, + completion_tokens=completion_tokens_total, ) if text_response and text_response.strip(): @@ -562,6 +613,21 @@ def _post_processing_call( ] full_response = self.llm.completion(messages=messages, temperature=0) logging.debug(f"Post processing response {full_response}") + + # Log cost information for post-processing + try: + cost_value = ( + full_response._hidden_params.get("response_cost", 0) + if hasattr(full_response, "_hidden_params") + else 0 + ) + # Ensure cost is a float + cost = float(cost_value) if cost_value is not None else 0.0 + if cost > 0: + cost_logger.debug(f"Post-processing LLM cost: ${cost:.6f}") + except Exception: + pass # Silent fail for cost logging + return full_response.choices[0].message.content # type: ignore except Exception: logging.exception("Failed to run post processing", exc_info=True) @@ -638,6 +704,28 @@ def call_stream( stream=False, drop_params=True, ) + + # Log cost information if available + try: + cost_value = ( + full_response._hidden_params.get("response_cost", 0) + if hasattr(full_response, "_hidden_params") + else 0 + ) + # Ensure cost is a float + cost = float(cost_value) if cost_value is not None else 0.0 + usage = getattr(full_response, "usage", {}) + if usage: + cost_logger.debug( + f"LLM iteration cost: ${cost:.6f} | Tokens: {usage.get('prompt_tokens', 0)} prompt + {usage.get('completion_tokens', 0)} completion = {usage.get('total_tokens', 0)} total" + ) + elif cost > 0: + cost_logger.debug( + f"LLM iteration cost: ${cost:.6f} | Token usage not available" + ) + except Exception as e: + logging.debug(f"Could not extract cost information: {e}") + perf_timing.measure("llm.completion") # catch a known error that occurs with Azure and replace the error message with something more obvious to the user except BadRequestError as e: diff --git a/holmes/main.py b/holmes/main.py index e7cad87f1b..f1c07126c7 100644 --- a/holmes/main.py +++ b/holmes/main.py @@ -104,6 +104,11 @@ "-v", help="Verbose output. You can pass multiple times to increase the verbosity. e.g. -v or -vv or -vvv", ) +opt_log_costs: bool = typer.Option( + False, + "--log-costs", + help="Show LLM cost information in the output", +) opt_echo_request: bool = typer.Option( True, "--echo/--no-echo", @@ -176,6 +181,7 @@ def ask( custom_toolsets: Optional[List[Path]] = opt_custom_toolsets, max_steps: Optional[int] = opt_max_steps, verbose: Optional[List[bool]] = opt_verbose, + log_costs: bool = opt_log_costs, # semi-common options destination: Optional[DestinationType] = opt_destination, slack_token: Optional[str] = opt_slack_token, @@ -219,7 +225,7 @@ def ask( """ Ask any question and answer using available tools """ - console = init_logging(verbose) # type: ignore + console = init_logging(verbose, log_costs) # type: ignore # Detect and read piped input piped_data = None diff --git a/holmes/utils/console/logging.py b/holmes/utils/console/logging.py index 42c8b6cdef..e155b0437f 100644 --- a/holmes/utils/console/logging.py +++ b/holmes/utils/console/logging.py @@ -41,9 +41,14 @@ def suppress_noisy_logs(): warnings.filterwarnings("ignore", category=UserWarning, module="slack_sdk.*") -def init_logging(verbose_flags: Optional[List[bool]] = None): +def init_logging(verbose_flags: Optional[List[bool]] = None, log_costs: bool = False): verbosity = cli_flags_to_verbosity(verbose_flags) # type: ignore + # Setup cost logger if requested + if log_costs: + cost_logger = logging.getLogger("holmes.costs") + cost_logger.setLevel(logging.DEBUG) + if verbosity == Verbosity.VERY_VERBOSE: logging.basicConfig( force=True, diff --git a/tests/llm/conftest.py b/tests/llm/conftest.py index 91a126d50a..12a486cf5f 100644 --- a/tests/llm/conftest.py +++ b/tests/llm/conftest.py @@ -535,12 +535,28 @@ def _collect_test_results_from_stats(terminalreporter): else: test_type = "unknown" + # Handle error cases - if there's an error, show it instead of generic message + actual_output = user_props.get("actual", "Unknown") + if actual_output in ["Test not executed", "Unknown"]: + # Check if we have error information + error_type = user_props.get("error_type") + error_message = user_props.get("error_message") + if error_type and error_message: + # Format error for display - keep it concise for table + if len(error_message) > 80: + # Truncate long error messages but keep the important part + actual_output = f"{error_type}: {error_message[:80]}..." + else: + actual_output = f"{error_type}: {error_message}" + elif error_type: + actual_output = f"Error: {error_type}" + # Store result (use nodeid as key to avoid duplicates) test_results[nodeid] = { "nodeid": nodeid, "test_type": test_type, "expected": user_props.get("expected", "Unknown"), - "actual": user_props.get("actual", "Unknown"), + "actual": actual_output, "tools_called": user_props.get("tools_called", []), "expected_correctness_score": float( user_props.get("expected_correctness_score", 1.0) @@ -556,11 +572,23 @@ def _collect_test_results_from_stats(terminalreporter): "is_setup_failure": user_props.get("is_setup_failure", False), "model": user_props.get("model", "Unknown"), "clean_test_case_id": user_props.get("clean_test_case_id"), - "error_message": str(report.longrepr) - if hasattr(report, "longrepr") and report.longrepr - else None, "braintrust_span_id": user_props.get("braintrust_span_id"), "braintrust_root_span_id": user_props.get("braintrust_root_span_id"), + # Cost tracking + "cost": user_props.get("cost", 0.0), + "total_tokens": user_props.get("total_tokens", 0), + "prompt_tokens": user_props.get("prompt_tokens", 0), + "completion_tokens": user_props.get("completion_tokens", 0), + # Tag tracking for performance analysis + "tags": user_props.get("tags", []), + # Error tracking for better reporting + "error_type": user_props.get("error_type"), + "error_message": user_props.get( + "error_message", + str(report.longrepr) + if hasattr(report, "longrepr") and report.longrepr + else None, + ), } # Extract test case names for all results diff --git a/tests/llm/test_ask_holmes.py b/tests/llm/test_ask_holmes.py index 68c69488ea..c4a189ee5c 100644 --- a/tests/llm/test_ask_holmes.py +++ b/tests/llm/test_ask_holmes.py @@ -44,6 +44,7 @@ print_tool_calls_detailed, ) from tests.llm.utils.iteration_utils import get_test_cases +from tests.llm.utils.braintrust import log_to_braintrust TEST_CASES_FOLDER = Path( path.abspath(path.join(path.dirname(__file__), "fixtures", "test_ask_holmes")) @@ -78,6 +79,8 @@ def test_ask_holmes( request.node.user_properties.append(("model", model)) # Add clean test case ID (without model suffix) request.node.user_properties.append(("clean_test_case_id", test_case.id)) + # Add tags for tag-based performance analysis + request.node.user_properties.append(("tags", test_case.tags or [])) # Check if test should be skipped check_and_skip_test(test_case) @@ -168,23 +171,29 @@ def test_ask_holmes( # Log error to span if available try: if "eval_span" in locals(): - # Prepare tags with model - tags = (test_case.tags or []).copy() - tags.append(f"model:{model}") - - eval_span.log( - input=test_case.user_prompt, - output=result.result if result else str(e), - expected=test_case.expected_output, - dataset_record_id=test_case.id, - scores={}, - tags=tags, + log_to_braintrust( + eval_span=eval_span, + test_case=test_case, + model=model, + result=result, + error=e, + mock_generation_config=mock_generation_config, ) except Exception: pass # Don't fail the test due to logging issues + # Store error information in user_properties for reporting + error_type = type(e).__name__ + error_message = str(e) + request.node.user_properties.append(("error_type", error_type)) + request.node.user_properties.append(("error_message", error_message)) + + # Store partial result if available + if result: + request.node.user_properties.append(("partial_output", result.result or "")) + # Check if this is a MockDataError - is_mock_error = "MockDataError" in type(e).__name__ or any( + is_mock_error = "MockDataError" in error_type or any( "MockData" in base.__name__ for base in type(e).__mro__ ) @@ -236,18 +245,13 @@ def test_ask_holmes( # Log evaluation results directly to the span if eval_span: - # Prepare tags with model - tags = (test_case.tags or []).copy() - tags.append(f"model:{model}") - - eval_span.log( - input=input, - output=output or "", - expected=str(expected), - dataset_record_id=test_case.id, + log_to_braintrust( + eval_span=eval_span, + test_case=test_case, + model=model, + result=result, scores=scores, - metadata={"system_prompt": prompt, "model": model}, - tags=tags, + mock_generation_config=mock_generation_config, ) # Print tool calls summary @@ -261,8 +265,8 @@ def test_ask_holmes( # Print detailed tool output print_tool_calls_detailed(result.tool_calls) - # Update test results - update_test_results(request, output, tools_called, scores) + # Update test results (including cost tracking) + update_test_results(request, output, tools_called, scores, result) # Check if the output contains MockDataError (indicating a mock failure) if output and any( @@ -369,5 +373,6 @@ def ask_holmes( start_time = time.time() result = ai.messages_call(messages=messages, trace_span=llm_span) holmes_duration = time.time() - start_time - eval_span.log(metadata={"Holmes Duration": holmes_duration}) + # Log duration directly to eval_span + eval_span.log(metadata={"holmes_duration": holmes_duration}) return result diff --git a/tests/llm/test_investigate.py b/tests/llm/test_investigate.py index 6047c7e25b..e7412f6469 100644 --- a/tests/llm/test_investigate.py +++ b/tests/llm/test_investigate.py @@ -29,6 +29,7 @@ from unittest.mock import patch from tests.llm.utils.iteration_utils import get_test_cases +from tests.llm.utils.braintrust import log_to_braintrust TEST_CASES_FOLDER = Path( path.abspath(path.join(path.dirname(__file__), "fixtures", "test_investigate")) @@ -96,6 +97,8 @@ def test_investigate( request.node.user_properties.append(("model", model)) # Add clean test case ID (without model suffix) request.node.user_properties.append(("clean_test_case_id", test_case.id)) + # Add tags for tag-based performance analysis + request.node.user_properties.append(("tags", test_case.tags or [])) # Check if test should be skipped check_and_skip_test(test_case) @@ -127,40 +130,82 @@ def test_investigate( if not investigate_request.sections: investigate_request.sections = DEFAULT_SECTIONS - with patch.dict( - os.environ, {"HOLMES_STRUCTURED_OUTPUT_CONVERSION_FEATURE_FLAG": "False"} - ): - with tracer.start_trace( - name=f"{test_case.id}[{model}]", span_type=SpanType.EVAL - ) as eval_span: - # Store span info in user properties for conftest to access - if hasattr(eval_span, "id"): - request.node.user_properties.append( - ("braintrust_span_id", str(eval_span.id)) - ) - if hasattr(eval_span, "root_span_id"): - request.node.user_properties.append( - ("braintrust_root_span_id", str(eval_span.root_span_id)) + try: + with patch.dict( + os.environ, {"HOLMES_STRUCTURED_OUTPUT_CONVERSION_FEATURE_FLAG": "False"} + ): + with tracer.start_trace( + name=f"{test_case.id}[{model}]", span_type=SpanType.EVAL + ) as eval_span: + # Store span info in user properties for conftest to access + if hasattr(eval_span, "id"): + request.node.user_properties.append( + ("braintrust_span_id", str(eval_span.id)) + ) + if hasattr(eval_span, "root_span_id"): + request.node.user_properties.append( + ("braintrust_root_span_id", str(eval_span.root_span_id)) + ) + + with set_test_env_vars(test_case): + with eval_span.start_span( + "Caching tools executor for create_issue_investigator", + type=SpanType.TASK.value, + ): + config.create_tool_executor(mock_dal) + with eval_span.start_span( + "Holmes Run", type=SpanType.TASK.value + ) as holmes_span: + start_time = time.time() + result = investigate_issues( + investigate_request=investigate_request, + config=config, + dal=mock_dal, + trace_span=holmes_span, + ) + holmes_duration = time.time() - start_time + # Log duration directly to eval_span + eval_span.log(metadata={"holmes_duration": holmes_duration}) + except Exception as e: + # Log error to span if available + try: + if "eval_span" in locals(): + log_to_braintrust( + eval_span=eval_span, + test_case=test_case, + model=model, + result=result, + error=e, + mock_generation_config=mock_generation_config, ) + except Exception: + pass # Don't fail the test due to logging issues + + # Store error information in user_properties for reporting + error_type = type(e).__name__ + error_message = str(e) + request.node.user_properties.append(("error_type", error_type)) + request.node.user_properties.append(("error_message", error_message)) + + # Store partial result if available + if result and hasattr(result, "analysis"): + request.node.user_properties.append( + ("partial_output", result.analysis or "") + ) + + # Check if this is a MockDataError + is_mock_error = "MockDataError" in error_type or any( + "MockData" in base.__name__ for base in type(e).__mro__ + ) + + if is_mock_error: + # Update properties for mock error (would need to import update_mock_error) + from tests.llm.utils.property_manager import update_mock_error + + update_mock_error(request, e) + + raise - with set_test_env_vars(test_case): - with eval_span.start_span( - "Caching tools executor for create_issue_investigator", - type=SpanType.TASK.value, - ): - config.create_tool_executor(mock_dal) - with eval_span.start_span( - "Holmes Run", type=SpanType.TASK.value - ) as holmes_span: - start_time = time.time() - result = investigate_issues( - investigate_request=investigate_request, - config=config, - dal=mock_dal, - trace_span=holmes_span, - ) - holmes_duration = time.time() - start_time - eval_span.log(metadata={"Holmes Duration": holmes_duration}) assert result, "No result returned by investigate_issues()" output = result.analysis @@ -195,18 +240,13 @@ def test_investigate( # Log evaluation results directly to the span if eval_span: - # Prepare tags with model - tags = (test_case.tags or []).copy() - tags.append(f"model:{model}") - - eval_span.log( - input=input, - output=output or "", - expected=str(expected), - dataset_record_id=test_case.id, + log_to_braintrust( + eval_span=eval_span, + test_case=test_case, + model=model, + result=result, scores=scores, - metadata={"model": model}, - tags=tags, + mock_generation_config=mock_generation_config, ) tools_called = [t.tool_name for t in result.tool_calls] print(f"\n** TOOLS CALLED **\n{tools_called}") @@ -214,8 +254,8 @@ def test_investigate( print(f"\n** SCORES **\n{scores}") # Store data for summary plugin - # Update test results - update_test_results(request, output, tools_called, scores) + # Update test results (including cost tracking) + update_test_results(request, output, tools_called, scores, result) assert result.sections, "Missing sections" assert ( diff --git a/tests/llm/utils/braintrust.py b/tests/llm/utils/braintrust.py index 671c1b3cdc..074bd1a498 100644 --- a/tests/llm/utils/braintrust.py +++ b/tests/llm/utils/braintrust.py @@ -2,6 +2,7 @@ import braintrust from braintrust import Dataset, Experiment, ReadonlyExperiment, Span import logging +import os from typing import Any, List, Optional, Union from tests.llm.utils.test_case_utils import HolmesTestCase # type: ignore @@ -169,6 +170,141 @@ def get_dataset_name(test_suite: str): return f"{test_suite}:{system_metadata.get('branch', 'unknown_branch')}" +def log_to_braintrust( + eval_span, + test_case: HolmesTestCase, + model: str, + result: Optional[Any] = None, # Can be LLMResult or InvestigationResult + scores: Optional[dict] = None, + error: Optional[Exception] = None, + mock_generation_config: Optional[Any] = None, +) -> None: + """Shared function to log evaluation data to Braintrust. + + Args: + eval_span: The Braintrust evaluation span + test_case: The test case being evaluated (AskHolmesTestCase or InvestigateTestCase) + model: The model being tested + result: The result object (LLMResult for ask, InvestigationResult for investigate) + scores: Dictionary of scores (e.g., correctness) + error: Exception if the test failed + mock_generation_config: Mock configuration for additional context + """ + from tests.llm.utils.test_case_utils import AskHolmesTestCase, InvestigateTestCase + + # Prepare tags + tags = (test_case.tags or []).copy() + tags.append(f"model:{model}") + + # Determine output based on test type and error state + if error: + if hasattr(result, "result"): # AskHolmesTestCase with LLMResult + output = result.result if result else str(error) + elif hasattr( + result, "analysis" + ): # InvestigateTestCase with InvestigationResult + output = result.analysis if result else str(error) + else: + output = str(error) + scores = scores or {} + else: + if hasattr(result, "result"): # AskHolmesTestCase with LLMResult + output = result.result if result else "" + elif hasattr( + result, "analysis" + ): # InvestigateTestCase with InvestigationResult + output = result.analysis if result else "" + else: + output = "" + + # Get prompt/system prompt for ask tests + prompt = None + if isinstance(test_case, AskHolmesTestCase): + if ( + result + and hasattr(result, "messages") + and result.messages + and len(result.messages) > 0 + ): + prompt = result.messages[0]["content"] + elif result and hasattr(result, "prompt"): + prompt = result.prompt + + # Build comprehensive metadata + metadata: dict[str, Any] = { + "model": model, + "eval_id": test_case.id, # Clean test case ID without model + } + + # Add test type for ask tests + if isinstance(test_case, AskHolmesTestCase): + metadata["test_type"] = ( + test_case.test_type or os.environ.get("ASK_HOLMES_TEST_TYPE", "cli").lower() + ) + + # Add prompt if available + if prompt: + metadata["system_prompt"] = prompt + + # Add execution context + if mock_generation_config and hasattr(mock_generation_config, "mode"): + metadata["mock_mode"] = mock_generation_config.mode.value + + # Add test configuration if present + if hasattr(test_case, "conversation_history") and test_case.conversation_history: + metadata["has_conversation_history"] = True + if hasattr(test_case, "runbooks") and test_case.runbooks is not None: + metadata["has_custom_runbooks"] = True + + # Add tool usage metrics if available + if result: + if hasattr(result, "tool_calls") and result.tool_calls: + metadata["tool_call_count"] = len(result.tool_calls) + metadata["tools_used"] = list( + { + tc.tool_name if hasattr(tc, "tool_name") else tc.description + for tc in result.tool_calls + } + ) + # Note: holmes_duration is logged separately directly to eval_span in ask_holmes() + + # Add error information if present + if error: + metadata["error_type"] = type(error).__name__ + metadata["error_message"] = str(error) + is_mock_error = "MockDataError" in type(error).__name__ or any( + "MockData" in base.__name__ for base in type(error).__mro__ + ) + if is_mock_error: + metadata["is_mock_data_error"] = True + + # Determine input and expected based on test type + if isinstance(test_case, AskHolmesTestCase): + input_data = test_case.user_prompt + expected = ( + test_case.expected_output + if isinstance(test_case.expected_output, str) + else str(test_case.expected_output) + ) + elif isinstance(test_case, InvestigateTestCase): + input_data = str(test_case.investigate_request) + expected = str(test_case.expected_output) + else: + input_data = "" + expected = "" + + # Log to Braintrust + eval_span.log( + input=input_data, + output=output, + expected=expected, + dataset_record_id=test_case.id, + scores=scores or {}, + metadata=metadata, + tags=tags, + ) + + def get_braintrust_url( span_id: Optional[str] = None, root_span_id: Optional[str] = None, diff --git a/tests/llm/utils/property_manager.py b/tests/llm/utils/property_manager.py index c17c098d20..68f476f226 100644 --- a/tests/llm/utils/property_manager.py +++ b/tests/llm/utils/property_manager.py @@ -50,9 +50,21 @@ def update_property(request, key: str, value: Any) -> None: def update_test_results( - request, output: str, tools_called: Union[List[str], str], scores: dict + request, + output: str, + tools_called: Union[List[str], str], + scores: dict, + result: Any = None, ) -> None: - """Update test result properties after test execution.""" + """Update test result properties after test execution. + + Args: + request: The pytest request object + output: The test output string + tools_called: List of tools called or a string description + scores: Dictionary of scores (e.g., correctness) + result: Optional result object (LLMResult or InvestigationResult) containing cost info + """ update_property(request, "actual", output or "") update_property( request, @@ -61,6 +73,40 @@ def update_test_results( ) update_property(request, "actual_correctness_score", scores.get("correctness", 0)) + # Log test cost information and add to user properties if available + if result: + import logging + + # Check for cost tracking in LLMResult (from ask_holmes tests) + if hasattr(result, "total_cost") and result.total_cost > 0: + test_case_id = None + model = None + # Extract test_case_id and model from user_properties + for key, value in request.node.user_properties: + if key == "clean_test_case_id": + test_case_id = value + elif key == "model": + model = value + + if test_case_id and model: + logging.info( + f"Test {test_case_id} with {model} - Total cost: ${result.total_cost:.6f}, Total tokens: {result.total_tokens if hasattr(result, 'total_tokens') else 'N/A'}" + ) + + request.node.user_properties.append(("cost", result.total_cost)) + if hasattr(result, "total_tokens"): + request.node.user_properties.append( + ("total_tokens", result.total_tokens) + ) + if hasattr(result, "prompt_tokens"): + request.node.user_properties.append( + ("prompt_tokens", result.prompt_tokens) + ) + if hasattr(result, "completion_tokens"): + request.node.user_properties.append( + ("completion_tokens", result.completion_tokens) + ) + def update_mock_error(request, error: Exception) -> None: """Update properties when a mock error occurs.""" diff --git a/tests/llm/utils/reporting/terminal_reporter.py b/tests/llm/utils/reporting/terminal_reporter.py index 60c2dcd404..3e27921065 100644 --- a/tests/llm/utils/reporting/terminal_reporter.py +++ b/tests/llm/utils/reporting/terminal_reporter.py @@ -1,7 +1,8 @@ """Terminal reporting functionality for test results.""" import textwrap -from typing import List, Dict, Optional, Any +from enum import Enum +from typing import List, Dict, Optional, Any, Tuple from collections import defaultdict from rich.console import Console @@ -10,6 +11,66 @@ from tests.llm.utils.test_results import TestStatus, TestResult +class ResultType(Enum): + """Types of test results to count.""" + + PASSED = "passed" + FAILED = "failed" # Real test failures + SKIPPED = "skipped" + SETUP_FAILED = "setup_failed" + MOCK_FAILED = "mock_failed" + VALID_RUNS = "valid_runs" # Not skipped or setup failed + ALL = "all" + + +def count_results(results: List[dict], result_type: ResultType) -> int: + """Count results of a specific type. + + Args: + results: List of test result dictionaries + result_type: Type of results to count + + Returns: + Count of results matching the type + """ + if not results: + return 0 + + if result_type == ResultType.ALL: + return len(results) + + if result_type == ResultType.PASSED: + return sum(1 for r in results if TestStatus(r).passed) + + if result_type == ResultType.SKIPPED: + return sum(1 for r in results if r.get("status") == "skipped") + + if result_type == ResultType.SETUP_FAILED: + return sum(1 for r in results if r.get("is_setup_failure", False)) + + if result_type == ResultType.MOCK_FAILED: + return sum(1 for r in results if r.get("mock_data_failure", False)) + + if result_type == ResultType.FAILED: + # Real failures (not mock or setup) + return sum( + 1 + for r in results + if not TestStatus(r).passed + and not r.get("mock_data_failure", False) + and not r.get("is_setup_failure", False) + and r.get("status") != "skipped" + ) + + if result_type == ResultType.VALID_RUNS: + # Runs that actually executed (not skipped or setup failed) + skipped = count_results(results, ResultType.SKIPPED) + setup_failed = count_results(results, ResultType.SETUP_FAILED) + return len(results) - skipped - setup_failed + + raise ValueError(f"Unknown result type: {result_type}") + + def _calculate_p90(times: List[float]) -> float: """Calculate the 90th percentile of a list of times. @@ -30,20 +91,6 @@ def _calculate_p90(times: List[float]) -> float: return sorted_times[p90_index] -def _calculate_valid_runs(results: List[dict]) -> int: - """Calculate the number of valid test runs (excluding skipped and setup failures). - - Args: - results: List of test results - - Returns: - Number of valid runs - """ - setup_failures = sum(1 for r in results if r.get("is_setup_failure", False)) - skipped = sum(1 for r in results if r.get("status") == "skipped") - return len(results) - setup_failures - skipped - - def _calculate_pass_percentage(passed: int, valid_runs: int) -> float: """Calculate pass percentage from passed count and valid runs. @@ -136,9 +183,10 @@ def handle_console_output(sorted_results: List[dict], terminalreporter=None) -> table.add_column("Test", style="cyan", width=12) table.add_column("Status", justify="center", width=13) table.add_column("Time", justify="right", width=10) - table.add_column("User Prompt", style="white", width=20) - table.add_column("Expected", style="green", width=20) - table.add_column("Actual", style="yellow", width=20) + table.add_column("Cost", justify="right", width=8) + table.add_column("User Prompt", style="white", width=18) + table.add_column("Expected", style="green", width=18) + table.add_column("Actual", style="yellow", width=18) # Add rows to table for result in sorted_results: @@ -171,26 +219,16 @@ def handle_console_output(sorted_results: List[dict], terminalreporter=None) -> # Wrap test name to fit column test_name_wrapped = "\n".join(textwrap.wrap(combined_test_name, width=10)) - # Format execution time with P90 if available + # Format execution time - show individual time for this specific test run exec_time = result.get("execution_time") - if exec_time: - # Get the test case name to look up all times for this test - test_case_name = result["test_case_name"] - # Find all execution times for this specific test case (across all models) - test_times = [] - for r in sorted_results: - if r["test_case_name"] == test_case_name and r.get("execution_time"): - test_times.append(r["execution_time"]) - - # Calculate average time for multiple runs - if len(test_times) > 1: - avg_time = sum(test_times) / len(test_times) - p90 = _calculate_p90(test_times) - time_str = f"Avg: {avg_time:.1f}s\nP90: {p90:.1f}s" - else: - time_str = f"{exec_time:.1f}s" + time_str = _format_time(exec_time) + + # Format cost - show individual cost for this specific test run + cost = result.get("cost", 0) + if cost > 0: + cost_str = f"${cost:.4f}" else: - time_str = "N/A" + cost_str = "โ€”" # Disabled for now - get analysis for failed tests with openai # analysis = _get_analysis_for_result(test_result) @@ -199,6 +237,7 @@ def handle_console_output(sorted_results: List[dict], terminalreporter=None) -> test_name_wrapped, status.console_status, time_str, + cost_str, user_prompt_wrapped, expected_wrapped, actual_wrapped, @@ -207,9 +246,12 @@ def handle_console_output(sorted_results: List[dict], terminalreporter=None) -> # Use force_terminal to ensure output is displayed even when captured console.print(table) - # Print summary statistics table + # Print summary statistics table (always shown) _print_summary_statistics(sorted_results, console) + # Print model comparison tables if multiple models detected + _print_model_comparison_if_multiple(sorted_results, console) + def _get_analysis_for_result(result: TestResult) -> str: """Get analysis text for a test result, with proper text wrapping.""" @@ -299,6 +341,416 @@ def _get_status_emoji( return "โš ๏ธ" +def _get_pass_color(pass_pct: float, bold: bool = False) -> str: + """Get color for pass percentage. + + Args: + pass_pct: Pass percentage (0-100) + bold: Whether to use bold variant + + Returns: + Color name for Rich formatting + """ + base_color = "green" if pass_pct == 100 else "red" if pass_pct == 0 else "yellow" + return f"bold {base_color}" if bold else base_color + + +def _format_pass_percentage(pass_pct: float, with_emoji: bool = False) -> str: + """Format pass percentage with color and optionally emoji. + + Args: + pass_pct: Pass percentage (0-100) + with_emoji: Whether to include emoji prefix + + Returns: + Formatted string with Rich color tags + """ + color = _get_pass_color(pass_pct) + + if with_emoji: + emoji = _get_status_emoji(pass_pct) + return f"{emoji} [{color}]{pass_pct:.1f}%[/{color}]" + else: + return f"[{color}]{pass_pct:.1f}%[/{color}]" + + +def _create_separator_row(column_widths: List[int]) -> List[str]: + """Create a separator row for tables. + + Args: + column_widths: List of column widths + + Returns: + List of separator strings + """ + return ["โ”€" * width for width in column_widths] + + +def _format_time(time_value: Optional[float], default: str = "N/A") -> str: + """Format a time value for display. + + Args: + time_value: Time in seconds or None + default: Default string if time is None or <= 0 + + Returns: + Formatted time string + """ + return f"{time_value:.1f}s" if time_value and time_value > 0 else default + + +def _get_time_color(value: float, best: float, worst: float) -> str: + """Get color for a time value based on best/worst in the set. + + Args: + value: The time value to color + best: The best (minimum) time + worst: The worst (maximum) time + + Returns: + Color name for Rich formatting + """ + if best == worst: + # All times are the same + return "" + elif value == best: + return "green" + elif value == worst: + return "red" + else: + return "yellow" + + +def _format_colored_times( + times_dict: Dict[str, Optional[float]], label: str = "" +) -> List[str]: + """Format a row of times with appropriate coloring. + + Args: + times_dict: Dictionary mapping model names to time values + label: Optional label prefix for the time (e.g., "Avg: ") + + Returns: + List of formatted time strings for each model + """ + # Filter out None values + valid_times = [(k, v) for k, v in times_dict.items() if v is not None and v > 0] + + if not valid_times: + return ["โ€”"] * len(times_dict) + + # Find best and worst + time_values = [v for _, v in valid_times] + best_time = min(time_values) + worst_time = max(time_values) + + # Build formatted strings + result = [] + for model in times_dict.keys(): + time_val = times_dict[model] + if time_val is None or time_val <= 0: + result.append("โ€”") + else: + time_str = f"{time_val:.1f}s" + color = _get_time_color(time_val, best_time, worst_time) + if color: + result.append(f"{label}[{color}]{time_str}[/{color}]") + else: + result.append(f"{label}{time_str}") + + return result + + +def _format_colored_costs(costs_dict: Dict[str, float]) -> List[str]: + """Format a row of costs with appropriate coloring (cheapest=green, most expensive=red). + + Args: + costs_dict: Dictionary mapping model names to cost values + + Returns: + List of formatted cost strings for each model + """ + # Filter out zero/None values + valid_costs = [(k, v) for k, v in costs_dict.items() if v and v > 0] + + if not valid_costs: + return ["โ€”"] * len(costs_dict) + + # Find cheapest and most expensive + cost_values = [v for _, v in valid_costs] + cheapest = min(cost_values) + most_expensive = max(cost_values) + + # Build formatted strings + result = [] + for model in costs_dict.keys(): + cost = costs_dict[model] + if cost is None or cost <= 0: + result.append("โ€”") + else: + cost_str = f"${cost:.4f}" + # Color: green for cheapest, red for most expensive, yellow for middle + if cheapest == most_expensive: + # All costs are the same + result.append(cost_str) + elif cost == cheapest: + result.append(f"[green]{cost_str}[/green]") + elif cost == most_expensive: + result.append(f"[red]{cost_str}[/red]") + else: + result.append(f"[yellow]{cost_str}[/yellow]") + + return result + + +class TestStatistics: + """Calculates statistics for test results.""" + + def __init__(self, results: List[dict]): + """Initialize with test results. + + Args: + results: List of test result dictionaries + """ + self.results = results + self._build_data() + + def _build_data(self) -> None: + """Organize results by test case and model.""" + self._data: Dict[str, Dict[str, List[dict]]] = defaultdict( + lambda: defaultdict(list) + ) + + for result in self.results: + model = result.get("model", "Unknown") + test_case = result["test_case_name"] + self._data[test_case][model].append(result) + + self._models = sorted({r.get("model", "Unknown") for r in self.results}) + self._test_cases = sorted(self._data.keys()) + + @property + def models(self) -> List[str]: + """Get sorted list of unique models.""" + return self._models + + @property + def test_cases(self) -> List[str]: + """Get sorted list of unique test cases.""" + return self._test_cases + + def _calculate_stats_for_results( + self, results: List[dict] + ) -> Optional[Dict[str, Any]]: + """Calculate statistics for a list of results. + + Args: + results: List of result dictionaries + + Returns: + Dictionary with statistics or None if no results + """ + if not results: + return None + + # Calculate all statistics using count_results + runs = count_results(results, ResultType.ALL) + passed = count_results(results, ResultType.PASSED) + skipped = count_results(results, ResultType.SKIPPED) + setup_failures = count_results(results, ResultType.SETUP_FAILED) + valid_runs = count_results(results, ResultType.VALID_RUNS) + + times = [r.get("execution_time", 0) for r in results if r.get("execution_time")] + + # Calculate cost metrics + total_cost = sum(r.get("cost", 0) for r in results) + avg_cost = total_cost / len(results) if results else 0 + + return { + "runs": runs, + "passed": passed, + "skipped": skipped, + "setup_failures": setup_failures, + "times": times, + "avg_time": sum(times) / len(times) if times else None, + "valid_runs": valid_runs, + "pass_rate": (passed / valid_runs * 100) if valid_runs > 0 else 0, + "total_cost": total_cost, + "avg_cost": avg_cost, + } + + def get_stats(self, test_case: str, model: str) -> Optional[Dict[str, Any]]: + """Get statistics for a specific test case and model combination. + + Args: + test_case: Name of the test case + model: Name of the model + + Returns: + Dictionary with statistics or None if no results exist + """ + results = self._data[test_case].get(model, []) + return self._calculate_stats_for_results(results) + + def get_test_times(self, test_case: str) -> Dict[str, Optional[float]]: + """Get average execution times for a test case across all models. + + Args: + test_case: Name of the test case + + Returns: + Dictionary mapping model names to average times + """ + result = {} + for model in self.models: + stats = self.get_stats(test_case, model) + result[model] = stats["avg_time"] if stats else None + return result + + def get_test_time_range( + self, test_case: str + ) -> Tuple[Optional[float], Optional[float]]: + """Get min and max average times for a test case across models. + + Args: + test_case: Name of the test case + + Returns: + Tuple of (min_time, max_time) or (None, None) if no valid times + """ + times = [t for t in self.get_test_times(test_case).values() if t and t > 0] + return (min(times), max(times)) if times else (None, None) + + def get_model_summary(self, model: str) -> Dict[str, Any]: + """Get summary statistics for a model across all test cases. + + Args: + model: Name of the model + + Returns: + Dictionary with aggregate statistics + """ + summaries = [self.get_stats(test_case, model) for test_case in self.test_cases] + + # Filter out None results + valid_summaries = [s for s in summaries if s] + + if not valid_summaries: + return { + "runs": 0, + "passed": 0, + "skipped": 0, + "setup_failures": 0, + "pass_rate": 0, + "avg_time": None, + "p90_time": None, + "all_times": [], + } + + total_runs = sum(s["runs"] for s in valid_summaries) + total_passed = sum(s["passed"] for s in valid_summaries) + total_skipped = sum(s["skipped"] for s in valid_summaries) + total_setup_fail = sum(s["setup_failures"] for s in valid_summaries) + total_cost = sum(s.get("total_cost", 0) for s in valid_summaries) + + all_times = [] + for s in valid_summaries: + all_times.extend(s["times"]) + + valid_runs = total_runs - total_skipped - total_setup_fail + + return { + "runs": total_runs, + "passed": total_passed, + "skipped": total_skipped, + "setup_failures": total_setup_fail, + "pass_rate": (total_passed / valid_runs * 100) if valid_runs > 0 else 0, + "avg_time": sum(all_times) / len(all_times) if all_times else None, + "p90_time": _calculate_p90(all_times) if all_times else None, + "all_times": all_times, + "total_cost": total_cost, + } + + def get_model_times(self, metric: str = "avg") -> Dict[str, Optional[float]]: + """Get time metric for all models. + + Args: + metric: "avg" or "p90" + + Returns: + Dictionary mapping model names to time values + """ + result = {} + for model in self.models: + summary = self.get_model_summary(model) + if metric == "avg": + result[model] = summary["avg_time"] + elif metric == "p90": + result[model] = summary["p90_time"] + else: + raise ValueError(f"Unknown metric: {metric}") + return result + + def get_model_costs(self) -> Dict[str, float]: + """Get total cost for all models. + + Returns: + Dictionary mapping model names to total costs + """ + result = {} + for model in self.models: + summary = self.get_model_summary(model) + result[model] = summary.get("total_cost", 0.0) + return result + + def get_unique_tags(self) -> List[str]: + """Get sorted list of all unique tags across all test results. + + Returns: + Sorted list of unique tag strings + """ + tags = set() + for result in self.results: + result_tags = result.get("tags", []) + if result_tags: + tags.update(result_tags) + return sorted(tags) + + def get_tag_stats(self, tag: str, model: str) -> Optional[Dict[str, Any]]: + """Get statistics for a specific tag-model combination. + + Args: + tag: Tag name to filter by + model: Model name to filter by + + Returns: + Dictionary with statistics (same format as get_stats) or None if no results + """ + # Collect all results for this model that have the specified tag + results = [] + for test_case in self._test_cases: + model_results = self._data[test_case].get(model, []) + for result in model_results: + if tag in result.get("tags", []): + results.append(result) + + return self._calculate_stats_for_results(results) + + def get_time_range( + self, model_times: Dict[str, Optional[float]] + ) -> Tuple[Optional[float], Optional[float]]: + """Get min and max from a dictionary of times. + + Args: + model_times: Dictionary mapping names to time values + + Returns: + Tuple of (min_time, max_time) or (None, None) if no valid times + """ + valid_times = [t for t in model_times.values() if t is not None and t > 0] + return (min(valid_times), max(valid_times)) if valid_times else (None, None) + + def _detect_multiple_models(sorted_results: List[dict]) -> bool: """Detect if results contain multiple models. @@ -320,23 +772,8 @@ def _print_model_comparison_table(sorted_results: List[dict], console: Console) if not sorted_results: return - # Group results by test case and model - test_model_groups: Dict[str, Dict[str, List[dict]]] = defaultdict( - lambda: defaultdict(list) - ) - models = set() - - for result in sorted_results: - model = result.get("model", "Unknown") - models.add(model) - - # Use the test_case_name which is already clean - test_case = result["test_case_name"] - - test_model_groups[test_case][model].append(result) - - # Sort models for consistent column order - sorted_models = sorted(models) + # Use TestStatistics for all calculations + stats = TestStatistics(sorted_results) # Create comparison table comparison_table = Table( @@ -349,77 +786,57 @@ def _print_model_comparison_table(sorted_results: List[dict], console: Console) # Add columns comparison_table.add_column("Test Case", style="bright_blue", width=30) - for model in sorted_models: + for model in stats.models: comparison_table.add_column(model, justify="center", width=22) # Process each test case - model_totals: Dict[str, Dict[str, Any]] = { - model: { - "runs": 0, - "pass": 0, - "times": [], - "setup_fail": 0, - "mock_fail": 0, - "skip": 0, - } - for model in sorted_models - } - - for test_case in sorted(test_model_groups.keys()): + for test_case in stats.test_cases: row_data = [test_case] - for model in sorted_models: - results = test_model_groups[test_case].get(model, []) + # Get time bounds for coloring this row + min_time, max_time = stats.get_test_time_range(test_case) - if not results: + for model in stats.models: + test_stats = stats.get_stats(test_case, model) + + if not test_stats: row_data.append("โ€”") continue - # Calculate statistics for this test/model combination - runs = len(results) - passed = sum(1 for r in results if TestStatus(r).passed) - skipped = sum(1 for r in results if r.get("status") == "skipped") - setup_failures = sum(1 for r in results if r.get("is_setup_failure", False)) - mock_failures = sum(1 for r in results if r.get("mock_data_failure", False)) - - # Calculate times - times = [ - r.get("execution_time", 0) for r in results if r.get("execution_time") - ] - avg_time = sum(times) / len(times) if times else 0 - - # Update model totals - model_totals[model]["runs"] += runs - model_totals[model]["pass"] += passed - model_totals[model]["times"].extend(times) - model_totals[model]["setup_fail"] += setup_failures - model_totals[model]["mock_fail"] += mock_failures - model_totals[model]["skip"] += skipped - # Determine display based on status - if skipped == runs: + if test_stats["skipped"] == test_stats["runs"]: cell_text = "[cyan]Skipped[/cyan]" - elif setup_failures == runs: + elif test_stats["setup_failures"] == test_stats["runs"]: cell_text = "[magenta]Setup Fail[/magenta]" else: - # Calculate pass percentage from valid runs - valid_runs = _calculate_valid_runs(results) - pass_pct = _calculate_pass_percentage(passed, valid_runs) - - # Choose color based on pass percentage - if pass_pct == 100: - color = "green" - elif pass_pct >= 50: - color = "yellow" - else: - color = "red" + # Choose score color based on pass percentage + pass_pct = test_stats["pass_rate"] + score_color = _get_pass_color(pass_pct) # Format as 3 lines: Score, Pass count, Avg time cell_lines = [] - cell_lines.append(f"[{color}]{pass_pct:.0f}%[/{color}]") - cell_lines.append(f"{passed}/{valid_runs}") - if avg_time > 0: - cell_lines.append(f"Avg: {avg_time:.1f}s") + cell_lines.append( + f"Score: [{score_color}]{pass_pct:.0f}%[/{score_color}]" + ) + cell_lines.append( + f"Pass: {test_stats['passed']}/{test_stats['valid_runs']}" + ) + + # Color time based on best/worst in row + if test_stats["avg_time"]: + time_str = f"{test_stats['avg_time']:.1f}s" + if min_time is not None and max_time is not None: + time_color = _get_time_color( + test_stats["avg_time"], min_time, max_time + ) + if time_color: + cell_lines.append( + f"Avg: [{time_color}]{time_str}[/{time_color}]" + ) + else: + cell_lines.append(f"Avg: {time_str}") + else: + cell_lines.append(f"Avg: {time_str}") cell_text = "\n".join(cell_lines) @@ -428,70 +845,57 @@ def _print_model_comparison_table(sorted_results: List[dict], console: Console) comparison_table.add_row(*row_data) # Add separator - separator_row = ["โ”€" * 28] + ["โ”€" * 18] * len(sorted_models) + separator_row = _create_separator_row([28] + [18] * len(stats.models)) comparison_table.add_row(*separator_row, style="dim") # Add model average row average_row = ["Model Average"] - for model in sorted_models: - totals = model_totals[model] - if totals["runs"] > 0: - # Calculate pass percentage from valid runs - valid_runs = totals["runs"] - totals["setup_fail"] - totals["skip"] - pass_pct = _calculate_pass_percentage(totals["pass"], valid_runs) - if valid_runs > 0: - # Choose color based on pass percentage - if pass_pct == 100: - color = "bold green" - elif pass_pct >= 50: - color = "bold yellow" - else: - color = "bold red" - average_row.append(f"[{color}]{pass_pct:.1f}%[/{color}]") - else: - average_row.append("โ€”") + model_costs = {} # Track costs for comparison logging + for model in stats.models: + summary = stats.get_model_summary(model) + if summary["runs"] > 0 and summary["pass_rate"] is not None: + pass_pct = summary["pass_rate"] + # Choose color based on pass percentage + color = _get_pass_color(pass_pct, bold=True) + average_row.append(f"[{color}]{pass_pct:.1f}%[/{color}]") + + # Track model costs if available + if "total_cost" in summary: + model_costs[model] = summary["total_cost"] else: average_row.append("โ€”") comparison_table.add_row(*average_row) - # Add average time row - time_row = ["Average Time"] - for model in sorted_models: - times = model_totals[model]["times"] - if times: - avg_time = sum(times) / len(times) - time_row.append(f"{avg_time:.1f}s") - else: - time_row.append("โ€”") + # Add average time row with coloring + avg_times_dict = stats.get_model_times("avg") + time_row = ["Average Time"] + _format_colored_times(avg_times_dict) comparison_table.add_row(*time_row) - # Add P90 time row - p90_row = ["P90 Time"] - for model in sorted_models: - times = model_totals[model]["times"] - if times: - p90_time = _calculate_p90(times) - p90_row.append(f"{p90_time:.1f}s") - else: - p90_row.append("โ€”") + # Add P90 time row with coloring + p90_times_dict = stats.get_model_times("p90") + p90_row = ["P90 Time"] + _format_colored_times(p90_times_dict) comparison_table.add_row(*p90_row) + # Add Total Cost row with coloring + costs_dict = stats.get_model_costs() + cost_row = ["Total Cost"] + _format_colored_costs(costs_dict) + comparison_table.add_row(*cost_row) + console.print(comparison_table) # Print summary - total_tests = len(test_model_groups) + total_tests = len(stats.test_cases) console.print( - f"\n[dim]Compared {len(sorted_models)} models across {total_tests} test cases[/dim]" + f"\n[dim]Compared {len(stats.models)} models across {total_tests} test cases[/dim]" ) # Find best performing model(s) best_models = [] best_pass_pct = 0.0 - for model in sorted_models: - totals = model_totals[model] - valid_runs = totals["runs"] - totals["setup_fail"] - totals["skip"] - pass_pct = _calculate_pass_percentage(totals["pass"], valid_runs) - if valid_runs > 0: + for model in stats.models: + summary = stats.get_model_summary(model) + pass_pct = summary["pass_rate"] + if summary["runs"] > 0: if pass_pct > best_pass_pct: best_pass_pct = pass_pct best_models = [model] @@ -501,23 +905,140 @@ def _print_model_comparison_table(sorted_results: List[dict], console: Console) if best_models: if len(best_models) == 1: console.print( - f"[bold green]Best performing model: {best_models[0]} ({best_pass_pct:.1f}% pass rate)[/bold green]" + f"[cyan]Best performing model: {best_models[0]} ({best_pass_pct:.1f}% pass rate)[/cyan]" ) else: models_str = ", ".join(best_models) console.print( - f"[bold green]Best performing models: {models_str} ({best_pass_pct:.1f}% pass rate)[/bold green]" + f"[cyan]Best performing models: {models_str} ({best_pass_pct:.1f}% pass rate)[/cyan]" ) + # Calculate and print total evaluation cost + total_cost = sum(model_costs.values()) if model_costs else 0 + if total_cost > 0: + # Count unique test cases across all models + unique_tests = len(set(r["test_case_name"] for r in sorted_results)) + avg_cost_per_test = total_cost / unique_tests if unique_tests else 0 + console.print( + f"[cyan]Total evaluation cost: ${total_cost:.4f}, Average per test: ${avg_cost_per_test:.6f}[/cyan]" + ) -def _print_summary_statistics(sorted_results: List[dict], console: Console) -> None: - """Print a summary statistics table similar to pytest coverage reports.""" + # Print cost comparison if available (after total cost) + if model_costs and len(model_costs) >= 2: + sorted_costs = sorted(model_costs.items(), key=lambda x: x[1]) + cheapest_model, cheapest_cost = sorted_costs[0] + most_expensive_model, most_expensive_cost = sorted_costs[-1] + + if cheapest_cost > 0: + diff_pct = (most_expensive_cost / cheapest_cost - 1) * 100 + console.print( + f"[cyan]Cost comparison - Cheapest: {cheapest_model} (${cheapest_cost:.4f}) vs Most expensive: {most_expensive_model} (${most_expensive_cost:.4f}) - Difference: {diff_pct:+.1f}%[/cyan]" + ) + + +def _print_tag_performance_table(sorted_results: List[dict], console: Console) -> None: + """Print a performance table organized by eval tags.""" if not sorted_results: return - # Check if we should use model comparison view - if _detect_multiple_models(sorted_results): - _print_model_comparison_table(sorted_results, console) + # Use TestStatistics for all calculations + stats = TestStatistics(sorted_results) + + # Get unique tags + tags = stats.get_unique_tags() + if not tags: + return # No tags to display + + # Create tag performance table + tag_table = Table( + title="\n๐Ÿ“ PERFORMANCE BY EVAL TAG", + show_header=True, + header_style="bold magenta", + show_lines=True, + padding=(0, 1), + ) + + # Add columns + tag_table.add_column("Tag", style="cyan", width=20) + for model in stats.models: + tag_table.add_column(model, justify="center", width=18) + + # Process each tag + overall_by_model = {model: {"passed": 0, "total": 0} for model in stats.models} + + for tag in tags: + row_data = [tag] + + for model in stats.models: + tag_stats = stats.get_tag_stats(tag, model) + + if not tag_stats or tag_stats["valid_runs"] == 0: + row_data.append("โ€”") + else: + # Track overall stats + overall_by_model[model]["passed"] += tag_stats["passed"] + overall_by_model[model]["total"] += tag_stats["valid_runs"] + + # Format cell with pass percentage and count + pass_pct = tag_stats["pass_rate"] + + # Choose color based on pass percentage + color = _get_pass_color(pass_pct) + + cell_text = f"[{color}]{pass_pct:.0f}%[/{color}] ({tag_stats['passed']}/{tag_stats['valid_runs']})" + row_data.append(cell_text) + + tag_table.add_row(*row_data) + + # Add separator + separator_row = _create_separator_row([18] + [16] * len(stats.models)) + tag_table.add_row(*separator_row, style="dim") + + # Add overall row + overall_row = ["[bold]Overall[/bold]"] + for model in stats.models: + if overall_by_model[model]["total"] > 0: + overall_passed = overall_by_model[model]["passed"] + overall_total = overall_by_model[model]["total"] + overall_pct = overall_passed / overall_total * 100 + + # Choose color based on percentage + color = _get_pass_color(overall_pct, bold=True) + + overall_row.append( + f"[{color}]{overall_pct:.0f}%[/{color}] ({overall_passed}/{overall_total})" + ) + else: + overall_row.append("โ€”") + + tag_table.add_row(*overall_row) + + console.print(tag_table) + + # Print summary + console.print( + f"\n[dim]Tag performance across {len(tags)} tags and {len(stats.models)} models[/dim]" + ) + + +def _print_model_comparison_if_multiple( + sorted_results: List[dict], console: Console +) -> None: + """Print model comparison and tag performance tables if multiple models detected.""" + if not sorted_results: + return + + # Only show these tables for multiple models + if not _detect_multiple_models(sorted_results): + return + + _print_model_comparison_table(sorted_results, console) + _print_tag_performance_table(sorted_results, console) + + +def _print_summary_statistics(sorted_results: List[dict], console: Console) -> None: + """Print a summary statistics table similar to pytest coverage reports.""" + if not sorted_results: return # Group results by test name (without iteration number) @@ -564,27 +1085,20 @@ def _print_summary_statistics(sorted_results: List[dict], console: Console) -> N total_skip += len(results) continue - runs = len(results) - passed = sum(1 for r in results if TestStatus(r).passed) + runs = count_results(results, ResultType.ALL) + passed = count_results(results, ResultType.PASSED) # Count different failure types - setup_failures = sum(1 for r in results if r.get("is_setup_failure", False)) - mock_failures = sum(1 for r in results if r.get("mock_data_failure", False)) - other_failures = sum( - 1 - for r in results - if not TestStatus(r).passed - and not r.get("mock_data_failure", False) - and not r.get("is_setup_failure", False) - and r.get("status") != "skipped" - ) + setup_failures = count_results(results, ResultType.SETUP_FAILED) + mock_failures = count_results(results, ResultType.MOCK_FAILED) + other_failures = count_results(results, ResultType.FAILED) # Determine pass percentage display all_skipped = all(r.get("status") == "skipped" for r in results) all_setup_fail = setup_failures == runs # Calculate pass percentage from valid runs - valid_runs = _calculate_valid_runs(results) + valid_runs = count_results(results, ResultType.VALID_RUNS) pass_pct = _calculate_pass_percentage(passed, valid_runs) # Calculate average and P90 execution time @@ -599,18 +1113,17 @@ def _print_summary_statistics(sorted_results: List[dict], console: Console) -> N total_setup_fail += setup_failures total_mock_fail += mock_failures - # Format pass percentage with emoji + # Format pass percentage with color (no emoji) if all_skipped: - pass_pct_str = "โญ๏ธ Skipped" + pass_pct_str = "[cyan]Skipped[/cyan]" elif all_setup_fail: - pass_pct_str = "๐Ÿ”ง Setup Fail" + pass_pct_str = "[magenta]Setup Fail[/magenta]" else: - emoji = _get_status_emoji(pass_pct) indicators = _get_failure_indicators(mock_failures, setup_failures, runs) - pass_pct_str = f"{emoji} {pass_pct:.1f}%{indicators}" + pass_pct_str = f"{_format_pass_percentage(pass_pct)}{indicators}" - avg_time_str = f"{avg_time:.1f}s" if avg_time > 0 else "N/A" - p90_time_str = f"{p90_time:.1f}s" if p90_time > 0 else "N/A" + avg_time_str = _format_time(avg_time) + p90_time_str = _format_time(p90_time) # Add row summary_table.add_row( @@ -626,25 +1139,14 @@ def _print_summary_statistics(sorted_results: List[dict], console: Console) -> N ) # Add separator - summary_table.add_row( - "โ”€" * 38, - "โ”€" * 4, - "โ”€" * 4, - "โ”€" * 4, - "โ”€" * 8, - "โ”€" * 8, - "โ”€" * 6, - "โ”€" * 8, - "โ”€" * 8, - style="dim", - ) + separator_row = _create_separator_row([38, 4, 4, 4, 8, 8, 6, 8, 8]) + summary_table.add_row(*separator_row, style="dim") # Add totals row total_actual_runs = total_runs total_pass_pct = _calculate_pass_percentage(total_pass, total_actual_runs) - # Format total pass percentage with emoji - total_emoji = _get_status_emoji(total_pass_pct) + # Format total pass percentage with color (no emoji) # For totals, always show indicators if any failures exist total_indicators = "" if total_mock_fail > 0: @@ -652,6 +1154,13 @@ def _print_summary_statistics(sorted_results: List[dict], console: Console) -> N if total_setup_fail > 0: total_indicators += " ๐Ÿ”ง" + # Use bold color for total row + total_color = _get_pass_color(total_pass_pct, bold=True) + + total_pass_pct_str = ( + f"[{total_color}]{total_pass_pct:.1f}%[/{total_color}]{total_indicators}" + ) + summary_table.add_row( "TOTAL", str(total_runs), @@ -659,7 +1168,7 @@ def _print_summary_statistics(sorted_results: List[dict], console: Console) -> N str(total_fail), str(total_setup_fail), str(total_mock_fail), - f"{total_emoji} {total_pass_pct:.1f}%{total_indicators}", + total_pass_pct_str, "", "", style="bold", From 1021d98add430306f3fe934c0d5c137a06935867 Mon Sep 17 00:00:00 2001 From: Natan Yellin Date: Sat, 23 Aug 2025 16:50:10 +0300 Subject: [PATCH 03/14] Update tests/llm/test_workload_health.py Co-authored-by: coderabbitai[bot] <136622811+coderabbitai[bot]@users.noreply.github.com> --- tests/llm/test_workload_health.py | 7 +++---- 1 file changed, 3 insertions(+), 4 deletions(-) diff --git a/tests/llm/test_workload_health.py b/tests/llm/test_workload_health.py index 7e9789cb9b..44d26414ba 100644 --- a/tests/llm/test_workload_health.py +++ b/tests/llm/test_workload_health.py @@ -63,11 +63,10 @@ def get_workload_health_test_cases(): return get_test_cases(TEST_CASES_FOLDER) -def get_models(): - """Get list of models to test from MODELS env var.""" +def get_models() -> list[str]: + """Get list of models to test from MODELS env var (comma-separated).""" models_str = os.environ.get("MODELS", "gpt-4o") - return models_str.split(",") - + return [m.strip() for m in models_str.split(",") if m.strip()] @pytest.mark.llm @pytest.mark.parametrize("model", get_models()) From 3532d2442d04ee7ffddb1d8f80841fd9ea228225 Mon Sep 17 00:00:00 2001 From: Robusta Runner Date: Sat, 23 Aug 2025 16:50:35 +0300 Subject: [PATCH 04/14] fix --- holmes/core/tracing.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/holmes/core/tracing.py b/holmes/core/tracing.py index c4ecc89400..a18a70f694 100644 --- a/holmes/core/tracing.py +++ b/holmes/core/tracing.py @@ -120,7 +120,7 @@ def __exit__(self, exc_type, exc_val, exc_tb): class DummyTracer: """A no-op tracer implementation for when tracing is disabled.""" - def start_experiment(self, experiment_name=None, metadata=None): + def start_experiment(self, experiment_name=None, additional_metadata=None): """No-op experiment creation.""" return None From 06956b0ad0f16c7b5f672320c5dc0ed26a734c95 Mon Sep 17 00:00:00 2001 From: Robusta Runner Date: Sat, 23 Aug 2025 17:46:38 +0300 Subject: [PATCH 05/14] fixes and refactor --- tests/llm/test_ask_holmes.py | 177 ++------------- tests/llm/test_investigate.py | 89 ++------ tests/llm/test_workload_health.py | 153 ++++++------- tests/llm/utils/property_manager.py | 207 ++++++++++++++---- .../llm/utils/reporting/terminal_reporter.py | 11 - tests/llm/utils/setup_cleanup.py | 14 +- tests/llm/utils/test_case_utils.py | 22 +- tests/llm/utils/test_helpers.py | 60 ----- 8 files changed, 314 insertions(+), 419 deletions(-) delete mode 100644 tests/llm/utils/test_helpers.py diff --git a/tests/llm/test_ask_holmes.py b/tests/llm/test_ask_holmes.py index c4a189ee5c..086f14ca9e 100644 --- a/tests/llm/test_ask_holmes.py +++ b/tests/llm/test_ask_holmes.py @@ -15,17 +15,15 @@ from holmes.core.llm import DefaultLLM from holmes.core.tool_calling_llm import LLMResult, ToolCallingLLM from holmes.core.tools_utils.tool_executor import ToolExecutor -from tests.llm.utils.classifiers import evaluate_correctness from tests.llm.utils.commands import set_test_env_vars from tests.llm.utils.mock_toolset import ( MockToolsetManager, - MockMode, MockGenerationConfig, ) from tests.llm.utils.test_case_utils import ( AskHolmesTestCase, - Evaluation, check_and_skip_test, + get_models, ) from holmes.core.prompt import build_initial_ask_messages @@ -33,16 +31,10 @@ from tests.llm.utils.property_manager import ( set_initial_properties, update_test_results, - update_mock_error, + handle_test_error, ) from os import path from holmes.core.tracing import SpanType -from tests.llm.utils.test_helpers import ( - print_expected_output, - print_correctness_evaluation, - print_tool_calls_summary, - print_tool_calls_detailed, -) from tests.llm.utils.iteration_utils import get_test_cases from tests.llm.utils.braintrust import log_to_braintrust @@ -55,12 +47,6 @@ def get_ask_holmes_test_cases(): return get_test_cases(TEST_CASES_FOLDER) -def get_models(): - """Get list of models to test from MODELS env var.""" - models_str = os.environ.get("MODELS", "gpt-4o") - return models_str.split(",") - - @pytest.mark.llm @pytest.mark.parametrize("model", get_models()) @pytest.mark.parametrize("test_case", get_ask_holmes_test_cases()) @@ -73,47 +59,12 @@ def test_ask_holmes( shared_test_infrastructure, # type: ignore ): # Set initial properties early so they're available even if test fails - set_initial_properties(request, test_case) - - # Add model to user properties for reporting - request.node.user_properties.append(("model", model)) - # Add clean test case ID (without model suffix) - request.node.user_properties.append(("clean_test_case_id", test_case.id)) - # Add tags for tag-based performance analysis - request.node.user_properties.append(("tags", test_case.tags or [])) - - # Check if test should be skipped - check_and_skip_test(test_case) + set_initial_properties(request, test_case, model) - # Check for setup failures - setup_failures = shared_test_infrastructure.get("setup_failures", {}) - if test_case.id in setup_failures: - request.node.user_properties.append(("is_setup_failure", True)) - pytest.fail(f"Test setup failed: {setup_failures[test_case.id]}") + # Check if test should be skipped or has setup failures + check_and_skip_test(test_case, request, shared_test_infrastructure) print(f"\n๐Ÿงช TEST: {test_case.id}") - print(" CONFIGURATION:") - print( - f" โ€ข Mode: {'โšช๏ธ MOCKED' if mock_generation_config.mode == MockMode.MOCK else '๐Ÿ”ฅ LIVE'}, Generate Mocks: {mock_generation_config.generate_mocks}" - ) - print(f" โ€ข Model: {model}") - print(f" โ€ข User Prompt: {test_case.user_prompt}") - print(f" โ€ข Expected Output: {test_case.expected_output}") - if test_case.before_test: - if "\n" in test_case.before_test: - print(" โ€ข Before Test:") - for line in test_case.before_test.strip().split("\n"): - print(f" {line}") - else: - print(f" โ€ข Before Test: {test_case.before_test}") - - if test_case.after_test: - if "\n" in test_case.after_test: - print(" โ€ข After Test:") - for line in test_case.after_test.strip().split("\n"): - print(f" {line}") - else: - print(f" โ€ข After Test: {test_case.after_test}") tracer = TracingFactory.create_tracer("braintrust") metadata = {"model": model} @@ -168,82 +119,32 @@ def test_ask_holmes( ) except Exception as e: - # Log error to span if available - try: - if "eval_span" in locals(): - log_to_braintrust( - eval_span=eval_span, - test_case=test_case, - model=model, - result=result, - error=e, - mock_generation_config=mock_generation_config, - ) - except Exception: - pass # Don't fail the test due to logging issues - - # Store error information in user_properties for reporting - error_type = type(e).__name__ - error_message = str(e) - request.node.user_properties.append(("error_type", error_type)) - request.node.user_properties.append(("error_message", error_message)) - - # Store partial result if available - if result: - request.node.user_properties.append(("partial_output", result.result or "")) - - # Check if this is a MockDataError - is_mock_error = "MockDataError" in error_type or any( - "MockData" in base.__name__ for base in type(e).__mro__ + handle_test_error( + request=request, + error=e, + eval_span=eval_span if "eval_span" in locals() else None, + test_case=test_case, + model=model, + result=result, + mock_generation_config=mock_generation_config, ) - - if is_mock_error: - # Update properties for mock error - update_mock_error(request, e) - - # Cleanup is handled by session-scoped fixture now raise - finally: - # Cleanup is handled by session-scoped fixture now - pass - - input = test_case.user_prompt output = result.result - expected = test_case.expected_output - - scores = {} - - if not isinstance(expected, list): - expected = [expected] - print_expected_output(expected) - - prompt = ( - result.messages[0]["content"] - if result.messages and len(result.messages) > 0 - else result.prompt - ) - evaluation_type: str = ( - test_case.evaluation.correctness.type - if isinstance(test_case.evaluation.correctness, Evaluation) - else "strict" - ) - correctness_eval = evaluate_correctness( + scores = update_test_results( + request=request, output=output, - expected_elements=expected, - parent_span=eval_span, - evaluation_type=evaluation_type, + tools_called=[tc.description for tc in result.tool_calls] + if result.tool_calls + else [], + scores=None, # Let it calculate + result=result, + test_case=test_case, + eval_span=eval_span, caplog=caplog, ) - print("\n๐Ÿ’ฌ ACTUAL OUTPUT:") - print(f" {output}") - - print_correctness_evaluation(correctness_eval) - scores["correctness"] = correctness_eval.score - - # Log evaluation results directly to the span if eval_span: log_to_braintrust( eval_span=eval_span, @@ -254,40 +155,6 @@ def test_ask_holmes( mock_generation_config=mock_generation_config, ) - # Print tool calls summary - print_tool_calls_summary(result.tool_calls) - - if result.tool_calls: - tools_called = [tc.description for tc in result.tool_calls] - else: - tools_called = "None" - - # Print detailed tool output - print_tool_calls_detailed(result.tool_calls) - - # Update test results (including cost tracking) - update_test_results(request, output, tools_called, scores, result) - - # Check if the output contains MockDataError (indicating a mock failure) - if output and any( - error_type in output - for error_type in [ - "MockDataError", - "MockDataNotFoundError", - "MockDataCorruptedError", - ] - ): - # Record mock failure in user_properties - request.node.user_properties.append(("mock_data_failure", True)) - # Fail the test - # Get expected from test_case since debug_expected is no longer in local scope - expected_output = test_case.expected_output - if isinstance(expected_output, list): - expected_output = "\n- ".join(expected_output) - pytest.fail( - f"Test {test_case.id} failed due to mock data error\nActual: {output}\nExpected: {expected_output}" - ) - # Get expected for assertion message expected_output = test_case.expected_output if isinstance(expected_output, list): diff --git a/tests/llm/test_investigate.py b/tests/llm/test_investigate.py index e7412f6469..4124cd7e25 100644 --- a/tests/llm/test_investigate.py +++ b/tests/llm/test_investigate.py @@ -23,8 +23,13 @@ from tests.llm.utils.test_case_utils import ( InvestigateTestCase, check_and_skip_test, + get_models, +) +from tests.llm.utils.property_manager import ( + set_initial_properties, + update_test_results, + handle_test_error, ) -from tests.llm.utils.property_manager import set_initial_properties, update_test_results from os import path from unittest.mock import patch @@ -73,12 +78,6 @@ def get_investigate_test_cases(): return get_test_cases(TEST_CASES_FOLDER) -def get_models(): - """Get list of models to test from MODELS env var.""" - models_str = os.environ.get("MODELS", "gpt-4o") - return models_str.split(",") - - @pytest.mark.llm @pytest.mark.parametrize("model", get_models()) @pytest.mark.parametrize("test_case", get_investigate_test_cases()) @@ -91,23 +90,10 @@ def test_investigate( shared_test_infrastructure, # type: ignore ): # Set initial properties early so they're available even if test fails - set_initial_properties(request, test_case) - - # Add model to user properties for reporting - request.node.user_properties.append(("model", model)) - # Add clean test case ID (without model suffix) - request.node.user_properties.append(("clean_test_case_id", test_case.id)) - # Add tags for tag-based performance analysis - request.node.user_properties.append(("tags", test_case.tags or [])) - - # Check if test should be skipped - check_and_skip_test(test_case) + set_initial_properties(request, test_case, model) - # Check for setup failures - setup_failures = shared_test_infrastructure.get("setup_failures", {}) - if test_case.id in setup_failures: - request.node.user_properties.append(("is_setup_failure", True)) - pytest.fail(f"Test setup failed: {setup_failures[test_case.id]}") + # Check if test should be skipped or has setup failures + check_and_skip_test(test_case, request, shared_test_infrastructure) tracer = TracingFactory.create_tracer("braintrust") config = MockConfig(test_case, tracer, mock_generation_config) @@ -167,43 +153,15 @@ def test_investigate( # Log duration directly to eval_span eval_span.log(metadata={"holmes_duration": holmes_duration}) except Exception as e: - # Log error to span if available - try: - if "eval_span" in locals(): - log_to_braintrust( - eval_span=eval_span, - test_case=test_case, - model=model, - result=result, - error=e, - mock_generation_config=mock_generation_config, - ) - except Exception: - pass # Don't fail the test due to logging issues - - # Store error information in user_properties for reporting - error_type = type(e).__name__ - error_message = str(e) - request.node.user_properties.append(("error_type", error_type)) - request.node.user_properties.append(("error_message", error_message)) - - # Store partial result if available - if result and hasattr(result, "analysis"): - request.node.user_properties.append( - ("partial_output", result.analysis or "") - ) - - # Check if this is a MockDataError - is_mock_error = "MockDataError" in error_type or any( - "MockData" in base.__name__ for base in type(e).__mro__ + handle_test_error( + request=request, + error=e, + eval_span=eval_span if "eval_span" in locals() else None, + test_case=test_case, + model=model, + result=result, + mock_generation_config=mock_generation_config, ) - - if is_mock_error: - # Update properties for mock error (would need to import update_mock_error) - from tests.llm.utils.property_manager import update_mock_error - - update_mock_error(request, e) - raise assert result, "No result returned by investigate_issues()" @@ -212,11 +170,6 @@ def test_investigate( scores = {} - debug_expected = "\n- ".join(expected) - - print(f"\n๐Ÿงช TEST: {test_case.id}") - print(f" โ€ข Model: {model}") - print(f"** EXPECTED **\n- {debug_expected}") correctness_eval = evaluate_correctness( output=output, expected_elements=expected, @@ -224,9 +177,6 @@ def test_investigate( caplog=caplog, evaluation_type="strict", ) - print( - f"\n** CORRECTNESS **\nscore = {correctness_eval.score}\nrationale = {correctness_eval.metadata.get('rationale', '')}" - ) scores["correctness"] = correctness_eval.score if test_case.expected_sections: @@ -249,12 +199,7 @@ def test_investigate( mock_generation_config=mock_generation_config, ) tools_called = [t.tool_name for t in result.tool_calls] - print(f"\n** TOOLS CALLED **\n{tools_called}") - print(f"\n** OUTPUT **\n{output}") - print(f"\n** SCORES **\n{scores}") - # Store data for summary plugin - # Update test results (including cost tracking) update_test_results(request, output, tools_called, scores, result) assert result.sections, "Missing sections" diff --git a/tests/llm/test_workload_health.py b/tests/llm/test_workload_health.py index 44d26414ba..c219e169ca 100644 --- a/tests/llm/test_workload_health.py +++ b/tests/llm/test_workload_health.py @@ -1,5 +1,4 @@ # type: ignore -import os import time from pathlib import Path from typing import Optional @@ -21,8 +20,13 @@ Evaluation, HealthCheckTestCase, check_and_skip_test, + get_models, +) +from tests.llm.utils.property_manager import ( + set_initial_properties, + update_test_results, + handle_test_error, ) -from tests.llm.utils.property_manager import set_initial_properties, update_test_results from os import path from unittest.mock import patch @@ -63,11 +67,6 @@ def get_workload_health_test_cases(): return get_test_cases(TEST_CASES_FOLDER) -def get_models() -> list[str]: - """Get list of models to test from MODELS env var (comma-separated).""" - models_str = os.environ.get("MODELS", "gpt-4o") - return [m.strip() for m in models_str.split(",") if m.strip()] - @pytest.mark.llm @pytest.mark.parametrize("model", get_models()) @pytest.mark.parametrize("test_case", get_workload_health_test_cases()) @@ -80,21 +79,10 @@ def test_health_check( shared_test_infrastructure, # type: ignore ): # Set initial properties early so they're available even if test fails - set_initial_properties(request, test_case) - - # Add model to user properties for reporting - request.node.user_properties.append(("model", model)) - # Add clean test case ID (without model suffix) - request.node.user_properties.append(("clean_test_case_id", test_case.id)) + set_initial_properties(request, test_case, model) - # Check if test should be skipped - check_and_skip_test(test_case) - - # Check for setup failures - setup_failures = shared_test_infrastructure.get("setup_failures", {}) - if test_case.id in setup_failures: - request.node.user_properties.append(("is_setup_failure", True)) - pytest.fail(f"Test setup failed: {setup_failures[test_case.id]}") + # Check if test should be skipped or has setup failures + check_and_skip_test(test_case, request, shared_test_infrastructure) tracer = TracingFactory.create_tracer("braintrust") metadata = {"model": model} @@ -113,6 +101,7 @@ def test_health_check( input = test_case.workload_health_request expected = test_case.expected_output + result = None with tracer.start_trace( name=f"{test_case.id}[{model}]", span_type=SpanType.EVAL ) as eval_span: @@ -126,61 +115,75 @@ def test_health_check( ("braintrust_root_span_id", str(eval_span.root_span_id)) ) - with patch.multiple("server", dal=mock_dal, config=config): - # Note: Currently workload_health_check does not trace llm calls and the run includes the startup time of the tools - with eval_span.start_span("Holmes Run", type=SpanType.TASK.value): - start_time = time.time() - result = workload_health_check(request=input) - holmes_duration = time.time() - start_time - eval_span.log(metadata={"Holmes Duration": holmes_duration}) - - assert result, "No result returned by workload_health_check()" - # check that analysis is json parsable otherwise failed. - print(f"\n๐Ÿงช TEST: {test_case.id}") - print(f" โ€ข Model: {model}") - print(f"** ANALYSIS **\n- {result.analysis}") - json.loads(result.analysis) - output = result.analysis - - debug_expected = "\n- ".join(expected) - - print(f"** EXPECTED **\n- {debug_expected}") - correctness_eval = evaluate_correctness( - output=output, - expected_elements=expected, - parent_span=eval_span, - caplog=caplog, - evaluation_type="strict", - ) - print( - f"\n** CORRECTNESS **\nscore = {correctness_eval.score}\nrationale = {correctness_eval.metadata.get('rationale', '')}" - ) - scores = {} - scores["correctness"] = correctness_eval.score - - # Log evaluation results directly to the span - if eval_span: - # Prepare tags with model - tags = (test_case.tags or []).copy() - tags.append(f"model:{model}") - - eval_span.log( - input=input, - output=output or "", - expected=str(expected), - dataset_record_id=test_case.id, - scores=scores, - metadata={"model": model}, - tags=tags, + try: + with patch.multiple("server", dal=mock_dal, config=config): + # Note: Currently workload_health_check does not trace llm calls and the run includes the startup time of the tools + with eval_span.start_span("Holmes Run", type=SpanType.TASK.value): + start_time = time.time() + result = workload_health_check(request=input) + holmes_duration = time.time() - start_time + eval_span.log(metadata={"Holmes Duration": holmes_duration}) + + assert result, "No result returned by workload_health_check()" + + # check that analysis is json parsable otherwise failed. + print(f"\n๐Ÿงช TEST: {test_case.id}") + print(f" โ€ข Model: {model}") + print(f"** ANALYSIS **\n- {result.analysis}") + json.loads(result.analysis) + output = result.analysis + + debug_expected = "\n- ".join(expected) + + print(f"** EXPECTED **\n- {debug_expected}") + correctness_eval = evaluate_correctness( + output=output, + expected_elements=expected, + parent_span=eval_span, + caplog=caplog, + evaluation_type="strict", ) - - tools_called = [t.tool_name for t in result.tool_calls] - print(f"\n** TOOLS CALLED **\n{tools_called}") - print(f"\n** OUTPUT **\n{output}") - print(f"\n** SCORES **\n{scores}") - - # Update test results - update_test_results(request, output, tools_called, scores) + print( + f"\n** CORRECTNESS **\nscore = {correctness_eval.score}\nrationale = {correctness_eval.metadata.get('rationale', '')}" + ) + scores = {} + scores["correctness"] = correctness_eval.score + + # Log evaluation results directly to the span + if eval_span: + # Prepare tags with model + tags = (test_case.tags or []).copy() + tags.append(f"model:{model}") + + eval_span.log( + input=input, + output=output or "", + expected=str(expected), + dataset_record_id=test_case.id, + scores=scores, + metadata={"model": model}, + tags=tags, + ) + + tools_called = [t.tool_name for t in result.tool_calls] + print(f"\n** TOOLS CALLED **\n{tools_called}") + print(f"\n** OUTPUT **\n{output}") + print(f"\n** SCORES **\n{scores}") + + # Update test results + update_test_results(request, output, tools_called, scores, result) + + except Exception as e: + handle_test_error( + request=request, + error=e, + eval_span=eval_span, + test_case=test_case, + model=model, + result=result, + mock_generation_config=mock_generation_config, + ) + raise if test_case.evaluation.correctness: expected_correctness = test_case.evaluation.correctness diff --git a/tests/llm/utils/property_manager.py b/tests/llm/utils/property_manager.py index 68f476f226..a39e967e48 100644 --- a/tests/llm/utils/property_manager.py +++ b/tests/llm/utils/property_manager.py @@ -1,11 +1,16 @@ -"""Manage test properties for pytest reporting.""" - -from typing import List, Any, Union +import logging +from typing import List, Any, Union, Optional, Dict from tests.llm.utils.test_case_utils import Evaluation, HolmesTestCase # type: ignore[attr-defined] -def set_initial_properties(request, test_case: HolmesTestCase) -> None: - """Set initial properties at the beginning of a test so they're available even if test fails early.""" +def set_initial_properties(request, test_case: HolmesTestCase, model: str) -> None: + """Set initial properties at the beginning of a test so they're available even if test fails early. + + Args: + request: The pytest request object + test_case: The test case being executed + model: The model being used for this test run + """ expected = test_case.expected_output if not isinstance(expected, list): expected = [expected] @@ -38,6 +43,13 @@ def set_initial_properties(request, test_case: HolmesTestCase) -> None: ("tools_called", []) ) # Will be overwritten if test runs + # Add model and test identification properties + request.node.user_properties.append(("model", model)) + # Add clean test case ID (without model suffix that pytest adds during parameterization) + request.node.user_properties.append(("clean_test_case_id", test_case.id)) + # Add tags for tag-based performance analysis + request.node.user_properties.append(("tags", test_case.tags or [])) + def update_property(request, key: str, value: Any) -> None: """Update an existing property value instead of appending a duplicate.""" @@ -53,18 +65,71 @@ def update_test_results( request, output: str, tools_called: Union[List[str], str], - scores: dict, + scores: Optional[Dict[str, Any]] = None, result: Any = None, -) -> None: - """Update test result properties after test execution. + test_case: Any = None, + eval_span: Any = None, + caplog: Any = None, +) -> Dict[str, Any]: + """Update test result properties after test execution and optionally calculate scores. Args: request: The pytest request object output: The test output string tools_called: List of tools called or a string description - scores: Dictionary of scores (e.g., correctness) + scores: Dictionary of scores (e.g., correctness). If None and test_case is provided, will calculate result: Optional result object (LLMResult or InvestigationResult) containing cost info + test_case: Optional test case for score calculation + eval_span: Optional Braintrust span for evaluation + caplog: Optional caplog for evaluation + + Returns: + dict: The scores dictionary (either passed in or calculated) """ + # Calculate scores if not provided but test_case is available + if scores is None and test_case is not None: + from tests.llm.utils.classifiers import evaluate_correctness, evaluate_sections + + scores = {} + + # Get expected output + expected = test_case.expected_output + if not isinstance(expected, list): + expected = [expected] + + # Determine evaluation type + evaluation_type = "strict" + if hasattr(test_case, "evaluation") and hasattr( + test_case.evaluation, "correctness" + ): + if isinstance(test_case.evaluation.correctness, Evaluation): + evaluation_type = test_case.evaluation.correctness.type + + # Evaluate correctness + correctness_eval = evaluate_correctness( + output=output, + expected_elements=expected, + parent_span=eval_span, + evaluation_type=evaluation_type, + caplog=caplog, + ) + scores["correctness"] = correctness_eval.score + + # Evaluate sections if applicable (for investigate tests) + if hasattr(test_case, "expected_sections") and test_case.expected_sections: + sections = { + key: bool(value) for key, value in test_case.expected_sections.items() + } + sections_eval = evaluate_sections( + sections=sections, output=output, parent_span=eval_span + ) + scores["sections"] = sections_eval.score + + # Default scores if still None + if scores is None: + scores = {} + + # Update properties update_property(request, "actual", output or "") update_property( request, @@ -73,42 +138,100 @@ def update_test_results( ) update_property(request, "actual_correctness_score", scores.get("correctness", 0)) - # Log test cost information and add to user properties if available - if result: - import logging - - # Check for cost tracking in LLMResult (from ask_holmes tests) - if hasattr(result, "total_cost") and result.total_cost > 0: - test_case_id = None - model = None - # Extract test_case_id and model from user_properties - for key, value in request.node.user_properties: - if key == "clean_test_case_id": - test_case_id = value - elif key == "model": - model = value - - if test_case_id and model: - logging.info( - f"Test {test_case_id} with {model} - Total cost: ${result.total_cost:.6f}, Total tokens: {result.total_tokens if hasattr(result, 'total_tokens') else 'N/A'}" - ) - - request.node.user_properties.append(("cost", result.total_cost)) - if hasattr(result, "total_tokens"): - request.node.user_properties.append( - ("total_tokens", result.total_tokens) - ) - if hasattr(result, "prompt_tokens"): - request.node.user_properties.append( - ("prompt_tokens", result.prompt_tokens) - ) - if hasattr(result, "completion_tokens"): - request.node.user_properties.append( - ("completion_tokens", result.completion_tokens) - ) + if not result: + return scores + + # Check for cost tracking in LLMResult (from ask_holmes tests) + if hasattr(result, "total_cost") and result.total_cost > 0: + test_case_id = None + model = None + # Extract test_case_id and model from user_properties + for key, value in request.node.user_properties: + if key == "clean_test_case_id": + test_case_id = value + elif key == "model": + model = value + + if test_case_id and model: + logging.info( + f"Test {test_case_id} with {model} - Total cost: ${result.total_cost:.6f}, Total tokens: {result.total_tokens if hasattr(result, 'total_tokens') else 'N/A'}" + ) + + request.node.user_properties.append(("cost", result.total_cost)) + if hasattr(result, "total_tokens"): + request.node.user_properties.append(("total_tokens", result.total_tokens)) + if hasattr(result, "prompt_tokens"): + request.node.user_properties.append(("prompt_tokens", result.prompt_tokens)) + if hasattr(result, "completion_tokens"): + request.node.user_properties.append( + ("completion_tokens", result.completion_tokens) + ) + + return scores def update_mock_error(request, error: Exception) -> None: """Update properties when a mock error occurs.""" update_property(request, "actual", f"Mock data error: {str(error)}") request.node.user_properties.append(("mock_data_failure", True)) + + +def handle_test_error( + request, + error: Exception, + eval_span=None, + test_case=None, + model: Optional[str] = None, + result=None, + mock_generation_config=None, +) -> None: + """Centralized error handling for LLM tests. + + Args: + request: The pytest request object + error: The exception that was raised + eval_span: Optional Braintrust evaluation span for logging + test_case: The test case being executed + model: The model being tested + result: Optional partial result if available + mock_generation_config: Mock configuration for logging + """ + # Import here to avoid circular dependency + from tests.llm.utils.braintrust import log_to_braintrust + + # Log error to Braintrust span if available + if eval_span is not None and test_case is not None and model is not None: + try: + log_to_braintrust( + eval_span=eval_span, + test_case=test_case, + model=model, + result=result, + error=error, + mock_generation_config=mock_generation_config, + ) + except Exception: + pass # Don't fail the test due to logging issues + + # Store error information in user_properties for reporting + error_type = type(error).__name__ + error_message = str(error) + request.node.user_properties.append(("error_type", error_type)) + request.node.user_properties.append(("error_message", error_message)) + + # Store partial result if available + if result: + partial_output = ( + getattr(result, "result", "") or getattr(result, "output", "") or "" + ) + if partial_output: + request.node.user_properties.append(("partial_output", partial_output)) + + # Check if this is a MockDataError + is_mock_error = "MockDataError" in error_type or any( + "MockData" in base.__name__ for base in type(error).__mro__ + ) + + if is_mock_error: + # Update properties for mock error + update_mock_error(request, error) diff --git a/tests/llm/utils/reporting/terminal_reporter.py b/tests/llm/utils/reporting/terminal_reporter.py index 3e27921065..8e159a0862 100644 --- a/tests/llm/utils/reporting/terminal_reporter.py +++ b/tests/llm/utils/reporting/terminal_reporter.py @@ -883,12 +883,6 @@ def _print_model_comparison_table(sorted_results: List[dict], console: Console) console.print(comparison_table) - # Print summary - total_tests = len(stats.test_cases) - console.print( - f"\n[dim]Compared {len(stats.models)} models across {total_tests} test cases[/dim]" - ) - # Find best performing model(s) best_models = [] best_pass_pct = 0.0 @@ -1015,11 +1009,6 @@ def _print_tag_performance_table(sorted_results: List[dict], console: Console) - console.print(tag_table) - # Print summary - console.print( - f"\n[dim]Tag performance across {len(tags)} tags and {len(stats.models)} models[/dim]" - ) - def _print_model_comparison_if_multiple( sorted_results: List[dict], console: Console diff --git a/tests/llm/utils/setup_cleanup.py b/tests/llm/utils/setup_cleanup.py index e3d37ba864..8f809afb5d 100644 --- a/tests/llm/utils/setup_cleanup.py +++ b/tests/llm/utils/setup_cleanup.py @@ -11,7 +11,6 @@ from tests.llm.utils.commands import run_commands # type: ignore[attr-defined] from tests.llm.utils.test_case_utils import HolmesTestCase # type: ignore[attr-defined] -from tests.llm.utils.test_helpers import truncate_output # Configuration MAX_ERROR_LINES = 10 @@ -30,9 +29,20 @@ def log(msg): logging.info(msg) +def _truncate_output(data: str, max_lines: int = 10, label: str = "lines") -> str: + """Truncate output to max_lines for readability.""" + lines = data.split("\n") + if len(lines) > max_lines: + preview_lines = lines[:max_lines] + remaining = len(lines) - max_lines + preview_lines.append(f"... [TRUNCATED: {remaining} more {label} not shown]") + return "\n".join(preview_lines) + return data + + def format_error_output(error_details: str) -> str: """Format error details with truncation if needed.""" - return truncate_output(error_details, max_lines=MAX_ERROR_LINES) + return _truncate_output(error_details, max_lines=MAX_ERROR_LINES) class Operation(StrEnum): diff --git a/tests/llm/utils/test_case_utils.py b/tests/llm/utils/test_case_utils.py index 28565829e9..595e6c0e4e 100644 --- a/tests/llm/utils/test_case_utils.py +++ b/tests/llm/utils/test_case_utils.py @@ -15,6 +15,12 @@ from tests.llm.utils.constants import ALLOWED_EVAL_TAGS, get_allowed_tags_list +def get_models(): + """Get list of models to test from MODELS env var.""" + models_str = os.environ.get("MODELS", "gpt-4o") + return models_str.split(",") + + def read_file(file_path: Path): with open(file_path, "r", encoding="utf-8") as file: return file.read().strip() @@ -101,15 +107,27 @@ class HealthCheckTestCase(HolmesTestCase, BaseModel): request: Any = None -def check_and_skip_test(test_case: HolmesTestCase) -> None: - """Check if test should be skipped and raise pytest.skip if needed. +def check_and_skip_test( + test_case: HolmesTestCase, request=None, shared_test_infrastructure=None +) -> None: + """Check if test should be skipped or has setup failures, and raise appropriate pytest exceptions. Args: test_case: A HolmesTestCase or any of its subclasses + request: The pytest request object (optional, needed for setup failure tracking) + shared_test_infrastructure: Shared test infrastructure dict (optional, needed for setup failure checking) """ + # Check if test should be skipped if test_case.skip: pytest.skip(test_case.skip_reason or "Test skipped") + # Check for setup failures if infrastructure is provided + if shared_test_infrastructure is not None and request is not None: + setup_failures = shared_test_infrastructure.get("setup_failures", {}) + if test_case.id in setup_failures: + request.node.user_properties.append(("is_setup_failure", True)) + pytest.fail(f"Test setup failed: {setup_failures[test_case.id]}") + class MockHelper: def __init__(self, test_cases_folder: Path) -> None: diff --git a/tests/llm/utils/test_helpers.py b/tests/llm/utils/test_helpers.py deleted file mode 100644 index 8a8f688f52..0000000000 --- a/tests/llm/utils/test_helpers.py +++ /dev/null @@ -1,60 +0,0 @@ -"""Test helper functions for enhanced output formatting.""" - -import textwrap -from typing import List, Any - - -def truncate_output(data: str, max_lines: int = 10, label: str = "lines") -> str: - """Truncate output to max_lines for readability.""" - lines = data.split("\n") - if len(lines) > max_lines: - preview_lines = lines[:max_lines] - remaining = len(lines) - max_lines - preview_lines.append(f"... [TRUNCATED: {remaining} more {label} not shown]") - return "\n".join(preview_lines) - return data - - -# Backward compatibility alias -_truncate_tool_output = truncate_output - - -def print_tool_calls_detailed(tool_calls: List[Any]) -> None: - """Print detailed tool output for debugging (limited to 10 lines per tool)""" - if tool_calls: - print("\n๐Ÿ”ง TOOLS CALLED (DETAILED):") - for tc in tool_calls: - truncated_data = _truncate_tool_output(tc.result.data) - print(f"\n") - print(textwrap.indent(truncated_data, " ")) - print("") - else: - print("\n๐Ÿ”ง TOOLS CALLED: None") - - -def print_tool_calls_summary(tool_calls: List[Any]) -> None: - """Print summary of tool calls.""" - if tool_calls: - print(f"\n๐Ÿ”ง TOOLS CALLED ({len(tool_calls)}):") - for i, tc in enumerate(tool_calls, 1): - print(f" {i}. {tc.description}") - else: - print("\n๐Ÿ”ง TOOLS CALLED: None") - - -def print_expected_output(expected: List[str]) -> None: - """Print expected output in formatted way.""" - print("\n๐Ÿ“ EXPECTED OUTPUT:") - for exp in expected: - print(f" - {exp}") - - -def print_correctness_evaluation(correctness_eval: Any) -> None: - """Print correctness evaluation results.""" - print("\nโš–๏ธ CORRECTNESS EVALUATION:") - print(f" Score: {correctness_eval.score}") - print(" Rationale: ") - rationale = correctness_eval.metadata.get("rationale", "") - for line in rationale.split("\n"): - if line.strip(): - print(f" {line}") From 1300185c8bf839b36d1e1f78d5da0fd18850ccfb Mon Sep 17 00:00:00 2001 From: Robusta Runner Date: Sat, 23 Aug 2025 18:03:54 +0300 Subject: [PATCH 06/14] fixes --- docs/development/evals/index.md | 12 ++++++------ tests/llm/utils/test_case_utils.py | 4 ++-- 2 files changed, 8 insertions(+), 8 deletions(-) diff --git a/docs/development/evals/index.md b/docs/development/evals/index.md index 8921742ad7..ea70f5ff02 100644 --- a/docs/development/evals/index.md +++ b/docs/development/evals/index.md @@ -71,18 +71,18 @@ HolmesGPT supports running evaluations across multiple models simultaneously to ```bash # Test multiple models in a single run # Models are specified as comma-separated list -RUN_LIVE=true MODELS=gpt-4o,anthropic/claude-3-5-sonnet-20241022,gpt-4o-mini \ +RUN_LIVE=true MODEL=gpt-4o,anthropic/claude-3-5-sonnet-20241022,gpt-4o-mini \ CLASSIFIER_MODEL=gpt-4o \ poetry run pytest -m 'llm and easy' --no-cov # Run with multiple iterations for statistically significant results RUN_LIVE=true ITERATIONS=10 \ - MODELS=gpt-4o,anthropic/claude-3-5-sonnet-20241022 \ + MODEL=gpt-4o,anthropic/claude-3-5-sonnet-20241022 \ CLASSIFIER_MODEL=gpt-4o \ poetry run pytest -m 'llm and easy' -n 10 # Test specific scenario across models -RUN_LIVE=true MODELS=gpt-4o,gpt-4o-mini \ +RUN_LIVE=true MODEL=gpt-4o,gpt-4o-mini \ poetry run pytest tests/llm/test_ask_holmes.py -k "01_how_many_pods" ``` @@ -177,12 +177,12 @@ RUN_LIVE=true pytest -k "test" --skip-setup ### Recommended: Multi-Model Testing (Single Run) -**Use the `MODELS` environment variable to test multiple models in a single run:** +**Use the `MODEL` environment variable to test multiple models in a single run:** ```bash # Compare multiple models simultaneously - RECOMMENDED approach RUN_LIVE=true ITERATIONS=10 \ - MODELS=gpt-4o,anthropic/claude-3-5-sonnet-20241022,gpt-4o-mini \ + MODEL=gpt-4o,anthropic/claude-3-5-sonnet-20241022,gpt-4o-mini \ CLASSIFIER_MODEL=gpt-4o \ poetry run pytest -m 'llm and easy' -n 10 @@ -221,7 +221,7 @@ export BRAINTRUST_API_KEY=your-key export BRAINTRUST_ORG=your-org # Then run any evaluation command - results will be tracked automatically -RUN_LIVE=true MODELS=gpt-4o,anthropic/claude-3-5-sonnet-20241022 pytest -m 'llm and easy' +RUN_LIVE=true MODEL=gpt-4o,anthropic/claude-3-5-sonnet-20241022 pytest -m 'llm and easy' ``` ## Test Markers diff --git a/tests/llm/utils/test_case_utils.py b/tests/llm/utils/test_case_utils.py index 595e6c0e4e..e76004bc27 100644 --- a/tests/llm/utils/test_case_utils.py +++ b/tests/llm/utils/test_case_utils.py @@ -16,8 +16,8 @@ def get_models(): - """Get list of models to test from MODELS env var.""" - models_str = os.environ.get("MODELS", "gpt-4o") + """Get list of models to test from MODEL env var (supports comma-separated list).""" + models_str = os.environ.get("MODEL", "gpt-4o") return models_str.split(",") From 1ec009212a9e3cd36a967ceb5d82e4123714bb14 Mon Sep 17 00:00:00 2001 From: Robusta Runner Date: Sat, 23 Aug 2025 19:00:52 +0300 Subject: [PATCH 07/14] fixes --- holmes/core/tool_calling_llm.py | 112 +++++++++++++++----------------- 1 file changed, 52 insertions(+), 60 deletions(-) diff --git a/holmes/core/tool_calling_llm.py b/holmes/core/tool_calling_llm.py index 0e988966e0..689f241612 100644 --- a/holmes/core/tool_calling_llm.py +++ b/holmes/core/tool_calling_llm.py @@ -10,7 +10,7 @@ from openai.types.chat.chat_completion_message_tool_call import ( ChatCompletionMessageToolCall, ) -from pydantic import BaseModel +from pydantic import BaseModel, Field from rich.console import Console from holmes.common.env_vars import TEMPERATURE, MAX_OUTPUT_TOKEN_RESERVATION @@ -148,7 +148,9 @@ class ToolCallResult(BaseModel): tool_name: str description: str result: StructuredToolResult - size: Optional[int] = None + size: Optional[int] = ( + None # TODO: currently unused - remove it? need to verify this doesn't break clients + ) def as_tool_call_message(self): content = format_tool_result_data(self.result) @@ -190,24 +192,19 @@ def as_streaming_tool_result_response(self): class LLMResult(BaseModel): - tool_calls: Optional[List[ToolCallResult]] = None + tool_calls: Optional[List[dict]] = None result: Optional[str] = None unprocessed_result: Optional[str] = None - instructions: List[str] = [] - # TODO: clean up these two - prompt: Optional[str] = None + instructions: List[str] = Field(default_factory=list) + prompt: Optional[str] = ( + None # somewhat redundant with messages, can likely be removed + ) messages: Optional[List[dict]] = None - # Cost tracking total_cost: float = 0.0 total_tokens: int = 0 prompt_tokens: int = 0 completion_tokens: int = 0 - def get_tool_usage_summary(self): - return "AI used info from issue and " + ",".join( - [f"`{tool_call.description}`" for tool_call in self.tool_calls] - ) - class ToolCallingLLM: llm: LLM @@ -266,18 +263,15 @@ def call( # type: ignore tool_number_offset: int = 0, ) -> LLMResult: perf_timing = PerformanceTiming("tool_calling_llm.call") - tool_calls = [] # type: ignore + # Initialize result object that we'll populate throughout execution + result = LLMResult() + tools = self.tool_executor.get_all_tools_openai_format( target_model=self.llm.model ) perf_timing.measure("get_all_tools_openai_format") max_steps = self.max_steps i = 0 - # Initialize cost tracking - total_cost = 0.0 - total_tokens = 0 - prompt_tokens_total = 0 - completion_tokens_total = 0 while i < max_steps: i += 1 @@ -287,12 +281,12 @@ def call( # type: ignore tools = None if i == max_steps else tools tool_choice = "auto" if tools else None - total_tokens = self.llm.count_tokens_for_message(messages) + message_tokens = self.llm.count_tokens_for_message(messages) max_context_size = self.llm.get_context_window_size() maximum_output_token = self.llm.get_maximum_output_token() perf_timing.measure("count tokens") - if (total_tokens + maximum_output_token) > max_context_size: + if (message_tokens + maximum_output_token) > max_context_size: logging.warning("Token limit exceeded. Truncating tool responses.") messages = self.truncate_messages_to_fit_context( messages, max_context_size, maximum_output_token @@ -330,15 +324,15 @@ def call( # type: ignore f"LLM call cost: ${cost:.6f} | Tokens: {prompt_toks} prompt + {completion_toks} completion = {total_toks} total" ) # Accumulate costs - total_cost += cost - prompt_tokens_total += prompt_toks - completion_tokens_total += completion_toks - total_tokens += total_toks + result.total_cost += cost + result.prompt_tokens += prompt_toks + result.completion_tokens += completion_toks + result.total_tokens += total_toks elif cost > 0: cost_logger.debug( f"LLM call cost: ${cost:.6f} | Token usage not available" ) - total_cost += cost + result.total_cost += cost except Exception as e: logging.debug(f"Could not extract cost information: {e}") @@ -395,36 +389,27 @@ def call( # type: ignore if post_process_prompt and user_prompt: logging.info("Running post processing on investigation.") raw_response = text_response - post_processed_response = self._post_processing_call( - prompt=user_prompt, - investigation=raw_response, - user_prompt=post_process_prompt, + post_processed_response, post_processing_cost = ( + self._post_processing_call( + prompt=user_prompt, + investigation=raw_response, + user_prompt=post_process_prompt, + ) ) + result.total_cost += post_processing_cost perf_timing.end(f"- completed in {i} iterations -") - return LLMResult( - result=post_processed_response, - unprocessed_result=raw_response, - tool_calls=tool_calls, - prompt=json.dumps(messages, indent=2), - messages=messages, - total_cost=total_cost, - total_tokens=total_tokens, - prompt_tokens=prompt_tokens_total, - completion_tokens=completion_tokens_total, - ) + result.result = post_processed_response + result.unprocessed_result = raw_response + result.prompt = json.dumps(messages, indent=2) + result.messages = messages + return result perf_timing.end(f"- completed in {i} iterations -") - return LLMResult( - result=text_response, - tool_calls=tool_calls, - prompt=json.dumps(messages, indent=2), - messages=messages, - total_cost=total_cost, - total_tokens=total_tokens, - prompt_tokens=prompt_tokens_total, - completion_tokens=completion_tokens_total, - ) + result.result = text_response + result.prompt = json.dumps(messages, indent=2) + result.messages = messages + return result if text_response and text_response.strip(): logging.info(f"[bold {AI_COLOR}]AI:[/bold {AI_COLOR}] {text_response}") @@ -440,7 +425,7 @@ def call( # type: ignore executor.submit( self._invoke_tool, tool_to_call=t, - previous_tool_calls=tool_calls, + previous_tool_calls=result.tool_calls or [], trace_span=trace_span, tool_number=tool_number_offset + tool_index, ) @@ -449,7 +434,9 @@ def call( # type: ignore for future in concurrent.futures.as_completed(futures): tool_call_result: ToolCallResult = future.result() - tool_calls.append(tool_call_result.as_tool_result_response()) + if result.tool_calls is None: + result.tool_calls = [] + result.tool_calls.append(tool_call_result.as_tool_result_response()) messages.append(tool_call_result.as_tool_call_message()) perf_timing.measure(f"tool completed {tool_call_result.tool_name}") @@ -594,7 +581,7 @@ def _post_processing_call( investigation, user_prompt: Optional[str] = None, system_prompt: str = "You are an AI assistant summarizing Kubernetes issues.", - ) -> Optional[str]: + ) -> tuple[Optional[str], float]: try: user_prompt = ToolCallingLLM.__load_post_processing_user_prompt( prompt, investigation, user_prompt @@ -615,6 +602,7 @@ def _post_processing_call( logging.debug(f"Post processing response {full_response}") # Log cost information for post-processing + post_processing_cost = 0.0 try: cost_value = ( full_response._hidden_params.get("response_cost", 0) @@ -622,16 +610,20 @@ def _post_processing_call( else 0 ) # Ensure cost is a float - cost = float(cost_value) if cost_value is not None else 0.0 - if cost > 0: - cost_logger.debug(f"Post-processing LLM cost: ${cost:.6f}") + post_processing_cost = ( + float(cost_value) if cost_value is not None else 0.0 + ) + if post_processing_cost > 0: + cost_logger.debug( + f"Post-processing LLM cost: ${post_processing_cost:.6f}" + ) except Exception: pass # Silent fail for cost logging - return full_response.choices[0].message.content # type: ignore + return full_response.choices[0].message.content, post_processing_cost # type: ignore except Exception: logging.exception("Failed to run post processing", exc_info=True) - return investigation + return investigation, 0.0 @sentry_sdk.trace def truncate_messages_to_fit_context( @@ -681,12 +673,12 @@ def call_stream( tools = None if i == max_steps else tools tool_choice = "auto" if tools else None - total_tokens = self.llm.count_tokens_for_message(messages) # type: ignore + message_tokens = self.llm.count_tokens_for_message(messages) # type: ignore max_context_size = self.llm.get_context_window_size() maximum_output_token = self.llm.get_maximum_output_token() perf_timing.measure("count tokens") - if (total_tokens + maximum_output_token) > max_context_size: + if (message_tokens + maximum_output_token) > max_context_size: logging.warning("Token limit exceeded. Truncating tool responses.") messages = self.truncate_messages_to_fit_context( messages, max_context_size, maximum_output_token From 92460097e453589e5c9e2f822d7ebaf06ecccf44 Mon Sep 17 00:00:00 2001 From: Robusta Runner Date: Sat, 23 Aug 2025 19:17:11 +0300 Subject: [PATCH 08/14] fixes --- tests/llm/test_ask_holmes.py | 2 +- tests/llm/test_investigate.py | 73 ++++++++++--------- tests/llm/utils/braintrust.py | 12 +-- tests/llm/utils/property_manager.py | 26 ++----- .../llm/utils/reporting/terminal_reporter.py | 9 ++- 5 files changed, 54 insertions(+), 68 deletions(-) diff --git a/tests/llm/test_ask_holmes.py b/tests/llm/test_ask_holmes.py index 086f14ca9e..68194d2e1b 100644 --- a/tests/llm/test_ask_holmes.py +++ b/tests/llm/test_ask_holmes.py @@ -135,7 +135,7 @@ def test_ask_holmes( scores = update_test_results( request=request, output=output, - tools_called=[tc.description for tc in result.tool_calls] + tools_called=[tc["description"] for tc in result.tool_calls] if result.tool_calls else [], scores=None, # Let it calculate diff --git a/tests/llm/test_investigate.py b/tests/llm/test_investigate.py index 4124cd7e25..aefc8a3db8 100644 --- a/tests/llm/test_investigate.py +++ b/tests/llm/test_investigate.py @@ -111,6 +111,8 @@ def test_investigate( input = test_case.investigate_request expected = test_case.expected_output result = None + output = None + scores = {} investigate_request = test_case.investigate_request if not investigate_request.sections: @@ -152,6 +154,40 @@ def test_investigate( holmes_duration = time.time() - start_time # Log duration directly to eval_span eval_span.log(metadata={"holmes_duration": holmes_duration}) + + # Evaluate and log results inside the span context + assert result, "No result returned by investigate_issues()" + + output = result.analysis + + correctness_eval = evaluate_correctness( + output=output, + expected_elements=expected, + parent_span=eval_span, + caplog=caplog, + evaluation_type="strict", + ) + scores["correctness"] = correctness_eval.score + + if test_case.expected_sections: + sections = { + key: bool(value) + for key, value in test_case.expected_sections.items() + } + sections_eval = evaluate_sections( + sections=sections, output=output, parent_span=eval_span + ) + scores["sections"] = sections_eval.score + + # Log evaluation results to the span + log_to_braintrust( + eval_span=eval_span, + test_case=test_case, + model=model, + result=result, + scores=scores, + mock_generation_config=mock_generation_config, + ) except Exception as e: handle_test_error( request=request, @@ -164,42 +200,7 @@ def test_investigate( ) raise - assert result, "No result returned by investigate_issues()" - - output = result.analysis - - scores = {} - - correctness_eval = evaluate_correctness( - output=output, - expected_elements=expected, - parent_span=eval_span, - caplog=caplog, - evaluation_type="strict", - ) - scores["correctness"] = correctness_eval.score - - if test_case.expected_sections: - sections = { - key: bool(value) for key, value in test_case.expected_sections.items() - } - sections_eval = evaluate_sections( - sections=sections, output=output, parent_span=eval_span - ) - scores["sections"] = sections_eval.score - - # Log evaluation results directly to the span - if eval_span: - log_to_braintrust( - eval_span=eval_span, - test_case=test_case, - model=model, - result=result, - scores=scores, - mock_generation_config=mock_generation_config, - ) - tools_called = [t.tool_name for t in result.tool_calls] - + tools_called = [t["tool_name"] for t in result.tool_calls] update_test_results(request, output, tools_called, scores, result) assert result.sections, "Missing sections" diff --git a/tests/llm/utils/braintrust.py b/tests/llm/utils/braintrust.py index 074bd1a498..cfd949f4d7 100644 --- a/tests/llm/utils/braintrust.py +++ b/tests/llm/utils/braintrust.py @@ -257,15 +257,9 @@ def log_to_braintrust( metadata["has_custom_runbooks"] = True # Add tool usage metrics if available - if result: - if hasattr(result, "tool_calls") and result.tool_calls: - metadata["tool_call_count"] = len(result.tool_calls) - metadata["tools_used"] = list( - { - tc.tool_name if hasattr(tc, "tool_name") else tc.description - for tc in result.tool_calls - } - ) + if result and getattr(result, "tool_calls", None): + metadata["tool_call_count"] = len(result.tool_calls) + metadata["tools_used"] = list({tc["tool_name"] for tc in result.tool_calls}) # Note: holmes_duration is logged separately directly to eval_span in ask_holmes() # Add error information if present diff --git a/tests/llm/utils/property_manager.py b/tests/llm/utils/property_manager.py index a39e967e48..3ef7d2cf1d 100644 --- a/tests/llm/utils/property_manager.py +++ b/tests/llm/utils/property_manager.py @@ -1,4 +1,3 @@ -import logging from typing import List, Any, Union, Optional, Dict from tests.llm.utils.test_case_utils import Evaluation, HolmesTestCase # type: ignore[attr-defined] @@ -141,23 +140,14 @@ def update_test_results( if not result: return scores - # Check for cost tracking in LLMResult (from ask_holmes tests) - if hasattr(result, "total_cost") and result.total_cost > 0: - test_case_id = None - model = None - # Extract test_case_id and model from user_properties - for key, value in request.node.user_properties: - if key == "clean_test_case_id": - test_case_id = value - elif key == "model": - model = value - - if test_case_id and model: - logging.info( - f"Test {test_case_id} with {model} - Total cost: ${result.total_cost:.6f}, Total tokens: {result.total_tokens if hasattr(result, 'total_tokens') else 'N/A'}" - ) - - request.node.user_properties.append(("cost", result.total_cost)) + # Track cost and token usage from LLMResult + # Tokens are useful even when cost is 0 (e.g., local or free-tier runs) + # Record token counts when present regardless of total_cost + if hasattr(result, "total_cost") or hasattr(result, "total_tokens"): + # Always record cost if present (even if 0) + if hasattr(result, "total_cost"): + request.node.user_properties.append(("cost", result.total_cost)) + # Always record tokens if present if hasattr(result, "total_tokens"): request.node.user_properties.append(("total_tokens", result.total_tokens)) if hasattr(result, "prompt_tokens"): diff --git a/tests/llm/utils/reporting/terminal_reporter.py b/tests/llm/utils/reporting/terminal_reporter.py index 8e159a0862..c6442f7058 100644 --- a/tests/llm/utils/reporting/terminal_reporter.py +++ b/tests/llm/utils/reporting/terminal_reporter.py @@ -1132,8 +1132,9 @@ def _print_summary_statistics(sorted_results: List[dict], console: Console) -> N summary_table.add_row(*separator_row, style="dim") # Add totals row - total_actual_runs = total_runs - total_pass_pct = _calculate_pass_percentage(total_pass, total_actual_runs) + # Calculate valid runs (exclude skipped and setup-failed runs) + total_valid_runs = total_runs - total_skip - total_setup_fail + total_pass_pct = _calculate_pass_percentage(total_pass, total_valid_runs) # Format total pass percentage with color (no emoji) # For totals, always show indicators if any failures exist @@ -1177,11 +1178,11 @@ def _print_summary_statistics(sorted_results: List[dict], console: Console) -> N total_failures = total_fail + total_setup_fail + total_mock_fail console.print( - f"\n[bold red]FAIL[/bold red] {total_failures} out of {total_actual_runs} tests failed ({', '.join(failure_parts)})" + f"\n[bold red]FAIL[/bold red] {total_failures} out of {total_valid_runs} tests failed ({', '.join(failure_parts)})" ) else: console.print( - f"\n[bold green]SUCCESS[/bold green] All {total_actual_runs} tests passed!" + f"\n[bold green]SUCCESS[/bold green] All {total_valid_runs} tests passed!" ) # Print skip info if any From 1edaf716df4dc538049f67f304d0ba18a49ee3ee Mon Sep 17 00:00:00 2001 From: Robusta Runner Date: Sat, 23 Aug 2025 19:36:19 +0300 Subject: [PATCH 09/14] Update test_case.yaml --- .../test_ask_holmes/97_logs_clarification_needed/test_case.yaml | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/tests/llm/fixtures/test_ask_holmes/97_logs_clarification_needed/test_case.yaml b/tests/llm/fixtures/test_ask_holmes/97_logs_clarification_needed/test_case.yaml index b2dbe5e2d1..abf244b9f2 100644 --- a/tests/llm/fixtures/test_ask_holmes/97_logs_clarification_needed/test_case.yaml +++ b/tests/llm/fixtures/test_ask_holmes/97_logs_clarification_needed/test_case.yaml @@ -4,4 +4,4 @@ expected_output: tags: - ask-for-clarification - logs - - easy + - medium From 07235ba87d4c060c2bd06f6f24d2fe339a5900ac Mon Sep 17 00:00:00 2001 From: Robusta Runner Date: Sat, 23 Aug 2025 21:46:23 +0300 Subject: [PATCH 10/14] update --- holmes/core/tool_calling_llm.py | 157 ++++++++++++++++++-------------- 1 file changed, 91 insertions(+), 66 deletions(-) diff --git a/holmes/core/tool_calling_llm.py b/holmes/core/tool_calling_llm.py index 689f241612..edb819737b 100644 --- a/holmes/core/tool_calling_llm.py +++ b/holmes/core/tool_calling_llm.py @@ -47,6 +47,88 @@ cost_logger = logging.getLogger("holmes.costs") +def _extract_cost_from_response(full_response) -> float: + """Extract cost value from LLM response. + + Args: + full_response: The raw LLM response object + + Returns: + The cost as a float, or 0.0 if not available + """ + try: + cost_value = ( + full_response._hidden_params.get("response_cost", 0) + if hasattr(full_response, "_hidden_params") + else 0 + ) + # Ensure cost is a float + return float(cost_value) if cost_value is not None else 0.0 + except Exception: + return 0.0 + + +def _log_cost_info(full_response, log_prefix: str = "LLM call") -> None: + """Log cost and token information from LLM response. + + Args: + full_response: The raw LLM response object + log_prefix: Prefix for logging messages + """ + try: + cost = _extract_cost_from_response(full_response) + usage = getattr(full_response, "usage", {}) + + if usage: + prompt_toks = usage.get("prompt_tokens", 0) + completion_toks = usage.get("completion_tokens", 0) + total_toks = usage.get("total_tokens", 0) + cost_logger.debug( + f"{log_prefix} cost: ${cost:.6f} | Tokens: {prompt_toks} prompt + {completion_toks} completion = {total_toks} total" + ) + elif cost > 0: + cost_logger.debug( + f"{log_prefix} cost: ${cost:.6f} | Token usage not available" + ) + except Exception as e: + logging.debug(f"Could not extract cost information: {e}") + + +def _extract_and_update_costs( + full_response, result: "LLMResult", log_prefix: str = "LLM call" +) -> None: + """Extract cost and token information from LLM response and update result. + + Args: + full_response: The raw LLM response object + result: The LLMResult to update with cost information + log_prefix: Prefix for logging messages (e.g., "LLM call", "Post-processing") + """ + try: + cost = _extract_cost_from_response(full_response) + usage = getattr(full_response, "usage", {}) + + if usage: + prompt_toks = usage.get("prompt_tokens", 0) + completion_toks = usage.get("completion_tokens", 0) + total_toks = usage.get("total_tokens", 0) + cost_logger.debug( + f"{log_prefix} cost: ${cost:.6f} | Tokens: {prompt_toks} prompt + {completion_toks} completion = {total_toks} total" + ) + # Accumulate costs and tokens + result.total_cost += cost + result.prompt_tokens += prompt_toks + result.completion_tokens += completion_toks + result.total_tokens += total_toks + elif cost > 0: + cost_logger.debug( + f"{log_prefix} cost: ${cost:.6f} | Token usage not available" + ) + result.total_cost += cost + except Exception as e: + logging.debug(f"Could not extract cost information: {e}") + + def format_tool_result_data(tool_result: StructuredToolResult) -> str: tool_response = tool_result.data if isinstance(tool_result.data, str): @@ -306,35 +388,8 @@ def call( # type: ignore ) logging.debug(f"got response {full_response.to_json()}") # type: ignore - # Log and accumulate cost information if available - try: - cost_value = ( - full_response._hidden_params.get("response_cost", 0) - if hasattr(full_response, "_hidden_params") - else 0 - ) - # Ensure cost is a float - cost = float(cost_value) if cost_value is not None else 0.0 - usage = getattr(full_response, "usage", {}) - if usage: - prompt_toks = usage.get("prompt_tokens", 0) - completion_toks = usage.get("completion_tokens", 0) - total_toks = usage.get("total_tokens", 0) - cost_logger.debug( - f"LLM call cost: ${cost:.6f} | Tokens: {prompt_toks} prompt + {completion_toks} completion = {total_toks} total" - ) - # Accumulate costs - result.total_cost += cost - result.prompt_tokens += prompt_toks - result.completion_tokens += completion_toks - result.total_tokens += total_toks - elif cost > 0: - cost_logger.debug( - f"LLM call cost: ${cost:.6f} | Token usage not available" - ) - result.total_cost += cost - except Exception as e: - logging.debug(f"Could not extract cost information: {e}") + # Extract and accumulate cost information + _extract_and_update_costs(full_response, result, "LLM call") perf_timing.measure("llm.completion") # catch a known error that occurs with Azure and replace the error message with something more obvious to the user @@ -601,24 +656,12 @@ def _post_processing_call( full_response = self.llm.completion(messages=messages, temperature=0) logging.debug(f"Post processing response {full_response}") - # Log cost information for post-processing - post_processing_cost = 0.0 - try: - cost_value = ( - full_response._hidden_params.get("response_cost", 0) - if hasattr(full_response, "_hidden_params") - else 0 + # Extract and log cost information for post-processing + post_processing_cost = _extract_cost_from_response(full_response) + if post_processing_cost > 0: + cost_logger.debug( + f"Post-processing LLM cost: ${post_processing_cost:.6f}" ) - # Ensure cost is a float - post_processing_cost = ( - float(cost_value) if cost_value is not None else 0.0 - ) - if post_processing_cost > 0: - cost_logger.debug( - f"Post-processing LLM cost: ${post_processing_cost:.6f}" - ) - except Exception: - pass # Silent fail for cost logging return full_response.choices[0].message.content, post_processing_cost # type: ignore except Exception: @@ -697,26 +740,8 @@ def call_stream( drop_params=True, ) - # Log cost information if available - try: - cost_value = ( - full_response._hidden_params.get("response_cost", 0) - if hasattr(full_response, "_hidden_params") - else 0 - ) - # Ensure cost is a float - cost = float(cost_value) if cost_value is not None else 0.0 - usage = getattr(full_response, "usage", {}) - if usage: - cost_logger.debug( - f"LLM iteration cost: ${cost:.6f} | Tokens: {usage.get('prompt_tokens', 0)} prompt + {usage.get('completion_tokens', 0)} completion = {usage.get('total_tokens', 0)} total" - ) - elif cost > 0: - cost_logger.debug( - f"LLM iteration cost: ${cost:.6f} | Token usage not available" - ) - except Exception as e: - logging.debug(f"Could not extract cost information: {e}") + # Log cost information for this iteration (no accumulation in streaming) + _log_cost_info(full_response, "LLM iteration") perf_timing.measure("llm.completion") # catch a known error that occurs with Azure and replace the error message with something more obvious to the user From 881e447c25fd9aa19a85a68c95251b791773155a Mon Sep 17 00:00:00 2001 From: Robusta Runner Date: Sat, 23 Aug 2025 21:58:14 +0300 Subject: [PATCH 11/14] fixes --- holmes/core/tool_calling_llm.py | 17 +++++++++++------ tests/llm/test_ask_holmes.py | 2 +- tests/llm/test_investigate.py | 2 +- tests/llm/utils/braintrust.py | 2 +- 4 files changed, 14 insertions(+), 9 deletions(-) diff --git a/holmes/core/tool_calling_llm.py b/holmes/core/tool_calling_llm.py index edb819737b..ca8f13a0d7 100644 --- a/holmes/core/tool_calling_llm.py +++ b/holmes/core/tool_calling_llm.py @@ -274,7 +274,7 @@ def as_streaming_tool_result_response(self): class LLMResult(BaseModel): - tool_calls: Optional[List[dict]] = None + tool_calls: Optional[List[ToolCallResult]] = None result: Optional[str] = None unprocessed_result: Optional[str] = None instructions: List[str] = Field(default_factory=list) @@ -491,7 +491,7 @@ def call( # type: ignore if result.tool_calls is None: result.tool_calls = [] - result.tool_calls.append(tool_call_result.as_tool_result_response()) + result.tool_calls.append(tool_call_result) messages.append(tool_call_result.as_tool_call_message()) perf_timing.measure(f"tool completed {tool_call_result.tool_name}") @@ -508,7 +508,7 @@ def call( # type: ignore def _invoke_tool( self, tool_to_call: ChatCompletionMessageToolCall, - previous_tool_calls: list[dict], + previous_tool_calls: List[ToolCallResult], trace_span=DummySpan(), tool_number=None, ) -> ToolCallResult: @@ -565,10 +565,15 @@ def _invoke_tool( tool_span = trace_span.start_span(name=tool_name, type="tool") try: + # Convert ToolCallResult objects to dicts for safeguard checking + tool_calls_as_dicts = [ + tc.as_tool_result_response() if isinstance(tc, ToolCallResult) else tc + for tc in previous_tool_calls + ] tool_response = prevent_overly_repeated_tool_call( tool_name=tool.name, tool_params=tool_params, - tool_calls=previous_tool_calls, + tool_calls=tool_calls_as_dicts, ) if not tool_response: tool_response = tool.invoke(tool_params, tool_number=tool_number) @@ -699,7 +704,7 @@ def call_stream( if msgs: messages.extend(msgs) perf_timing = PerformanceTiming("tool_calling_llm.call") - tool_calls: list[dict] = [] + tool_calls: List[ToolCallResult] = [] tools = self.tool_executor.get_all_tools_openai_format( target_model=self.llm.model ) @@ -815,7 +820,7 @@ def call_stream( for future in concurrent.futures.as_completed(futures): tool_call_result: ToolCallResult = future.result() - tool_calls.append(tool_call_result.as_tool_result_response()) + tool_calls.append(tool_call_result) messages.append(tool_call_result.as_tool_call_message()) perf_timing.measure(f"tool completed {tool_call_result.tool_name}") diff --git a/tests/llm/test_ask_holmes.py b/tests/llm/test_ask_holmes.py index 68194d2e1b..086f14ca9e 100644 --- a/tests/llm/test_ask_holmes.py +++ b/tests/llm/test_ask_holmes.py @@ -135,7 +135,7 @@ def test_ask_holmes( scores = update_test_results( request=request, output=output, - tools_called=[tc["description"] for tc in result.tool_calls] + tools_called=[tc.description for tc in result.tool_calls] if result.tool_calls else [], scores=None, # Let it calculate diff --git a/tests/llm/test_investigate.py b/tests/llm/test_investigate.py index aefc8a3db8..cce3b47d96 100644 --- a/tests/llm/test_investigate.py +++ b/tests/llm/test_investigate.py @@ -200,7 +200,7 @@ def test_investigate( ) raise - tools_called = [t["tool_name"] for t in result.tool_calls] + tools_called = [t.tool_name for t in result.tool_calls] update_test_results(request, output, tools_called, scores, result) assert result.sections, "Missing sections" diff --git a/tests/llm/utils/braintrust.py b/tests/llm/utils/braintrust.py index cfd949f4d7..0585e4e60e 100644 --- a/tests/llm/utils/braintrust.py +++ b/tests/llm/utils/braintrust.py @@ -259,7 +259,7 @@ def log_to_braintrust( # Add tool usage metrics if available if result and getattr(result, "tool_calls", None): metadata["tool_call_count"] = len(result.tool_calls) - metadata["tools_used"] = list({tc["tool_name"] for tc in result.tool_calls}) + metadata["tools_used"] = list({tc.tool_name for tc in result.tool_calls}) # Note: holmes_duration is logged separately directly to eval_span in ask_holmes() # Add error information if present From 820eb20d4dd256f556097367c71626f357aa0334 Mon Sep 17 00:00:00 2001 From: Robusta Runner Date: Sat, 23 Aug 2025 22:10:26 +0300 Subject: [PATCH 12/14] fixes --- holmes/core/tool_calling_llm.py | 83 +++++++++++++++++---------------- 1 file changed, 44 insertions(+), 39 deletions(-) diff --git a/holmes/core/tool_calling_llm.py b/holmes/core/tool_calling_llm.py index ca8f13a0d7..e4c8ff044a 100644 --- a/holmes/core/tool_calling_llm.py +++ b/holmes/core/tool_calling_llm.py @@ -47,6 +47,15 @@ cost_logger = logging.getLogger("holmes.costs") +class LLMCosts(BaseModel): + """Tracks cost and token usage for LLM calls.""" + + total_cost: float = 0.0 + total_tokens: int = 0 + prompt_tokens: int = 0 + completion_tokens: int = 0 + + def _extract_cost_from_response(full_response) -> float: """Extract cost value from LLM response. @@ -95,13 +104,13 @@ def _log_cost_info(full_response, log_prefix: str = "LLM call") -> None: def _extract_and_update_costs( - full_response, result: "LLMResult", log_prefix: str = "LLM call" + full_response, costs: LLMCosts, log_prefix: str = "LLM call" ) -> None: - """Extract cost and token information from LLM response and update result. + """Extract cost and token information from LLM response and update costs. Args: full_response: The raw LLM response object - result: The LLMResult to update with cost information + costs: The LLMCosts to update with cost information log_prefix: Prefix for logging messages (e.g., "LLM call", "Post-processing") """ try: @@ -116,15 +125,15 @@ def _extract_and_update_costs( f"{log_prefix} cost: ${cost:.6f} | Tokens: {prompt_toks} prompt + {completion_toks} completion = {total_toks} total" ) # Accumulate costs and tokens - result.total_cost += cost - result.prompt_tokens += prompt_toks - result.completion_tokens += completion_toks - result.total_tokens += total_toks + costs.total_cost += cost + costs.prompt_tokens += prompt_toks + costs.completion_tokens += completion_toks + costs.total_tokens += total_toks elif cost > 0: cost_logger.debug( f"{log_prefix} cost: ${cost:.6f} | Token usage not available" ) - result.total_cost += cost + costs.total_cost += cost except Exception as e: logging.debug(f"Could not extract cost information: {e}") @@ -273,7 +282,7 @@ def as_streaming_tool_result_response(self): } -class LLMResult(BaseModel): +class LLMResult(LLMCosts): tool_calls: Optional[List[ToolCallResult]] = None result: Optional[str] = None unprocessed_result: Optional[str] = None @@ -282,10 +291,6 @@ class LLMResult(BaseModel): None # somewhat redundant with messages, can likely be removed ) messages: Optional[List[dict]] = None - total_cost: float = 0.0 - total_tokens: int = 0 - prompt_tokens: int = 0 - completion_tokens: int = 0 class ToolCallingLLM: @@ -345,8 +350,9 @@ def call( # type: ignore tool_number_offset: int = 0, ) -> LLMResult: perf_timing = PerformanceTiming("tool_calling_llm.call") - # Initialize result object that we'll populate throughout execution - result = LLMResult() + tool_calls: list[dict] = [] + # Use LLMCosts object to accumulate costs + costs = LLMCosts() tools = self.tool_executor.get_all_tools_openai_format( target_model=self.llm.model @@ -389,7 +395,7 @@ def call( # type: ignore logging.debug(f"got response {full_response.to_json()}") # type: ignore # Extract and accumulate cost information - _extract_and_update_costs(full_response, result, "LLM call") + _extract_and_update_costs(full_response, costs, "LLM call") perf_timing.measure("llm.completion") # catch a known error that occurs with Azure and replace the error message with something more obvious to the user @@ -451,20 +457,26 @@ def call( # type: ignore user_prompt=post_process_prompt, ) ) - result.total_cost += post_processing_cost + costs.total_cost += post_processing_cost perf_timing.end(f"- completed in {i} iterations -") - result.result = post_processed_response - result.unprocessed_result = raw_response - result.prompt = json.dumps(messages, indent=2) - result.messages = messages - return result + return LLMResult( + result=post_processed_response, + unprocessed_result=raw_response, + tool_calls=tool_calls, # type: ignore # Pydantic converts dicts to ToolCallResult + prompt=json.dumps(messages, indent=2), + messages=messages, + **costs.model_dump(), # Include all cost fields + ) perf_timing.end(f"- completed in {i} iterations -") - result.result = text_response - result.prompt = json.dumps(messages, indent=2) - result.messages = messages - return result + return LLMResult( + result=text_response, + tool_calls=tool_calls, # type: ignore # Pydantic converts dicts to ToolCallResult + prompt=json.dumps(messages, indent=2), + messages=messages, + **costs.model_dump(), # Include all cost fields + ) if text_response and text_response.strip(): logging.info(f"[bold {AI_COLOR}]AI:[/bold {AI_COLOR}] {text_response}") @@ -480,7 +492,7 @@ def call( # type: ignore executor.submit( self._invoke_tool, tool_to_call=t, - previous_tool_calls=result.tool_calls or [], + previous_tool_calls=tool_calls, trace_span=trace_span, tool_number=tool_number_offset + tool_index, ) @@ -489,9 +501,7 @@ def call( # type: ignore for future in concurrent.futures.as_completed(futures): tool_call_result: ToolCallResult = future.result() - if result.tool_calls is None: - result.tool_calls = [] - result.tool_calls.append(tool_call_result) + tool_calls.append(tool_call_result.as_tool_result_response()) messages.append(tool_call_result.as_tool_call_message()) perf_timing.measure(f"tool completed {tool_call_result.tool_name}") @@ -508,7 +518,7 @@ def call( # type: ignore def _invoke_tool( self, tool_to_call: ChatCompletionMessageToolCall, - previous_tool_calls: List[ToolCallResult], + previous_tool_calls: list[dict], trace_span=DummySpan(), tool_number=None, ) -> ToolCallResult: @@ -565,15 +575,10 @@ def _invoke_tool( tool_span = trace_span.start_span(name=tool_name, type="tool") try: - # Convert ToolCallResult objects to dicts for safeguard checking - tool_calls_as_dicts = [ - tc.as_tool_result_response() if isinstance(tc, ToolCallResult) else tc - for tc in previous_tool_calls - ] tool_response = prevent_overly_repeated_tool_call( tool_name=tool.name, tool_params=tool_params, - tool_calls=tool_calls_as_dicts, + tool_calls=previous_tool_calls, ) if not tool_response: tool_response = tool.invoke(tool_params, tool_number=tool_number) @@ -704,7 +709,7 @@ def call_stream( if msgs: messages.extend(msgs) perf_timing = PerformanceTiming("tool_calling_llm.call") - tool_calls: List[ToolCallResult] = [] + tool_calls: list[dict] = [] tools = self.tool_executor.get_all_tools_openai_format( target_model=self.llm.model ) @@ -820,7 +825,7 @@ def call_stream( for future in concurrent.futures.as_completed(futures): tool_call_result: ToolCallResult = future.result() - tool_calls.append(tool_call_result) + tool_calls.append(tool_call_result.as_tool_result_response()) messages.append(tool_call_result.as_tool_call_message()) perf_timing.measure(f"tool completed {tool_call_result.tool_name}") From d38644cc61b7f6a21f467c8793abda5882209902 Mon Sep 17 00:00:00 2001 From: Robusta Runner Date: Sat, 23 Aug 2025 22:36:31 +0300 Subject: [PATCH 13/14] fixes --- holmes/core/tool_calling_llm.py | 83 ++++++++++++--------------------- 1 file changed, 31 insertions(+), 52 deletions(-) diff --git a/holmes/core/tool_calling_llm.py b/holmes/core/tool_calling_llm.py index e4c8ff044a..6d7fd2d2f4 100644 --- a/holmes/core/tool_calling_llm.py +++ b/holmes/core/tool_calling_llm.py @@ -77,40 +77,16 @@ def _extract_cost_from_response(full_response) -> float: return 0.0 -def _log_cost_info(full_response, log_prefix: str = "LLM call") -> None: - """Log cost and token information from LLM response. - - Args: - full_response: The raw LLM response object - log_prefix: Prefix for logging messages - """ - try: - cost = _extract_cost_from_response(full_response) - usage = getattr(full_response, "usage", {}) - - if usage: - prompt_toks = usage.get("prompt_tokens", 0) - completion_toks = usage.get("completion_tokens", 0) - total_toks = usage.get("total_tokens", 0) - cost_logger.debug( - f"{log_prefix} cost: ${cost:.6f} | Tokens: {prompt_toks} prompt + {completion_toks} completion = {total_toks} total" - ) - elif cost > 0: - cost_logger.debug( - f"{log_prefix} cost: ${cost:.6f} | Token usage not available" - ) - except Exception as e: - logging.debug(f"Could not extract cost information: {e}") - - -def _extract_and_update_costs( - full_response, costs: LLMCosts, log_prefix: str = "LLM call" +def _process_cost_info( + full_response, costs: Optional[LLMCosts] = None, log_prefix: str = "LLM call" ) -> None: - """Extract cost and token information from LLM response and update costs. + """Process cost and token information from LLM response. + + Logs the cost information and optionally accumulates it into a costs object. Args: full_response: The raw LLM response object - costs: The LLMCosts to update with cost information + costs: Optional LLMCosts object to accumulate costs into log_prefix: Prefix for logging messages (e.g., "LLM call", "Post-processing") """ try: @@ -124,16 +100,18 @@ def _extract_and_update_costs( cost_logger.debug( f"{log_prefix} cost: ${cost:.6f} | Tokens: {prompt_toks} prompt + {completion_toks} completion = {total_toks} total" ) - # Accumulate costs and tokens - costs.total_cost += cost - costs.prompt_tokens += prompt_toks - costs.completion_tokens += completion_toks - costs.total_tokens += total_toks + # Accumulate costs and tokens if costs object provided + if costs: + costs.total_cost += cost + costs.prompt_tokens += prompt_toks + costs.completion_tokens += completion_toks + costs.total_tokens += total_toks elif cost > 0: cost_logger.debug( f"{log_prefix} cost: ${cost:.6f} | Token usage not available" ) - costs.total_cost += cost + if costs: + costs.total_cost += cost except Exception as e: logging.debug(f"Could not extract cost information: {e}") @@ -239,9 +217,7 @@ class ToolCallResult(BaseModel): tool_name: str description: str result: StructuredToolResult - size: Optional[int] = ( - None # TODO: currently unused - remove it? need to verify this doesn't break clients - ) + size: Optional[int] = None def as_tool_call_message(self): content = format_tool_result_data(self.result) @@ -287,11 +263,15 @@ class LLMResult(LLMCosts): result: Optional[str] = None unprocessed_result: Optional[str] = None instructions: List[str] = Field(default_factory=list) - prompt: Optional[str] = ( - None # somewhat redundant with messages, can likely be removed - ) + # TODO: clean up these two + prompt: Optional[str] = None messages: Optional[List[dict]] = None + def get_tool_usage_summary(self): + return "AI used info from issue and " + ",".join( + [f"`{tool_call.description}`" for tool_call in self.tool_calls] + ) + class ToolCallingLLM: llm: LLM @@ -350,8 +330,7 @@ def call( # type: ignore tool_number_offset: int = 0, ) -> LLMResult: perf_timing = PerformanceTiming("tool_calling_llm.call") - tool_calls: list[dict] = [] - # Use LLMCosts object to accumulate costs + tool_calls = [] # type: ignore costs = LLMCosts() tools = self.tool_executor.get_all_tools_openai_format( @@ -369,12 +348,12 @@ def call( # type: ignore tools = None if i == max_steps else tools tool_choice = "auto" if tools else None - message_tokens = self.llm.count_tokens_for_message(messages) + total_tokens = self.llm.count_tokens_for_message(messages) max_context_size = self.llm.get_context_window_size() maximum_output_token = self.llm.get_maximum_output_token() perf_timing.measure("count tokens") - if (message_tokens + maximum_output_token) > max_context_size: + if (total_tokens + maximum_output_token) > max_context_size: logging.warning("Token limit exceeded. Truncating tool responses.") messages = self.truncate_messages_to_fit_context( messages, max_context_size, maximum_output_token @@ -395,7 +374,7 @@ def call( # type: ignore logging.debug(f"got response {full_response.to_json()}") # type: ignore # Extract and accumulate cost information - _extract_and_update_costs(full_response, costs, "LLM call") + _process_cost_info(full_response, costs, "LLM call") perf_timing.measure("llm.completion") # catch a known error that occurs with Azure and replace the error message with something more obvious to the user @@ -463,7 +442,7 @@ def call( # type: ignore return LLMResult( result=post_processed_response, unprocessed_result=raw_response, - tool_calls=tool_calls, # type: ignore # Pydantic converts dicts to ToolCallResult + tool_calls=tool_calls, prompt=json.dumps(messages, indent=2), messages=messages, **costs.model_dump(), # Include all cost fields @@ -472,7 +451,7 @@ def call( # type: ignore perf_timing.end(f"- completed in {i} iterations -") return LLMResult( result=text_response, - tool_calls=tool_calls, # type: ignore # Pydantic converts dicts to ToolCallResult + tool_calls=tool_calls, prompt=json.dumps(messages, indent=2), messages=messages, **costs.model_dump(), # Include all cost fields @@ -726,12 +705,12 @@ def call_stream( tools = None if i == max_steps else tools tool_choice = "auto" if tools else None - message_tokens = self.llm.count_tokens_for_message(messages) # type: ignore + total_tokens = self.llm.count_tokens_for_message(messages) # type: ignore max_context_size = self.llm.get_context_window_size() maximum_output_token = self.llm.get_maximum_output_token() perf_timing.measure("count tokens") - if (message_tokens + maximum_output_token) > max_context_size: + if (total_tokens + maximum_output_token) > max_context_size: logging.warning("Token limit exceeded. Truncating tool responses.") messages = self.truncate_messages_to_fit_context( messages, max_context_size, maximum_output_token @@ -751,7 +730,7 @@ def call_stream( ) # Log cost information for this iteration (no accumulation in streaming) - _log_cost_info(full_response, "LLM iteration") + _process_cost_info(full_response, log_prefix="LLM iteration") perf_timing.measure("llm.completion") # catch a known error that occurs with Azure and replace the error message with something more obvious to the user From 568b34041614c2a0f5b7784385233db8d944efc7 Mon Sep 17 00:00:00 2001 From: Robusta Runner Date: Sat, 23 Aug 2025 22:42:58 +0300 Subject: [PATCH 14/14] fixes --- tests/llm/test_investigate.py | 2 +- tests/llm/test_workload_health.py | 4 +++- 2 files changed, 4 insertions(+), 2 deletions(-) diff --git a/tests/llm/test_investigate.py b/tests/llm/test_investigate.py index cce3b47d96..8cf08c9af6 100644 --- a/tests/llm/test_investigate.py +++ b/tests/llm/test_investigate.py @@ -200,7 +200,7 @@ def test_investigate( ) raise - tools_called = [t.tool_name for t in result.tool_calls] + tools_called = [t.tool_name for t in result.tool_calls] if result.tool_calls else [] update_test_results(request, output, tools_called, scores, result) assert result.sections, "Missing sections" diff --git a/tests/llm/test_workload_health.py b/tests/llm/test_workload_health.py index c219e169ca..15e49fabe9 100644 --- a/tests/llm/test_workload_health.py +++ b/tests/llm/test_workload_health.py @@ -165,7 +165,9 @@ def test_health_check( tags=tags, ) - tools_called = [t.tool_name for t in result.tool_calls] + tools_called = ( + [t.tool_name for t in result.tool_calls] if result.tool_calls else [] + ) print(f"\n** TOOLS CALLED **\n{tools_called}") print(f"\n** OUTPUT **\n{output}") print(f"\n** SCORES **\n{scores}")