diff --git a/frontend/performance/benches/render_wasm/errors.cljc b/frontend/performance/benches/render_wasm/errors.cljc index 837d435dba..8ac55169b4 100644 --- a/frontend/performance/benches/render_wasm/errors.cljc +++ b/frontend/performance/benches/render_wasm/errors.cljc @@ -74,6 +74,12 @@ [:actual-id {:optional true} [:string {:max 1024}]] [:command {:optional true} [:string {:max 1024}]] [:exit-code {:optional true} :int] + [:pid {:optional true} [:int {:min 1}]] + [:pgid {:optional true} [:int {:min 1}]] + [:signals {:optional true} [:vector [:string {:max 1024}]]] + [:profile-path {:optional true} [:string {:max 1024}]] + [:fatal {:optional true} boolean?] + [:unresolved-process {:optional true} boolean?] [:signal {:optional true} [:string {:max 1024}]] [:endpoint {:optional true} [:string {:max 1024}]]]) @@ -257,20 +263,27 @@ unrenderable-value)) (defn project-context - "Returns bounded build identity and process details. + "Returns bounded identity, process and ownership details. Args: - data: Diagnostic data with optional identity or process fields. + data: Diagnostic data with available identity or process fields. Returns: - Expected/actual build IDs, command, signal and endpoint limited to - 1024 UTF-16 units, and an integer exit code when supplied." + Bounded text, integer process IDs and exit code, attempted signals, + and available fatal or unresolved-ownership markers." [data] (cond-> {} (string? (:expected-id data)) (assoc :expected-id (bounded-text (:expected-id data) 1024)) (string? (:actual-id data)) (assoc :actual-id (bounded-text (:actual-id data) 1024)) (string? (:command data)) (assoc :command (bounded-text (:command data) 1024)) (integer? (:exit-code data)) (assoc :exit-code (:exit-code data)) + (and (integer? (:pid data)) (pos? (:pid data))) (assoc :pid (:pid data)) + (and (integer? (:pgid data)) (pos? (:pgid data))) (assoc :pgid (:pgid data)) + (and (vector? (:signals data)) (every? string? (:signals data))) + (assoc :signals (mapv #(bounded-text % 1024) (:signals data))) + (string? (:profile-path data)) (assoc :profile-path (bounded-text (:profile-path data) 1024)) + (true? (:fatal data)) (assoc :fatal true) + (true? (:unresolved-process data)) (assoc :unresolved-process true) (string? (:signal data)) (assoc :signal (bounded-text (:signal data) 1024)) (string? (:endpoint data)) (assoc :endpoint (bounded-text (:endpoint data) 1024)))) @@ -362,16 +375,17 @@ Portable diagnostics with bounded cause descriptions. Collected errors retain occurrence order and messages within 1024 UTF-16 units." [phase cause] - (let [entries (get-error-collection cause)] + (let [entries (get-error-collection cause) + projected (when entries + (mapv (fn [{:keys [error operation path partial] entry-phase :phase :as entry}] + (cond-> (merge (diagnostic-data (or entry-phase phase) error) + (project-context entry) + (select-keys entry [:reason :deadline-exceeded]) + {:message (bounded-text (message-of error) 1024)}) + operation (assoc :operation operation) + partial (assoc :partial partial) + (string? path) (assoc :path (bounded-text path 1024)))) + entries))] (cond-> (diagnostic-data phase cause) - entries - (assoc :errors - (mapv (fn [{:keys [error operation path partial] entry-phase :phase :as entry}] - (cond-> (merge (diagnostic-data (or entry-phase phase) error) - (project-context entry) - (select-keys entry [:reason :deadline-exceeded]) - {:message (bounded-text (message-of error) 1024)}) - operation (assoc :operation operation) - partial (assoc :partial partial) - (string? path) (assoc :path (bounded-text path 1024)))) - entries))))))) + projected (assoc :errors projected) + (some :unresolved-process projected) (assoc :unresolved-process true)))))) diff --git a/frontend/performance/benches/render_wasm/node/process.cljs b/frontend/performance/benches/render_wasm/node/process.cljs index 53d2b5218a..a01af9077e 100644 --- a/frontend/performance/benches/render_wasm/node/process.cljs +++ b/frontend/performance/benches/render_wasm/node/process.cljs @@ -10,9 +10,19 @@ ["child_process" :as child-process] ["fs" :as fs] ["node:readline" :as readline] + [benches.render-wasm.errors :as errors :refer [attempt failure?]] [clojure.string :as str])) (def default-termination-grace-ms 5000) +(def ^:private final-termination-wait-ms 5000) + +(def ^:private max-timer-delay-ms + "Largest delay that Node timers accept; longer delays overflow a signed 32-bit integer." + 2147483647) + +(def ^:private default-options + {:termination-grace-ms default-termination-grace-ms + :capture-output? true}) (defn signal-name "Returns the signal name for an aborted AbortSignal, defaulting to SIGINT." @@ -36,6 +46,29 @@ [deadline] (max 0 (- deadline (js/Date.now)))) + +(defn- unresolved-cause? + [cause seen] + (cond + (nil? cause) false + (:unresolved-process (ex-data cause)) true + (contains? seen cause) false + :else (recur (ex-cause cause) (conj seen cause)))) + +(defn unresolved? + "True when a command's process group may still be running. + + Args: + cause: An Error, including collected errors and wrapped causes, or nil. + + Returns: + True if any error reports :unresolved-process true after termination." + [cause] + (boolean + (some (fn [{:keys [error] :as entry}] + (or (:unresolved-process entry) (unresolved-cause? error #{}))) + (errors/get-errors cause)))) + (defn- signal-group [pid signal] (try @@ -74,21 +107,95 @@ [ms] (js/Promise. (fn [resolve _] (js/setTimeout resolve ms)))) + +(defn- get-group-observation + "Checks whether a process group has a live member. + + Args: + pid: The group's leader PID. + + Returns: + A map with :status set to :running, :stopped or :unknown, and :error + when the operating system rejects the probe." + [pid] + (let [result (attempt :catch-fatal (group-running? pid))] + (if (failure? result) + {:status :unknown :error result} + {:status (if result :running :stopped)}))) + +(defn- wait-again? + "Decides whether to take another process-group observation. + + Args: + observation: A map with :status :running, :stopped or :unknown. + context: The absolute :deadline and :phase, either :grace before SIGKILL + or :confirmation after SIGKILL. + now: Current time in milliseconds since the Unix epoch. + + Returns: + True while time remains and the group may be running. Grace ends on a + failed probe; confirmation continues through probe failures." + [observation {:keys [phase deadline]} now] + (and (not= :stopped (:status observation)) + (< now deadline) + (or (= :confirmation phase) (= :running (:status observation))))) + +(defn- group-failed + "Returns the failure of an operation on a command group. + + Args: + kind: The failure type. + action: Text that describes the failed operation. The message appends the + bounded text of the cause. + cause: The Error that the operation raised. + data: Diagnostic data of the failure." + [kind action cause data] + {:type kind + :message (str action ": " (errors/bounded-text (errors/message-of cause) 500)) + :cause cause + :data data}) + +(defn- ^:async wait-for-group + [{:keys [pid deadline signals] :as context} record] + (let [observation (get-group-observation pid) + now (js/Date.now)] + (when-let [cause (:error observation)] + (record :probe-group (group-failed :process-probe "Could not inspect command group" cause {:signals signals}))) + (if (wait-again? observation context now) + (do + (await (pause (min 10 (- deadline now)))) + (await (wait-for-group context record))) + observation))) + +(defn- send-group-signal + [pid signal record] + (let [result (attempt :catch-fatal (signal-group pid signal))] + (when (failure? result) + (record :signal-group + (group-failed :process-signal (str "Could not send " signal " to command group") result {:signal signal}))) + result)) + (defn- ^:async terminate-group - [pid grace-deadline] - (try - (signal-group pid "SIGTERM") - (loop [] - (when (group-running? pid) - (when (zero? (remaining grace-deadline)) - ;; Include members forked while earlier members handled termination. - (signal-group pid "SIGKILL")) - (await (pause 10)) - (recur))) - (catch :default cause - ;; A failed liveness probe must not leave a running compiler or lock owner. - (signal-group pid "SIGKILL") - (throw cause)))) + [pid grace-deadline record] + (let [signals ["SIGTERM"] + term (send-group-signal pid "SIGTERM" record) + grace {:pid pid :phase :grace :signals signals + :deadline (if (failure? term) (js/Date.now) grace-deadline)} + observation (await (wait-for-group grace record))] + (if (= :stopped (:status observation)) + {:signals signals :unresolved-process false} + (let [signals (conj signals "SIGKILL")] + (send-group-signal pid "SIGKILL" record) + (let [confirmation (assoc grace :phase :confirmation :signals signals + :deadline (deadline final-termination-wait-ms)) + observation (await (wait-for-group confirmation record)) + unresolved (not= :stopped (:status observation))] + (when unresolved + (record :terminate-group + {:type :process-unresolved + :message "Command group ownership remains unresolved after SIGKILL" + :data {:fatal true :unresolved-process true :signals signals}})) + {:signals signals :unresolved-process unresolved}))))) (defn- process-error [{:keys [command args cwd]} result {:keys [type message cause data]}] @@ -98,9 +205,11 @@ (defn- cancelled [^js signal] - {:type :process-cancelled - :message "Command cancelled" - :data {:reason (.-reason signal)}}) + (let [reason (.-reason signal)] + {:type :process-cancelled + :message "Command cancelled" + :cause (when (failure? reason) reason) + :data {:reason (signal-name signal)}})) (defn- timed-out [deadline] @@ -134,153 +243,362 @@ (js/clearTimeout timer) (resolve))))))) +(def ^:private empty-result {:exit-code nil :signal nil :stdout "" :stderr ""}) +(def ^:private read-failed-message "Could not read command output") +(def ^:private callback-failed-message "Command output callback failed") + +(defn- group-ids + "Returns {:pid pid :pgid pid} for the leader of a detached process group." + [pid] + {:pid pid :pgid pid}) + +(defn- launch-error + [options failure] + (process-error options empty-result failure)) + +(defn- launch-failure + "Returns the failure that forbids starting a command, or nil. + + Args: + options: Command settings with the absolute :deadline and the optional + AbortSignal :signal." + [{:keys [signal deadline]}] + (cond + (and signal (.-aborted ^js signal)) (cancelled signal) + (zero? (remaining deadline)) (timed-out deadline))) + +(defn- output-failed + [stream cause message] + {:type :process-output :message message :cause cause :data {:stream stream}}) + +(defn- completion-failure + "Returns the failure to record for the reason a command completes. + + Args: + reason: The exit status {:exit-code :signal} or a failure map with :type. + + Returns: + The failure, or nil for a zero exit code. Output failures are recorded + when they occur." + [reason] + (let [kind (:type reason)] + (cond + (= :process-output kind) nil + kind reason + (not= 0 (:exit-code reason)) {:type :process-exit :message "Command exited unsuccessfully"}))) + +(defn- spawn-child + "Spawns the command in a new process group. + + Args: + options: Command settings with :command and literal :args, and optional + :cwd and :env. A map or JS object under :env merges over process.env. + + Returns: + The ChildProcess. + + Throws: + A launch error when the operating system rejects the spawn." + [{:keys [command args cwd env] :as options}] + (let [environment (js/Object.assign #js {} (.-env js/process) (if (map? env) (clj->js env) env))] + (try + (child-process/spawn command (clj->js args) + #js {:cwd cwd :env environment :detached true + :stdio #js ["pipe" "pipe" "pipe"]}) + (catch :default cause + (throw (launch-error options (spawn-failed cause))))))) + +(defn- watch-exit + "Observes the exit and the process errors of a child. + + Returns: + A map with :promise, which resolves with the first outcome, and :state, + a volatile holding the latest outcome. An outcome is {:exit-code :signal} + or the failure of a process error." + [^js child] + (let [state (volatile! nil) + observe (fn [resolve outcome] + (vreset! state outcome) + (resolve outcome))] + {:state state + :promise (js/Promise. + (fn [resolve _] + (.once child "exit" (fn [code signal] (observe resolve {:exit-code code :signal signal}))) + (.once child "error" #(observe resolve (spawn-failed %)))))})) + +(defn- destroy-stream + [^js stream] + (when stream (.destroy stream))) + +(defn- failure-recorder + "Returns (record operation failure), which appends a failure occurrence. + + Args: + options: Command settings. Occurrences carry its :command, :args and :cwd. + child: The ChildProcess. + exit-state: Volatile with the latest exit outcome. Occurrences carry the + exit status known when they occur. + failures: Volatile vector that receives the occurrences in order." + [options ^js child exit-state failures] + (fn [operation failure] + (let [context (merge empty-result + (group-ids (.-pid child)) + (select-keys @exit-state [:exit-code :signal]))] + (vswap! failures conj {:phase "process" :operation operation + :error (process-error options context failure)})))) + +(defn- new-completion + "Returns the settlement of the completion of a command. + + Args: + record: Function from `failure-recorder`. + + Returns: + A map with :promise and :settle. `settle` takes a completion reason. The + first reason records its failure, if any, and resolves :promise. Later + reasons do nothing." + [record] + (let [^js completion (js/Promise.withResolvers) + settled (volatile! false)] + {:promise (.-promise completion) + :settle (fn [reason] + (when-not @settled + (vreset! settled true) + (when-let [failure (completion-failure reason)] + (record :run-command failure)) + ((.-resolve completion) reason)))})) + +(defn- watch-deadline + "Calls `settle` with a timeout failure once `deadline` passes. + + Args: + deadline: Absolute Date.now() timestamp in milliseconds. + settle: Function of a completion reason. + + Returns: + A function that cancels the pending check." + [deadline settle] + (let [timer (volatile! nil) + check (fn check [] + (let [ms (remaining deadline)] + (if (zero? ms) + (settle (timed-out deadline)) + (vreset! timer (js/setTimeout check (min ms max-timer-delay-ms))))))] + (check) + #(js/clearTimeout @timer))) + +(defn- watch-abort + "Calls `settle` with a cancellation failure when `signal` aborts, or at once + when it already aborted. + + Args: + signal: An AbortSignal, or nil. + settle: Function of a completion reason. + + Returns: + A function that removes the listener." + [^js signal settle] + (if signal + (let [abort (fn [_] (settle (cancelled signal)))] + (.addEventListener signal "abort" abort #js {:once true}) + (when (.-aborted signal) (abort nil)) + #(.removeEventListener signal "abort" abort)) + (constantly nil))) + +(defn- watch-completion + "Calls `settle` with the first completion reason among the exit outcome, the + deadline and the abort. + + Args: + options: Command settings with :deadline and the optional :signal. + exited: Promise of the exit outcome. + settle: Function of a completion reason. + + Returns: + A function that stops watching the deadline and the signal." + [{:keys [deadline signal]} ^js exited settle] + (.then exited settle) + (let [stop-deadline (watch-deadline deadline settle) + stop-abort (watch-abort signal settle)] + (fn [] + (stop-deadline) + (stop-abort)))) + +(defn- open-line-reader + "Returns a readline interface that passes the complete lines of `input` to + `on-line` with `stream`. Callback failures and stream errors go to `fail`. + Stream errors keep going to `fail` after the reader closes." + [^js input stream on-line fail] + (let [reader (readline/createInterface #js {:input input :terminal false :crlfDelay js/Infinity}) + unreadable #(fail stream % read-failed-message)] + (.on reader "line" + (fn [line] + (try + (on-line line stream) + (catch :default cause + (fail stream cause callback-failed-message))))) + (.on reader "error" unreadable) + (.once reader "close" #(.on input "error" unreadable)) + reader)) + +(defn- observe-output + "Decodes stdout and stderr of a child as UTF-8 and routes their text. + + Appends each chunk to `captured` when :capture-output? is set, and calls + :on-output with each chunk and :on-line with each complete line. + + Args: + options: Command settings with :capture-output?, :on-output and :on-line. + child: The ChildProcess. + captured: Volatile map from :stdout and :stderr to vectors of text. + fail: Function of a stream, a cause and a message that receives the + failures of streams and callbacks. + + Returns: + A vector with the line readers it opened." + [{:keys [on-output on-line capture-output?]} ^js child captured fail] + (let [route (fn [stream text] + (when capture-output? (vswap! captured update stream conj text)) + (when on-output + (try + (on-output text stream) + (catch :default cause + (fail stream cause callback-failed-message))))) + listen (fn [^js input stream] + (.setEncoding input "utf8") + (.on input "data" #(route stream %)) + (when-not on-line + (.on input "error" #(fail stream % read-failed-message))))] + (listen (.-stdout child) :stdout) + (listen (.-stderr child) :stderr) + (if on-line + [(open-line-reader (.-stdout child) :stdout on-line fail) + (open-line-reader (.-stderr child) :stderr on-line fail)] + []))) + +(defn- close-stdin + "Closes the stdin of a child. Write errors go to `fail`, except EPIPE, which + a command that exits without reading stdin causes." + [^js child fail] + (.on (.-stdin child) "error" + (fn [cause] + (when-not (= "EPIPE" (.-code cause)) + (fail :stdin cause "Could not close command stdin")))) + (.end (.-stdin child))) + +(defn- command-result + "Returns the exit status and the captured text of a finished command." + [status captured] + {:exit-code (:exit-code status) + :signal (:signal status) + :stdout (str/join "" (:stdout captured)) + :stderr (str/join "" (:stderr captured))}) + +(defn- ^:async terminate-and-drain + "Terminates the process group of a child and drains its queued output. + + Args: + options: Command settings with :termination-grace-ms. + child: The ChildProcess. + exit: Map from `watch-exit`. + output-done: Promise that resolves when stdout and stderr end. + record: Function from `failure-recorder`. + + Returns: + A promise of {:status exit-status :termination termination}. The status + comes from the exit of the child. When the group stays unresolved, the + status is the one already known, and the child no longer keeps this + process alive." + [{:keys [termination-grace-ms]} ^js child {exit-state :state exited :promise} output-done record] + (let [grace-deadline (deadline termination-grace-ms) + termination (await (terminate-group (.-pid child) grace-deadline record)) + unresolved? (:unresolved-process termination)] + (when unresolved? (.unref child)) + (let [status (if unresolved? @exit-state (await exited))] + (await (drain-output output-done grace-deadline)) + {:status status :termination termination}))) + +(defn- ^:async supervise + "Watches a spawned command until it completes, then terminates its group. + + Args: + options: The options of `run` with defaults applied. + child: The spawned ChildProcess. + exit: Map from `watch-exit`. + + Returns: + A promise of {:exit-code 0 :stdout string :stderr string}. + + Throws: + The Error that combines the recorded failures with the result, the + termination and the process identity." + [options ^js child exit] + (let [pid (.-pid child) + failures (volatile! []) + captured (volatile! {:stdout [] :stderr []}) + record (failure-recorder options child (:state exit) failures) + {completed :promise settle :settle} (new-completion record) + fail (fn [stream cause message] + (let [failure (output-failed stream cause message)] + (record :read-output failure) + (settle failure))) + output-done (js/Promise.all #js [(stream-done (.-stdout child)) + (stream-done (.-stderr child))]) + readers (observe-output options child captured fail) + stop-waiting (watch-completion options (:promise exit) settle)] + (try + (close-stdin child fail) + (await completed) + (stop-waiting) + (let [{:keys [status termination]} (await (terminate-and-drain options child exit output-done record)) + result (command-result status @captured) + failure (errors/combine @failures)] + (if failure + (throw (errors/with-context failure (errors/message-of failure) + (merge result termination (group-ids pid)))) + (dissoc result :signal))) + (finally + (run! #(.close ^js %) readers) + (stop-waiting))))) + (defn ^:async run - "Spawns command with literal args, cwd and env merged over process.env. - deadline is an absolute Date.now() timestamp; signal is an optional - AbortSignal. An expired deadline or aborted signal starts no process. + "Runs a command and owns its detached POSIX process group. - on-output receives [UTF-8 text :stdout/:stderr] as data arrives. Optional - on-line receives [line :stdout/:stderr], including a final unterminated line. - Output is also collected unless capture-output? is false; then both result - strings are empty. Returns a promise of - {:exit-code 0 :stdout string :stderr string}. + An expired deadline or aborted signal starts no process. Output callbacks + receive UTF-8 chunks or complete lines, including a final unterminated + line. Completion follows the exit of the root process, not the close of its + output pipes, because descendants can keep the pipes open. Cleanup sends + SIGTERM and waits the termination grace. If the group still runs, it sends + SIGKILL once and allows five more seconds for the group to stop. Unresolved + ownership produces a fatal failure. - Failures reject with ex-info carrying :command, :exit-code, :signal and - output. Types are :process-exit, :process-spawn, :process-timeout and - :process-cancelled; output/cleanup errors use :process-output/:process-cleanup. + Args: + options: Command settings with :command, literal :args, optional :cwd and + :env, absolute :deadline and optional AbortSignal under :signal. + :termination-grace-ms defaults to 5000. :on-output receives text and + :stdout/:stderr; :on-line receives a line and its stream. Output capture + defaults to true and accepts :capture-output? false for streamed output. - The detached POSIX group belongs to this call, including descendants left - after a successful root exit. Cleanup sends SIGTERM then, after the grace, - SIGKILL. Settlement waits for live group members to stop. It uses root exit, - not child close, since descendants may inherit and retain the output pipes." - [{:keys [command args cwd env deadline signal termination-grace-ms on-output on-line capture-output?] - :or {termination-grace-ms default-termination-grace-ms capture-output? true} - :as options}] - (let [empty-result {:exit-code nil :signal nil :stdout "" :stderr ""} - environment (js/Object.assign #js {} (.-env js/process) (if (map? env) (clj->js env) env))] - (when (and signal (.-aborted ^js signal)) - (throw (process-error options empty-result (cancelled signal)))) - (when (zero? (remaining deadline)) - (throw (process-error options empty-result (timed-out deadline)))) - (let [^js child (try - (child-process/spawn command (clj->js args) - #js {:cwd cwd - :env environment - :detached true - :stdio #js ["pipe" "pipe" "pipe"]}) - (catch :default cause - (throw (process-error options empty-result (spawn-failed cause))))) - exited (js/Promise. - (fn [resolve _] - (.once child "exit" - (fn [code signal] - (resolve {:exit-code code :signal signal}))) - (.once child "error" #(resolve (spawn-failed %)))))] + Returns: + A promise resolving to {:exit-code 0 :stdout string :stderr string}. + + Throws: + Failures reject with command, output and process identity. Collected + occurrences retain execution, output, signalling and probe failures in + order. :process-unresolved marks unresolved group ownership as fatal. + Cancellation records the signal name as :reason and retains an Error + supplied as the abort reason as a cause." + [options] + (let [options (merge default-options options)] + (when-let [failure (launch-failure options)] + (throw (launch-error options failure))) + (let [^js child (spawn-child options) + exit (watch-exit child)] (try - (if-not (.-pid child) - ;; A failed spawn may not provide stdin/stdout/stderr at all. - (throw (process-error options empty-result (await exited))) - (let [stdout (volatile! []) - stderr (volatile! []) - output-failure (volatile! nil) - line-readers (volatile! []) - complete (volatile! nil) - timeout (volatile! nil) - abort (fn [_] (@complete (cancelled signal))) - stop-waiting (fn [] - (js/clearTimeout @timeout) - (when signal - (.removeEventListener ^js signal "abort" abort))) - stream-error (fn [stream cause message] - (let [failure {:type :process-output - :message message - :cause cause - :data {:stream stream}}] - (vreset! output-failure failure) - (@complete failure))) - route (fn [parts stream text] - (when capture-output? - (vswap! parts conj text)) - (when on-output - (try - (on-output text stream) - (catch :default cause - (stream-error stream cause "Command output callback failed"))))) - output-done (js/Promise.all #js [(stream-done (.-stdout child)) - (stream-done (.-stderr child))]) - completed (js/Promise. - (fn [resolve _] - (vreset! complete resolve) - (.then exited resolve) - (letfn [(check-deadline [] - (let [ms (remaining deadline)] - (if (zero? ms) - (resolve (timed-out deadline)) - ;; Node timers overflow above a signed 32-bit delay. - (vreset! timeout - (js/setTimeout check-deadline (min ms 2147483647))))))] - (check-deadline)) - (when signal - (.addEventListener ^js signal "abort" abort #js {:once true}) - (when (.-aborted ^js signal) - (abort nil)))))] - (try - (.setEncoding (.-stdout child) "utf8") - (.setEncoding (.-stderr child) "utf8") - (.on (.-stdout child) "data" #(route stdout :stdout %)) - (.on (.-stderr child) "data" #(route stderr :stderr %)) - (.on (.-stdout child) "error" #(stream-error :stdout % "Could not read command output")) - (.on (.-stderr child) "error" #(stream-error :stderr % "Could not read command output")) - (when on-line - (doseq [[stream input] [[:stdout (.-stdout child)] [:stderr (.-stderr child)]]] - (let [reader (readline/createInterface - #js {:input input :terminal false :crlfDelay js/Infinity})] - (vswap! line-readers conj reader) - (.on reader "line" - (fn [line] - (try - (on-line line stream) - (catch :default cause - (stream-error stream cause "Command output callback failed"))))) - (.on reader "error" #(stream-error stream % "Could not read command output"))))) - ;; EPIPE is normal when a command exits without reading stdin. - (.on (.-stdin child) "error" - (fn [cause] - (when-not (= "EPIPE" (.-code cause)) - (stream-error :stdin cause "Could not close command stdin")))) - (.end (.-stdin child)) - (let [reason (await completed) - grace-deadline (benches.render-wasm.node.process/deadline termination-grace-ms)] - (stop-waiting) - (let [cleanup-failure (try - (await (terminate-group (.-pid child) grace-deadline)) - nil - (catch :default cause - {:type :process-cleanup - :message "Could not terminate command group" - :cause cause})) - exit (await exited)] - (await (drain-output output-done grace-deadline)) - (let [result {:exit-code (:exit-code exit) - :signal (:signal exit) - :stdout (str/join "" @stdout) - :stderr (str/join "" @stderr)} - failure (or (when (:type reason) reason) - @output-failure - cleanup-failure - (when (not= 0 (:exit-code exit)) - {:type :process-exit :message "Command exited unsuccessfully"}))] - (if failure - (throw (process-error options result failure)) - (dissoc result :signal))))) - (finally - (doseq [reader @line-readers] - (.close ^js reader)) - (stop-waiting))))) + (if (.-pid child) + (await (supervise options child exit)) + (throw (launch-error options (await (:promise exit))))) (finally - (when-let [stream (.-stdin child)] - (.destroy ^js stream)) - (when-let [stream (.-stdout child)] - (.destroy ^js stream)) - (when-let [stream (.-stderr child)] - (.destroy ^js stream))))))) + (destroy-stream (.-stdin child)) + (destroy-stream (.-stdout child)) + (destroy-stream (.-stderr child))))))) diff --git a/frontend/performance/benches/render_wasm/node/runner/browser.cljs b/frontend/performance/benches/render_wasm/node/runner/browser.cljs index b2fd51ec4c..6d1a237745 100644 --- a/frontend/performance/benches/render_wasm/node/runner/browser.cljs +++ b/frontend/performance/benches/render_wasm/node/runner/browser.cljs @@ -143,8 +143,12 @@ (await process) nil (catch :default cause - (when-not (= :process-cancelled (:type (ex-data cause))) - (throw cause))))) + (let [entries (remove (fn [{:keys [error]}] + (and (= :process-cancelled (:type (ex-data error))) + (not (errors/fatal? error)))) + (errors/get-errors cause))] + (when-let [failure (errors/combine entries)] + (throw (errors/with-data failure (errors/project-context (ex-data cause))))))))) (defn- disconnect "Disconnects only after the group has stopped. A late CDP attachment is also @@ -192,15 +196,18 @@ (let [page-failure (attempt :catch-fatal (await (close-page owner)) nil) process-failure (attempt :catch-fatal (await (stop-process owner)) nil) disconnect-failure (attempt :catch-fatal (await (disconnect owner)) nil) - profile-failure (attempt :catch-fatal - (fs/rmSync user-data-dir #js {:recursive true :force true}) - nil)] + profile-failure (when-not (process/unresolved? process-failure) + (attempt :catch-fatal + (fs/rmSync user-data-dir #js {:recursive true :force true}) + nil))] (when (or process-failure disconnect-failure profile-failure) - (throw (errors/combine - [{:phase "cleanup" :operation :close-page :error page-failure} - {:phase "cleanup" :operation :stop-process :error process-failure} - {:phase "cleanup" :operation :disconnect-browser :error disconnect-failure} - {:phase "cleanup" :operation :remove-profile :path user-data-dir :error profile-failure}]))))) + (throw (errors/with-data + (errors/combine + [{:phase "cleanup" :operation :close-page :error page-failure} + {:phase "cleanup" :operation :stop-process :profile-path user-data-dir :error process-failure} + {:phase "cleanup" :operation :disconnect-browser :error disconnect-failure} + {:phase "cleanup" :operation :remove-profile :path user-data-dir :error profile-failure}]) + {:profile-path user-data-dir}))))) (defn close "Returns one shutdown Promise for this owner. Aborting the internal process @@ -283,8 +290,7 @@ (into seen (map :error (errors/get-errors observed))) (recur (ex-cause current) (conj seen current))))] (errors/combine - (remove #(and (= :stop-process (:operation %)) - (contains? reported (:error %))) + (remove #(contains? reported (:error %)) (errors/get-errors cleanup-cause)))))] (if cleanup (throw (errors/with-context diff --git a/frontend/performance/benches/render_wasm/node/runner/build.cljs b/frontend/performance/benches/render_wasm/node/runner/build.cljs index 78999f1198..d6e962ec50 100644 --- a/frontend/performance/benches/render_wasm/node/runner/build.cljs +++ b/frontend/performance/benches/render_wasm/node/runner/build.cljs @@ -40,8 +40,8 @@ Return a promise of a map containing :sha, the commit ID, and :dirty, which is true when the checkout has local changes. If Git information is - unavailable, log a warning and return nil for both values. A timeout or - cancellation rejects the promise." + unavailable, log a warning and return nil for both values. Fatal process + failures, timeouts and cancellation reject the promise." [root bounds] (try (let [options (merge bounds {:command "git" :cwd root}) @@ -49,7 +49,8 @@ status (await (process/run (assoc options :args ["status" "--porcelain"])))] {:sha (str/trim (:stdout sha)) :dirty (not (str/blank? (:stdout status)))}) (catch :default cause - (if (contains? #{:process-timeout :process-cancelled} (:type (ex-data cause))) + (if (or (errors/fatal? cause) + (contains? #{:process-timeout :process-cancelled} (:type (ex-data cause)))) (throw cause) (do (log/warn (str "Git provenance unavailable: " (errors/message-of cause))) diff --git a/frontend/performance/benches/render_wasm/node/runner/feature_comparison.cljs b/frontend/performance/benches/render_wasm/node/runner/feature_comparison.cljs index 2597196c00..21120ca473 100644 --- a/frontend/performance/benches/render_wasm/node/runner/feature_comparison.cljs +++ b/frontend/performance/benches/render_wasm/node/runner/feature_comparison.cljs @@ -277,9 +277,13 @@ (defn- fail-or-interrupt [state slug phase cause] - (if-let [signal (process/signal-name (:signal state))] - (interrupt-configuration state slug signal phase cause) - (fail-configuration state slug phase (str (name phase) " failure") cause))) + (try + (if-let [signal (process/signal-name (:signal state))] + (interrupt-configuration state slug signal phase cause) + (fail-configuration state slug phase (str (name phase) " failure") cause)) + (catch :default recorded + (throw (errors/combine [{:error cause} + {:phase "comparison-storage" :operation :record-configuration-failure :error recorded}]))))) (defn- begin-configuration [state configuration] @@ -315,15 +319,18 @@ (if (:outcome flow) flow (let [{:keys [slug selection]} (:configuration flow) - built (attempt - (await ((:prepare-build (:services state)) - {:root (:root state) - :selection selection - :build-timeout-ms (get-in state [:options :build-timeout-ms]) - :signal (:signal state) - :on-created (partial record-created-build state slug)}))) + built (attempt :catch-fatal + (await ((:prepare-build (:services state)) + {:root (:root state) + :selection selection + :build-timeout-ms (get-in state [:options :build-timeout-ms]) + :signal (:signal state) + :on-created (partial record-created-build state slug)}))) signal (process/signal-name (:signal state))] (cond + (and (failure? built) (errors/fatal? built) (not (process/unresolved? built))) + (throw built) + (failure? built) (assoc flow :outcome (fail-or-interrupt state slug :build built)) @@ -630,25 +637,39 @@ (catch :default cause (throw (storage-error cause (get-in state [:home :log-path])))))) +(defn- stop-unresolved-comparison + [state error] + (let [recorded (attempt :catch-fatal + (mark-edges-unattempted state "process group may still be running") + nil)] + (if (failure? recorded) + (failure-outcome state (process/signal-name (:signal state)) + (errors/combine [{:error error} + {:phase "comparison-storage" :operation :skip-comparisons :error recorded}])) + (finish state :failed 1 [error])))) + (defn- ^:async run-edges [state error] - (if-let [signal (process/signal-name (:signal state))] - (interrupt-comparison state signal error) - (do - (try - (create-comparison-directory state) - (catch :default cause - (throw (errors/combine [{:error error} - {:phase "comparison-storage" :operation :create-comparison-directory :error cause}])))) - (let [analyzed (attempt :catch-fatal - (await (analyze-edges state (:edges @(:record-ref state)) error)))] - (cond - (failure? analyzed) - (if-let [signal (process/signal-name (:signal state))] - (failure-outcome state signal analyzed) - (finish state :failed 1 [analyzed])) - (:interrupted analyzed) (interrupt-comparison state (:interrupted analyzed) (:error analyzed)) - :else (finish-root state (:error analyzed))))))) + (let [signal (process/signal-name (:signal state))] + (cond + signal (interrupt-comparison state signal error) + (process/unresolved? error) (stop-unresolved-comparison state error) + :else + (do + (try + (create-comparison-directory state) + (catch :default cause + (throw (errors/combine [{:error error} + {:phase "comparison-storage" :operation :create-comparison-directory :error cause}])))) + (let [analyzed (attempt :catch-fatal + (await (analyze-edges state (:edges @(:record-ref state)) error)))] + (cond + (failure? analyzed) + (if-let [signal (process/signal-name (:signal state))] + (failure-outcome state signal analyzed) + (finish state :failed 1 [analyzed])) + (:interrupted analyzed) (interrupt-comparison state (:interrupted analyzed) (:error analyzed)) + :else (finish-root state (:error analyzed)))))))) (defn- ^:async run-comparisons [state configurations] diff --git a/frontend/performance/benches/render_wasm/node/runner/run.cljs b/frontend/performance/benches/render_wasm/node/runner/run.cljs index d2d2feb849..9848c1afaf 100644 --- a/frontend/performance/benches/render_wasm/node/runner/run.cljs +++ b/frontend/performance/benches/render_wasm/node/runner/run.cljs @@ -774,11 +774,17 @@ "failure: " (errors/message-of recorded) "\n"))))) (defn- ^:async execute-session - "Runs the session. Returns the failure that ended it, or nil. An interruption - is not a failure." + "Runs the session and retains failures that require final reporting. + + Args: + state: The session's execution state. + + Returns: + The failure that ended execution, or nil. Interrupted sessions retain + fatal failures." [state] (let [ended (attempt :catch-fatal (await (run-session state)))] - (when (and (failure? ended) (not (interrupted? state))) + (when (and (failure? ended) (or (not (interrupted? state)) (errors/fatal? ended))) (record-session-failure state :runner ended) ended))) @@ -789,8 +795,8 @@ cause)) (defn- remove-run-build - [state saved?] - (when (and saved? (:remove (:opts state))) + [state saved? failures] + (when (and saved? (:remove (:opts state)) (not-any? process/unresolved? failures)) (attempt :catch-fatal (remove-build (:root state) (:selected-build state)) nil))) @@ -820,7 +826,8 @@ [state session-error cleanup-error] (let [saved (attempt :catch-fatal (finish-run state)) run (if (failure? saved) @(:run-ref state) saved) - removal (remove-run-build state (not (failure? saved))) + removal (remove-run-build state (not (failure? saved)) + (filter failure? [session-error cleanup-error saved @(:sink-failure-ref state)])) report (format-run-report state run) logged (log-run-completion state run) causes (->> [cleanup-error session-error saved removal report logged diff --git a/frontend/performance/benches/render_wasm/report/format.cljs b/frontend/performance/benches/render_wasm/report/format.cljs index d80dbb0ec9..16c52bfc1d 100644 --- a/frontend/performance/benches/render_wasm/report/format.cljs +++ b/frontend/performance/benches/render_wasm/report/format.cljs @@ -64,13 +64,32 @@ [value] (errors/bounded-text (js/JSON.stringify value) 1024)) +(defn- identifier->text + [value] + (if (string? value) + (quoted-detail value) + (errors/bounded-text (pr-str value) 1024))) + +(def ^:private process-detail-keys + [:command :pid :pgid :signals :profile-path :fatal :unresolved-process]) + (defn format-error-entry - "Formats a failure location with its available operation, message and path." - [{:keys [phase operation message path]}] + "Formats an error with its location and available process details. + + Args: + entry: A projected error occurrence. + + Returns: + Bounded error text and process details when a group may still be running." + [{:keys [phase operation message path] :as entry}] (str (when operation (str (pr-str operation) " ")) (quoted-detail phase) (when (some? message) (str ": " (quoted-detail message))) - (when path (str "\n Path " (quoted-detail path))))) + (when path (str "\n Path " (quoted-detail path))) + (when (:unresolved-process entry) + (apply str + (map (fn [[key value]] (str "\n " (name key) " " (identifier->text value))) + (select-keys entry process-detail-keys)))))) (defn- failure->text [{:keys [failure reason]}] @@ -78,23 +97,23 @@ (if-let [n (:unacknowledged-differences failure)] (str n " unacknowledged " (if (= n 1) "difference" "differences")) (if-let [entries (seq (:errors failure))] - (str (if (not= (errors/bounded-text (:message failure) 1024) (:message (first entries))) - (str (format-error-entry failure) "\n ") - (when (not= (select-keys failure [:phase :operation :path]) - (select-keys (first entries) [:phase :operation :path])) - (str "Context " (format-error-entry (dissoc failure :message)) "\n "))) - (str/join "\n " (map format-error-entry (take 8 entries))) - (when (> (count entries) 8) - (str "\n " (- (count entries) 8) " more errors recorded"))) + (let [header (apply dissoc failure process-detail-keys) + omitted (drop 8 entries) + unresolved (filter :unresolved-process omitted)] + (str (if (not= (errors/bounded-text (:message failure) 1024) (:message (first entries))) + (str (format-error-entry header) "\n ") + (when (not= (select-keys failure [:phase :operation :path]) + (select-keys (first entries) [:phase :operation :path])) + (str "Context " (format-error-entry (dissoc header :message)) "\n "))) + (str/join "\n " (map format-error-entry (take 8 entries))) + (when (seq omitted) + (str "\n " (count omitted) " more errors recorded")) + (when-let [entry (first unresolved)] + (str "\n " (count unresolved) " unresolved process errors in the saved record; first: " + (format-error-entry entry))))) (format-error-entry 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) @@ -148,8 +167,10 @@ (defn- diagnostic->text [failure] - (let [details (merge (select-keys (first (:cause failure)) [:type :code :fn]) - (errors/project-context failure) + (let [context (errors/project-context failure) + context (if (:unresolved-process failure) (apply dissoc context process-detail-keys) context) + details (merge (select-keys (first (:cause failure)) [:type :code :fn]) + context (select-keys failure [:reason :deadline-exceeded]))] (str (failure->text {:failure failure}) (apply str (map (fn [[key value]] diff --git a/frontend/test/performance_tests/render_wasm/browser_test.cljs b/frontend/test/performance_tests/render_wasm/browser_test.cljs index 90ab342ad3..e0b88af31d 100644 --- a/frontend/test/performance_tests/render_wasm/browser_test.cljs +++ b/frontend/test/performance_tests/render_wasm/browser_test.cljs @@ -127,6 +127,39 @@ (mapv :error (errors/get-errors cause))))) (t/is (nil? (await closing))))))) + +(t/deftest ^:async unresolved-cancellation-retains-the-browser-profile + (let [profile (path/join @temporary-root "profile.info") + controller (js/AbortController.) + failure (errors/combine + [{:error (ex-info "Command cancelled" {:type :process-cancelled})} + {:error (errors/fatal-error "Command group may still be running" + {:type :process-unresolved :unresolved-process true + :pid 4242 :pgid 4242 :signals ["SIGTERM" "SIGKILL"]} nil)}]) + running (js/Promise. (fn [_ reject] + (.addEventListener (.-signal controller) "abort" #(reject failure)))) + owner {:controller controller :process running :shutdown (atom nil) + :connection (atom nil) :user-data-dir @temporary-root}] + (fs/writeFileSync profile "retained") + (let [cause (try (await (browser/close owner)) nil (catch :default cause cause))] + (t/is (errors/fatal? cause)) + (t/is (process/unresolved? cause)) + (t/is (= @temporary-root (:profile-path (errors/evidence :cleanup cause)))) + (t/is (= "retained" (when (fs/existsSync profile) (fs/readFileSync profile "utf8"))))))) + + +(t/deftest ^:async process-stop-retains-other-errors-after-cancellation + (let [controller (js/AbortController.) + probe (ex-info "Probe failed" {:type :process-probe}) + failure (errors/combine [{:error (ex-info "Command cancelled" {:type :process-cancelled})} + {:error probe}]) + running (js/Promise. (fn [_ reject] + (.addEventListener (.-signal controller) "abort" #(reject failure)))) + owner {:controller controller :process running :shutdown (atom nil) + :connection (atom nil) :user-data-dir @temporary-root} + cause (try (await (browser/close owner)) nil (catch :default cause cause))] + (t/is (= [probe] (mapv :error (errors/get-errors cause)))))) + (t/deftest ^:async browser-startup-retains-a-failure-of-its-disposal (let [run-process process/run close browser/close @@ -142,7 +175,7 @@ (let [cause (await (rejected (browser/launch {:startup-timeout-ms 10000}))) entries (errors/get-errors cause)] (t/is (= ::browser/startup-cleanup (:type (ex-data cause)))) - (t/is (= ["Chromium exited before its CDP endpoint became ready" "startup disposal failed"] + (t/is (= ["Command exited unsuccessfully" "startup disposal failed"] (mapv #(errors/message-of (:error %)) entries)))))))) (defn- ^:async check-stopped diff --git a/frontend/test/performance_tests/render_wasm/build_test.cljs b/frontend/test/performance_tests/render_wasm/build_test.cljs index 0cc435a0ce..1975ab86aa 100644 --- a/frontend/test/performance_tests/render_wasm/build_test.cljs +++ b/frontend/test/performance_tests/render_wasm/build_test.cljs @@ -19,7 +19,8 @@ [benches.render-wasm.node.process :as process] [benches.render-wasm.node.runner.build :as build] [cljs.test :as t :include-macros true] - [clojure.string :as str])) + [clojure.string :as str] + [frontend-tests.helpers.mock :as mock])) (def ^:private temporary-root (atom nil)) @@ -183,6 +184,21 @@ (t/is (= {:sha nil :dirty nil} git))))) done))) + +(t/deftest ^:async git-provenance-propagates-unresolved-process-failures + (let [failure (errors/fatal-error "Git process may still be running" + {:type :process-unresolved :unresolved-process true + :command "git" :pid 4242 :pgid 4242 :signals ["SIGTERM" "SIGKILL"]} nil)] + (await + (mock/with-mocks* + {process/run (fn [_] (js/Promise.reject failure))} + (let [cause (try + (await (build/git-provenance (frontend-root) {:deadline (process/deadline 1000)})) + nil + (catch :default cause cause))] + (t/is (errors/fatal? cause)) + (t/is (process/unresolved? cause))))))) + (t/deftest nonzero-renderer-retains-created-evidence-output-and-failed-manifest (t/async done (complete diff --git a/frontend/test/performance_tests/render_wasm/cli_integration.cjs b/frontend/test/performance_tests/render_wasm/cli_integration.cjs index 6c8f7d0106..149180eadf 100644 --- a/frontend/test/performance_tests/render_wasm/cli_integration.cjs +++ b/frontend/test/performance_tests/render_wasm/cli_integration.cjs @@ -28,7 +28,7 @@ // The normal unit test build does not build this CLI. const assert = require("node:assert/strict"); -const { execFile, spawn } = require("node:child_process"); +const { execFile, spawn, spawnSync } = require("node:child_process"); const { once } = require("node:events"); const { setTimeout: pause } = require("node:timers/promises"); const { randomUUID } = require("node:crypto"); @@ -437,6 +437,99 @@ fs.writeFileSync(path.join(process.env.RENDER_BENCH_BROWSER_DIR, 'browser.js'), fixture.env.PATH = `${bin}${path.delimiter}${process.env.PATH}`; } + +test("unresolved compiler ownership exits while retaining its build and lock", testOptions, async (t) => { + for (const [command, interrupt] of [["build", null], ["run", "SIGINT"], ["ab", "SIGTERM"]]) { + const fixture = createFrontend(t); + if (command === "ab") installCargoMetadata(fixture, { default: [], a: [] }); + const groupFile = path.join(fixture.managed, "compiler-group.pid"); + const signalsFile = path.join(fixture.managed, "termination-signals.log"); + const lockFile = path.join(fixture.rendererRoot, "compiler.lock"); + const guard = path.join(fixture.managed, "unresolved-process.cjs"); + fs.writeFileSync(fixture.compiler, `#!/usr/bin/env node +const fs = require("node:fs"); +const path = require("node:path"); +const { spawn } = require("node:child_process"); +fs.writeFileSync(path.join(process.env.FRONTEND_DEST, "partial.js"), "retained compiler output"); +const worker = spawn("flock", ["--exclusive", ${JSON.stringify(lockFile)}, process.execPath, "-e", + "process.stdout.write('compiler ready'); setInterval(() => {}, 1000);"], { stdio: "inherit" }); +worker.on("exit", (code) => { process.exitCode = code; }); +`, { mode: 0o755 }); + fs.writeFileSync(guard, ` +const fs = require("node:fs"); +const cp = require("node:child_process"); +const spawn = cp.spawn; +const kill = process.kill; +const interrupt = ${JSON.stringify(interrupt)}; +let group; +cp.spawn = function (command, ...args) { + const child = spawn.call(this, command, ...args); + if (command === ${JSON.stringify(fixture.compiler)} && child.pid) { + group = child.pid; + fs.writeFileSync(${JSON.stringify(groupFile)}, String(group)); + if (interrupt) child.stdout.once("data", () => process.kill(process.pid, interrupt)); + } + return child; +}; +process.kill = function (pid, signal) { + if (pid === -group && ["SIGTERM", "SIGKILL"].includes(signal)) { + fs.appendFileSync(${JSON.stringify(signalsFile)}, signal + "\\n"); + return true; + } + return kill.apply(this, arguments); +}; +require("node:module").syncBuiltinESMExports(); +`); + fixture.nodeArgs = ["--require", guard]; + const args = command === "ab" ? ["ab", "--features", "a", "--filter", "rects/load"] : [command]; + if (!interrupt) args.push("--build-timeout-ms", "1000"); + if (command === "run") args.push("--remove"); + args.push("--no-color"); + try { + const result = await runCli(fixture, args); + assert.equal(result.exitCode, interrupt === "SIGINT" ? 130 : interrupt === "SIGTERM" ? 143 : 1, result.stderr); + assert.match(result.stderr, /unresolved/); + assert.match(result.stderr, /pgid/); + assert.ok(result.stderr.includes(fixture.compiler), result.stderr); + assert.deepEqual(fs.readFileSync(signalsFile, "utf8").trim().split("\n"), ["SIGTERM", "SIGKILL"]); + const group = Number(fs.readFileSync(groupFile, "utf8")); + assert.ok(process.kill(group, 0)); + assert.equal(spawnSync("flock", ["--nonblock", lockFile, "true"], { timeout: 1000 }).status, 1); + const ids = fs.readdirSync(fixture.builds); + assert.equal(ids.length, 1); + const directory = path.join(fixture.builds, ids[0]); + const manifest = readManifest(path.join(directory, "build.transit")); + assert.equal(manifest.get(transit.keyword("status")).toString(), ":failed"); + assert.equal(manifest.get(transit.keyword("failure")).get(transit.keyword("unresolved-process")), true); + assert.equal(fs.readFileSync(path.join(directory, "renderer", "partial.js"), "utf8"), "retained compiler output"); + if (command === "ab") { + const k = transit.keyword; + const [id] = fs.readdirSync(fixture.comparisons); + const comparison = readManifest(path.join(fixture.comparisons, id, "feature-comparison.transit")); + assert.equal(comparison.get(k("status")).toString(), ":interrupted"); + assert.deepEqual(comparison.get(k("configurations")).map((entry) => entry.get(k("status")).toString()), + [":failed", ":unattempted"]); + assert.deepEqual(comparison.get(k("edges")).map((entry) => entry.get(k("status")).toString()), [":unattempted"]); + } + } finally { + if (fs.existsSync(groupFile)) { + const group = Number(fs.readFileSync(groupFile, "utf8")); + assert.ok(Number.isSafeInteger(group) && group > 0); + try { + process.kill(-group, "SIGKILL"); + } catch (error) { + if (error.code !== "ESRCH") throw error; + } + const deadline = Date.now() + 3000; + while (spawnSync("flock", ["--nonblock", lockFile, "true"], { timeout: 1000 }).status === 1) { + assert.ok(Date.now() < deadline, "Owned fixture lock did not release"); + await pause(10); + } + } + } + } +}); + function runFixtureText({ runId, caseId, diff --git a/frontend/test/performance_tests/render_wasm/execution_test.cljs b/frontend/test/performance_tests/render_wasm/execution_test.cljs index b0bd7c0bcb..a2e65445c1 100644 --- a/frontend/test/performance_tests/render_wasm/execution_test.cljs +++ b/frontend/test/performance_tests/render_wasm/execution_test.cljs @@ -188,13 +188,16 @@ (if (nil? old) (js-delete env "PENPOT_GPU") (set! (.-PENPOT_GPU env) old)))))) (t/deftest ^:async thrown-and-rejected-failures-use-checked-console-and-release-listeners - (doseq [handler [(fn [_ _] (throw (js/Error. "failed work"))) - (^:async fn [_ _] - (await (timers/setTimeout 1)) - (throw (js/Error. "failed work"))) - (^:async fn [_ _] - (await (timers/setTimeout 1)) - (throw (errors/fatal-error "failed work" {} (js/Error. "storage"))))]] + (doseq [[handler expected] [[(fn [_ _] (throw (js/Error. "failed work"))) + "✖ failed work\n"] + [(^:async fn [_ _] + (await (timers/setTimeout 1)) + (throw (js/Error. "failed work"))) + "✖ failed work\n"] + [(^:async fn [_ _] + (await (timers/setTimeout 1)) + (throw (errors/fatal-error "failed work" {} (js/Error. "storage")))) + "✖ failed work\n fatal true\n"]]] (let [local (capture) before (listeners) request (assoc (resolved "help" {:topic nil}) :console {:level :warn :color :never})] @@ -202,7 +205,7 @@ request {"help" (fn [context options] (log/info "hidden progress") (handler context options))} local)))) - (t/is (= "✖ failed work\n" @(:errors local))) + (t/is (= expected @(:errors local))) (t/is (= before (listeners)))))) (t/deftest ^:async final-publication-uses-the-outcomes-log-and-numeric-status @@ -281,7 +284,7 @@ {"help" handler} local))))) (t/is (= "partial evidence" (fs/readFileSync file "utf8"))) (t/is (= "partial report\n" @(:output local))) - (t/is (= "✖ fatal storage\n" @(:errors local))) + (t/is (= "✖ fatal storage\n fatal true\n" @(:errors local))) (t/is (= before (listeners)))))) (t/deftest failure-adapters-preserve-usage-validation-and-decoder-diagnostics diff --git a/frontend/test/performance_tests/render_wasm/feature_comparison_test.cljs b/frontend/test/performance_tests/render_wasm/feature_comparison_test.cljs index 3882fbb93e..67bb5aff2d 100644 --- a/frontend/test/performance_tests/render_wasm/feature_comparison_test.cljs +++ b/frontend/test/performance_tests/render_wasm/feature_comparison_test.cljs @@ -789,6 +789,93 @@ (when (not= :terminal point) (t/is (= 1 (count (filter #(= "interrupted operation failed" (:message %)) (:errors evidence)))))))))))) + +(t/deftest ^:async unresolved-run-stops-the-feature-matrix + (create-frontend-root) + (let [prepared (comparison-prepared ["a"]) + execute (execute-service {}) + failure (errors/fatal-error "Command group may still be running" + {:type :process-unresolved :unresolved-process true + :pid 4242 :pgid 4242 :signals ["SIGTERM" "SIGKILL"]} nil) + response (await (feature-comparison/execute + (frontend-root) prepared nil + {:services (comparison-services + {:prepare-build (build-service {}) + :execute-run (fn [& args] + (.then (apply execute args) + #(assoc % :exit-code 1 :errors [failure])))})})) + saved (saved-comparison response)] + (t/is (= 1 (:exit-code response))) + (t/is (some process/unresolved? (:errors response))) + (t/is (= [:failed :unattempted] (mapv :status (:configurations saved)))) + (t/is (= [:unattempted] (mapv :status (:edges saved)))))) + + +(t/deftest ^:async unresolved-build-finishes-the-feature-matrix + (create-frontend-root) + (doseq [signal [nil "SIGTERM"]] + (let [prepared (comparison-prepared ["a"] {:output-dir (path/join @temporary-root (str "unresolved-build-" signal))}) + controller (js/AbortController.) + prepare (build-service {}) + failure (errors/fatal-error "Compiler group may still be running" + {:type :process-unresolved :unresolved-process true + :pid 4242 :pgid 4242 :signals ["SIGTERM" "SIGKILL"]} nil) + response (await (feature-comparison/execute + (frontend-root) prepared (.-signal controller) + {:services (comparison-services + {:prepare-build (fn [request] + (.then (prepare request) + (fn [_] + (when signal (.abort controller signal)) + (throw failure)))) + :execute-run (execute-service {})})})) + saved (saved-comparison response)] + (t/is (= (if signal 143 1) (:exit-code response))) + (t/is (= (if signal :interrupted :failed) (:status saved))) + (t/is (= [:failed :unattempted] (mapv :status (:configurations saved)))) + (t/is (= [:unattempted] (mapv :status (:edges saved)))) + (t/is (true? (get-in saved [:configurations 0 :failure :unresolved-process]))) + (t/is (some process/unresolved? (:errors response))) + (t/is (= (:comparison response) saved))))) + +(t/deftest ^:async unresolved-build-and-failed-comparison-save-retain-both-errors + (create-frontend-root) + (doseq [signal [nil "SIGTERM"]] + (let [prepared (comparison-prepared ["a"] {:output-dir (path/join @temporary-root (str "unresolved-save-" signal))}) + controller (js/AbortController.) + write feature-comparison/write-record + prepare (build-service {}) + failure (errors/fatal-error "Compiler group may still be running" + {:type :process-unresolved :unresolved-process true + :pid 4242 :pgid 4242 :signals ["SIGTERM" "SIGKILL"]} nil) + save-error (js/Error. "comparison save failed")] + (await + (mock/with-mocks* + {feature-comparison/write-record + (fn [home record] + (if (= :failed (get-in record [:configurations 0 :status])) + (throw save-error) + (write home record)))} + (let [response (await (feature-comparison/execute + (frontend-root) prepared (.-signal controller) + {:services (comparison-services + {:prepare-build (fn [request] + (.then (prepare request) + (fn [_] + (when signal (.abort controller signal)) + (throw failure)))) + :execute-run (execute-service {})})})) + evidence (errors/evidence :comparison (first (:errors response)))] + (t/is (= (if signal 143 1) (:exit-code response))) + (t/is (= :running (get-in response [:comparison :status]))) + (t/is (= (:comparison response) (saved-comparison response))) + (t/is (some process/unresolved? (:errors response))) + (t/is (= ["Compiler group may still be running" "cannot persist feature comparison"] + (mapv :message (:errors evidence)))) + (t/is (= 4242 (get-in evidence [:errors 0 :pgid]))) + (t/is (some #(= "comparison save failed" (:message %)) + (get-in evidence [:errors 1 :cause]))))))))) + (t/deftest ^:async edge-report-storage-failure-preserves-failed-and-unattempted-edges (create-frontend-root) (let [prepared (comparison-prepared ["a" "b"]) diff --git a/frontend/test/performance_tests/render_wasm/process_test.cljs b/frontend/test/performance_tests/render_wasm/process_test.cljs index a3a253cb50..65862e7bb8 100644 --- a/frontend/test/performance_tests/render_wasm/process_test.cljs +++ b/frontend/test/performance_tests/render_wasm/process_test.cljs @@ -7,9 +7,13 @@ (ns performance-tests.render-wasm.process-test "Real Node/POSIX processes, files and Linux flock ownership." (:require + ["child_process" :as child-process] ["fs" :as fs] + ["node:module" :as node-module] ["os" :as os] ["path" :as path] + [app.common.transit :as transit] + [benches.render-wasm.errors :as errors] [benches.render-wasm.node.process :as process] [cljs.test :as t :include-macros true] [clojure.string :as str])) @@ -27,17 +31,69 @@ (defn- within "A broken lifecycle must fail the test rather than stall the test runner." - [promise] - (let [timer (volatile! nil)] - (-> (js/Promise.race - #js [promise - (js/Promise. - (fn [_ reject] - (vreset! timer - (js/setTimeout - #(reject (ex-info "Process test stalled" {:type :test-watchdog})) - 5000))))]) - (.finally #(js/clearTimeout @timer))))) + ([promise] (within promise 5000)) + ([promise timeout-ms] + (let [timer (volatile! nil)] + (-> (js/Promise.race + #js [promise + (js/Promise. + (fn [_ reject] + (vreset! timer + (js/setTimeout + #(reject (ex-info "Process test stalled" {:type :test-watchdog})) + timeout-ms))))]) + (.finally #(js/clearTimeout @timer)))))) + +(defn- ^:async with-live-group + [faults f] + (let [^js native-fs ((node-module/createRequire (path/join (.cwd js/process) "package.json")) "fs") + kill (.-kill js/process) + read-dir (.-readdirSync native-fs) + read-file (.-readFileSync native-fs) + group (atom nil) + signals (atom []) + probed (atom false) + fake-pid "2147483646"] + (set! (.-kill js/process) + (fn [pid signal] + (if (neg? pid) + (do + (reset! group (- pid)) + (when-not (:keep-child faults) + (try + (.call kill js/process pid signal) + (catch :default cause + (when-not (= "ESRCH" (.-code cause)) (throw cause))))) + (when (string? signal) + (swap! signals conj {:signal signal :time-ms (js/Date.now)})) + (when-let [cause (get faults signal)] (throw cause)) + true) + (.call kill js/process pid signal)))) + (set! (.-readdirSync native-fs) + (fn [location & args] + (if (and (= "/proc" location) @group) + (if (and (:probe faults) (compare-and-set! probed false true)) + (throw (:probe faults)) + (.concat (apply read-dir location args) #js [fake-pid])) + (apply read-dir location args)))) + (set! (.-readFileSync native-fs) + (fn [location & args] + (if (and @group (= location (str "/proc/" fake-pid "/stat"))) + (str fake-pid " (unresolved) S 0 " @group " " @group " 0") + (apply read-file location args)))) + (node-module/syncBuiltinESMExports) + (try + (await (f signals)) + (finally + (when (and (:keep-child faults) @group) + (try + (.call kill js/process (- @group) "SIGKILL") + (catch :default cause + (when-not (= "ESRCH" (.-code cause)) (throw cause))))) + (set! (.-kill js/process) kill) + (set! (.-readdirSync native-fs) read-dir) + (set! (.-readFileSync native-fs) read-file) + (node-module/syncBuiltinESMExports))))) (defn- ^:async wait-for [pred] @@ -125,6 +181,97 @@ :termination-grace-ms test-grace-ms} overrides)) +(t/deftest ^:async unresolved-group-termination-is-bounded-and-fatal + (await + (with-live-group + {} + (^:async fn [signals] + (let [started (js/Date.now) + cause (try + (await (within (process/run (node-options "process.exit(0);" {:termination-grace-ms 20})) 8000)) + nil + (catch :default cause cause)) + data (ex-data cause)] + (t/is (errors/fatal? cause)) + (t/is (= :process-unresolved (:type data))) + (t/is (= (.-execPath js/process) (:command data))) + (t/is (integer? (:pid data))) + (t/is (= (:pid data) (:pgid data))) + (t/is (= ["SIGTERM" "SIGKILL"] (:signals data))) + (t/is (= ["SIGTERM" "SIGKILL"] (mapv :signal @signals))) + (let [killed-at (some #(when (= "SIGKILL" (:signal %)) (:time-ms %)) @signals)] + (t/is (and (number? killed-at) (>= (- (js/Date.now) killed-at) 5000)))) + (t/is (< (- (js/Date.now) started) 8000)) + (t/is (not (running? (read-pid "root.pid"))))))))) + + +(t/deftest ^:async unresolved-owner-retains-a-live-lock-and-all-failures + (let [lock-file (file "unresolved.lock") + messages ["output handler failed" "TERM denied" "probe unavailable" "KILL denied"]] + (await + (with-live-group + {"SIGTERM" (js/Error. (nth messages 1)) + :probe (js/Error. (nth messages 2)) + "SIGKILL" (js/Error. (nth messages 3)) + :keep-child true} + (^:async fn [signals] + (let [options (node-options "" + {:command "flock" + :args ["--exclusive" lock-file (.-execPath js/process) "-e" + (node-source "root.pid" "process.stdout.write('ready'); setInterval(() => {}, 1000);")] + :deadline (process/deadline 30000) + :termination-grace-ms 20 + :on-output (fn [& _] (throw (js/Error. (first messages))))}) + cause (try + (await (within (process/run options) 8000)) + nil + (catch :default cause cause)) + entries (errors/get-errors cause) + wire (-> (errors/evidence :process cause) transit/encode-str transit/decode-str)] + (t/is (process/unresolved? cause)) + (t/is (errors/fatal? cause)) + (t/is (= [:process-output :process-signal :process-probe :process-signal :process-unresolved] + (mapv #(-> % :error ex-data :type) entries))) + (doseq [[entry message] (map vector (:errors wire) messages)] + (t/is (some #(= message (:message %)) (:cause entry)))) + (t/is (true? (:unresolved-process wire))) + (t/is (true? (:fatal wire))) + (t/is (= ["SIGTERM" "SIGKILL"] (mapv :signal @signals))) + (t/is (running? (read-pid "root.pid"))) + (t/is (= 1 (.-status (child-process/spawnSync "flock" #js ["--nonblock" lock-file "true"] + #js {:timeout 1000})))))))) + (await (wait-for #(zero? (.-status (child-process/spawnSync "flock" #js ["--nonblock" lock-file "true"] + #js {:timeout 1000}))))))) + + +(t/deftest ^:async input-stream-errors-have-one-occurrence-each-with-line-output + (let [^js native ((node-module/createRequire (path/join (.cwd js/process) "package.json")) "child_process") + spawn (.-spawn native)] + (set! (.-spawn native) + (fn [& args] + (let [^js child (apply spawn args)] + (.once (.-stdout child) "data" + (fn [_] + (.emit (.-stdout child) "error" (js/Error. "first read failed")) + (.emit (.-stdout child) "error" (js/Error. "second read failed")))) + child))) + (node-module/syncBuiltinESMExports) + (try + (let [cause (try + (await (within (process/run + (node-options "process.stdout.write('ready'); setInterval(() => {}, 1000);" + {:on-line (fn [& _] nil)})))) + nil + (catch :default cause cause)) + wire (errors/evidence :process cause)] + (t/is (= [:process-output :process-output] + (mapv #(-> % :error ex-data :type) (errors/get-errors cause)))) + (doseq [[entry message] (map vector (:errors wire) ["first read failed" "second read failed"])] + (t/is (some #(= message (:message %)) (:cause entry))))) + (finally + (set! (.-spawn native) spawn) + (node-module/syncBuiltinESMExports))))) + (defn- ^:async rejected [promise] (try @@ -356,6 +503,20 @@ (t/is (not= (:runner @groups) (:root @groups)) "the group is separate from the runner") (await (assert-tree-stopped)))) + +(t/deftest ^:async default-cancellation-produces-portable-error-evidence + (let [controller (js/AbortController.) + cause (try + (await (within (process/run + (node-options "process.stdout.write('ready'); setInterval(() => {}, 1000);" + {:signal (.-signal controller) + :on-output (fn [& _] (.abort controller))})))) + nil + (catch :default cause cause)) + evidence (errors/evidence :process cause)] + (t/is (= :process-cancelled (:type (ex-data cause)))) + (t/is (= evidence (-> evidence transit/encode-str transit/decode-str))))) + (t/deftest ^:async output-callback-failure-cleans-the-owned-group (doseq [callback [:on-output :on-line]] (let [seen (atom "") diff --git a/frontend/test/performance_tests/render_wasm/report_test.cljs b/frontend/test/performance_tests/render_wasm/report_test.cljs index 9559d83dc9..48cda88851 100644 --- a/frontend/test/performance_tests/render_wasm/report_test.cljs +++ b/frontend/test/performance_tests/render_wasm/report_test.cljs @@ -7,6 +7,7 @@ (ns performance-tests.render-wasm.report-test (:require [app.common.transit :as transit] + [benches.render-wasm.errors :as errors] [benches.render-wasm.measurement :as measurement] [benches.render-wasm.report.analysis :as method] [benches.render-wasm.report.compare :as compare] @@ -348,6 +349,25 @@ (t/is (str/includes? text "Path \"scene.transit\"")) (t/is (str/includes? text ":serialize-shapes \"upload\"")))) +(t/deftest unresolved-process-details-survive-the-report-entry-limit + (let [failure (errors/evidence + :cleanup + (errors/combine + (conj (mapv (fn [index] {:phase "cleanup" :error (js/Error. (str "cleanup " index))}) + (range 8)) + {:phase "cleanup" :operation :stop-process + :error (errors/fatal-error "Compiler group may still be running" + {:unresolved-process true :pid 4242 :pgid 4242 + :signals ["SIGTERM" "SIGKILL"]} nil)}))) + run (-> (new-run 0 1 :fresh) + (result/finish-run "end" {:reason :failed :failure failure}) + result/encode result/decode) + text (format/format-run (summary/summarize run))] + (t/is (str/includes? text "pgid 4242")) + (t/is (str/includes? text "SIGKILL")) + (t/is (str/includes? text "unresolved-process true")) + (t/is (str/includes? text "1 more errors recorded")))) + (t/deftest equal-diagnostics-keep-failures-from-distinct-preparations (let [failure {:phase "renderer" :message "shared renderer failure"}] (doseq [phases [[] diff --git a/frontend/test/performance_tests/render_wasm/run_test.cljs b/frontend/test/performance_tests/render_wasm/run_test.cljs index 5473375ceb..ee71a21f8f 100644 --- a/frontend/test/performance_tests/render_wasm/run_test.cljs +++ b/frontend/test/performance_tests/render_wasm/run_test.cljs @@ -15,6 +15,7 @@ [benches.render-wasm.node.cli.deferred :as deferred] [benches.render-wasm.node.cli.request :as request] [benches.render-wasm.node.log :as log] + [benches.render-wasm.node.process :as process] [benches.render-wasm.node.runner.browser :as browser] [benches.render-wasm.node.runner.feature-comparison :as feature-comparison] [benches.render-wasm.node.runner.run :as run] @@ -1251,6 +1252,43 @@ (t/is (= :completed (get-in result [:run :termination :reason]))) (t/is (zero? (:exit-code result))))) + +(t/deftest ^:async unresolved-failure-retains-build-and-earlier-results-on-interruption + (doseq [signal [nil "SIGINT" "SIGTERM"]] + (let [root @temporary-root + id (str "unresolved-" (or signal "failure")) + dir (path/join (artifacts/managed-root root) "builds" id) + index (path/join dir "index.html") + controller (js/AbortController.) + failure (errors/fatal-error "Command group may still be running" + {:type :process-unresolved :unresolved-process true + :pid 4242 :pgid 4242 :signals ["SIGTERM" "SIGKILL"]} nil) + base (fake-browser {}) + prepare (get-in base [:service :prepare]) + fake (assoc-in base [:service :prepare] + (fn [page request bounds] + (if (= :case/b (get-in (transit/decode-str request) [:case :id])) + (do + (when signal (.abort controller signal)) + (throw failure)) + (prepare page request bounds)))) + out (path/join root id) + home (runs/create-home {:root root :run-id id :output-dir out :remove true})] + (fs/mkdirSync dir #js {:recursive true}) + (fs/writeFileSync index "retained renderer") + (let [response (await (run/execute root home (selected-build dir id) + [(collected :case/a :reuse) (collected :case/b :reuse) (collected :case/c :reuse)] + (assoc (options fake out) :remove true) (.-signal controller))) + saved (saved-record response)] + (t/is (= (case signal "SIGINT" 130 "SIGTERM" 143 1) (:exit-code response))) + (t/is (some process/unresolved? (:errors response))) + (t/is (= [:completed] (mapv :outcome (attempts-for saved :case/a)))) + (t/is (= 1 (get-in saved [:remaining :case/c :repetitions]))) + (t/is (str/includes? (:report response) "pgid 4242")) + (t/is (str/includes? (:report response) "SIGKILL")) + (t/is (= "retained renderer" (when (fs/existsSync index) (fs/readFileSync index "utf8")))) + (t/is (false? (.-listening ^js (get-in @(:state fake) [:host :server])))))))) + (t/deftest ^:async failed-final-record-write-retains-the-selected-build (let [root @temporary-root id "retained-after-write-failure"