Merge branch 'feature/add-more-debug-logging' into 'master'

Add more logging to gitlab pages daemon

See merge request gitlab-org/gitlab-pages!62

7 files changed, 104 insertions, 12 deletions

diff --git a/app.go b/app.go
index 77ad5bff..3a032a59 100644
--- a/app.go
+++ b/app.go
@@ -228,7 +228,7 @@ func runApp(config appConfig) {
 		a.Artifact = artifact.New(config.ArtifactsServer, config.ArtifactsServerTimeout, config.Domain)
 	}
 
-	configureLogging(config.LogFormat)
+	configureLogging(config.LogFormat, config.LogVerbose)
 
 	if err := mimedb.LoadTypes(); err != nil {
 		log.WithError(err).Warn("Loading extended MIME database failed")
diff --git a/app_config.go b/app_config.go
index 2f8cbd1f..34b01e15 100644
--- a/app_config.go
+++ b/app_config.go
@@ -18,5 +18,6 @@ type appConfig struct {
 
 	DisableCrossOriginRequests bool
 
-	LogFormat string
+	LogFormat  string
+	LogVerbose bool
 }
diff --git a/daemon.go b/daemon.go
index 8f71940f..e77bce61 100644
--- a/daemon.go
+++ b/daemon.go
@@ -25,7 +25,7 @@ func daemonMain() {
 	log.WithFields(log.Fields{
 		"uid": syscall.Getuid(),
 		"gid": syscall.Getgid(),
-	}).Print("starting the daemon as unprivileged user")
+	}).Info("starting the daemon as unprivileged user")
 
 	// read the configuration from the pipe "ExtraFiles"
 	var config appConfig
@@ -184,7 +184,7 @@ func daemonize(config appConfig, uid, gid uint) {
 	log.WithFields(log.Fields{
 		"uid": uid,
 		"gid": gid,
-	}).Print("running the daemon as unprivileged user")
+	}).Info("running the daemon as unprivileged user")
 
 	cmd, err := daemonReexec(uid, gid, daemonRunProgram)
 	if err != nil {
@@ -195,7 +195,7 @@ func daemonize(config appConfig, uid, gid uint) {
 	// Run daemon in chroot environment
 	temporaryExecutable, err := daemonChroot(cmd)
 	if err != nil {
-		log.WithError(err).Print("chroot failed")
+		log.WithError(err).Error("chroot failed")
 		return
 	}
 	defer os.Remove(temporaryExecutable)
@@ -218,7 +218,7 @@ func daemonize(config appConfig, uid, gid uint) {
 
 	// Start the process
 	if err = cmd.Start(); err != nil {
-		log.WithError(err).Print("start failed")
+		log.WithError(err).Error("start failed")
 		return
 	}
 
diff --git a/domain.go b/domain.go
index 6e909ec7..9804321f 100644
--- a/domain.go
+++ b/domain.go
@@ -41,6 +41,18 @@ type domain struct {
 	Projects projects
 }
 
+func (d *domain) String() string {
+	if d.Group != "" && d.ProjectName != "" {
+		return d.Group + "/" + d.ProjectName
+	}
+
+	if d.Group != "" {
+		return d.Group
+	}
+
+	return d.ProjectName
+}
+
 func (l *locationDirectoryError) Error() string {
 	return "location error accessing directory where file expected"
 }
diff --git a/domains.go b/domains.go
index fddbcc1c..c3fff1cf 100644
--- a/domains.go
+++ b/domains.go
@@ -45,6 +45,7 @@ func (d domains) updateGroupDomain(rootDomain, group, projectName string, httpsO
 	groupDomain.Projects[projectName] = &project{
 		HTTPSOnly: httpsOnly,
 	}
+
 	d[domainName] = groupDomain
 }
 
@@ -132,7 +133,14 @@ func (d domains) ReadGroups(rootDomain string) error {
 			buf := make([]byte, 2*os.Getpagesize())
 
 			for group := range fanOutGroups {
+				started := time.Now()
+
 				readProjects(group, buf, fanIn)
+
+				log.WithFields(log.Fields{
+					"group":    group,
+					"duration": time.Since(started).Seconds(),
+				}).Debug("Loaded projects for group")
 			}
 
 			wg.Done()
@@ -198,11 +206,20 @@ func watchDomains(rootDomain string, updater domainsUpdater, interval time.Durat
 		}
 		duration := time.Since(started).Seconds()
 
+		var hash string
+		if len(update) < 1 {
+			hash = "<empty>"
+		} else {
+			hash = strings.TrimSpace(string(update))
+		}
+
+		logConfiguredDomains(domains)
+
 		log.WithFields(log.Fields{
-			"domains":  len(domains),
-			"duration": duration,
-			"hash":     update,
-		}).Print("updated domains")
+			"count(domains)": len(domains),
+			"duration":       duration,
+			"hash":           hash,
+		}).Info("Updated all domains")
 
 		if updater != nil {
 			updater(domains)
@@ -216,3 +233,16 @@ func watchDomains(rootDomain string, updater domainsUpdater, interval time.Durat
 		time.Sleep(interval)
 	}
 }
+
+func logConfiguredDomains(ds domains) {
+	if log.GetLevel() == log.DebugLevel {
+		return
+	}
+
+	for h, d := range ds {
+		log.WithFields(log.Fields{
+			"domain": d,
+			"host":   h,
+		}).Debug("Configured domain")
+	}
+}
diff --git a/logging.go b/logging.go
index dd282b1a..f3859059 100644
--- a/logging.go
+++ b/logging.go
@@ -13,7 +13,11 @@ var (
 	logrusEntry     = log.WithField("system", "http")
 )
 
-func configureLogging(format string) {
+func configureLogging(format string, verbose bool) {
+	if verbose {
+		log.SetLevel(log.DebugLevel)
+	}
+
 	switch format {
 	case "json":
 		log.SetFormatter(&log.JSONFormatter{})
diff --git a/main.go b/main.go
index d71c1e8c..c5243207 100644
--- a/main.go
+++ b/main.go
@@ -32,6 +32,7 @@ var (
 	daemonUID              = flag.Uint("daemon-uid", 0, "Drop privileges to this user")
 	daemonGID              = flag.Uint("daemon-gid", 0, "Drop privileges to this group")
 	logFormat              = flag.String("log-format", "text", "The log output format: 'text' or 'json'")
+	logVerbose             = flag.Bool("log-verbose", false, "Verbose logging")
 
 	disableCrossOriginRequests     = flag.Bool("disable-cross-origin-requests", false, "Disable cross-origin requests")
 	errArtifactSchemaUnsupported   = errors.New("artifacts-server scheme must be either http:// or https://")
@@ -47,6 +48,7 @@ func configFromFlags() appConfig {
 	config.DisableCrossOriginRequests = *disableCrossOriginRequests
 	config.StatusPath = *pagesStatus
 	config.LogFormat = *logFormat
+	config.LogVerbose = *logVerbose
 
 	if *pagesRootCert != "" {
 		config.RootCertificate = readFile(*pagesRootCert)
@@ -93,7 +95,7 @@ func appMain() {
 
 	printVersion(*showVersion, VERSION)
 
-	configureLogging(*logFormat)
+	configureLogging(*logFormat, *logVerbose)
 
 	log.WithFields(log.Fields{
 		"version":  VERSION,
@@ -108,27 +110,70 @@ func appMain() {
 
 	config := configFromFlags()
 
+	log.WithFields(log.Fields{
+		"artifacts-server":              *artifactsServer,
+		"artifacts-server-timeout":      *artifactsServerTimeout,
+		"daemon-gid":                    *daemonGID,
+		"daemon-uid":                    *daemonUID,
+		"default-config-filename":       flag.DefaultConfigFlagname,
+		"disable-cross-origin-requests": *disableCrossOriginRequests,
+		"domain":                        config.Domain,
+		"listen-http":                   strings.Join(listenHTTP, ","),
+		"listen-https":                  strings.Join(listenHTTPS, ","),
+		"listen-proxy":                  strings.Join(listenProxy, ","),
+		"log-format":                    *logFormat,
+		"metrics-address":               *metricsAddress,
+		"pages-domain":                  *pagesDomain,
+		"pages-root":                    *pagesRoot,
+		"pages-status":                  *pagesStatus,
+		"redirect-http":                 config.RedirectHTTP,
+		"root-cert":                     *pagesRootKey,
+		"root-key":                      *pagesRootCert,
+		"status_path":                   config.StatusPath,
+		"use-http-2":                    config.HTTP2,
+	}).Debug("Start daemon with configuration")
+
 	for _, addr := range listenHTTP.Split() {
 		l, fd := createSocket(addr)
 		defer l.Close()
+
+		log.WithFields(log.Fields{
+			"listener": addr,
+		}).Debug("Set up HTTP listener")
+
 		config.ListenHTTP = append(config.ListenHTTP, fd)
 	}
 
 	for _, addr := range listenHTTPS.Split() {
 		l, fd := createSocket(addr)
 		defer l.Close()
+
+		log.WithFields(log.Fields{
+			"listener": addr,
+		}).Debug("Set up HTTPS listener")
+
 		config.ListenHTTPS = append(config.ListenHTTPS, fd)
 	}
 
 	for _, addr := range listenProxy.Split() {
 		l, fd := createSocket(addr)
 		defer l.Close()
+
+		log.WithFields(log.Fields{
+			"listener": addr,
+		}).Debug("Set up proxy listener")
+
 		config.ListenProxy = append(config.ListenProxy, fd)
 	}
 
 	if *metricsAddress != "" {
 		l, fd := createSocket(*metricsAddress)
 		defer l.Close()
+
+		log.WithFields(log.Fields{
+			"listener": *metricsAddress,
+		}).Debug("Set up metrics listener")
+
 		config.ListenMetrics = fd
 	}