From f4d7350beb1c49cfa50a3afd982193e301a4ae07 Mon Sep 17 00:00:00 2001 From: Miguel de Benito Delgado Date: Mon, 9 Nov 2026 15:40:32 +0100 Subject: [PATCH] :sparkles: Improve failure reporting - Each recorded failure gets one diagnostic entry. - Distinct metadata events retain separate entries even when their messages match. - Run and comparison reports expose screenshot warnings, files and skip reasons. AI-assisted-by: gpt-6.1-sol --- .../benches/render_wasm/report/format.cljs | 272 +++++++++++++----- .../render_wasm/lifecycle_test.cljs | 6 +- .../render_wasm/report_test.cljs | 21 ++ .../render_wasm/run_test.cljs | 33 ++- 4 files changed, 258 insertions(+), 74 deletions(-) diff --git a/frontend/performance/benches/render_wasm/report/format.cljs b/frontend/performance/benches/render_wasm/report/format.cljs index 0150e2f0e8..f27aaadf0b 100644 --- a/frontend/performance/benches/render_wasm/report/format.cljs +++ b/frontend/performance/benches/render_wasm/report/format.cljs @@ -60,42 +60,6 @@ " MAD " (estimate->text (:mad statistics)) " p95 " (estimate->text (:p95 statistics)) " p99 " (estimate->text (:p99 statistics)))))) -(defn- case-status->text - "Displays pending slots and failed attempts, including excluded warmups." - [{:keys [remaining failed-attempts preparations phases outcome]}] - (str " remaining " (pr-str remaining) - (when outcome (str "\n outcome " (pr-str outcome))) - "\n phases " (pr-str phases) - " failed-warmups=" (count (filter :warmup? failed-attempts)) - (when-let [failures (seq (keep :failure preparations))] - (str "\n preparation failures " (pr-str failures))) - (when (seq failed-attempts) - (str "\n failed attempts " (pr-str failed-attempts))))) - -(defn format-run - "Formats a summary without browser, registry or renderer access." - [{:keys [run-id metadata analysis termination source-coverage interpretation cases]}] - (str "Run " (pr-str run-id) " " (pr-str termination) - "\nGit " (pr-str (:git metadata)) - "\nAnalysis " (pr-str analysis) - "\n" source-coverage "\n" interpretation - (when (some #(get-in % [:effective-graphics :software]) - (mapcat :preparations cases)) "\nSOFTWARE RENDERER recorded") - (apply str (map (fn [{:keys [case-id metrics] :as case-report}] - (str "\n\nCase " (result/case-name case-id) - (case-status->text case-report) - (apply str (map (fn [[id metric]] (str "\n" (metric->text id metric))) metrics)))) - cases)))) - -(defn- side->text - "Displays one comparison side's definitions, preparation facts and observations." - [label {:keys [case-id definition preparations metrics] :as side}] - (str "\n" label " " (result/case-name case-id) - (case-status->text side) - "\n case " (pr-str definition) - "\n preparations " (pr-str preparations) - (apply str (map (fn [[id metric]] (str "\n" (metric->text id metric))) metrics)))) - (defn- quoted-detail [value] (errors/bounded-text (js/JSON.stringify value) 1024)) @@ -108,6 +72,162 @@ (str (quoted-detail (:phase failure)) ": " (quoted-detail (:message failure)))) (quoted-detail reason))) +(defn- identifier->text + [value] + (if (string? value) + (quoted-detail value) + (errors/bounded-text (pr-str value) 1024))) + +(defn- same-diagnostic? + [left right] + (= (dissoc (errors/project-diagnostic left) :status :partial) + (dissoc (errors/project-diagnostic right) :status :partial))) + +(defn- case-failures + [{:keys [case-id preparations failed-attempts]}] + (let [preparations (filter :failure preparations) + by-id (into {} (map (juxt :preparation-id identity)) preparations)] + (concat + (map (fn [preparation] + (assoc (select-keys preparation [:preparation-id :warmup? :failure]) + :kind :preparation :case-id case-id)) + preparations) + (keep (fn [{:keys [preparation-id failure phases] :as attempt}] + (let [preparation (get by-id preparation-id) + copied? (and preparation + (every? #(= :preparation (:phase %)) phases) + (same-diagnostic? failure (:failure preparation)))] + (when (and failure (not copied?)) + (assoc (select-keys attempt [:attempt-id :preparation-id :warmup? :failure :partial]) + :kind :attempt :case-id case-id)))) + failed-attempts)))) + +(defn- run-failures + [cases metadata termination] + (let [case-entries (vec (mapcat case-failures cases)) + by-case (group-by :case-id case-entries) + harness (keep-indexed + (fn [index failure] + (let [copied? (and (= :preparation (:stage failure)) + (some #(and (= :preparation (:kind %)) + (same-diagnostic? (:failure %) failure)) + (get by-case (:case-id failure))))] + (when-not copied? + {:kind :harness :index index :stage (:stage failure) + :case-id (:case-id failure) :failure failure}))) + (get-in metadata [:diagnostics :failures])) + recorded (into case-entries harness) + by-owner (group-by :case-id recorded) + outcomes (keep (fn [{:keys [case-id outcome]}] + (when-let [failure (:failure outcome)] + (when-not (some #(same-diagnostic? failure (:failure %)) (get by-owner case-id)) + {:kind :case :case-id case-id :failure failure}))) + cases) + entries (into recorded outcomes)] + (cond-> entries + (and (:failure termination) + (not-any? #(same-diagnostic? (:failure termination) (:failure %)) entries)) + (conj {:kind :termination :failure (:failure termination)})))) + +(defn- diagnostic->text + [failure] + (let [details (merge (select-keys (first (:cause failure)) [:type :code :fn]) + (errors/project-context failure) + (select-keys failure [:reason :deadline-exceeded]))] + (str (failure->text {:failure failure}) + (apply str (map (fn [[key value]] + (str "\n " (name key) " " (identifier->text value))) + (sort-by (comp name key) (filter (comp some? val) details))))))) + +(defn- failure-entry->text + [{:keys [kind case-id preparation-id attempt-id index stage warmup? failure partial]}] + (str " " (case kind + :preparation (str "Preparation " (identifier->text preparation-id)) + :attempt (str "Attempt " attempt-id " (preparation " (identifier->text preparation-id) ")") + :harness (str "Harness " index " " (identifier->text stage)) + :case "Case outcome" + :termination "Termination") + (when (some? case-id) (str " (case " (identifier->text case-id) ")")) + (when warmup? " warmup") + ": " (diagnostic->text failure) + (when (or partial (:partial failure)) "\n Partial evidence recorded"))) + +(defn- failures->text + [heading entries] + (when (seq entries) + (str "\n\n" heading "\n" (str/join "\n" (map failure-entry->text entries))))) + +(defn- screenshots->text + [heading metadata failures cases] + (let [screenshots (get-in metadata [:diagnostics :screenshots]) + names (frequencies (map result/case-name + (distinct (concat (map :case-id cases) (keep :case-id failures))))) + deadlines (group-by #(result/case-name (:case-id %)) + (filter #(and (= :harness (:kind %)) + (= :case-deadline (:stage %)) + (some? (:case-id %))) failures))] + (when (seq screenshots) + (str "\n\n" heading "\n" + (str/join + "\n" + (map (fn [[case-name {:keys [status message reason file cause]}]] + (let [matches (when (and (= 1 (get names case-name)) (string? message) (seq cause)) + (filter #(and (= message (get-in % [:failure :message])) + (= cause (get-in % [:failure :cause]))) + (get deadlines case-name))) + related (when (= 1 (count matches)) (first matches))] + (str " " (identifier->text case-name) ": " + (if related + (str "failed; see Harness " (:index related)) + (case status + :failed "warning" + :ok "ok" + :skipped "skipped" + (identifier->text status))) + (when (and message (not related)) (str "; " (quoted-detail message))) + (when reason (str "; reason " (identifier->text reason))) + (when file (str "\n File " (quoted-detail file)))))) + (sort-by (comp str key) screenshots))))))) + +(defn- case-status->text + "Displays pending slots, phase counts and failed execution identities." + [{:keys [remaining failed-attempts phases outcome]}] + (str " remaining " (pr-str remaining) + (when outcome (str "\n outcome " (pr-str (:outcome outcome)))) + "\n phases " (pr-str phases) + " failed-warmups=" (count (filter :warmup? failed-attempts)) + (when (seq failed-attempts) + (str "\n failed attempts " + (pr-str (mapv #(select-keys % [:attempt-id :preparation-id :warmup? :outcome]) failed-attempts)))))) + +(defn format-run + "Formats run statistics, recorded failures and screenshot diagnostics." + [{:keys [run-id metadata analysis termination source-coverage interpretation cases]}] + (let [failures (run-failures cases metadata termination)] + (str "Run " (pr-str run-id) " " (pr-str (dissoc termination :failure)) + "\nGit " (pr-str (:git metadata)) + "\nAnalysis " (pr-str analysis) + "\n" source-coverage "\n" interpretation + (when (some #(get-in % [:effective-graphics :software]) + (mapcat :preparations cases)) "\nSOFTWARE RENDERER recorded") + (apply str (map (fn [{:keys [case-id metrics] :as case-report}] + (str "\n\nCase " (result/case-name case-id) + (case-status->text case-report) + (apply str (map (fn [[id metric]] (str "\n" (metric->text id metric))) metrics)))) + cases)) + (failures->text "Failures" failures) + (screenshots->text "Screenshots" metadata failures cases)))) + +(defn- side->text + "Displays one comparison side's definitions, preparation facts and observations." + [label {:keys [case-id definition preparations metrics] :as side}] + (str "\n" label " " (result/case-name case-id) + (case-status->text side) + "\n case " (pr-str definition) + "\n preparations " (pr-str (mapv #(select-keys % [:preparation-id :warmup? :fingerprint :effective-graphics]) + preparations)) + (apply str (map (fn [[id metric]] (str "\n" (metric->text id metric))) metrics)))) + (defn- configuration-failure->text [{:keys [slug run build] :as configuration}] (str " Configuration " (quoted-detail slug) ": " (failure->text configuration) @@ -153,37 +273,49 @@ Both saved definitions remain visible. Edge labels describe actual feature evidence, including equal effective sets, without predicting a timing effect." [{:keys [baseline candidate analysis permissions edge source-coverage interpretation pairs]}] - (str "Permissions " (pr-str permissions) "\n" - (when edge - (str "Edge " (:from edge) " -> " (:to edge) " feature " (:feature edge) - (when (= (set (:baseline-features edge)) (set (:candidate-features edge))) - " (effective feature sets identical)") - "\n effective features " (pr-str (select-keys edge [:baseline-features :candidate-features :added :removed])) - "\n")) - (when (some #(get-in % [:effective-graphics :software]) - (mapcat (fn [pair] (concat (get-in pair [:baseline :preparations]) - (get-in pair [:candidate :preparations]))) pairs)) - "SOFTWARE RENDERER recorded\n") - "Baseline " (pr-str (:run-id baseline)) " Git " (pr-str (get-in baseline [:metadata :git])) - "\nBaseline termination " (pr-str (:termination baseline)) - "\nCandidate " (pr-str (:run-id candidate)) " Git " (pr-str (get-in candidate [:metadata :git])) - "\nCandidate termination " (pr-str (:termination candidate)) - "\nAnalysis " (pr-str analysis) "\n" source-coverage "\n" interpretation - (apply str - (map (fn [{:keys [baseline candidate mismatches metrics]}] - (str "\n\nPair " (result/case-name (:case-id baseline)) "," - (result/case-name (:case-id candidate)) - (apply str - (map (fn [mismatch] - (str "\n" (if (:waived? mismatch) "ACKNOWLEDGED" "UNACKNOWLEDGED") - " DIFFERENCE " (pr-str mismatch))) mismatches)) - (side->text "Baseline" baseline) - (side->text "Candidate" candidate) - (str/join "\n" - (map (fn [[id change]] - (str "\n" (pr-str id) - " median change " (estimate->text (:absolute change)) - " CI " (estimate->text (:absolute-ci change)) - "; percent " (estimate->text (:percentage change)) - " CI " (estimate->text (:percentage-ci change)))) metrics)))) - pairs)))) + (let [side-cases (fn [side] + (let [cases (map side pairs) + by-id (group-by :case-id cases)] + (map #(first (get by-id %)) (distinct (map :case-id cases))))) + baseline-cases (side-cases :baseline) + candidate-cases (side-cases :candidate) + baseline-failures (run-failures baseline-cases (:metadata baseline) (:termination baseline)) + candidate-failures (run-failures candidate-cases (:metadata candidate) (:termination candidate))] + (str "Permissions " (pr-str permissions) "\n" + (when edge + (str "Edge " (:from edge) " -> " (:to edge) " feature " (:feature edge) + (when (= (set (:baseline-features edge)) (set (:candidate-features edge))) + " (effective feature sets identical)") + "\n effective features " (pr-str (select-keys edge [:baseline-features :candidate-features :added :removed])) + "\n")) + (when (some #(get-in % [:effective-graphics :software]) + (mapcat (fn [pair] (concat (get-in pair [:baseline :preparations]) + (get-in pair [:candidate :preparations]))) pairs)) + "SOFTWARE RENDERER recorded\n") + "Baseline " (pr-str (:run-id baseline)) " Git " (pr-str (get-in baseline [:metadata :git])) + "\nBaseline termination " (pr-str (dissoc (:termination baseline) :failure)) + "\nCandidate " (pr-str (:run-id candidate)) " Git " (pr-str (get-in candidate [:metadata :git])) + "\nCandidate termination " (pr-str (dissoc (:termination candidate) :failure)) + "\nAnalysis " (pr-str analysis) "\n" source-coverage "\n" interpretation + (failures->text "Baseline failures" baseline-failures) + (screenshots->text "Baseline screenshots" (:metadata baseline) baseline-failures baseline-cases) + (failures->text "Candidate failures" candidate-failures) + (screenshots->text "Candidate screenshots" (:metadata candidate) candidate-failures candidate-cases) + (apply str + (map (fn [{:keys [baseline candidate mismatches metrics]}] + (str "\n\nPair " (result/case-name (:case-id baseline)) "," + (result/case-name (:case-id candidate)) + (apply str + (map (fn [mismatch] + (str "\n" (if (:waived? mismatch) "ACKNOWLEDGED" "UNACKNOWLEDGED") + " DIFFERENCE " (pr-str mismatch))) mismatches)) + (side->text "Baseline" baseline) + (side->text "Candidate" candidate) + (str/join "\n" + (map (fn [[id change]] + (str "\n" (pr-str id) + " median change " (estimate->text (:absolute change)) + " CI " (estimate->text (:absolute-ci change)) + "; percent " (estimate->text (:percentage change)) + " CI " (estimate->text (:percentage-ci change)))) metrics)))) + pairs))))) diff --git a/frontend/test/performance_tests/render_wasm/lifecycle_test.cljs b/frontend/test/performance_tests/render_wasm/lifecycle_test.cljs index 410b5fc453..d17fceeb0c 100644 --- a/frontend/test/performance_tests/render_wasm/lifecycle_test.cljs +++ b/frontend/test/performance_tests/render_wasm/lifecycle_test.cljs @@ -22,8 +22,7 @@ [benches.render-wasm.report.summarize :as summary] [benches.render-wasm.result :as result] [benches.render-wasm.runtime.camera :as camera] - [cljs.test :as t :include-macros true] - [clojure.string :as str])) + [cljs.test :as t :include-macros true])) ;; Forward declaration: entry-test helpers below build args against the ;; fake Emscripten factory URL defined alongside the fake-DOM harness. @@ -790,7 +789,8 @@ (t/is (= (:cause evidence) (get-in stored [:failure :cause]))) (t/is (= blocks (:phases stored))) (t/is (= "phase-failure" (:preparation-id stored))) - (t/is (str/includes? (format/format-run (summary/summarize saved)) "phase fixture failed")) + (t/is (= 1 (count (re-seq #"phase fixture failed" + (format/format-run (summary/summarize saved)))))) (t/is (= (case failed-phase :preparation [:preparation] :main [:preparation :main] diff --git a/frontend/test/performance_tests/render_wasm/report_test.cljs b/frontend/test/performance_tests/render_wasm/report_test.cljs index 0482cca20b..df84731352 100644 --- a/frontend/test/performance_tests/render_wasm/report_test.cljs +++ b/frontend/test/performance_tests/render_wasm/report_test.cljs @@ -300,6 +300,27 @@ (t/is (str/includes? (format/format-run (summary/summarize (result/decode (result/encode failed)))) "setup failed")))) +(t/deftest comparison-reports-preparation-failures-once-per-source + (let [failure {:phase "preparation" :message "setup failed"} + run (-> (new-run 0 2 :fresh) + (result/record-preparation (preparation :ready [])) + (add-attempt :ready false :completed [(block :main :ready [(event :test/work [2])])]) + (result/record-preparation {:preparation-id :failed :case-id :saved/pan :warmup? false + :diagnostics {} :phases [] :failure failure}) + (result/record-attempt (measurement/attempt :saved/pan :failed false + {:status "failed" :phase "preparation" + :message "setup failed" :phases []})) + (result/record-case-outcome :saved/pan {:outcome :failed :failure failure}) + (result/finish-run "end" {:reason :failed :failure failure}) + result/encode result/decode) + compared (-> (compare/compare-runs run (assoc run :run-id "candidate") + {:allow-all-differences true}) + result/encode result/decode) + text (format/format-comparison compared)] + (t/is (= 2 (count (re-seq #"setup failed" text)))) + (t/is (str/includes? text "median change")) + (t/is (= 2 (count (re-seq #"Preparation :failed" text)))))) + (t/deftest offline-comparison-uses-one-analysis-and-saved-quantity-units (let [base (-> (sample-run [1 2 3]) result/encode result/decode) candidate (-> (sample-run [3 4 5]) diff --git a/frontend/test/performance_tests/render_wasm/run_test.cljs b/frontend/test/performance_tests/render_wasm/run_test.cljs index c9fa0189b6..4f2e4c0caa 100644 --- a/frontend/test/performance_tests/render_wasm/run_test.cljs +++ b/frontend/test/performance_tests/render_wasm/run_test.cljs @@ -20,6 +20,8 @@ [benches.render-wasm.node.runner.run :as run] [benches.render-wasm.node.storage.artifacts :as artifacts] [benches.render-wasm.node.storage.runs :as runs] + [benches.render-wasm.report.format :as format] + [benches.render-wasm.report.summarize :as summary] [benches.render-wasm.result :as result] [cljs.test :as t :include-macros true] [clojure.string :as str] @@ -345,6 +347,9 @@ (t/is (= 1 (:exit-code result))) (t/is (= :skipped (get-in shots ["case/reuse" :status]))) (t/is (= :ok (get-in shots ["case/fresh" :status]))) + (t/is (= 1 (count (re-seq (re-pattern (if (= kind :throw) + "scene preparation failed" "scene rejected")) + (:report result))))) (let [failure (last (get-in run [:metadata :diagnostics :failures]))] (t/is (= :preparation (:stage failure))) (t/is (= :case/reuse (:case-id failure))) @@ -368,6 +373,11 @@ (t/is (= :skipped (get-in run [:metadata :diagnostics :screenshots "case/fresh" :status]))) (t/is (= {:warmups 0 :repetitions 1} (get-in run [:remaining :case/fresh]))) (t/is (= :incomplete (get-in run [:termination :reason]))) + (t/is (= 1 (count (re-seq (re-pattern (if (= kind :throw) + "scene preparation failed" "scene rejected")) + (:report result))))) + (t/is (str/includes? (:report result) "no-completed-measured-attempt")) + (t/is (= (:report result) (format/format-run (summary/summarize (saved-record result))))) (t/is (= 1 (:exit-code result)))))) (t/deftest ^:async reuse-attempt-failure-leaves-pending-slots-and-continues-to-the-next-case @@ -789,7 +799,8 @@ (t/is (= {:warmups 0 :repetitions (if (= :page stage) 1 0)} (get-in saved [:remaining :case/a]))) (when (= :screenshot stage) - (t/is (= [:completed] (mapv :outcome (attempts-for saved :case/a)))))) + (t/is (= [:completed] (mapv :outcome (attempts-for saved :case/a)))) + (t/is (= 1 (count (re-seq #"browser work timed out" (:report response))))))) (finally (set! (.-now js/Date) system-now)))))) @@ -802,6 +813,21 @@ (t/is (= {:warmups 0 :repetitions 2} (get-in saved [:remaining :case/b]))) (t/is (= :browser-close (get-in saved [:termination :failure :stage]))))) +(t/deftest ^:async distinct-harness-failures-with-equal-diagnostics-appear-separately + (let [fake (fake-browser {:run-failure (fn [_ _] :response) + :close-failure (constantly true)}) + response (await (execute fake [(collected :case/a :reuse)] + (options fake (output-dir)))) + saved (saved-record response) + report (:report response)] + (t/is (= [:browser-close :cleanup] (mapv :stage (get-in saved [:metadata :diagnostics :failures])))) + (t/is (str/includes? report "Harness 0")) + (t/is (str/includes? report "Harness 1")) + (t/is (str/includes? report ":browser-close")) + (t/is (str/includes? report ":cleanup")) + (t/is (= 2 (count (re-seq #"browser shutdown failed" report)))) + (t/is (= 1 (count (re-seq #"attempt rejected" report)))))) + (t/deftest ^:async failed-startup-cleanup-aborts-even-after-the-case-deadline (let [system-now (.-now js/Date) clock (atom (system-now)) @@ -1126,6 +1152,8 @@ (t/is (= "case-a.png" (:file shot))) (t/is (fs/existsSync (path/join (get-in result [:home :dir]) "case-a.png"))) (t/is (= :completed (get-in run [:termination :reason]))) + (t/is (str/includes? (:report result) "Screenshots")) + (t/is (str/includes? (:report result) "case-a.png")) (t/is (zero? (:exit-code result))))) (let [fake (fake-browser {:screenshot-failure (constantly true)}) opts (assoc (options fake (output-dir)) :screenshots true) @@ -1135,6 +1163,9 @@ (t/is (= :failed (:status shot))) (t/is (= "case-a.png" (:file shot))) (t/is (= :completed (get-in run [:termination :reason]))) + (t/is (str/includes? (:report result) "\"case/a\": warning")) + (t/is (= 1 (count (re-seq #"screenshot failed" (:report result))))) + (t/is (str/includes? (:report result) "case-a.png")) (t/is (zero? (:exit-code result))))) (t/deftest ^:async metadata-records-build-and-controller-provenance-and-budgets