Merge pull request #151 from devtron-labs/main-watcher-logs

misc: Main watcher logs

Author: prkhrkat

git-sensor/go.mod

@@ -13,6 +13,7 @@ require (
 	github.com/gammazero/workerpool v1.1.3
 	github.com/go-git/go-git/v5 v5.11.0
 	github.com/go-pg/pg v6.15.1+incompatible
+	github.com/google/uuid v1.6.0
 	github.com/google/wire v0.6.0
 	github.com/gorilla/handlers v1.4.2
 	github.com/gorilla/mux v1.8.0

git-sensor/go.sum

@@ -66,6 +66,8 @@ github.com/google/go-cmp v0.2.0/go.mod h1:oXzfMopK8JAjlY9xF4vHSVASa0yLyX7SntLO5a
 github.com/google/go-cmp v0.6.0 h1:ofyhxvXcZhMsU5ulbFiLKl/XBFqE1GSq7atu8tAmTRI=
 github.com/google/go-cmp v0.6.0/go.mod h1:17dUlkBOakJ0+DkrSSNjCkIjxS6bF9zb3elmeNGIjoY=
 github.com/google/subcommands v1.2.0/go.mod h1:ZjhPrFU+Olkh9WazFPsl27BQ4UPiG37m3yTrtFlrHVk=
+github.com/google/uuid v1.6.0 h1:NIvaJDMOsjHA8n1jAhLSgzrAzy1Hgr+hNrb57e+94F0=
+github.com/google/uuid v1.6.0/go.mod h1:TIyPZe4MgqvfeYDBFedMoGGpEw/LqOeaOT+nhxU+yHo=
 github.com/google/wire v0.6.0 h1:HBkoIh4BdSxoyo9PveV8giw7ZsaBOvzWKfcg/6MrVwI=
 github.com/google/wire v0.6.0/go.mod h1:F4QhpQ9EDIdJ1Mbop/NZBRB+5yrR6qg3BnctaoUk6NA=
 github.com/gorilla/handlers v1.4.2 h1:0QniY0USkHQ1RGCLfKxeNHK9bkDHGRYGNDFBCS+YARg=

git-sensor/pkg/git/GitBaseManager.go

@@ -31,6 +31,7 @@ import (
 	"os/exec"
 	"regexp"
 	"strings"
+	"time"
 )
 
 type GitManager interface {
@@ -196,6 +197,12 @@ func (impl *GitManagerBaseImpl) runCommandWithCred(cmd *exec.Cmd, gitCtx GitCont
 
 func (impl *GitManagerBaseImpl) runCommand(gitCtx GitContext, cmd *exec.Cmd) (response, errMsg string, err error) {
 	cmd.Env = append(cmd.Env, "HOME=/dev/null")
+	startTime := time.Now()
+	// logging context deadline for the command
+	deadline, ok := gitCtx.Deadline()
+	if ok {
+		impl.logger.Infow("context deadline", "deadline", deadline)
+	}
 	outBytes, err := cmd.CombinedOutput()
 	output := string(outBytes)
 	output = strings.TrimSpace(output)
@@ -204,7 +211,8 @@ func (impl *GitManagerBaseImpl) runCommand(gitCtx GitContext, cmd *exec.Cmd) (re
 		errMsg = output
 		if errors.Is(gitCtx.Err(), context.DeadlineExceeded) {
 			errMsg = "command timed out"
-			impl.logger.Errorw("command timed out", "cmd", cmd.String())
+			impl.logger.Errorw(errMsg, "startTime", startTime, "processingTime", time.Since(startTime).Seconds(), "cmd", cmd.String())
+
 			// prometheus event count for timeout
 			middleware.GitFetchTimeoutCounter.WithLabelValues().Inc()
 			return output, errMsg, err

git-sensor/pkg/git/Watcher.go

@@ -30,6 +30,7 @@ import (
 	"github.com/devtron-labs/git-sensor/internals/sql"
 	util2 "github.com/devtron-labs/git-sensor/util"
 	"github.com/gammazero/workerpool"
+	"github.com/google/uuid"
 	"github.com/robfig/cron/v3"
 	"go.uber.org/zap"
 	"runtime/debug"
@@ -112,16 +113,17 @@ func (impl GitWatcherImpl) StopCron() {
 }
 
 func (impl GitWatcherImpl) Watch() {
-	impl.logger.Infow("starting git watch thread")
+	watchID := uuid.New().String()
+	impl.logger.Infow("starting git watch thread", "watchID", watchID)
 	materials, err := impl.materialRepo.FindActive()
 	if err != nil {
-		impl.logger.Error("error in fetching watchlist", "err", err)
+		impl.logger.Error("error in fetching watchlist", "err", err, "watchID", watchID)
 		return
 	}
 	// impl.Publish(materials)
 	middleware.ActiveGitRepoCount.WithLabelValues().Set(float64(len(materials)))
 	impl.RunOnWorker(materials)
-	impl.logger.Infow("stop git watch thread")
+	impl.logger.Infow("stop git watch thread", "watchID", watchID)
 }
 
 func (impl *GitWatcherImpl) RunOnWorker(materials []*sql.GitMaterial) {