Deflake enricher unit tests

There is a race between the for loop evaluating the line and the test
assertion. We now wait for a function call to happen and then assert
correctly the results of it.

Signed-off-by: Sascha Grunert <sgrunert@redhat.com>

internal/pkg/cli/runner/impl.go

@@ -21,6 +21,7 @@ package runner
 
 import (
 	"encoding/json"
+	"log"
 	"os"
 	"sync/atomic"
 
@@ -56,6 +57,7 @@ type impl interface {
 	ExtractAuditLine(string) (*types.AuditLine, error)
 	GetName(libseccomp.ScmpSyscall) (string, error)
 	PidLoad() uint32
+	Printf(format string, v ...any)
 }
 
 func (*defaultImpl) ReadFile(name string) ([]byte, error) {
@@ -113,3 +115,7 @@ func (*defaultImpl) GetName(s libseccomp.ScmpSyscall) (string, error) {
 func (*defaultImpl) PidLoad() uint32 {
 	return atomic.LoadUint32(&pid)
 }
+
+func (*defaultImpl) Printf(format string, v ...any) {
+	log.Printf(format, v...)
+}

internal/pkg/cli/runner/runner.go

@@ -167,7 +167,7 @@ func (r *Runner) printAuditLine(line *types.AuditLine) {
 }
 
 func (r *Runner) printSelinuxLine(line *types.AuditLine) {
-	log.Printf(
+	r.Printf(
 		"SELinux: perm: %s, scontext: %s, tcontext: %s, tclass: %s",
 		line.Perm, line.Scontext, line.Tcontext, line.Tclass,
 	)
@@ -180,11 +180,11 @@ func (r *Runner) printSeccompLine(line *types.AuditLine) {
 		return
 	}
 
-	log.Printf("Seccomp: %s (%d)", syscallName, line.SystemCallID)
+	r.Printf("Seccomp: %s (%d)", syscallName, line.SystemCallID)
 }
 
 func (r *Runner) printApparmorLine(line *types.AuditLine) {
-	log.Printf(
+	r.Printf(
 		"AppArmor: %s, operation: %s, profile: %s, name: %s, extra: %s",
 		line.Apparmor, line.Operation, line.Profile, line.Name, line.ExtraInfo,
 	)

internal/pkg/cli/runner/runner_test.go

@@ -22,6 +22,7 @@ package runner
 import (
 	"errors"
 	"testing"
+	"time"
 
 	"github.com/nxadm/tail"
 	"github.com/stretchr/testify/require"
@@ -137,6 +138,20 @@ func TestRun(t *testing.T) {
 	}
 }
 
+func waitForFunctionCall(t *testing.T, fn func() int) {
+	t.Helper()
+
+	countGreaterZero := false
+	for i := 0; i < 5; i++ {
+		if fn() > 0 {
+			countGreaterZero = true
+			break
+		}
+		time.Sleep(time.Second)
+	}
+	require.True(t, countGreaterZero)
+}
+
 func TestStartEnricher(t *testing.T) {
 	const testPid = 123
 
@@ -160,7 +175,9 @@ func TestStartEnricher(t *testing.T) {
 			},
 			assert: func(mock *runnerfakes.FakeImpl, lineChan chan *tail.Line) {
 				lineChan <- &tail.Line{}
-				require.Equal(t, 1, mock.GetNameCallCount())
+				waitForFunctionCall(t, mock.PrintfCallCount)
+				arg, _ := mock.PrintfArgsForCall(0)
+				require.Contains(t, arg, "Seccomp")
 			},
 		},
 		{
@@ -178,6 +195,8 @@ func TestStartEnricher(t *testing.T) {
 			},
 			assert: func(mock *runnerfakes.FakeImpl, lineChan chan *tail.Line) {
 				lineChan <- &tail.Line{}
+				waitForFunctionCall(t, mock.GetNameCallCount)
+				require.Zero(t, mock.PrintfCallCount())
 			},
 		},
 		{
@@ -194,6 +213,9 @@ func TestStartEnricher(t *testing.T) {
 			},
 			assert: func(mock *runnerfakes.FakeImpl, lineChan chan *tail.Line) {
 				lineChan <- &tail.Line{}
+				waitForFunctionCall(t, mock.PrintfCallCount)
+				arg, _ := mock.PrintfArgsForCall(0)
+				require.Contains(t, arg, "AppArmor")
 			},
 		},
 		{
@@ -210,6 +232,9 @@ func TestStartEnricher(t *testing.T) {
 			},
 			assert: func(mock *runnerfakes.FakeImpl, lineChan chan *tail.Line) {
 				lineChan <- &tail.Line{}
+				waitForFunctionCall(t, mock.PrintfCallCount)
+				arg, _ := mock.PrintfArgsForCall(0)
+				require.Contains(t, arg, "SELinux")
 			},
 		},
 		{