diff --git a/llama_stack/core/testing_context.py b/llama_stack/core/testing_context.py index 23cef751b..6c3e09987 100644 --- a/llama_stack/core/testing_context.py +++ b/llama_stack/core/testing_context.py @@ -42,3 +42,8 @@ def sync_test_context_from_provider_data(): return TEST_CONTEXT.set(provider_data["__test_id"]) return None + + +def is_debug_mode() -> bool: + """Check if test recording debug mode is enabled via LLAMA_STACK_TEST_DEBUG env var.""" + return os.environ.get("LLAMA_STACK_TEST_DEBUG", "").lower() in ("1", "true", "yes") diff --git a/llama_stack/testing/api_recorder.py b/llama_stack/testing/api_recorder.py index 4a4644dad..9e272ca3a 100644 --- a/llama_stack/testing/api_recorder.py +++ b/llama_stack/testing/api_recorder.py @@ -37,7 +37,7 @@ _id_counters: dict[str, dict[str, int]] = {} # Test context uses ContextVar since it changes per-test and needs async isolation from openai.types.completion_choice import CompletionChoice -from llama_stack.core.testing_context import get_test_context +from llama_stack.core.testing_context import get_test_context, is_debug_mode # update the "finish_reason" field, since its type definition is wrong (no None is accepted) CompletionChoice.model_fields["finish_reason"].annotation = Literal["stop", "length", "content_filter"] | None @@ -146,6 +146,7 @@ def normalize_inference_request(method: str, url: str, headers: dict[str, Any], body_for_hash = _normalize_body_for_hash(body) + test_id = get_test_context() normalized: dict[str, Any] = { "method": method.upper(), "endpoint": parsed.path, @@ -154,10 +155,20 @@ def normalize_inference_request(method: str, url: str, headers: dict[str, Any], # Include test_id for isolation, except for shared infrastructure endpoints if parsed.path not in ("/api/tags", "/v1/models"): - normalized["test_id"] = get_test_context() + normalized["test_id"] = test_id normalized_json = json.dumps(normalized, sort_keys=True) - return hashlib.sha256(normalized_json.encode()).hexdigest() + request_hash = hashlib.sha256(normalized_json.encode()).hexdigest() + + if is_debug_mode(): + logger.info("[RECORDING DEBUG] Hash computation:") + logger.info(f" Test ID: {test_id}") + logger.info(f" Method: {method.upper()}") + logger.info(f" Endpoint: {parsed.path}") + logger.info(f" Model: {body.get('model', 'N/A')}") + logger.info(f" Computed hash: {request_hash}") + + return request_hash def normalize_tool_request(provider_name: str, tool_name: str, kwargs: dict[str, Any]) -> str: @@ -212,6 +223,11 @@ def patch_httpx_for_test_id(): provider_data["__test_id"] = test_id request.headers["X-LlamaStack-Provider-Data"] = json.dumps(provider_data) + if is_debug_mode(): + logger.info("[RECORDING DEBUG] Injected test ID into request header:") + logger.info(f" Test ID: {test_id}") + logger.info(f" URL: {request.url}") + return None LlamaStackClient._prepare_request = patched_prepare_request @@ -355,18 +371,35 @@ class ResponseStorage: test_file = test_id.split("::")[0] # Remove test function part test_dir = Path(test_file).parent # Get parent directory - # Make it absolute by resolving against base_dir - # If base_dir is absolute, use it as the root, otherwise resolve relative to cwd if self.base_dir.is_absolute(): - # base_dir is something like /app/llama-stack-source/tests/integration/common - # We need to go up to the repo root and then back down to the test dir - repo_root = self.base_dir.parent.parent.parent # go up from common -> integration -> tests -> repo - return repo_root / test_dir / "recordings" + repo_root = self.base_dir.parent.parent.parent + result = repo_root / test_dir / "recordings" + if is_debug_mode(): + logger.info("[RECORDING DEBUG] Path resolution (absolute base_dir):") + logger.info(f" Test ID: {test_id}") + logger.info(f" Base dir: {self.base_dir}") + logger.info(f" Repo root: {repo_root}") + logger.info(f" Test file: {test_file}") + logger.info(f" Test dir: {test_dir}") + logger.info(f" Recordings dir: {result}") + return result else: - return test_dir / "recordings" + result = test_dir / "recordings" + if is_debug_mode(): + logger.info("[RECORDING DEBUG] Path resolution (relative base_dir):") + logger.info(f" Test ID: {test_id}") + logger.info(f" Base dir: {self.base_dir}") + logger.info(f" Test dir: {test_dir}") + logger.info(f" Recordings dir: {result}") + return result else: # Fallback for non-test contexts - return self.base_dir / "recordings" + result = self.base_dir / "recordings" + if is_debug_mode(): + logger.info("[RECORDING DEBUG] Path resolution (no test context):") + logger.info(f" Base dir: {self.base_dir}") + logger.info(f" Recordings dir: {result}") + return result def _ensure_directory(self): """Ensure test-specific directories exist.""" @@ -401,6 +434,13 @@ class ResponseStorage: response_path = responses_dir / response_file + if is_debug_mode(): + logger.info("[RECORDING DEBUG] Storing recording:") + logger.info(f" Request hash: {request_hash}") + logger.info(f" File: {response_path}") + logger.info(f" Test ID: {get_test_context()}") + logger.info(f" Endpoint: {endpoint}") + # Save response to JSON file with metadata with open(response_path, "w") as f: json.dump( @@ -429,16 +469,33 @@ class ResponseStorage: test_dir = self._get_test_dir() response_path = test_dir / response_file + if is_debug_mode(): + logger.info("[RECORDING DEBUG] Looking up recording:") + logger.info(f" Request hash: {request_hash}") + logger.info(f" Primary path: {response_path}") + logger.info(f" Primary exists: {response_path.exists()}") + if response_path.exists(): + if is_debug_mode(): + logger.info(" Found in primary location") return _recording_from_file(response_path) # Fallback to base recordings directory (for session-level recordings) fallback_dir = self.base_dir / "recordings" fallback_path = fallback_dir / response_file + if is_debug_mode(): + logger.info(f" Fallback path: {fallback_path}") + logger.info(f" Fallback exists: {fallback_path.exists()}") + if fallback_path.exists(): + if is_debug_mode(): + logger.info(" Found in fallback location") return _recording_from_file(fallback_path) + if is_debug_mode(): + logger.info(" Recording not found in either location") + return None def _model_list_responses(self, request_hash: str) -> list[dict[str, Any]]: @@ -594,6 +651,13 @@ async def _patched_inference_method(original_method, self, client_type, endpoint mode = _current_mode storage = _current_storage + if is_debug_mode(): + logger.info("[RECORDING DEBUG] Entering inference method:") + logger.info(f" Mode: {mode}") + logger.info(f" Client type: {client_type}") + logger.info(f" Endpoint: {endpoint}") + logger.info(f" Test context: {get_test_context()}") + if mode == APIRecordingMode.LIVE or storage is None: if endpoint == "/v1/models": return original_method(self, *args, **kwargs) @@ -649,6 +713,18 @@ async def _patched_inference_method(original_method, self, client_type, endpoint return response_body elif mode == APIRecordingMode.REPLAY: # REPLAY mode requires recording to exist + if is_debug_mode(): + logger.error("[RECORDING DEBUG] Recording not found!") + logger.error(f" Mode: {mode}") + logger.error(f" Request hash: {request_hash}") + logger.error(f" Method: {method}") + logger.error(f" URL: {url}") + logger.error(f" Endpoint: {endpoint}") + logger.error(f" Model: {body.get('model', 'unknown')}") + logger.error(f" Test context: {get_test_context()}") + logger.error( + f" Stack config type: {os.environ.get('LLAMA_STACK_TEST_STACK_CONFIG_TYPE', 'library_client')}" + ) raise RuntimeError( f"Recording not found for request hash: {request_hash}\n" f"Model: {body.get('model', 'unknown')} | Request: {method} {url}\n" diff --git a/scripts/diagnose_recordings.py b/scripts/diagnose_recordings.py new file mode 100755 index 000000000..9c255f6f0 --- /dev/null +++ b/scripts/diagnose_recordings.py @@ -0,0 +1,370 @@ +#!/usr/bin/env python3 +# Copyright (c) Meta Platforms, Inc. and affiliates. +# All rights reserved. +# +# This source code is licensed under the terms described in the LICENSE file in +# the root directory of this source tree. + +""" +Diagnostic tool for debugging test recording issues. + +Usage: + # Find where a hash would be looked up + ./scripts/diagnose_recordings.py find-hash 7526c930eab04ce337496a26cd15f2591d7943035f2527182861643da9b837a7 + + # Show what's in a recording file + ./scripts/diagnose_recordings.py show tests/integration/agents/recordings/7526c930....json + + # List all recordings for a test + ./scripts/diagnose_recordings.py list-test "tests/integration/agents/test_agents.py::test_custom_tool" + + # Explain lookup paths for a test + ./scripts/diagnose_recordings.py explain-paths --test-id "tests/integration/agents/test_agents.py::test_foo" + + # Compare request hash computation + ./scripts/diagnose_recordings.py compute-hash --endpoint /v1/chat/completions --method POST --body '{"model":"llama3.2:3b"}' --test-id "..." +""" + +import argparse +import json +import sys +from pathlib import Path + +# Add parent directory to path to import from llama_stack +REPO_ROOT = Path(__file__).parent.parent +sys.path.insert(0, str(REPO_ROOT)) + +try: + from llama_stack.testing.api_recorder import normalize_inference_request +except ImportError: + normalize_inference_request = None + + +def find_hash(hash_value: str, base_dir: Path | None = None, test_id: str | None = None): + """Find where a hash would be looked up and what exists""" + if base_dir is None: + base_dir = REPO_ROOT / "tests/integration/common" + + print(f"Searching for hash: {hash_value}\n") + print(f"Base dir: {base_dir} (absolute={base_dir.is_absolute()})") + + # Compute test directory + if test_id: + test_file = test_id.split("::")[0] + test_dir = Path(test_file).parent + + if base_dir.is_absolute(): + repo_root = base_dir.parent.parent.parent + test_recordings_dir = repo_root / test_dir / "recordings" + else: + test_recordings_dir = test_dir / "recordings" + print(f"Test ID: {test_id}") + print(f"Test dir: {test_recordings_dir}\n") + else: + test_recordings_dir = base_dir / "recordings" + print("No test ID provided, using base dir\n") + + # Check primary location + response_file = f"{hash_value}.json" + response_path = test_recordings_dir / response_file + + print("Checking primary location:") + print(f" {response_path}") + if response_path.exists(): + print(" EXISTS") + print("\nFound! Contents:") + show_recording(response_path) + return True + else: + print(" Does not exist") + + # Check fallback location + fallback_dir = base_dir / "recordings" + fallback_path = fallback_dir / response_file + + print("\nChecking fallback location:") + print(f" {fallback_path}") + if fallback_path.exists(): + print(" EXISTS") + print("\nFound in fallback! Contents:") + show_recording(fallback_path) + return True + else: + print(" Does not exist") + + # Show what files DO exist + print(f"\nFiles in test directory ({test_recordings_dir}):") + if test_recordings_dir.exists(): + json_files = list(test_recordings_dir.glob("*.json")) + if json_files: + for f in json_files[:20]: + print(f" - {f.name}") + if len(json_files) > 20: + print(f" ... and {len(json_files) - 20} more") + else: + print(" (empty)") + else: + print(" Directory does not exist") + + print(f"\nFiles in fallback directory ({fallback_dir}):") + if fallback_dir.exists(): + json_files = list(fallback_dir.glob("*.json")) + if json_files: + for f in json_files[:20]: + print(f" - {f.name}") + if len(json_files) > 20: + print(f" ... and {len(json_files) - 20} more") + else: + print(" (empty)") + else: + print(" Directory does not exist") + + # Try partial hash match + print("\nLooking for partial matches (first 16 chars)...") + partial = hash_value[:16] + matches = [] + + for dir_to_search in [test_recordings_dir, fallback_dir]: + if dir_to_search.exists(): + for f in dir_to_search.glob("*.json"): + if f.stem.startswith(partial): + matches.append(f) + + if matches: + print(f"Found {len(matches)} partial match(es):") + for m in matches: + print(f" {m}") + else: + print("No partial matches found") + + return False + + +def show_recording(file_path: Path): + """Show contents of a recording file""" + if not file_path.exists(): + print(f"File does not exist: {file_path}") + return + + with open(file_path) as f: + data = json.load(f) + + print(f"\nRecording: {file_path.name}\n") + print(f"Test ID: {data.get('test_id', 'N/A')}") + print("\nRequest:") + req = data.get("request", {}) + print(f" Method: {req.get('method', 'N/A')}") + print(f" URL: {req.get('url', 'N/A')}") + print(f" Endpoint: {req.get('endpoint', 'N/A')}") + print(f" Model: {req.get('model', 'N/A')}") + + body = req.get("body", {}) + if body: + print("\nRequest Body:") + print(f" Model: {body.get('model', 'N/A')}") + print(f" Stream: {body.get('stream', 'N/A')}") + if "messages" in body: + print(f" Messages: {len(body['messages'])} message(s)") + for i, msg in enumerate(body["messages"][:3]): + role = msg.get("role", "unknown") + content = msg.get("content", "") + if isinstance(content, str): + preview = content[:80] + "..." if len(content) > 80 else content + else: + preview = f"[{type(content).__name__}]" + print(f" [{i}] {role}: {preview}") + if "tools" in body: + print(f" Tools: {len(body['tools'])} tool(s)") + + response = data.get("response", {}) + if response: + print("\nResponse:") + print(f" Is streaming: {response.get('is_streaming', False)}") + response_body = response.get("body", {}) + if isinstance(response_body, dict): + if "__type__" in response_body: + print(f" Type: {response_body['__type__']}") + if "__data__" in response_body: + response_data = response_body["__data__"] + if "choices" in response_data: + print(f" Choices: {len(response_data['choices'])}") + if "usage" in response_data: + usage = response_data["usage"] + print(f" Usage: in={usage.get('input_tokens')}, out={usage.get('output_tokens')}") + + +def list_test_recordings(test_id: str, base_dir: Path | None = None): + """List all recordings for a specific test""" + if base_dir is None: + base_dir = REPO_ROOT / "tests/integration/common" + + test_file = test_id.split("::")[0] + test_dir = Path(test_file).parent + + if base_dir.is_absolute(): + repo_root = base_dir.parent.parent.parent + test_recordings_dir = repo_root / test_dir / "recordings" + else: + test_recordings_dir = test_dir / "recordings" + + print(f"Recordings for test: {test_id}\n") + print(f"Directory: {test_recordings_dir}\n") + + if not test_recordings_dir.exists(): + print("Directory does not exist") + return + + # Find all recordings for this specific test + recordings = [] + for f in test_recordings_dir.glob("*.json"): + try: + with open(f) as fp: + data = json.load(fp) + if data.get("test_id") == test_id: + recordings.append((f, data)) + except Exception as e: + print(f"Could not read {f.name}: {e}") + + if not recordings: + print("No recordings found for this exact test ID") + print("\nAll files in directory:") + for f in test_recordings_dir.glob("*.json"): + print(f" - {f.name}") + return + + print(f"Found {len(recordings)} recording(s):\n") + for f, data in recordings: + req = data.get("request", {}) + print(f" {f.name}") + print(f" Endpoint: {req.get('endpoint', 'N/A')}") + print(f" Model: {req.get('model', 'N/A')}") + print("") + + +def explain_paths(test_id: str | None = None, base_dir: Path | None = None): + """Explain where recordings would be searched""" + if base_dir is None: + base_dir = REPO_ROOT / "tests/integration/common" + + print("Recording Lookup Path Explanation\n") + print(f"Base directory: {base_dir}") + print(f" Absolute: {base_dir.is_absolute()}") + print("") + + if test_id: + print(f"Test ID: {test_id}") + test_file = test_id.split("::")[0] + print(f" Test file: {test_file}") + + test_dir = Path(test_file).parent + print(f" Test dir (relative): {test_dir}") + + if base_dir.is_absolute(): + repo_root = base_dir.parent.parent.parent + print(f" Repo root: {repo_root}") + test_recordings_dir = repo_root / test_dir / "recordings" + print(f" Test recordings dir (absolute): {test_recordings_dir}") + else: + test_recordings_dir = test_dir / "recordings" + print(f" Test recordings dir (relative): {test_recordings_dir}") + + print("\nLookup order for recordings:") + print(f" 1. Test-specific: {test_recordings_dir}/.json") + print(f" 2. Fallback: {base_dir}/recordings/.json") + + else: + print("No test ID provided") + print("\nLookup location:") + print(f" {base_dir}/recordings/.json") + + +def compute_hash(endpoint: str, method: str, body_json: str, test_id: str | None = None): + """Compute hash for a request""" + if normalize_inference_request is None: + print("Could not import normalize_inference_request from llama_stack.testing.api_recorder") + print("Make sure you're running from the repo root with proper PYTHONPATH") + return + + try: + body = json.loads(body_json) + except json.JSONDecodeError as e: + print(f"Invalid JSON in body: {e}") + return + + # Create a fake URL with the endpoint + url = f"http://example.com{endpoint}" + + # Set test context if provided + if test_id: + from llama_stack.core.testing_context import set_test_context + + set_test_context(test_id) + + hash_result = normalize_inference_request(method, url, {}, body) + + print("Hash Computation\n") + print(f"Method: {method}") + print(f"Endpoint: {endpoint}") + print(f"Test ID: {test_id or 'None (excluded from hash for model-list endpoints)'}") + print("\nBody:") + print(json.dumps(body, indent=2)) + print(f"\nComputed Hash: {hash_result}") + print(f"\nLooking for file: {hash_result}.json") + + +def main(): + parser = argparse.ArgumentParser( + description="Diagnostic tool for test recording issues", + formatter_class=argparse.RawDescriptionHelpFormatter, + epilog=__doc__, + ) + + subparsers = parser.add_subparsers(dest="command", help="Command to run") + + # find-hash command + find_parser = subparsers.add_parser("find-hash", help="Find where a hash would be looked up") + find_parser.add_argument("hash", help="Hash value to search for (full or partial)") + find_parser.add_argument("--test-id", help="Test ID to determine search paths") + find_parser.add_argument("--base-dir", type=Path, help="Base directory (default: tests/integration/common)") + + # show command + show_parser = subparsers.add_parser("show", help="Show contents of a recording file") + show_parser.add_argument("file", type=Path, help="Path to recording JSON file") + + # list-test command + list_parser = subparsers.add_parser("list-test", help="List all recordings for a test") + list_parser.add_argument("test_id", help="Full test ID (e.g., tests/integration/agents/test_agents.py::test_foo)") + list_parser.add_argument("--base-dir", type=Path, help="Base directory (default: tests/integration/common)") + + # explain-paths command + explain_parser = subparsers.add_parser("explain-paths", help="Explain where recordings are searched") + explain_parser.add_argument("--test-id", help="Test ID to show paths for") + explain_parser.add_argument("--base-dir", type=Path, help="Base directory (default: tests/integration/common)") + + # compute-hash command + hash_parser = subparsers.add_parser("compute-hash", help="Compute hash for a request") + hash_parser.add_argument("--endpoint", required=True, help="Endpoint path (e.g., /v1/chat/completions)") + hash_parser.add_argument("--method", default="POST", help="HTTP method (default: POST)") + hash_parser.add_argument("--body", required=True, help="Request body as JSON string") + hash_parser.add_argument("--test-id", help="Test ID (affects hash for non-model-list endpoints)") + + args = parser.parse_args() + + if not args.command: + parser.print_help() + return + + if args.command == "find-hash": + find_hash(args.hash, args.base_dir, args.test_id) + elif args.command == "show": + show_recording(args.file) + elif args.command == "list-test": + list_test_recordings(args.test_id, args.base_dir) + elif args.command == "explain-paths": + explain_paths(args.test_id, args.base_dir) + elif args.command == "compute-hash": + compute_hash(args.endpoint, args.method, args.body, args.test_id) + + +if __name__ == "__main__": + main()