fix: measure tavern stage timings via beta request/response hooks#493
Merged
Conversation
Steps were created up-front in start_pytest_item with StepExecution() auto-stamping start_time, and then all closed in a single pytest_runtest_makereport loop, so every stage of a multi-stage Tavern test ended up with identical start_time, end_time and a duration equal to the full test length. The TestOps timeline could not show stage ordering or per-stage runtime. Hook into Tavern's pluggy hooks: - pytest_tavern_beta_before_every_request stamps start_time on the step that matches the current stage index. - pytest_tavern_beta_after_every_response calls execution.complete() on that step and advances the cursor. Replace the unconditional execution.complete() calls in pytest_runtest_makereport with _ensure_step_closed(), which respects timings already set by the hooks and falls back to a zero-duration placeholder for steps that never ran (skip-after-failure, etc.). Add a test_multistage.tavern.yaml example demonstrating sequential stages with delay_before between them, and unit tests covering hook ordering, the extra-hook-after-last-stage guard, and _ensure_step_closed.
Adding pytest_tavern_beta_before_every_request and
pytest_tavern_beta_after_every_response as plain methods on
QasePytestPlugin makes pluggy refuse to load the plugin when the
Tavern package isn't installed, because the matching hookspecs
are only registered when tavern itself is imported. The tox
testing environment installs only qase-tavern + pytest, so CI
fails with:
PluginValidationError: unknown hook
'pytest_tavern_beta_after_every_response' in plugin
<qase.tavern.plugin.QasePytestPlugin object at ...>
Decorate both hooks with @pytest.hookimpl(optionalhook=True) so
pluggy skips the unknown-hook check; the hooks still fire when
Tavern is present at runtime.
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
1 participant
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
Summary
_set_stepscreated allStep()objects up-front instart_pytest_itemwithStepExecution()auto-stampingstart_time. Every step then went through onepytest_runtest_makereportloop callingexecution.complete(). Result: every stage of a multi-stage Tavern test shared the samestart_time, the sameend_time, and adurationequal to the full test length — the TestOps timeline could not show stage ordering or per-stage runtime.pytest_tavern_beta_before_every_requeststampsstart_timeon the step matching the current stage index.pytest_tavern_beta_after_every_responsecallsexecution.complete()on that step and advances the cursor.execution.complete()calls inpytest_runtest_makereportwith_ensure_step_closed()— respects timings already set by the hooks; falls back to a zero-duration placeholder for steps that never ran (skip-after-failure, no-hook).qase-tavernto3.1.1.Test plan
TestTavernBetaHooksTimingcovering distinct timings across 3 stages, single-pair advance of the cursor, extra-hook-after-last-stage guard, and_ensure_step_closedbehaviour for already-closed and skipped steps.pytest qase-tavern/tests/test_plugin.py -v→ 25 passed locally (Python 3.12).examples/single/tavern/test_multistage.tavern.yaml(3-stage tests withdelay_beforeso the gap between stages is visible).Multistage GET sequencesharestart_time≈…570…,end_time≈…692…,duration=1122ms each.delay_beforegaps are visible (~300 ms between stage 1 and stage 2).