fix: action error masked by following successful action (#1841)

* fix action error being masked by following action

* Self-review

* Fix uninitialized out parameter

src/alire/alire-os_lib-subprocess.adb

@@ -164,6 +164,16 @@ package body Alire.OS_Lib.Subprocess is
         Understands_Verbose => Understands_Verbose,
         Err_To_Out          => Err_To_Out));
 
+   ---------------------
+   -- Unchecked_Spawn --
+   ---------------------
+
+   function Unchecked_Spawn
+     (Command             : String;
+      Arguments           : AAA.Strings.Vector;
+      Understands_Verbose : Boolean := False) return Integer
+   is (Spawn (Command, Arguments, Understands_Verbose));
+
    -----------
    -- Spawn --
    -----------

src/alire/alire-os_lib-subprocess.ads

@@ -35,4 +35,10 @@ package Alire.OS_Lib.Subprocess is
       Err_To_Out          : Boolean := False) return Integer;
    --  Returns the output and exit code of the spawned command
 
+   function Unchecked_Spawn
+     (Command             : String;
+      Arguments           : AAA.Strings.Vector;
+      Understands_Verbose : Boolean := False) return Integer;
+   --  Doesn't capture output but doesn't fail on error either
+
 end Alire.OS_Lib.Subprocess;

src/alire/alire-properties-actions-executor.adb

@@ -42,7 +42,7 @@ package body Alire.Properties.Actions.Executor is
          Flags.Post_Fetch (CWD).Mark_Done;
       end if;
    exception
-      when Checked_Error =>
+      when Action_Failed | Checked_Error =>
          raise;
       when E : others =>
          Log_Exception (E);
@@ -78,6 +78,8 @@ package body Alire.Properties.Actions.Executor is
 
       Exec : String renames Cmd.First_Element;
    begin
+      Code := 0;
+
       if Alire.OS_Lib.Locate_Exec_On_Path (Exec) = "" and then
         not GNAT.OS_Lib.Is_Executable_File (Exec)
       then
@@ -96,7 +98,7 @@ package body Alire.Properties.Actions.Executor is
             Understands_Verbose => False,
             Err_To_Out          => Err_To_Out);
       else
-         Subprocess.Checked_Spawn
+         Code := Subprocess.Unchecked_Spawn
            (Command             => Cmd.First_Element,
             Arguments           => Cmd.Tail,
             Understands_Verbose => False);
@@ -111,19 +113,26 @@ package body Alire.Properties.Actions.Executor is
                               Env     : Properties.Vector;
                               Moment  : Moments)
    is
-      Unused_Code   : Integer;
+      Code          : Integer  := 0;
       Unused_Output : AAA.Strings.Vector;
+      --  Those are checked in the call to Execute_Actions below
    begin
       Execute_Actions
         (Release    => Release,
          Env        => Env,
          Moment     => Moment,
          Capture    => False,
          Err_To_Out => False,
-         Code       => Unused_Code,
+         Code       => Code,
          Output     => Unused_Output);
+
+      if Code /= 0 then
+         raise Action_Failed with
+           "Action failed with exit code " & AAA.Strings.Trim (Code'Image);
+         --  Details already printed by Execute_Actions
+      end if;
    exception
-      when Checked_Error =>
+      when Action_Failed | Checked_Error =>
          raise;
       when E : others =>
          Log_Exception (E);
@@ -148,25 +157,67 @@ package body Alire.Properties.Actions.Executor is
       Output     : out AAA.Strings.Vector;
       Prefix     : AAA.Strings.Vector := AAA.Strings.Empty_Vector)
    is
+      use AAA.Strings;
       Now : Releases.Moment_Array := (others => False);
+      Count, Current : Natural;
    begin
       Now (Moment) := True; -- Cannot be done in the initialization
 
-      if not Release.On_Platform_Actions (Env, Now).Is_Empty then
+      Output.Clear;
+
+      if Release.On_Platform_Actions (Env, Now).Is_Empty then
+         Code := 0;
+         return;
+      else
          Put_Info ("Running " &
                      Utils.TTY.Name (TOML_Adapters.Tomify (Moment'Image))
                    & " actions for " & Release.Milestone.TTY_Image & "...");
       end if;
 
+      Count   := Natural (Release.On_Platform_Actions (Env, Now).Length);
+      Current := 0;
+
       for Act of Release.On_Platform_Actions (Env, Now) loop
-         Trace.Detail ("Running action: " & Act.Image
+         Current := Current + 1;
+         Code    := 0;
+
+         Trace.Detail ("Running action "
+                       & Trim (Current'Image) & "/" & Trim (Count'Image)
+                       & ": " & Act.Image
                        & " (cwd:" & Directories.Current & ")");
          Execute_Run (This       => Runners.Run (Act),
                       Capture    => Capture,
                       Err_To_Out => Err_To_Out,
                       Code       => Code,
                       Output     => Output,
                       Prefix     => Prefix);
+
+         if Code /= 0 then
+            if Capture then
+
+               --  This is at debug level because sometimes we want silent
+               --  failure (e.g. during `alr test`), so the final reporting
+               --  must be done upstream (by using code/output).
+
+               Trace.Debug ("Execution failed for action: " & Act.Image);
+               Trace.Debug ("Exit code: " & AAA.Strings.Trim (Code'Image));
+               if Output.Is_Empty then
+                  Trace.Debug
+                    ("Actions produced no output up to error occurrence");
+               else
+                  Trace.Debug ("Action output begin:");
+                  Trace.Debug (Output.Flatten (New_Line));
+                  Trace.Debug ("Action output end.");
+               end if;
+
+            else -- Don't capture
+               Trace.Warning ("Execution failed for action: " & Act.Image);
+               Trace.Warning ("Exit code: " & AAA.Strings.Trim (Code'Image));
+               Trace.Warning ("Action output not captured, check it above.");
+            end if;
+
+            return; -- With exit code /= 0
+         end if;
       end loop;
    end Execute_Actions;
 

src/alire/alire-properties-actions.ads

@@ -5,7 +5,7 @@ with Alire.TOML_Keys;
 package Alire.Properties.Actions with Preelaborate is
 
    Action_Failed : exception;
-   --  Raised by the action runner when an action fails
+   --  Raised by the action runner when action execution fails (exit code /= 0)
 
    type Moments is
      (

src/alire/alire-roots.adb

@@ -287,7 +287,8 @@ package body Alire.Roots is
 
       return True;
    exception
-      when Properties.Actions.Action_Failed | Build_Failed =>
+      when E : Properties.Actions.Action_Failed | Build_Failed =>
+         Log_Exception (E);
          return False;
    end Build;
 

src/alr/alr-commands-action.adb

@@ -135,6 +135,10 @@ package body Alr.Commands.Action is
                     (Rel,
                      Env     => Cmd.Root.Environment,
                      Moment  => Moment);
+               exception
+                  when Alire.Properties.Actions.Action_Failed =>
+                     Reportaise_Command_Failed
+                       ("An action exited with error");
                end;
             end if;
          end Run_Release;

src/alr/alr-commands-test.adb

@@ -37,6 +37,8 @@ package body Alr.Commands.Test is
    package Platform renames Alire.Platforms.Current;
    package Query    renames Alire.Solver;
 
+   Prefix : constant String := "[alr test] ";
+
    -----------------
    -- Check_Files --
    -----------------
@@ -190,7 +192,7 @@ package body Alr.Commands.Test is
                   --  release mode.
 
                   Output.Append_Line
-                    ("[alr test] Spawning default local test: "
+                    (Prefix & "Spawning default local test: "
                      & Command.Flatten);
 
                   Code := Unchecked_Spawn_And_Capture
@@ -216,7 +218,7 @@ package body Alr.Commands.Test is
                   --  Start with a standard crate retrieval
 
                   Output.Append_Line
-                    ("[alr test] Spawning retrieval for remote crate: "
+                    (Prefix & "Spawning retrieval for remote crate: "
                      & Command.Flatten);
 
                   Code := Unchecked_Spawn_And_Capture
@@ -251,7 +253,7 @@ package body Alr.Commands.Test is
                                  & "-gnatwn";
                   begin
                      Output.Append_Line
-                       ("[alr test] Spawning default test for remote crate: "
+                       (Prefix & "Spawning default test for remote crate: "
                         & Command.Flatten);
 
                      Code := Unchecked_Spawn_And_Capture
@@ -288,7 +290,7 @@ package body Alr.Commands.Test is
             -----------------
 
             procedure Custom_Test is
-               Exit_Code : Integer;
+               Exit_Code : Integer := 0;
                Alr_Custom_Cmd : constant Vector :=
                                   "alr"
                                   & Regular_Alr_Switches
@@ -324,7 +326,7 @@ package body Alr.Commands.Test is
                     with Unreferenced;
                begin
                   Alire.Properties.Actions.Executor.Execute_Actions
-                     (Release    => R,
+                    (Release    => R,
                      Env        => Platform.Properties,
                      Moment     => Alire.Properties.Actions.Test,
                      Capture    => True,
@@ -333,6 +335,9 @@ package body Alr.Commands.Test is
                      Output     => Output);
 
                   if Exit_Code /= 0 then
+                     Output.Append_Line
+                       (Prefix & "Test action exited with error code "
+                        & AAA.Strings.Trim (Exit_Code'Image));
                      raise Child_Failed;
                   end if;
                end;
@@ -378,13 +383,13 @@ package body Alr.Commands.Test is
             Trace.Detail ("Skipping already tested " & R.Milestone.Image);
          else
             begin
-               Output.Append ("[alr test] Testing " & R.Milestone.Image);
+               Output.Append (Prefix & "Testing " & R.Milestone.Image);
 
                --  Perform default or custom actions
                Test_Action;
 
                --  At this point the test ended successfully
-               Output.Append ("[alr test] Test completed SUCCESSFULLY");
+               Output.Append (Prefix & "Test completed SUCCESSFULLY");
 
                Reporters.End_Test (R, Testing.Pass, Clock - Start, Output);
                Trace.Detail (Output.Flatten (Newline));
@@ -400,7 +405,7 @@ package body Alr.Commands.Test is
                   Output.Append (Ada.Exceptions.Exception_Information (E));
                   Output.Append ("****** TRACE END");
 
-               when Child_Failed =>
+               when Child_Failed | Alire.Properties.Actions.Action_Failed =>
                   Reporters.End_Test (R, Testing.Fail, Clock - Start, Output);
                   Trace.Detail (Output.Flatten (Newline));
                   Some_Failed := True;

testsuite/tests/action/masked-error/test.py

@@ -0,0 +1,35 @@
+"""
+https://github.com/alire-project/alire/issues/1806
+Ensure that an error in an action is not masked by success in a following one.
+"""
+
+import os
+import uuid
+from drivers.alr import init_local_crate, run_alr, add_action
+from drivers.asserts import assert_substring
+
+
+def check_errors():
+    assert_substring("failed",
+                 run_alr("test", complain_on_error=False).out)
+    assert_substring("action exited with error",
+                    run_alr("action", "test", complain_on_error=False).out)
+
+
+init_local_crate()
+
+# Verify a successful action
+add_action("test", ["echo", "OK"])
+run_alr("test")
+
+# Verify a failing action both via `alr test` and `alr action`
+uuid = uuid.uuid4().hex
+assert not os.path.exists(uuid)
+add_action("test", ["ls", uuid])
+check_errors()
+
+# Verify that a subsequent successful action does not mask the error
+add_action("test", ["echo", "OK"])
+check_errors()
+
+print("SUCCESS")

testsuite/tests/action/masked-error/test.yaml

@@ -0,0 +1,4 @@
+driver: python-script
+build_mode: both
+indexes:
+    compiler_only_index: {}