sensor: Too fast lifecycle hook handlers cause false positive error c…

…onditions (#463)

exec.Command().Run() and its derivatives are prone to a race condition
between the underlying cmd.Start() + cmd.Wait() calls and the actual
child process execution. Too fast commands can cause the Wait() call
being called when the child process is already gone. This makes the
Run() method to return an error. This PR makes sensor ignore such
errors.

pkg/app/sensor/execution/hook.go

@@ -4,6 +4,7 @@ import (
 	"context"
 	"os/exec"
 
+	"github.com/docker-slim/docker-slim/pkg/util/errutil"
 	log "github.com/sirupsen/logrus"
 )
 
@@ -49,16 +50,17 @@ func (h *hookExecutor) doHook(k kind) {
 
 	cmd := exec.CommandContext(h.ctx, h.cmd, string(k))
 	out, err := cmd.CombinedOutput()
-	if err == nil {
-		log.
-			WithField("kind", k).
-			WithField("output", string(out)).
-			Info("lifecycle hook command succeeded")
+
+	logger := log.
+		WithField("kind", k).
+		WithField("command", h.cmd).
+		WithField("exit_code", cmd.ProcessState.ExitCode()).
+		WithField("output", string(out))
+
+	// Some lifecycle hooks are really fast - hence, the IsNoChildProcesses() check.
+	if err == nil || errutil.IsNoChildProcesses(err) {
+		logger.Info("lifecycle hook command succeeded")
 	} else {
-		log.
-			WithError(err).
-			WithField("kind", k).
-			WithField("output", string(out)).
-			Info("lifecycle hook command failed")
+		logger.WithError(err).Info("lifecycle hook command failed")
 	}
 }

pkg/util/errutil/errutil.go

@@ -3,6 +3,7 @@ package errutil
 import (
 	"fmt"
 	"runtime/debug"
+	"strings"
 
 	log "github.com/sirupsen/logrus"
 
@@ -80,3 +81,20 @@ func showCommunityInfo() {
 	fmt.Printf("docker-slim: message='join the Discord server to get help with this failure' info='%s'\n", consts.CommunityDiscord)
 	fmt.Printf("docker-slim: message='Github discussions' info='%s'\n", consts.CommunityDiscussions)
 }
+
+// exec.Command().Run() and its derivatives sometimes return
+// "wait: no child processes" or "waitid: no child processes"
+// even for successful runs. It's a race condition between the
+// Start() + Wait() calls and the actual underlying command
+// execution. The shorter the execution time, the higher are
+// the chances to get this error.
+//
+// Some examples from the wild:
+//  - https://github.com/gitpod-io/gitpod/blob/405d44b74b5ac1dffe20e076d59c2b5986f18960/components/common-go/process/process.go#L18.
+func IsNoChildProcesses(err error) bool {
+	if err == nil {
+		return false
+	}
+
+	return strings.HasSuffix(err.Error(), ": no child processes")
+}