Merge branch 'sh-fix-logrus-race' into 'master'

Fix race conditions with logrus testing

Closes #450

See merge request gitlab-org/gitlab-shell!385

4 files changed, 25 insertions, 0 deletions

diff --git a/client/client_test.go b/client/client_test.go
index 5e852dc..5c5fda8 100644
--- a/client/client_test.go
+++ b/client/client_test.go
@@ -123,6 +123,7 @@ func testSuccessfulGet(t *testing.T, client *GitlabNetClient) {
 		assert.NoError(t, err)
 		assert.Equal(t, string(responseBody), "Hello")
 
+		require.True(t, testhelper.WaitForLogEvent(hook))
 		entries := hook.AllEntries()
 		assert.Equal(t, 1, len(entries))
 		assert.Equal(t, logrus.InfoLevel, entries[0].Level)
@@ -147,6 +148,7 @@ func testSuccessfulPost(t *testing.T, client *GitlabNetClient) {
 		assert.NoError(t, err)
 		assert.Equal(t, "Echo: {\"key\":\"value\"}", string(responseBody))
 
+		require.True(t, testhelper.WaitForLogEvent(hook))
 		entries := hook.AllEntries()
 		assert.Equal(t, 1, len(entries))
 		assert.Equal(t, logrus.InfoLevel, entries[0].Level)
@@ -163,6 +165,7 @@ func testMissing(t *testing.T, client *GitlabNetClient) {
 		assert.EqualError(t, err, "Internal API error (404)")
 		assert.Nil(t, response)
 
+		require.True(t, testhelper.WaitForLogEvent(hook))
 		entries := hook.AllEntries()
 		assert.Equal(t, 1, len(entries))
 		assert.Equal(t, logrus.InfoLevel, entries[0].Level)
@@ -177,6 +180,7 @@ func testMissing(t *testing.T, client *GitlabNetClient) {
 		assert.EqualError(t, err, "Internal API error (404)")
 		assert.Nil(t, response)
 
+		require.True(t, testhelper.WaitForLogEvent(hook))
 		entries := hook.AllEntries()
 		assert.Equal(t, 1, len(entries))
 		assert.Equal(t, logrus.InfoLevel, entries[0].Level)
@@ -208,6 +212,7 @@ func testBrokenRequest(t *testing.T, client *GitlabNetClient) {
 		assert.EqualError(t, err, "Internal API unreachable")
 		assert.Nil(t, response)
 
+		require.True(t, testhelper.WaitForLogEvent(hook))
 		entries := hook.AllEntries()
 		assert.Equal(t, 1, len(entries))
 		assert.Equal(t, logrus.InfoLevel, entries[0].Level)
@@ -223,6 +228,7 @@ func testBrokenRequest(t *testing.T, client *GitlabNetClient) {
 		assert.EqualError(t, err, "Internal API unreachable")
 		assert.Nil(t, response)
 
+		require.True(t, testhelper.WaitForLogEvent(hook))
 		entries := hook.AllEntries()
 		assert.Equal(t, 1, len(entries))
 		assert.Equal(t, logrus.InfoLevel, entries[0].Level)
diff --git a/internal/command/receivepack/gitalycall_test.go b/internal/command/receivepack/gitalycall_test.go
index fd062b2..0cfbf5c 100644
--- a/internal/command/receivepack/gitalycall_test.go
+++ b/internal/command/receivepack/gitalycall_test.go
@@ -43,6 +43,7 @@ func TestReceivePack(t *testing.T) {
 
 	require.Equal(t, "ReceivePack: "+userId+" "+repo, output.String())
 
+	require.True(t, testhelper.WaitForLogEvent(hook))
 	entries := hook.AllEntries()
 	require.Equal(t, 2, len(entries))
 	require.Equal(t, logrus.InfoLevel, entries[1].Level)
diff --git a/internal/command/uploadarchive/gitalycall_test.go b/internal/command/uploadarchive/gitalycall_test.go
index 8b60e11..488c390 100644
--- a/internal/command/uploadarchive/gitalycall_test.go
+++ b/internal/command/uploadarchive/gitalycall_test.go
@@ -42,6 +42,8 @@ func TestUploadPack(t *testing.T) {
 	require.NoError(t, err)
 
 	require.Equal(t, "UploadArchive: "+repo, output.String())
+
+	require.True(t, testhelper.WaitForLogEvent(hook))
 	entries := hook.AllEntries()
 	require.Equal(t, 2, len(entries))
 	require.Equal(t, logrus.InfoLevel, entries[1].Level)
diff --git a/internal/testhelper/testhelper.go b/internal/testhelper/testhelper.go
index da781ce..5e98c1c 100644
--- a/internal/testhelper/testhelper.go
+++ b/internal/testhelper/testhelper.go
@@ -6,6 +6,7 @@ import (
 	"os"
 	"path"
 	"runtime"
+	"time"
 
 	"github.com/otiai10/copy"
 	"github.com/sirupsen/logrus"
@@ -100,3 +101,18 @@ func SetupLogger() *test.Hook {
 
 	return hook
 }
+
+// logrus fires a Goroutine to write the output log, but there's no way to
+// flush all outstanding hooks to fire. We just wait up to a second
+// for an event to appear.
+func WaitForLogEvent(hook *test.Hook) bool {
+	for i := 0; i < 10; i++ {
+		if entry := hook.LastEntry(); entry != nil {
+			return true
+		}
+
+		time.Sleep(100*time.Millisecond)
+	}
+
+	return false
+}