diff --git a/tavern/_core/pytest/item.py b/tavern/_core/pytest/item.py index 317332576..a34ed431e 100644 --- a/tavern/_core/pytest/item.py +++ b/tavern/_core/pytest/item.py @@ -1,6 +1,7 @@ import dataclasses import logging import pathlib +import time from collections.abc import Callable, Iterable, MutableMapping import pytest @@ -236,6 +237,7 @@ def _load_fixture_values(self): return values def runtest(self) -> None: + start_time = time.perf_counter() self.global_cfg = load_global_cfg(self.config) load_plugins(self.global_cfg) @@ -296,6 +298,12 @@ def runtest(self) -> None: if xfail: raise Exception(f"internal: xfail test did not fail '{xfail}'") finally: + duration = time.perf_counter() - start_time + logger.info( + "tavern.test_duration_seconds=%0.3f test=%s", + duration, + self.name, + ) call_hook( self.global_cfg, "pytest_tavern_beta_after_every_test_run", diff --git a/tavern/_core/schema/jsonschema.py b/tavern/_core/schema/jsonschema.py index 783a64c84..0b0890ffc 100644 --- a/tavern/_core/schema/jsonschema.py +++ b/tavern/_core/schema/jsonschema.py @@ -37,6 +37,44 @@ logger: logging.Logger = logging.getLogger(__name__) +def _format_error_path(path): + parts = [] + for item in path: + if isinstance(item, int): + if parts: + parts[-1] = f"{parts[-1]}[{item}]" + else: + parts.append(f"[{item}]") + else: + parts.append(str(item)) + return ".".join(parts) + + +def _extract_missing_required_key(error: ValidationError) -> str | None: + match = re.search(r"'(.+?)' is a required property", error.message) + if match: + return match.group(1) + return None + + +def _format_validation_message(error: ValidationError) -> str: + message = error.message + if error.validator == "required": + missing_key = _extract_missing_required_key(error) + path = list(error.absolute_path) + if missing_key: + path.append(missing_key) + path_str = _format_error_path(path) + stage_name = None + if isinstance(error.instance, Mapping): + stage_name = error.instance.get("name") or error.instance.get("id") + if stage_name: + message = f"{message} (stage: {stage_name})" + if path_str: + message = f"{message} (path: {path_str})" + return message + + def is_str_or_bytes_or_token(checker, instance): return Draft7Validator.TYPE_CHECKER.is_type(instance, "string") or isinstance( @@ -163,7 +201,7 @@ def verify_jsonschema(to_verify: Mapping, schema: Mapping) -> None: content = "\n".join(list(lines)) real_context.append( f""" -{c.message} +{_format_validation_message(c)} {filename}: line {first_line}-{last_line}: {content} @@ -172,7 +210,7 @@ def verify_jsonschema(to_verify: Mapping, schema: Mapping) -> None: else: real_context.append( f""" -{c.message} +{_format_validation_message(c)} """ diff --git a/tests/unit/test_helpers.py b/tests/unit/test_helpers.py index 3063d6215..ffd3d341f 100644 --- a/tests/unit/test_helpers.py +++ b/tests/unit/test_helpers.py @@ -1,4 +1,6 @@ import contextlib +import logging +import pathlib import json import sys import tempfile @@ -13,6 +15,7 @@ from tavern._core import exceptions from tavern._core.dict_util import _check_and_format_values, format_keys from tavern._core.loader import ForceIncludeToken +from tavern._core.pytest.config import TavernInternalConfig, TestConfig from tavern._core.pytest.item import YamlItem from tavern._core.schema.extensions import validate_file_spec from tavern._core.strict_util import ( @@ -458,3 +461,31 @@ def test_unset(self, section): level = StrictLevel.from_options([section]) assert level.option_for(section).setting == StrictSetting.UNSET + + +def test_logs_test_duration(caplog, monkeypatch, request): + spec = {"test_name": "duration", "stages": [{"name": "stage"}]} + item = YamlItem.from_parent( + name="duration", parent=request.node, spec=spec, path=pathlib.Path("test.tavern.yaml") + ) + item.funcargs = {} + item.fixturenames = [] + + test_config = TestConfig( + variables={}, + strict=StrictLevel(), + follow_redirects=False, + stages=[], + tavern_internal=TavernInternalConfig(pytest_hook_caller=Mock(), backends={}), + ) + + monkeypatch.setattr("tavern._core.pytest.item.load_global_cfg", lambda _cfg: test_config) + monkeypatch.setattr("tavern._core.pytest.item.load_plugins", lambda _cfg: None) + monkeypatch.setattr("tavern._core.pytest.item.verify_tests", lambda _spec: None) + monkeypatch.setattr("tavern._core.pytest.item.run_test", lambda *_args, **_kwargs: None) + monkeypatch.setattr("tavern._core.pytest.item.call_hook", lambda *_args, **_kwargs: None) + + with caplog.at_level(logging.INFO, logger="tavern._core.pytest.item"): + item.runtest() + + assert any("tavern.test_duration_seconds=" in record.message for record in caplog.records) diff --git a/tests/unit/test_schema.py b/tests/unit/test_schema.py index 3cedd9e57..73dd694fd 100644 --- a/tests/unit/test_schema.py +++ b/tests/unit/test_schema.py @@ -205,3 +205,14 @@ def test_empty_list_val(self): with TestBadSchemaAtCollect.wrapfile_nondict(text) as filename: with pytest.raises(BadSchemaError): load_single_document_yaml(filename) + + +def test_missing_required_key_includes_stage_context(test_dict): + test_dict["stages"][0].pop("request") + + with pytest.raises(BadSchemaError) as exc: + verify_tests(test_dict) + + msg = str(exc.value) + assert "stage: Make sure number is returned correctly" in msg + assert "path: stages[0].request" in msg