diff --git a/docs/configuration.md b/docs/configuration.md index 72ca103d..9d4f91c3 100644 --- a/docs/configuration.md +++ b/docs/configuration.md @@ -356,6 +356,63 @@ test 'stability_time_limit' do end ``` +### When the page will not settle + +The failure names the area that kept changing, and hands you the command that +fixes it: + +``` +Could not get stable screenshot for 'index-with-ticker' within 1.2s (5 attempts). + The page kept changing in 1 area, over 4 attempt pairs: + [67,50,213,68] (left,top,right,bottom edges) -- 0.55% of the 800x600 image, changed in 4 of 4 pairs + Always the same area, in every pair: that is an animation, clock, carousel or live counter. + Exclude it and the page is stable without waiting: + assert_matches_screenshot "index-with-ticker", skip_area: [67,50,213,68] + +``` + +The coordinates are measured, not guessed: they come from the comparisons the +gem just ran between consecutive attempts, so pasting the suggested `skip_area` +in works. + +**One caveat, and it is a real one.** The suggested box is the union of what +changed across the attempts that ran — a *sample* of the animation, not a proven +bound on it. If the moving thing also changes SIZE between frames (proportional +text of varying width in a centred box is the common case), a later frame can +render a pixel or two outside the box that was measured, and the masked run fails +again with a much smaller region. Paste the new suggestion, or widen the box by a +few pixels; it converges. For the usual case — a clock, spinner or counter +repainting inside a fixed element — the extent does not move and the first +suggestion is the whole fix. + +Read the "changed in N of N pairs" line before acting on it: + +- **N of N — one area, every single pair.** Something is animating in one place: + a clock, a carousel, a spinner, a live counter. `skip_area` is the fix, and + since masking no longer waits it costs nothing. +- **Fewer than N, or several areas each changing once.** The page is still + *rendering*, not animating. Masking those areas would hide real content. The + message says so and suggests nothing to mask — settle the page in a + [readiness block](#the-readiness-block) instead, or raise `wait:`. + +### Knowing what the waiting cost + +Every run that waited for stability ends with what it actually paid: + +``` +[snap_diff] 34 screenshots waited for the page to settle: 0.19s and 2 attempts at worst. Every screenshot settled on its first retry, so a lower stability_time_limit would cost less per screenshot. +``` + +Two attempts is the floor — one capture, plus the retry that matched it. Hitting +the floor across the whole run means no page was ever still moving when the +retry was taken, so every `stability_time_limit` sleep was spent on a page that +had already stopped. That is the evidence for tuning it *down*; without it, +lowering the setting is guesswork, and guesswork loses to `sleep`. + +Run-level and silent when nothing waited, for the same reason as the +never-matched-selector line: a line printed on every screenshot is a line +people learn to skip. + ### Maximum wait limit When the `stability_time_limit` is set, but no stable screenshot can be taken, a timeout occurs. @@ -489,7 +546,9 @@ screenshot. That wait is gone.) So content that arrives late — lazy-loaded images, JS-injected widgets, anything behind an unresolved fetch — has to be settled *before* the assertion, or its mask will be empty and the unstable region will be compared. Settle it in the -readiness block described below. +[readiness block](#the-readiness-block) described below; the two cases people +hit most (webfonts and lazy images) are written out in +[Recipes](#recipes). If a selector matched nothing in *every* screenshot of a run, the end-of-run summary names it: @@ -538,6 +597,58 @@ binds the block by Ruby's `{}`/`do...end` precedence rather than by intent, so the matcher does not take one. In Cucumber the DSL is in the World, so step definitions pass a block the same way a Minitest test does. +#### Recipes + +These are the workarounds people hand-roll anyway. The block is where they +belong, because that is the only place they are skipped when screenshots are +off. + +**Webfonts.** A font swapping in mid-capture reflows every line of text that +uses it, so the same page renders two different ways depending on when the +screenshot lands — the classic "it only fails on CI" flake. People usually +paper over it with a `skip_area`, a loosened `tolerance` and a retry, all three +of which weaken the comparison everywhere. Wait for the swap instead: + +```ruby +assert_matches_screenshot 'home' do + page.evaluate_async_script( + 'var done = arguments[0]; document.fonts.ready.then(function(){ done(true) })' + ) +end +``` + +`document.fonts.ready` resolves once every font used by the current layout has +loaded (or failed) — and on a warm cache that has already happened, so the call +returns on the first round trip. It is a Font Loading API promise, supported in +every browser Capybara drives. + +There is deliberately no built-in font wait: it would be a browser round trip +imposed on every screenshot in every suite, and a driver-compatibility surface +the gem would own forever, in exchange for one line you can write yourself. + +**Lazy-loaded images.** Anything behind `loading="lazy"`, an IntersectionObserver +or an unresolved fetch is simply not there when the screenshot is taken. Force +it in, then come back: + +```ruby +assert_matches_screenshot 'gallery', skip_area: ['article img'] do + scroll_to :bottom + assert_text 'End of gallery' + scroll_to :top +end +``` + +Note the order: `skip_area: ['article img']` masks what exists **at assertion +time**, so the images have to be in the DOM before the mask is resolved. A +selector for content that has not loaded yet produces an empty mask and the +unstable region is compared anyway — see [Skipping an area](#skipping-an-area). + +**What does not belong here.** Waits that every screenshot needs regardless +(`disable_animations`, `hide_caret`) are configuration, not readiness. And the +block runs once per assertion, not once per stability retry, so it cannot be +used to nudge a page that keeps moving — for that, see +[When the page will not settle](#when-the-page-will-not-settle). + The arguments are `[left, top, right, bottom]` for the area you want to ignore. You can also set this globally: ```ruby diff --git a/lib/snap_diff/attempts_reporter.rb b/lib/snap_diff/attempts_reporter.rb index c2eec960..21769fee 100644 --- a/lib/snap_diff/attempts_reporter.rb +++ b/lib/snap_diff/attempts_reporter.rb @@ -1,11 +1,29 @@ # frozen_string_literal: true require "fileutils" +require "json" require "snap_diff/comparison" +require "snap_diff/region" module SnapDiff + # The message a user reads when a page would not hold still. + # + # It used to be a bare list of attempt paths (#271). That made diagnosis a + # matter of opening N PNGs and eyeballing them, and faced with that versus + # `sleep 2`, sleep wins -- so the suite got SLOWER as a consequence of the + # diagnosis being hard. The information needed was already here and thrown + # away: every consecutive pair of attempts is compared, and that comparison + # knows the region that changed. + # + # So name it, and hand over the escape hatch that removes the need to sleep. class AttemptsReporter + # One place on the page that changed between attempts, and how many of + # the attempt pairs it showed up in. `pairs == total` means it changed + # EVERY time -- an animation, and `skip_area` is the fix. Fewer means the + # page was still rendering there, and masking would hide a real change. + Area = Struct.new(:region, :pairs) + def initialize(snapshot, comparison_options, stability_options = {}) @snapshot = snapshot @comparison_options = comparison_options @@ -13,11 +31,18 @@ def initialize(snapshot, comparison_options, stability_options = {}) end def generate - attempts_screenshot_paths = @snapshot.find_attempts_paths + # Sorted: `attempt_%02i` sorts lexically in capture order, and the + # reader wants oldest-first regardless of what the glob hands back. + attempts_screenshot_paths = @snapshot.find_attempts_paths.sort - annotate_attempts(attempts_screenshot_paths) + areas, dimensions = annotate_attempts(attempts_screenshot_paths) - "Could not get stable screenshot within #{@wait}s:\n#{attempts_screenshot_paths.join("\n")}" + [ + "Could not get stable screenshot for '#{@snapshot.full_name}' within #{@wait}s " \ + "(#{attempts_screenshot_paths.size} attempts).", + *diagnosis_lines(areas, dimensions), + *attempts_screenshot_paths + ].join("\n") end def build_comparison_for(attempt_path, previous_attempt_path) @@ -26,14 +51,25 @@ def build_comparison_for(attempt_path, previous_attempt_path) private + # Annotates each attempt with its diff against the next one -- and keeps + # the regions, which is the whole point of #271. + # + # @return [Array(Array, Array(Integer, Integer))] the clustered + # changed areas and the [width, height] of the attempts. def annotate_attempts(attempts_screenshot_paths) + regions = [] + dimensions = nil previous_file = nil + attempts_screenshot_paths.reverse_each do |file_name| if previous_file && File.exist?(previous_file) attempts_comparison = build_comparison_for(file_name, previous_file) if attempts_comparison.different? FileUtils.mv(attempts_comparison.reporter.annotated_base_image_path, previous_file, force: true) + region = attempts_comparison.difference.region + regions << region if region + dimensions ||= dimensions_of(attempts_comparison) else warn "[capybara-screenshot-diff] Some attempts was stable, but mistakenly marked as not: " \ "#{previous_file} and #{file_name} are equal" @@ -45,7 +81,123 @@ def annotate_attempts(attempts_screenshot_paths) previous_file = file_name end - previous_file + # Worst offender first: the area that changed in the most pairs is the + # one to act on, and a stable order keeps the message diffable. + areas = cluster(regions).sort_by { |area| [-area.pairs, -area.region.size] } + + [areas, dimensions] + end + + def dimensions_of(comparison) + images = comparison.difference.comparison + comparison.driver.dimension(images.base_image) if images&.base_image + end + + # Groups the per-pair regions into the places on the page they occupy: a + # region that overlaps one we have already seen is the same place, moved + # or resized, so the place grows to cover both. + # + # Merge every area the incoming region touches, not just the first. + # A grew to overlap C only after absorbing B, so first-overlap-wins would + # leave A and C as separate areas -- each then present in fewer pairs than + # the whole, so a single animation reads as churn and no mask is offered. + # Safe in the sense that it never invents a mask, but it withholds the one + # suggestion this message exists to make. + def cluster(regions) + regions.each_with_object([]) do |region, areas| + touching = areas.select { |area| area.region.intersect?(region) } + if touching.empty? + areas << Area.new(region, 1) + else + merged = touching.reduce(region) { |acc, area| union(acc, area.region) } + pairs = touching.sum(&:pairs) + 1 + areas.reject! { |area| touching.include?(area) } + areas << Area.new(merged, pairs) + end + end + end + + def union(one, other) + Region.from_edge_coordinates( + [one.left, other.left].min, + [one.top, other.top].min, + [one.right, other.right].max, + [one.bottom, other.bottom].max + ) + end + + def diagnosis_lines(areas, dimensions) + return [] if areas.empty? || dimensions.nil? + + total_pairs = areas.sum(&:pairs) + # An area that changed in EVERY pair is animating. One that did not is + # the page still rendering -- masking it would hide a real change. + animating, settling = areas.partition { |area| area.pairs == total_pairs } + + [ + " The page kept changing in #{count(areas.size, "area")}, over #{count(total_pairs, "attempt pair")}:", + *areas.map { |area| " #{area_line(area, total_pairs, dimensions)}" }, + *animating_lines(animating), + *settling_lines(settling, animating) + ] + end + + def area_line(area, total_pairs, dimensions) + width, height = dimensions + share = area.region.size.to_f / (width * height) + + "#{area.region.to_edge_coordinates.to_json} (left,top,right,bottom edges) " \ + "-- #{Reporters::Default.percent(share)} of the #{width}x#{height} image, " \ + "changed in #{area.pairs} of #{total_pairs} pairs" + end + + # The escape hatch. Every coordinate here came off the comparison that + # just ran -- never a placeholder, and never a knob nothing reads. + def animating_lines(animating) + return [] if animating.empty? + + skip_area = animating.map { |area| mask_coordinates(area.region) } + skip_area = skip_area.first if skip_area.size == 1 + + [ + " Always the same area, in every pair: that is an animation, clock, carousel or live counter.", + " Exclude it and the page is stable without waiting:", + " assert_matches_screenshot #{@snapshot.full_name.to_s.inspect}, skip_area: #{skip_area.to_json}" + ] + end + + # A mask must COVER the region that moved, and it has to be pasteable. + # Edge coordinates arrive as floats on some drivers/platforms, so round + # OUTWARD -- floor the near edges, ceil the far ones. Truncating instead + # would shave the right/bottom edge and leave the moving pixels exposed, + # which is worse than suggesting nothing. + # Round OUTWARD so the mask covers the region rather than shaving it, and + # never emit an edge pair that collapses: Region carries WIDTH, and + # `from_edge_coordinates` derives it as `right - left`, so a one-pixel-wide + # change (a ticker digit, a caret) arrives here as left == right and would + # be suggested as a mask of width 0 -- one that masks nothing, leaves the + # page unstable, and tells the user to paste a fix that cannot work. + def mask_coordinates(region) + left, top, right, bottom = region.to_edge_coordinates + left, top = left.floor, top.floor + + [left, top, [right.ceil, left + 1].max, [bottom.ceil, top + 1].max] + end + + def settling_lines(settling, animating) + return [] if settling.empty? + + subject = animating.empty? ? "D" : "The other #{count(settling.size, "area")}: d" + + [ + " #{subject}ifferent areas at different times -- the page is still rendering, not animating in one place.", + " skip_area masks a fixed area and will not help here: settle the page first (a readiness", + " block on the assertion -- see docs/configuration.md) or raise wait:." + ] + end + + def count(number, noun) + "#{number} #{noun}#{"s" unless number == 1}" end end end diff --git a/lib/snap_diff/reporters/default.rb b/lib/snap_diff/reporters/default.rb index 65d44d8a..9bcc439c 100644 --- a/lib/snap_diff/reporters/default.rb +++ b/lib/snap_diff/reporters/default.rb @@ -61,6 +61,14 @@ def build_error_for_different_dimensions NEW_LINE = "\n" + # The one place the gem turns a fraction of the image into prose. + # Public because AttemptsReporter reports the same kind of number and + # must say it the same way (#264 vocabulary). + def self.percent(fraction) + value = fraction * 100 + (value.positive? && value < 0.01) ? "<0.01%" : format("%.2f%%", value) + end + # The thresholds a comparison is judged against, in the order they read # best. Only the ones actually set are printed -- see #thresholds. THRESHOLDS = [ @@ -146,8 +154,7 @@ def display_path(path) end def percent(fraction) - value = fraction * 100 - (value.positive? && value < 0.01) ? "<0.01%" : format("%.2f%%", value) + self.class.percent(fraction) end def base_image_path diff --git a/lib/snap_diff/reporting.rb b/lib/snap_diff/reporting.rb index 397b6d2c..6989248d 100644 --- a/lib/snap_diff/reporting.rb +++ b/lib/snap_diff/reporting.rb @@ -23,6 +23,9 @@ module Reporting @unmatched_selectors = Set.new @verified = 0 @changed = 0 + @stable_captures = 0 + @worst_settle_seconds = 0.0 + @worst_settle_attempts = 0 class << self attr_reader :reporters, :mutex @@ -74,6 +77,19 @@ def record_selector_use(selector, matched:) end end + # Remembers what a capture that DID settle cost (#271). + # + # Only the worst case is kept, because that is the number the setting + # has to cover: an average would suggest a `stability_time_limit` that + # is too low for the slowest page in the suite. + def record_stable_capture(seconds, attempts) + @mutex.synchronize do + @stable_captures += 1 + @worst_settle_seconds = seconds if seconds > @worst_settle_seconds + @worst_settle_attempts = attempts if attempts > @worst_settle_attempts + end + end + # @api private # Per-test isolation for this gem's own suite: everything {finalize!} # reports, cleared in one call. One surface rather than one reset per @@ -86,6 +102,9 @@ def reset_run_totals! @unmatched_selectors.clear @verified = 0 @changed = 0 + @stable_captures = 0 + @worst_settle_seconds = 0.0 + @worst_settle_attempts = 0 end end @@ -222,6 +241,10 @@ def finalize! if (msg = never_matched_selectors_summary) $stdout.puts msg end + + if (msg = stable_captures_summary) + $stdout.puts msg + end end # --- fork-parallel reports (issue #258) --------------------------- @@ -279,6 +302,9 @@ def dump_parallel_fragment "unmatched_selectors" => @mutex.synchronize { @unmatched_selectors.to_a }, "verified" => @verified, "changed" => @changed, + "stable_captures" => @stable_captures, + "worst_settle_seconds" => @worst_settle_seconds, + "worst_settle_attempts" => @worst_settle_attempts, "reporters" => @mutex.synchronize { @reporters.dup } .map { |reporter| reporter.dump_state if reporter.respond_to?(:dump_state) } } @@ -315,6 +341,11 @@ def merge_parallel_fragments! payload.fetch("unmatched_selectors", []).each { |selector| @unmatched_selectors << selector } @verified += payload.fetch("verified", 0) @changed += payload.fetch("changed", 0) + # Counts add up; worst cases do not -- the slowest page in the + # run is the slowest page in whichever worker happened to run it. + @stable_captures += payload.fetch("stable_captures", 0) + @worst_settle_seconds = [@worst_settle_seconds, payload.fetch("worst_settle_seconds", 0.0)].max + @worst_settle_attempts = [@worst_settle_attempts, payload.fetch("worst_settle_attempts", 0)].max end reporters_snapshot = @mutex.synchronize { @reporters.dup } @@ -383,6 +414,45 @@ def never_matched_selectors_summary "#{names.map(&:inspect).join(", ")}. " \ "A selector that matches nothing masks nothing -- check for a typo or a stale selector." end + + # What waiting for the page to settle actually cost, on the runs where + # it WORKED (#271). + # + # The failure path names the region that would not settle; this is the + # other half. A maintainer who set `stability_time_limit: 2` on the + # docs' recommendation has no way to learn their pages settle on the + # first retry -- and without evidence, tuning it down is guesswork, + # which loses to `sleep`. The measurement is free: the stable + # screenshoter already knows both numbers at the moment it succeeds. + # + # Run-level rather than per-assertion, and silent when nothing waited: + # the same reasoning as {never_matched_selectors_summary}. A line + # printed on every screenshot of every run is a line users learn to + # skip, and per-test noise is exactly what a debugging aid must not + # add to a suite already too slow. + # + # @return [String, nil] nil when no capture waited for stability + def stable_captures_summary + captures, seconds, attempts = @mutex.synchronize { + [@stable_captures, @worst_settle_seconds, @worst_settle_attempts] + } + return if captures.zero? + + label = (captures == 1) ? "1 screenshot" : "#{captures} screenshots" + line = "[snap_diff] #{label} waited for the page to settle: " \ + "#{format("%.2f", seconds)}s and #{attempts} attempts at worst." + + # Two attempts is the floor -- one capture, then the retry that + # matched it. Hitting the floor everywhere means no page in the run + # was ever still moving, so every sleep between attempts was spent + # on a page that had already stopped. + if attempts <= 2 + line += " Every screenshot settled on its first retry, so a lower " \ + "stability_time_limit would cost less per screenshot." + end + + line + end end end end diff --git a/lib/snap_diff/stable_screenshoter.rb b/lib/snap_diff/stable_screenshoter.rb index 06f7e196..eb29fbd1 100644 --- a/lib/snap_diff/stable_screenshoter.rb +++ b/lib/snap_diff/stable_screenshoter.rb @@ -55,7 +55,8 @@ def take_comparison_screenshot(snapshot) def take_stable_screenshot(snapshot) # We try to compare first attempt with checkout version, in order to not run next screenshots - deadline_at = Process.clock_gettime(Process::CLOCK_MONOTONIC) + wait + started_at = Process.clock_gettime(Process::CLOCK_MONOTONIC) + deadline_at = started_at + wait # Cleanup all previous attempts for sure snapshot.cleanup_attempts! @@ -63,7 +64,17 @@ def take_stable_screenshot(snapshot) loop do attempt_next_screenshot(snapshot) - return true if attempt_successful?(snapshot) + if attempt_successful?(snapshot) + # What the wait actually cost, on the path where it worked. The + # failure path names the region that would not settle (#271); this + # is the evidence for tuning `stability_time_limit` DOWN, and it is + # free -- both numbers are already here. + Reporting.record_stable_capture( + Process.clock_gettime(Process::CLOCK_MONOTONIC) - started_at, + snapshot.attempts_count + ) + return true + end return false if timeout?(deadline_at) sleep(stability_time_limit) diff --git a/test/fixtures/app/index-with-ticker.html b/test/fixtures/app/index-with-ticker.html new file mode 100644 index 00000000..c17fa5e0 --- /dev/null +++ b/test/fixtures/app/index-with-ticker.html @@ -0,0 +1,78 @@ + + + + + + + + +

Ticker

+ +
0000000000
+ + + + + diff --git a/test/integration/browser_screenshot_test.rb b/test/integration/browser_screenshot_test.rb index eb5273e1..5fe63539 100644 --- a/test/integration/browser_screenshot_test.rb +++ b/test/integration/browser_screenshot_test.rb @@ -278,6 +278,41 @@ def test_screenshot_selected_element SnapDiff::SnapManager.snapshot("index-with-anim").delete! end + # #271, on a real browser rendering a really unstable page. + # + # A live ticker in a fixed box is the shape users actually hit -- a clock, + # a counter, a spinner -- and it is the shape `skip_area` can fix. The + # message has to (a) name the region, and (b) hand over a command that + # WORKS, which is the half this project has got wrong before: it shipped + # `RECORD_SCREENSHOTS=1` in its own error message for years while nothing + # read it. So this test does not check the prose; it follows the advice. + test "a page that never settles is told WHERE it kept changing, and the suggested skip_area works" do + visit "/index-with-ticker.html" + + error = assert_raises SnapDiff::UnstableImage do + assert_matches_screenshot "index-with-ticker", stability_time_limit: 0.1, wait: 1.2, tolerance: nil + end + + puts "\n--- #271 stability failure message ---\n#{error.message}\n---\n" if ENV["DEBUG"] + + assert_match(/Could not get stable screenshot for 'index-with-ticker' within 1.2s \(\d+ attempts\)/, error.message) + assert_match(/The page kept changing in 1 area/, error.message) + assert_match(/left,top,right,bottom edges/, error.message) + assert_match(/Always the same area/, error.message) + + suggested = error.message[/skip_area: (\[[\d,]+\])/, 1] + assert suggested, "the message must suggest a mask built from the measured region:\n#{error.message}" + + # THE round trip: the coordinates the message printed, pasted back in, + # make the same page stable. Nothing here is derived from the fixture's + # CSS -- only from what the failing run measured. + assert_matches_screenshot "index-with-ticker", + stability_time_limit: 0.1, wait: 1.2, tolerance: nil, + skip_area: JSON.parse(suggested) + ensure + SnapDiff::SnapManager.snapshot("index-with-ticker").delete! + end + def test_await_all_images_are_loaded visit "/index.html" assert_raises ::Minitest::Assertion do diff --git a/test/support/test_doubles.rb b/test/support/test_doubles.rb index 3c60d4cc..36858093 100644 --- a/test/support/test_doubles.rb +++ b/test/support/test_doubles.rb @@ -96,6 +96,10 @@ def class # Test double for difference results class TestDifference attr_reader :different_value + # AttemptsReporter reads both to name the region that would not settle + # (#271). nil on purpose here: a double that reported a region would let + # the reporter's own no-region path go untested. + attr_reader :region, :comparison def initialize(different_value) @different_value = different_value diff --git a/test/unit/attempts_reporter_test.rb b/test/unit/attempts_reporter_test.rb index c2fb19fc..0b1f0749 100644 --- a/test/unit/attempts_reporter_test.rb +++ b/test/unit/attempts_reporter_test.rb @@ -24,12 +24,77 @@ class AttemptsReporterTest < ActiveSupport::TestCase @manager.cleanup! end + # The suggested mask is pasted straight into a test file, so it must be + # integers -- and it must COVER the region that moved. Float edges appear on + # some drivers/platforms: CI produced [62.0,50.0,218.0,68.0] where macOS gave + # integers, and the message's own regex silently failed to match. Truncating + # would shave the right/bottom edge and leave the moving pixels exposed, + # which is worse than suggesting nothing at all. + # A chain: A touches B, B touches C, A does NOT touch C. First-overlap-wins + # would leave two areas, each seen in fewer pairs than the chain as a whole, + # so one animation reads as churn and no mask is offered. + test "#cluster merges every transitively overlapping region into one area" do + snap = attempt_snapshot("transitive_cluster", %i[a b]) + reporter = AttemptsReporter.new(snap, {driver: :chunky_png}, {wait: 2, stability_time_limit: 0.1}) + + a = SnapDiff::Region.new(0, 0, 20, 10) # 0..20 + c = SnapDiff::Region.new(30, 0, 20, 10) # 30..50 -- does NOT touch a + b = SnapDiff::Region.new(15, 0, 20, 10) # 15..35 -- bridges them + + areas = reporter.send(:cluster, [a, c, b]) + + assert_equal 1, areas.size, "the bridge should merge all three: #{areas.map { |x| x.region.to_edge_coordinates }.inspect}" + assert_equal 3, areas.first.pairs, "a merged area keeps every pair it was seen in" + edges = areas.first.region.to_edge_coordinates + assert_operator edges[0], :<=, 0 + assert_operator edges[2], :>=, 50 + end + + test "#mask_coordinates yields integers that round OUTWARD to cover the region" do + snap = attempt_snapshot("mask_rounding", %i[a b]) + reporter = AttemptsReporter.new(snap, {driver: :chunky_png}, {wait: 2, stability_time_limit: 0.1}) + # Region.new is (left, top, WIDTH, HEIGHT); edges land at + # [62.4, 50.2, 279.5, 119.1], all four fractional. + region = SnapDiff::Region.new(62.4, 50.2, 217.1, 68.9) + + coords = reporter.send(:mask_coordinates, region) + + assert_equal [62, 50, 280, 120], coords + assert(coords.all?(Integer), "a pasted mask must not contain floats: #{coords.inspect}") + assert_operator coords[0], :<=, region.left, "left edge must not shave the region" + assert_operator coords[1], :<=, region.top, "top edge must not shave the region" + assert_operator coords[2], :>=, region.right, "right edge must not shave the region" + assert_operator coords[3], :>=, region.bottom, "bottom edge must not shave the region" + end + + # A one-pixel-wide change (a ticker digit, a caret) yields left == right, + # because Region carries WIDTH and `from_edge_coordinates` computes it as + # `right - left`. Emitting those edges verbatim suggests a mask of width 0: + # it masks NOTHING, the page still will not settle, and the user is told to + # paste a fix that cannot work. That is the same "under-covers but looks + # like it worked" failure the outward rounding above exists to prevent -- + # this is its degenerate case, which floor/ceil alone cannot reach. + # Observed on CI: [216,52,216,65]. + test "#mask_coordinates never yields a mask that covers nothing" do + snap = attempt_snapshot("mask_degenerate", %i[a b]) + reporter = AttemptsReporter.new(snap, {driver: :chunky_png}, {wait: 2, stability_time_limit: 0.1}) + # One column at x=216, thirteen rows tall: width 0 in Region terms. + region = SnapDiff::Region.new(216, 52, 0, 13) + + left, top, right, bottom = reporter.send(:mask_coordinates, region) + + assert_operator right, :>, left, "a mask with right == left covers no pixels" + assert_operator bottom, :>, top, "a mask with bottom == top covers no pixels" + assert_equal [216, 52, 217, 65], [left, top, right, bottom] + assert_operator SnapDiff::Region.from_edge_coordinates(left, top, right, bottom).width, :>=, 1 + end + test "#generate returns the timeout message listing every attempt artifact" do snap = attempt_snapshot("unstable_message", %i[a b]) message = AttemptsReporter.new(snap, {driver: :chunky_png}, {wait: 2, stability_time_limit: 0.1}).generate - assert_match(/Could not get stable screenshot within 2s/, message) + assert_match(/Could not get stable screenshot for 'unstable_message' within 2s \(2 attempts\)/, message) snap.find_attempts_paths.each do |attempt_path| assert_includes message, attempt_path.to_s end @@ -70,7 +135,7 @@ def take_screenshot(screenshot_path) end end - assert_match(/Could not get stable screenshot within 0.2s/, error.message) + assert_match(/Could not get stable screenshot for 'unstable_end_to_end' within 0.2s/, error.message) attempts = snap.find_attempts_paths assert_operator attempts.size, :>=, 2, "the unstable run must leave its attempt artifacts for debugging" @@ -80,6 +145,64 @@ def take_screenshot(screenshot_path) assert_not_equal (TEST_IMAGES_DIR / "b.png").binread, annotated_attempt.binread end + # --- #271: name the region that would not settle ----------------- + # + # The whole point of the message. A bare list of attempt paths made the + # user open N images and eyeball them; faced with that, `sleep 2` wins + # and the suite gets slower because diagnosis was hard. + + test "#generate names the one area that changed in every attempt and suggests masking it" do + snap = painted_attempt_snapshot("ticker", [ + {[10, 10, 40, 30] => "#ff0000"}, + {[10, 10, 40, 30] => "#00ff00"}, + {[10, 10, 40, 30] => "#0000ff"}, + {[10, 10, 40, 30] => "#ffff00"} + ]) + + message = AttemptsReporter.new(snap, {driver: :chunky_png}, {wait: 2}).generate + + assert_match(/Could not get stable screenshot for 'ticker' within 2s \(4 attempts\)/, message) + assert_match(/changed in 3 of 3 pairs/, message) + assert_match(/Always the same area/, message) + + region = message[/The page kept changing in 1 area.*?\n\s*(\[[-\d,]+\])/m, 1] + assert region, "the message must print the measured region:\n#{message}" + # THE requirement: the suggested command carries the region actually + # measured, never a coordinate invented for the prose. + assert_includes message, %(skip_area: #{region}) + assert_includes message, %(assert_matches_screenshot "ticker", skip_area: #{region}) + end + + test "#generate reports areas that move around as churn and does NOT suggest skip_area" do + snap = painted_attempt_snapshot("churn", [ + {}, + {[5, 5, 20, 20] => "#ff0000"}, + {[5, 5, 20, 20] => "#ff0000", [50, 50, 70, 70] => "#00ff00"}, + {[5, 5, 20, 20] => "#ff0000", [50, 50, 70, 70] => "#00ff00", [5, 50, 20, 70] => "#0000ff"} + ]) + + message = AttemptsReporter.new(snap, {driver: :chunky_png}, {wait: 2}).generate + + assert_match(/The page kept changing in 3 areas, over 3 attempt pairs/, message) + assert_match(/Different areas at different times/, message) + assert_match(/skip_area masks a fixed area and will not help here/, message) + assert_no_match(/skip_area: \[/, message, + "a region that only changed once is not an animation -- masking it would hide a real render") + end + + test "#generate reports each area with its share of the image, in the #264 vocabulary" do + snap = painted_attempt_snapshot("vocabulary", [ + {[0, 0, 40, 40] => "#ff0000"}, + {[0, 0, 40, 40] => "#00ff00"} + ]) + + message = AttemptsReporter.new(snap, {driver: :chunky_png}, {wait: 2}).generate + + assert_match(/\(left,top,right,bottom edges\)/, message) + assert_match(/of the 80x80 image/, message) + assert_match(/%/, message) + end + private # Builds a snapshot with one attempt file per fixture, oldest first. @@ -92,5 +215,22 @@ def attempt_snapshot(name, fixtures) end end end + + # Builds a snapshot whose attempts are 80x80 white images with the given + # rectangles painted on. One entry per attempt, oldest first; rectangles + # are {[left, top, right, bottom] => "#rrggbb"}. + def painted_attempt_snapshot(name, rectangles_per_attempt) + @manager.snapshot(name).tap do |snap| + rectangles_per_attempt.each do |rectangles| + attempt_path = snap.next_attempt_path! + FileUtils.mkdir_p(attempt_path.dirname) + image = ChunkyPNG::Image.new(80, 80, ChunkyPNG::Color::WHITE) + rectangles.each do |(left, top, right, bottom), color| + image.rect(left, top, right, bottom, ChunkyPNG::Color::TRANSPARENT, ChunkyPNG::Color.from_hex(color)) + end + image.save(attempt_path.to_s) + end + end + end end end diff --git a/test/unit/parallel_report_merge_test.rb b/test/unit/parallel_report_merge_test.rb index e209e3b6..9721a77e 100644 --- a/test/unit/parallel_report_merge_test.rb +++ b/test/unit/parallel_report_merge_test.rb @@ -105,6 +105,29 @@ class ParallelReportMergeTest < ActiveSupport::TestCase refute_includes summary, "img" end + # The stabilisation evidence (#271) is a run-level fact too, and Rails' + # default `parallelize` is where a run-level line goes missing (#269). + # Counts add up across workers; the WORST case does not -- the slowest + # page in the run is the slowest page in whichever worker ran it. + test "the worst stabilisation across workers survives the merge" do + fork_worker { SnapDiff::Reporting.record_stable_capture(0.10, 2) } + fork_worker { SnapDiff::Reporting.record_stable_capture(0.20, 2) } + # The worst case is held by the PARENT here, not by a worker, and the + # fragments are merged in filename order. Assigning instead of maxing + # would clobber it whichever way the pids happened to sort -- an + # order-dependent fixture let exactly that mutation through once. + SnapDiff::Reporting.record_stable_capture(0.90, 5) + + SnapDiff::Reporting.merge_parallel_fragments! + + summary = SnapDiff::Reporting.stable_captures_summary + + assert_includes summary, "3 screenshots" + assert_includes summary, "0.90s" + assert_includes summary, "5 attempts" + refute_includes summary, "settled on its first retry" + end + test "the parent removes the fragments it merged" do fork_worker { @reporter.record([build_failing_assertion("cleaned")]) } diff --git a/test/unit/reporting_counts_test.rb b/test/unit/reporting_counts_test.rb index caa437e4..da692f76 100644 --- a/test/unit/reporting_counts_test.rb +++ b/test/unit/reporting_counts_test.rb @@ -216,6 +216,55 @@ class ReportingCountsTest < ActiveSupport::TestCase assert_nil SnapDiff::Reporting.never_matched_selectors_summary end + # --- #271: the evidence needed to tune stability_time_limit DOWN -------- + # + # A user who set `stability_time_limit: 2` has no way to learn their page + # settles on the first retry. Without that, tuning down is guesswork, and + # guesswork loses to `sleep`. + + test "the run reports the worst stabilisation it saw" do + SnapDiff::Reporting.record_stable_capture(0.12, 2) + SnapDiff::Reporting.record_stable_capture(0.66, 4) + + summary = SnapDiff::Reporting.stable_captures_summary + + assert_includes summary, "2 screenshots" + assert_includes summary, "0.66s" + assert_includes summary, "4 attempts" + end + + test "a run where every page settled on the first retry says so" do + SnapDiff::Reporting.record_stable_capture(0.5, 2) + + assert_includes SnapDiff::Reporting.stable_captures_summary, + "settled on its first retry" + end + + test "a run where some page needed more than one retry does not claim otherwise" do + SnapDiff::Reporting.record_stable_capture(0.5, 2) + SnapDiff::Reporting.record_stable_capture(1.5, 3) + + refute_includes SnapDiff::Reporting.stable_captures_summary, "settled on its first retry" + end + + # Silent for the majority who never enable stability waiting: a line that + # prints on every run is a line users learn to skip. + test "the stabilisation line is silent when nothing waited for stability" do + assert_nil SnapDiff::Reporting.stable_captures_summary + + out, _err = capture_io { SnapDiff::Reporting.finalize! } + + refute_includes out, "settle" + end + + test "reset_run_totals! clears the stabilisation tally" do + SnapDiff::Reporting.record_stable_capture(0.5, 2) + + SnapDiff::Reporting.reset_run_totals! + + assert_nil SnapDiff::Reporting.stable_captures_summary + end + private def build_passing_assertion(name) diff --git a/test/unit/stable_screenshoter_test.rb b/test/unit/stable_screenshoter_test.rb index 3a73d3b3..e7c2ce1e 100644 --- a/test/unit/stable_screenshoter_test.rb +++ b/test/unit/stable_screenshoter_test.rb @@ -67,6 +67,31 @@ def teardown assert_not_predicate snap.path.size, :zero? end + # #271: a user who set `stability_time_limit: 2` cannot tune it down + # without knowing how long their page actually took. Recorded on the + # SUCCESS path, where nothing was reported before. + test "#take_comparison_screenshot records how long the page took to settle" do + SnapDiff::Reporting.reset_run_totals! + image_compare_stub = build_image_compare_stub + + mock = ::Minitest::Mock.new(image_compare_stub) + mock.expect(:quick_equal?, false) + mock.expect(:quick_equal?, true) + + SnapDiff::Comparison.stub :new, mock do + SnapDiff::StableScreenshoter + .new({stability_time_limit: 0.05, wait: 1}, image_compare_stub.driver_options) + .take_comparison_screenshot(@manager.snapshot("02_a")) + end + + summary = SnapDiff::Reporting.stable_captures_summary + assert summary, "a successful stable capture must leave evidence for tuning" + assert_includes summary, "1 screenshot" + assert_includes summary, "3 attempts" + ensure + SnapDiff::Reporting.reset_run_totals! + end + test "#take_comparison_screenshot raises UnstableImage when stability timeout is reached" do snap = @manager.snapshot("01_a")