diff --git a/go/cmd/gitter/gitter.go b/go/cmd/gitter/gitter.go index 79eba120170..5ee05068484 100644 --- a/go/cmd/gitter/gitter.go +++ b/go/cmd/gitter/gitter.go @@ -17,6 +17,7 @@ import ( "os/exec" "os/signal" "path" + "path/filepath" "regexp" "strings" "syscall" @@ -26,6 +27,12 @@ import ( "golang.org/x/sync/singleflight" ) +type contextKey string + +const ( + urlKey contextKey = "url" +) + const getGitEndpoint = "/getgit" const defaultGitterWorkDir = "/work/gitter" const persistanceFileName = "last-fetch.json" @@ -43,6 +50,7 @@ const shutdownTimeout = 10 * time.Second // runCmd executes a command with context cancellation handled by sending SIGINT. // It logs cancellation errors separately as requested. func runCmd(ctx context.Context, dir string, env []string, name string, args ...string) error { + logger.Debug("Running command", slog.String("cmd", name), slog.String("url", ctx.Value(urlKey).(string)), slog.Any("args", args)) cmd := exec.CommandContext(ctx, name, args...) if dir != "" { cmd.Dir = dir @@ -52,6 +60,7 @@ func runCmd(ctx context.Context, dir string, env []string, name string, args ... } // Use SIGINT instead of SIGKILL for graceful shutdown of subprocesses cmd.Cancel = func() error { + logger.Debug("SIGINT sent to command", slog.String("cmd", name), slog.String("url", ctx.Value(urlKey).(string)), slog.Any("args", args)) return cmd.Process.Signal(syscall.SIGINT) } // Ensure it eventually dies if it ignores SIGINT @@ -61,12 +70,13 @@ func runCmd(ctx context.Context, dir string, env []string, name string, args ... if err != nil { if ctx.Err() != nil { // Log separately if cancelled - logger.Warn("Command cancelled", slog.String("cmd", name), slog.Any("err", ctx.Err())) + logger.Warn("Command cancelled", slog.String("cmd", name), slog.String("url", ctx.Value(urlKey).(string)), slog.Any("err", ctx.Err())) return fmt.Errorf("command %s cancelled: %w", name, ctx.Err()) } return fmt.Errorf("command %s failed: %w, output: %s", name, err, out) } + logger.Debug("Command completed successfully", slog.String("cmd", name), slog.String("url", ctx.Value(urlKey).(string)), slog.String("out", string(out))) return nil } @@ -103,6 +113,11 @@ func isAuthError(err error) bool { (strings.Contains(strings.ToLower(errString), "repository") && strings.Contains(strings.ToLower(errString), "not found")) } +func isIndexLockError(err error) bool { + errString := err.Error() + return strings.Contains(errString, "index.lock") && strings.Contains(errString, "File exists") +} + func fetchBlob(ctx context.Context, url string, forceUpdate bool) ([]byte, error) { repoDirName := getRepoDirName(url) repoPath := path.Join(gitStorePath, repoDirName) @@ -114,7 +129,7 @@ func fetchBlob(ctx context.Context, url string, forceUpdate bool) ([]byte, error // Check if we need to fetch if forceUpdate || !ok || time.Since(accessTime) > fetchTimeout { - logger.Info("Fetching git blob", slog.String("url", url), slog.Duration("sinceAccessTime", time.Since(accessTime))) + logger.Info("Fetching git blob", slog.String("url", ctx.Value(urlKey).(string)), slog.Duration("sinceAccessTime", time.Since(accessTime))) if _, err := os.Stat(path.Join(repoPath, ".git")); os.IsNotExist(err) { // Clone err := runCmd(ctx, "", []string{"GIT_TERMINAL_PROMPT=0"}, "git", "clone", "--", url, repoPath) @@ -130,12 +145,24 @@ func fetchBlob(ctx context.Context, url string, forceUpdate bool) ([]byte, error return nil, fmt.Errorf("git fetch failed: %w", err) } err = runCmd(ctx, repoPath, nil, "git", "reset", "--hard", "origin/HEAD") + if isIndexLockError(err) { + // index.lock exists, likely a previous git reset got terminated and wasn't cleaned up properly. + // We can remove the file and retry the command + logger.Warn("index.lock exists, attempting to remove and retry", slog.String("url", ctx.Value(urlKey).(string))) + indexLockPath := filepath.Join(repoPath, ".git", "index.lock") + if err := os.Remove(indexLockPath); err != nil { + return nil, fmt.Errorf("failed to remove index.lock in %s: %w", repoPath, err) + } + // One more attempt at git reset + err = runCmd(ctx, repoPath, nil, "git", "reset", "--hard", "origin/HEAD") + } + if err != nil { return nil, fmt.Errorf("git reset failed: %w", err) } } - logger.Info("Archiving git blob", slog.String("url", url)) + logger.Info("Archiving git blob", slog.String("url", ctx.Value(urlKey).(string))) // Archive // tar --zstd -cf -C "/" . // using -C to archive the relative path so it unzips nicely @@ -242,6 +269,8 @@ func gitHandler(w http.ResponseWriter, r *http.Request) { } forceUpdate := r.URL.Query().Get("force-update") == "true" + ctx := context.WithValue(r.Context(), urlKey, url) + logger.Info("Received request", slog.String("url", url), slog.Bool("forceUpdate", forceUpdate), slog.String("remoteAddr", r.RemoteAddr)) // If request came from a local ip, don't do the check if !isLocalRequest(r) { @@ -258,13 +287,12 @@ func gitHandler(w http.ResponseWriter, r *http.Request) { // That is highly unlikely in our use case, as importer only queries // the repo once, and always with force update. // This is a tradeoff for simplicity to avoid having to setup locks per repo. - //nolint:contextcheck // I can't change singleflight's interface fileData, err, _ := g.Do(url, func() (any, error) { - return fetchBlob(r.Context(), url, forceUpdate) + return fetchBlob(ctx, url, forceUpdate) }) if err != nil { - logger.Error("Error fetching/archiving blob", slog.String("url", url), slog.Any("error", err)) + logger.Error("Error fetching/archiving blob", slog.String("url", ctx.Value(urlKey).(string)), slog.Any("error", err)) if isAuthError(err) { http.Error(w, fmt.Sprintf("Error fetching blob: %v", err), http.StatusForbidden) return @@ -284,5 +312,5 @@ func gitHandler(w http.ResponseWriter, r *http.Request) { return } - logger.Info("Request completed successfully", slog.String("url", url)) + logger.Info("Request completed successfully", slog.String("url", ctx.Value(urlKey).(string))) }