command: Fix log message verification

The root cause of the change is a flaky behaviour
of a couple of the tests in the command package.
The tests assume the first log message would be
the output of the bash script that is invoked.
But it happens that 'spawn token acquired' text
is the first message instead. The output depends
on the execution time as this message appears only
if token acquire operation takes more than 5 ms.
In any case the message from the script would be the
last in the log output that is why extractMessage
renamed to extractLastMessage and now returns the
last message found.

Closes: https://gitlab.com/gitlab-org/gitaly/-/issues/3980

1 files changed, 12 insertions, 6 deletions

diff --git a/internal/command/command_test.go b/internal/command/command_test.go
index 72be22895..4d73c54f1 100644
--- a/internal/command/command_test.go
+++ b/internal/command/command_test.go
@@ -281,7 +281,7 @@ func TestCommandStdErr(t *testing.T) {
 	require.Error(t, cmd.Wait())
 
 	assert.Empty(t, stdout.Bytes())
-	require.Equal(t, expectedMessage, extractMessage(stderr.String()))
+	require.Equal(t, expectedMessage, extractLastMessage(stderr.String()))
 }
 
 func TestCommandStdErrLargeOutput(t *testing.T) {
@@ -300,7 +300,7 @@ func TestCommandStdErrLargeOutput(t *testing.T) {
 	require.Error(t, cmd.Wait())
 
 	assert.Empty(t, stdout.Bytes())
-	msg := strings.ReplaceAll(extractMessage(stderr.String()), "\\n", "\n")
+	msg := strings.ReplaceAll(extractLastMessage(stderr.String()), "\\n", "\n")
 	require.LessOrEqual(t, len(msg), maxStderrBytes)
 }
 
@@ -320,7 +320,7 @@ func TestCommandStdErrBinaryNullBytes(t *testing.T) {
 	require.Error(t, cmd.Wait())
 
 	assert.Empty(t, stdout.Bytes())
-	msg := strings.SplitN(extractMessage(stderr.String()), "\\n", 2)[0]
+	msg := strings.SplitN(extractLastMessage(stderr.String()), "\\n", 2)[0]
 	require.Equal(t, strings.Repeat("\\x00", maxStderrLineLength), msg)
 }
 
@@ -359,13 +359,19 @@ func TestCommandStdErrMaxBytes(t *testing.T) {
 	require.Error(t, cmd.Wait())
 
 	assert.Empty(t, stdout.Bytes())
-	require.Equal(t, maxStderrBytes, len(strings.ReplaceAll(extractMessage(stderr.String()), "\\n", "\n")))
+	message := extractLastMessage(stderr.String())
+	require.Equal(t, maxStderrBytes, len(strings.ReplaceAll(message, "\\n", "\n")))
 }
 
 var logMsgRegex = regexp.MustCompile(`msg="(.+?)"`)
 
-func extractMessage(logMessage string) string {
-	subMatches := logMsgRegex.FindStringSubmatch(logMessage)
+func extractLastMessage(logMessage string) string {
+	subMatchesAll := logMsgRegex.FindAllStringSubmatch(logMessage, -1)
+	if len(subMatchesAll) < 1 {
+		return ""
+	}
+
+	subMatches := subMatchesAll[len(subMatchesAll)-1]
 	if len(subMatches) != 2 {
 		return ""
 	}