Update

lib/ex_cmd/process.ex

@@ -577,6 +577,7 @@ defmodule ExCmd.Process do
 
   @impl true
   def handle_cast({:prepare_exit, caller, timeout}, state) do
+    Logger.debug("prepare_exit: #{timeout}")
     state = close_pipes(state, caller)
 
     case maybe_shutdown(state) do
@@ -660,6 +661,8 @@ defmodule ExCmd.Process do
         {:exit_sequence, current_stage, timeout, kill_timeout},
         %{status: status} = state
       ) do
+    Logger.debug("exit_sequence, #{current_stage} #{timeout} #{kill_timeout}, #{inspect(state)}")
+
     cond do
       status != :running ->
         {:noreply, state}
@@ -691,6 +694,8 @@ defmodule ExCmd.Process do
   end
 
   def handle_info({port, {:exit_status, odu_exit_status}}, %{port: port} = state) do
+    Logger.debug("port exit with status #{odu_exit_status} state: #{inspect(state)}")
+
     state =
       cond do
         odu_exit_status != 0 ->
@@ -712,6 +717,8 @@ defmodule ExCmd.Process do
 
   # we are only interested in Port exit signals
   def handle_info({:EXIT, port, reason}, %State{port: port} = state) when reason != :normal do
+    Logger.debug("port exit with error state: #{inspect(state)}")
+
     state =
       state
       |> cancel_pending_actions()
@@ -721,6 +728,7 @@ defmodule ExCmd.Process do
   end
 
   def handle_info({:EXIT, port, :normal}, %State{port: port} = state) do
+    Logger.debug("port exit normally state: #{inspect(state)}")
     maybe_shutdown(state)
   end
 
@@ -731,22 +739,27 @@ defmodule ExCmd.Process do
         {:DOWN, owner_ref, :process, _pid, reason},
         %State{monitor_ref: owner_ref} = state
       ) do
+    Logger.debug("process owner exit: state: #{inspect(state)}")
     {:stop, reason, state}
   end
 
   def handle_info({:DOWN, _ref, :process, pid, _reason}, state) do
+    Logger.debug("pipe owner exit: state: #{inspect(state)}")
     state = close_pipes(state, pid)
     maybe_shutdown(state)
   end
 
   @spec maybe_shutdown(State.t()) :: {:stop, :normal, State.t()} | {:noreply, State.t()}
   defp maybe_shutdown(state) do
+    Logger.debug("maybe_shutdown: state: #{inspect(state)}")
+
     open_pipes_count =
       state.pipes
       |> Map.values()
       |> Enum.count(&Pipe.open?/1)
 
     if open_pipes_count == 0 && !(state.status in [:init, :running]) do
+      Logger.debug("shutting down state: #{inspect(state)}")
       {:stop, :normal, state}
     else
       {:noreply, state}

test/ex_cmd/process_test.exs

@@ -20,6 +20,8 @@ defmodule ExCmd.ProcessTest do
 
       assert {:ok, 0} == Process.await_exit(s, 500)
 
+      # wait for the process to terminate
+      :timer.sleep(100)
       refute Elixir.Process.alive?(s.pid)
     end
 
@@ -39,6 +41,7 @@ defmodule ExCmd.ProcessTest do
 
       assert {:ok, 0} == Process.await_exit(s, 200)
 
+      # wait for the process to terminate
       :timer.sleep(100)
       refute Elixir.Process.alive?(s.pid)
     end

test/test_helper.exs

@@ -8,5 +8,5 @@
     end
   )
 
-Logger.configure(level: :warning)
-ExUnit.start(capture_log: true)
+Logger.configure(level: :debug)
+ExUnit.start(capture_log: false)