Quieter Integration Tests (#6513)

* Rename BaseLogger to WriterLogger to help the creation of other providers

* Don't export ColorBytes and ResetBytes from ColoredValues

* Make integration tests only print logs if they fail

* check can color before coloring

* I always forget about MSSQL

* Oh and use LEVEL in sqlite.ini

* Make the test logger log at info - as it means you see the router

* Remove empty expected changes

* Make the migrations quieter too

* Don't display SQL on error - it can be looked at in the file logs if necessary

* Fix skip when using onGiteaRun

10 files changed, 211 insertions, 45 deletions

diff --git a/integrations/git_helper_for_declarative_test.go b/integrations/git_helper_for_declarative_test.go
index 010f47a7ac..b4fead6625 100644
--- a/integrations/git_helper_for_declarative_test.go
+++ b/integrations/git_helper_for_declarative_test.go
@@ -50,7 +50,7 @@ func createSSHUrl(gitPath string, u *url.URL) *url.URL {
 }
 
 func onGiteaRun(t *testing.T, callback func(*testing.T, *url.URL)) {
-	prepareTestEnv(t)
+	prepareTestEnv(t, 1)
 	s := http.Server{
 		Handler: mac,
 	}
diff --git a/integrations/git_test.go b/integrations/git_test.go
index 28ead9d385..ebbf04f9d0 100644
--- a/integrations/git_test.go
+++ b/integrations/git_test.go
@@ -38,6 +38,7 @@ func testGit(t *testing.T, u *url.URL) {
 	u.Path = baseAPITestContext.GitPath()
 
 	t.Run("HTTP", func(t *testing.T) {
+		PrintCurrentTest(t)
 		httpContext := baseAPITestContext
 		httpContext.Reponame = "repo-tmp-17"
 
@@ -47,6 +48,7 @@ func testGit(t *testing.T, u *url.URL) {
 		assert.NoError(t, err)
 		defer os.RemoveAll(dstPath)
 		t.Run("Standard", func(t *testing.T) {
+			PrintCurrentTest(t)
 			ensureAnonymousClone(t, u)
 
 			t.Run("CreateRepo", doAPICreateRepository(httpContext, false))
@@ -57,16 +59,21 @@ func testGit(t *testing.T, u *url.URL) {
 			t.Run("Clone", doGitClone(dstPath, u))
 
 			t.Run("PushCommit", func(t *testing.T) {
+				PrintCurrentTest(t)
 				t.Run("Little", func(t *testing.T) {
+					PrintCurrentTest(t)
 					little = commitAndPush(t, littleSize, dstPath)
 				})
 				t.Run("Big", func(t *testing.T) {
+					PrintCurrentTest(t)
 					big = commitAndPush(t, bigSize, dstPath)
 				})
 			})
 		})
 		t.Run("LFS", func(t *testing.T) {
+			PrintCurrentTest(t)
 			t.Run("PushCommit", func(t *testing.T) {
+				PrintCurrentTest(t)
 				//Setup git LFS
 				_, err = git.NewCommand("lfs").AddArguments("install").RunInDir(dstPath)
 				assert.NoError(t, err)
@@ -76,17 +83,21 @@ func testGit(t *testing.T, u *url.URL) {
 				assert.NoError(t, err)
 
 				t.Run("Little", func(t *testing.T) {
+					PrintCurrentTest(t)
 					littleLFS = commitAndPush(t, littleSize, dstPath)
 				})
 				t.Run("Big", func(t *testing.T) {
+					PrintCurrentTest(t)
 					bigLFS = commitAndPush(t, bigSize, dstPath)
 				})
 			})
 			t.Run("Locks", func(t *testing.T) {
+				PrintCurrentTest(t)
 				lockTest(t, u.String(), dstPath)
 			})
 		})
 		t.Run("Raw", func(t *testing.T) {
+			PrintCurrentTest(t)
 			session := loginUser(t, "user2")
 
 			// Request raw paths
@@ -110,6 +121,7 @@ func testGit(t *testing.T, u *url.URL) {
 
 		})
 		t.Run("Media", func(t *testing.T) {
+			PrintCurrentTest(t)
 			session := loginUser(t, "user2")
 
 			// Request media paths
@@ -132,12 +144,14 @@ func testGit(t *testing.T, u *url.URL) {
 
 	})
 	t.Run("SSH", func(t *testing.T) {
+		PrintCurrentTest(t)
 		sshContext := baseAPITestContext
 		sshContext.Reponame = "repo-tmp-18"
 		keyname := "my-testing-key"
 		//Setup key the user ssh key
 		withKeyFile(t, keyname, func(keyFile string) {
 			t.Run("CreateUserKey", doAPICreateUserKey(sshContext, "test-key", keyFile))
+			PrintCurrentTest(t)
 
 			//Setup remote link
 			sshURL := createSSHUrl(sshContext.GitPath(), u)
@@ -149,6 +163,7 @@ func testGit(t *testing.T, u *url.URL) {
 			var little, big, littleLFS, bigLFS string
 
 			t.Run("Standard", func(t *testing.T) {
+				PrintCurrentTest(t)
 				t.Run("CreateRepo", doAPICreateRepository(sshContext, false))
 
 				//TODO get url from api
@@ -156,16 +171,21 @@ func testGit(t *testing.T, u *url.URL) {
 
 				//time.Sleep(5 * time.Minute)
 				t.Run("PushCommit", func(t *testing.T) {
+					PrintCurrentTest(t)
 					t.Run("Little", func(t *testing.T) {
+						PrintCurrentTest(t)
 						little = commitAndPush(t, littleSize, dstPath)
 					})
 					t.Run("Big", func(t *testing.T) {
+						PrintCurrentTest(t)
 						big = commitAndPush(t, bigSize, dstPath)
 					})
 				})
 			})
 			t.Run("LFS", func(t *testing.T) {
+				PrintCurrentTest(t)
 				t.Run("PushCommit", func(t *testing.T) {
+					PrintCurrentTest(t)
 					//Setup git LFS
 					_, err = git.NewCommand("lfs").AddArguments("install").RunInDir(dstPath)
 					assert.NoError(t, err)
@@ -175,17 +195,21 @@ func testGit(t *testing.T, u *url.URL) {
 					assert.NoError(t, err)
 
 					t.Run("Little", func(t *testing.T) {
+						PrintCurrentTest(t)
 						littleLFS = commitAndPush(t, littleSize, dstPath)
 					})
 					t.Run("Big", func(t *testing.T) {
+						PrintCurrentTest(t)
 						bigLFS = commitAndPush(t, bigSize, dstPath)
 					})
 				})
 				t.Run("Locks", func(t *testing.T) {
+					PrintCurrentTest(t)
 					lockTest(t, u.String(), dstPath)
 				})
 			})
 			t.Run("Raw", func(t *testing.T) {
+				PrintCurrentTest(t)
 				session := loginUser(t, "user2")
 
 				// Request raw paths
@@ -209,6 +233,7 @@ func testGit(t *testing.T, u *url.URL) {
 
 			})
 			t.Run("Media", func(t *testing.T) {
+				PrintCurrentTest(t)
 				session := loginUser(t, "user2")
 
 				// Request media paths
diff --git a/integrations/integration_test.go b/integrations/integration_test.go
index d300e4a38a..4263fa4805 100644
--- a/integrations/integration_test.go
+++ b/integrations/integration_test.go
@@ -165,7 +165,12 @@ func initIntegrationTest() {
 	routers.GlobalInit()
 }
 
-func prepareTestEnv(t testing.TB) {
+func prepareTestEnv(t testing.TB, skip ...int) {
+	ourSkip := 2
+	if len(skip) > 0 {
+		ourSkip += skip[0]
+	}
+	PrintCurrentTest(t, ourSkip)
 	assert.NoError(t, models.LoadFixtures())
 	assert.NoError(t, os.RemoveAll(setting.RepoRootPath))
 	assert.NoError(t, os.RemoveAll(models.LocalCopyPath()))
diff --git a/integrations/migration-test/migration_test.go b/integrations/migration-test/migration_test.go
index 6fd7af832e..93b60e0e31 100644
--- a/integrations/migration-test/migration_test.go
+++ b/integrations/migration-test/migration_test.go
@@ -9,13 +9,13 @@ import (
 	"database/sql"
 	"fmt"
 	"io/ioutil"
-	"log"
 	"os"
 	"path"
 	"regexp"
 	"sort"
 	"testing"
 
+	"code.gitea.io/gitea/integrations"
 	"code.gitea.io/gitea/models"
 	"code.gitea.io/gitea/models/migrations"
 	"code.gitea.io/gitea/modules/setting"
@@ -26,21 +26,22 @@ import (
 
 var currentEngine *xorm.Engine
 
-func initMigrationTest() {
+func initMigrationTest(t *testing.T) {
+	integrations.PrintCurrentTest(t, 2)
 	giteaRoot := os.Getenv("GITEA_ROOT")
 	if giteaRoot == "" {
-		fmt.Println("Environment variable $GITEA_ROOT not set")
+		integrations.Printf("Environment variable $GITEA_ROOT not set\n")
 		os.Exit(1)
 	}
 	setting.AppPath = path.Join(giteaRoot, "gitea")
 	if _, err := os.Stat(setting.AppPath); err != nil {
-		fmt.Printf("Could not find gitea binary at %s\n", setting.AppPath)
+		integrations.Printf("Could not find gitea binary at %s\n", setting.AppPath)
 		os.Exit(1)
 	}
 
 	giteaConf := os.Getenv("GITEA_CONF")
 	if giteaConf == "" {
-		fmt.Println("Environment variable $GITEA_CONF not set")
+		integrations.Printf("Environment variable $GITEA_CONF not set\n")
 		os.Exit(1)
 	} else if !path.IsAbs(giteaConf) {
 		setting.CustomConf = path.Join(giteaRoot, giteaConf)
@@ -51,6 +52,7 @@ func initMigrationTest() {
 	setting.NewContext()
 	setting.CheckLFSVersion()
 	models.LoadConfigs()
+	setting.NewLogServices(true)
 }
 
 func getDialect() string {
@@ -125,7 +127,7 @@ func restoreOldDB(t *testing.T, version string) bool {
 	data, err := readSQLFromFile(version)
 	assert.NoError(t, err)
 	if len(data) == 0 {
-		log.Printf("No db found to restore for %s version: %s\n", models.DbCfg.Type, version)
+		integrations.Printf("No db found to restore for %s version: %s\n", models.DbCfg.Type, version)
 		return false
 	}
 
@@ -212,7 +214,8 @@ func wrappedMigrate(x *xorm.Engine) error {
 }
 
 func doMigrationTest(t *testing.T, version string) {
-	log.Printf("Performing migration test for %s version: %s", models.DbCfg.Type, version)
+	integrations.PrintCurrentTest(t)
+	integrations.Printf("Performing migration test for %s version: %s\n", models.DbCfg.Type, version)
 	if !restoreOldDB(t, version) {
 		return
 	}
@@ -227,19 +230,22 @@ func doMigrationTest(t *testing.T, version string) {
 }
 
 func TestMigrations(t *testing.T) {
-	initMigrationTest()
+	initMigrationTest(t)
 
 	dialect := models.DbCfg.Type
 	versions, err := availableVersions()
 	assert.NoError(t, err)
 
 	if len(versions) == 0 {
-		log.Printf("No old database versions available to migration test for %s\n", dialect)
+		integrations.Printf("No old database versions available to migration test for %s\n", dialect)
 		return
 	}
 
-	log.Printf("Preparing to test %d migrations for %s\n", len(versions), dialect)
+	integrations.Printf("Preparing to test %d migrations for %s\n", len(versions), dialect)
 	for _, version := range versions {
-		doMigrationTest(t, version)
+		t.Run(fmt.Sprintf("Migrate-%s-%s", dialect, version), func(t *testing.T) {
+			doMigrationTest(t, version)
+		})
+
 	}
 }
diff --git a/integrations/mssql.ini.tmpl b/integrations/mssql.ini.tmpl
index 86d100845d..a8e6d332f0 100644
--- a/integrations/mssql.ini.tmpl
+++ b/integrations/mssql.ini.tmpl
@@ -60,14 +60,19 @@ PROVIDER = file
 PROVIDER_CONFIG = data/sessions-mssql
 
 [log]
-MODE      = console,file
-ROOT_PATH = mssql-log
+MODE                 = test,file
+ROOT_PATH            = sqlite-log
+REDIRECT_MACARON_LOG = true
+ROUTER               = ,
+MACARON              = ,
+XORM                 = file
 
-[log.console]
-LEVEL = Warn
+[log.test]
+LEVEL                = Info
+COLORIZE             = true
 
 [log.file]
-LEVEL = Debug
+LEVEL                = Debug
 
 [security]
 INSTALL_LOCK   = true
diff --git a/integrations/mysql.ini.tmpl b/integrations/mysql.ini.tmpl
index 0ba34f2d86..0c9e6c3ecd 100644
--- a/integrations/mysql.ini.tmpl
+++ b/integrations/mysql.ini.tmpl
@@ -60,14 +60,19 @@ PROVIDER = file
 PROVIDER_CONFIG = data/sessions-mysql
 
 [log]
-MODE      = console,file
-ROOT_PATH = mysql-log
+MODE                 = test,file
+ROOT_PATH            = sqlite-log
+REDIRECT_MACARON_LOG = true
+ROUTER               = ,
+MACARON              = ,
+XORM                 = file
 
-[log.console]
-LEVEL = Warn
+[log.test]
+LEVEL                = Info
+COLORIZE             = true
 
 [log.file]
-LEVEL = Debug
+LEVEL                = Debug
 
 [security]
 INSTALL_LOCK   = true
diff --git a/integrations/mysql8.ini.tmpl b/integrations/mysql8.ini.tmpl
index 246ec800a6..7006433276 100644
--- a/integrations/mysql8.ini.tmpl
+++ b/integrations/mysql8.ini.tmpl
@@ -57,14 +57,20 @@ PROVIDER = file
 PROVIDER_CONFIG = data/sessions-mysql8
 
 [log]
-MODE      = console,file
-ROOT_PATH = mysql8-log
+MODE                 = test,file
+ROOT_PATH            = sqlite-log
+REDIRECT_MACARON_LOG = true
+ROUTER               = ,
+MACARON              = ,
+XORM                 = file
 
-[log.console]
-LEVEL = Warn
+[log.test]
+LEVEL                = Info
+COLORIZE             = true
 
 [log.file]
-LEVEL = Debug
+LEVEL                = Debug
+
 
 [security]
 INSTALL_LOCK   = true
diff --git a/integrations/pgsql.ini.tmpl b/integrations/pgsql.ini.tmpl
index e617b1899c..894a243ba8 100644
--- a/integrations/pgsql.ini.tmpl
+++ b/integrations/pgsql.ini.tmpl
@@ -60,14 +60,19 @@ PROVIDER = file
 PROVIDER_CONFIG = data/sessions-pgsql
 
 [log]
-MODE      = console,file
-ROOT_PATH = pgsql-log
+MODE                 = test,file
+ROOT_PATH            = sqlite-log
+REDIRECT_MACARON_LOG = true
+ROUTER               = ,
+MACARON              = ,
+XORM                 = file
 
-[log.console]
-LEVEL = Warn
+[log.test]
+LEVEL                = Info
+COLORIZE             = true
 
 [log.file]
-LEVEL = Debug
+LEVEL                = Debug
 
 [security]
 INSTALL_LOCK   = true
diff --git a/integrations/sqlite.ini b/integrations/sqlite.ini
index f1e48617ac..086081b666 100644
--- a/integrations/sqlite.ini
+++ b/integrations/sqlite.ini
@@ -33,18 +33,19 @@ APP_DATA_PATH    = integrations/gitea-integration-sqlite/data
 ENABLE_GZIP      = true
 
 [mailer]
-ENABLED = false
+ENABLED     = true
+MAILER_TYPE = dummy
+FROM        = sqlite-integration-test@gitea.io
 
 [service]
 REGISTER_EMAIL_CONFIRM            = false
-ENABLE_NOTIFY_MAIL                = false
+ENABLE_NOTIFY_MAIL                = true
 DISABLE_REGISTRATION              = false
 ENABLE_CAPTCHA                    = false
 REQUIRE_SIGNIN_VIEW               = false
 DEFAULT_KEEP_EMAIL_PRIVATE        = false
 DEFAULT_ALLOW_CREATE_ORGANIZATION = true
 NO_REPLY_ADDRESS                  = noreply.example.org
-ENABLE_NOTIFY_MAIL                = true
 
 [picture]
 DISABLE_GRAVATAR        = false
@@ -54,21 +55,25 @@ ENABLE_FEDERATED_AVATAR = false
 PROVIDER = file
 
 [log]
-MODE      = console,file
-ROOT_PATH = sqlite-log
+MODE                 = test,file
+ROOT_PATH            = sqlite-log
+REDIRECT_MACARON_LOG = true
+ROUTER               = ,
+MACARON              = ,
+XORM                 = file
 
-[log.console]
-LEVEL = Warn
+[log.test]
+LEVEL                = Info
+COLORIZE             = true
 
 [log.file]
-LEVEL = Debug
+LEVEL                = Debug
 
 [security]
 INSTALL_LOCK   = true
 SECRET_KEY     = 9pCviYTWSb
 INTERNAL_TOKEN = eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJuYmYiOjE0OTI3OTU5ODN9.OQkH5UmzID2XBdwQ9TAI6Jj2t1X-wElVTjbE7aoN4I8
 
-[mailer]
-ENABLED = true
-MAILER_TYPE = dummy
-FROM = sqlite-integration-test@gitea.io
+[oauth2]
+JWT_SECRET = KZb_QLUd4fYVyxetjxC4eZkrBgWM2SndOOWDNtgUUko
+
diff --git a/integrations/testlogger.go b/integrations/testlogger.go
new file mode 100644
index 0000000000..9ee28d2ead
--- /dev/null
+++ b/integrations/testlogger.go
@@ -0,0 +1,104 @@
+// Copyright 2019 The Gitea Authors. All rights reserved.
+// Use of this source code is governed by a MIT-style
+// license that can be found in the LICENSE file.
+
+package integrations
+
+import (
+	"encoding/json"
+	"fmt"
+	"os"
+	"runtime"
+	"strings"
+	"testing"
+
+	"code.gitea.io/gitea/modules/log"
+)
+
+var prefix string
+
+// TestLogger is a logger which will write to the testing log
+type TestLogger struct {
+	log.WriterLogger
+}
+
+var writerCloser = &testLoggerWriterCloser{}
+
+type testLoggerWriterCloser struct {
+	t testing.TB
+}
+
+func (w *testLoggerWriterCloser) Write(p []byte) (int, error) {
+	if w.t != nil {
+		if len(p) > 0 && p[len(p)-1] == '\n' {
+			p = p[:len(p)-1]
+		}
+		w.t.Log(string(p))
+		return len(p), nil
+	}
+	return len(p), nil
+}
+
+func (w *testLoggerWriterCloser) Close() error {
+	return nil
+}
+
+// PrintCurrentTest prints the current test to os.Stdout
+func PrintCurrentTest(t testing.TB, skip ...int) {
+	actualSkip := 1
+	if len(skip) > 0 {
+		actualSkip = skip[0]
+	}
+	_, filename, line, _ := runtime.Caller(actualSkip)
+
+	if log.CanColorStdout {
+		fmt.Fprintf(os.Stdout, "=== %s (%s:%d)\n", log.NewColoredValue(t.Name()), strings.TrimPrefix(filename, prefix), line)
+	} else {
+		fmt.Fprintf(os.Stdout, "=== %s (%s:%d)\n", t.Name(), strings.TrimPrefix(filename, prefix), line)
+	}
+	writerCloser.t = t
+}
+
+// Printf takes a format and args and prints the string to os.Stdout
+func Printf(format string, args ...interface{}) {
+	if log.CanColorStdout {
+		for i := 0; i < len(args); i++ {
+			args[i] = log.NewColoredValue(args[i])
+		}
+	}
+	fmt.Fprintf(os.Stdout, "\t"+format, args...)
+}
+
+// NewTestLogger creates a TestLogger as a log.LoggerProvider
+func NewTestLogger() log.LoggerProvider {
+	logger := &TestLogger{}
+	logger.Colorize = log.CanColorStdout
+	logger.Level = log.TRACE
+	return logger
+}
+
+// Init inits connection writer with json config.
+// json config only need key "level".
+func (log *TestLogger) Init(config string) error {
+	err := json.Unmarshal([]byte(config), log)
+	if err != nil {
+		return err
+	}
+	log.NewWriterLogger(writerCloser)
+	return nil
+}
+
+// Flush when log should be flushed
+func (log *TestLogger) Flush() {
+}
+
+// GetName returns the default name for this implementation
+func (log *TestLogger) GetName() string {
+	return "test"
+}
+
+func init() {
+	log.Register("test", NewTestLogger)
+	_, filename, _, _ := runtime.Caller(0)
+	prefix = strings.TrimSuffix(filename, "integrations/testlogger.go")
+}