fix: kill hook when the command is stuck (#2469)

cmd/hook.go

@@ -1,6 +1,7 @@
 package cmd
 
 import (
+	"bufio"
 	"context"
 	"errors"
 	"fmt"
@@ -10,6 +11,7 @@ import (
 	"time"
 
 	"github.com/go-acme/lego/v4/certificate"
+	"github.com/go-acme/lego/v4/log"
 )
 
 const (
@@ -32,20 +34,44 @@ func launchHook(hook string, timeout time.Duration, meta map[string]string) erro
 
 	parts := strings.Fields(hook)
 
-	cmdCtx := exec.CommandContext(ctxCmd, parts[0], parts[1:]...)
-	cmdCtx.Env = append(os.Environ(), metaToEnv(meta)...)
+	cmd := exec.CommandContext(ctxCmd, parts[0], parts[1:]...)
+	cmd.Env = append(os.Environ(), metaToEnv(meta)...)
 
-	output, err := cmdCtx.CombinedOutput()
+	stdout, err := cmd.StdoutPipe()
+	if err != nil {
+		return fmt.Errorf("create pipe: %w", err)
+	}
+
+	cmd.Stderr = cmd.Stdout
 
-	if len(output) > 0 {
-		fmt.Println(string(output))
+	err = cmd.Start()
+	if err != nil {
+		return fmt.Errorf("start command: %w", err)
 	}
 
-	if errors.Is(ctxCmd.Err(), context.DeadlineExceeded) {
-		return errors.New("hook timed out")
+	timer := time.AfterFunc(timeout, func() {
+		log.Println("hook timed out: killing command")
+		_ = cmd.Process.Kill()
+		_ = stdout.Close()
+	})
+
+	defer timer.Stop()
+
+	scanner := bufio.NewScanner(stdout)
+	for scanner.Scan() {
+		fmt.Println(scanner.Text())
+	}
+
+	err = cmd.Wait()
+	if err != nil {
+		if errors.Is(ctxCmd.Err(), context.DeadlineExceeded) {
+			return errors.New("hook timed out")
+		}
+
+		return fmt.Errorf("wait command: %w", err)
 	}
 
-	return err
+	return nil
 }
 
 func metaToEnv(meta map[string]string) []string {

cmd/hook_test.go

@@ -0,0 +1,56 @@
+package cmd
+
+import (
+	"runtime"
+	"testing"
+	"time"
+
+	"github.com/stretchr/testify/require"
+)
+
+func Test_launchHook_errors(t *testing.T) {
+	if runtime.GOOS == "windows" {
+		t.Skip("skipping test on Windows")
+	}
+
+	testCases := []struct {
+		desc     string
+		hook     string
+		timeout  time.Duration
+		expected string
+	}{
+		{
+			desc:     "kill the hook",
+			hook:     "sleep 5",
+			timeout:  1 * time.Second,
+			expected: "hook timed out",
+		},
+		{
+			desc:     "context timeout on Start",
+			hook:     "echo foo",
+			timeout:  1 * time.Nanosecond,
+			expected: "start command: context deadline exceeded",
+		},
+		{
+			desc:     "multiple short sleeps",
+			hook:     "./testdata/sleepy.sh",
+			timeout:  1 * time.Second,
+			expected: "hook timed out",
+		},
+		{
+			desc:     "long sleep",
+			hook:     "./testdata/sleeping_beauty.sh",
+			timeout:  1 * time.Second,
+			expected: "hook timed out",
+		},
+	}
+
+	for _, test := range testCases {
+		t.Run(test.desc, func(t *testing.T) {
+			t.Parallel()
+
+			err := launchHook(test.hook, test.timeout, map[string]string{})
+			require.EqualError(t, err, test.expected)
+		})
+	}
+}

cmd/testdata/sleeping_beauty.sh

@@ -0,0 +1,3 @@
+#!/bin/bash -e
+
+sleep 50

cmd/testdata/sleepy.sh

@@ -0,0 +1,7 @@
+#!/bin/bash -e
+
+for i in `seq 1 10`
+do
+  echo $i
+  sleep 0.2
+done