Merge pull request #331 from nan-yu/release-3.x

Export the error details to an error file

cmd/git-sync/main.go

@@ -21,6 +21,7 @@ package main // import "k8s.io/git-sync/cmd/git-sync"
 import (
 	"bytes"
 	"context"
+	"encoding/json"
 	"flag"
 	"fmt"
 	"io/ioutil"
@@ -37,6 +38,7 @@ import (
 	"time"
 
 	"github.com/go-logr/glogr"
+	"github.com/go-logr/logr"
 	"github.com/prometheus/client_golang/prometheus"
 	"github.com/prometheus/client_golang/prometheus/promhttp"
 	"k8s.io/git-sync/pkg/pid1"
@@ -60,6 +62,8 @@ var flRoot = flag.String("root", envString("GIT_SYNC_ROOT", envString("HOME", ""
 	"the root directory for git-sync operations, under which --dest will be created")
 var flDest = flag.String("dest", envString("GIT_SYNC_DEST", ""),
 	"the name of (a symlink to) a directory in which to check-out files under --root (defaults to the leaf dir of --repo)")
+var flErrorFile = flag.String("error-file", envString("GIT_SYNC_ERROR_FILE", ""),
+	"the name of a file into which errors will be written under --root (defaults to \"\", disabling error reporting)")
 var flWait = flag.Float64("wait", envFloat("GIT_SYNC_WAIT", 1),
 	"the number of seconds between syncs")
 var flSyncTimeout = flag.Int("timeout", envInt("GIT_SYNC_TIMEOUT", 120),
@@ -119,7 +123,7 @@ var flHTTPMetrics = flag.Bool("http-metrics", envBool("GIT_SYNC_HTTP_METRICS", t
 var flHTTPprof = flag.Bool("http-pprof", envBool("GIT_SYNC_HTTP_PPROF", false),
 	"enable the pprof debug endpoints on git-sync's HTTP endpoint")
 
-var log = glogr.New()
+var log *customLogger
 
 // Total pull/error, summary on pull duration
 var (
@@ -155,6 +159,90 @@ const (
 	submodulesOff       = "off"
 )
 
+type customLogger struct {
+	logr.Logger
+	errorFile string
+}
+
+func (l customLogger) Error(err error, msg string, kvList ...interface{}) {
+	l.Logger.Error(err, msg, kvList...)
+	if l.errorFile == "" {
+		return
+	}
+	payload := struct {
+		Msg  string
+		Err  string
+		Args map[string]interface{}
+	}{
+		Msg:  msg,
+		Err:  err.Error(),
+		Args: map[string]interface{}{},
+	}
+	if len(kvList)%2 != 0 {
+		kvList = append(kvList, "<no-value>")
+	}
+	for i := 0; i < len(kvList); i += 2 {
+		k, ok := kvList[i].(string)
+		if !ok {
+			k = fmt.Sprintf("%v", kvList[i])
+		}
+		payload.Args[k] = kvList[i+1]
+	}
+	jb, err := json.Marshal(payload)
+	if err != nil {
+		l.Logger.Error(err, "can't encode error payload")
+		content := fmt.Sprintf("%v", err)
+		l.writeContent([]byte(content))
+	} else {
+		l.writeContent(jb)
+	}
+}
+
+// exportError exports the error to the error file if --export-error is enabled.
+func (l *customLogger) exportError(content string) {
+	if l.errorFile == "" {
+		return
+	}
+	l.writeContent([]byte(content))
+}
+
+// writeContent writes the error content to the error file.
+func (l *customLogger) writeContent(content []byte) {
+	tmpFile, err := ioutil.TempFile(*flRoot, "tmp-err-")
+	if err != nil {
+		l.Logger.Error(err, "can't create temporary error-file", "directory", *flRoot, "prefix", "tmp-err-")
+		return
+	}
+	defer func() {
+		if err := tmpFile.Close(); err != nil {
+			l.Logger.Error(err, "can't close temporary error-file", "filename", tmpFile.Name())
+		}
+	}()
+
+	if _, err = tmpFile.Write(content); err != nil {
+		l.Logger.Error(err, "can't write to temporary error-file", "filename", tmpFile.Name())
+		return
+	}
+
+	if err := os.Rename(tmpFile.Name(), l.errorFile); err != nil {
+		l.Logger.Error(err, "can't rename to error-file", "temp-file", tmpFile.Name(), "error-file", l.errorFile)
+		return
+	}
+}
+
+// deleteErrorFile deletes the error file.
+func (l *customLogger) deleteErrorFile() {
+	if l.errorFile == "" {
+		return
+	}
+	if err := os.Remove(l.errorFile); err != nil {
+		if os.IsNotExist(err) {
+			return
+		}
+		l.Logger.Error(err, "can't delete the error-file", "filename", l.errorFile)
+	}
+}
+
 func init() {
 	prometheus.MustRegister(syncDuration)
 	prometheus.MustRegister(syncCount)
@@ -184,7 +272,7 @@ func envInt(key string, def int) int {
 	if env := os.Getenv(key); env != "" {
 		val, err := strconv.ParseInt(env, 0, 0)
 		if err != nil {
-			log.Error(err, "invalid env value, using default", "key", key, "val", os.Getenv(key), "default", def)
+			fmt.Fprintf(os.Stderr, "WARNING: invalid env value (%v): using default, key=%s, val=%q, default=%d\n", err, key, env, def)
 			return def
 		}
 		return int(val)
@@ -196,7 +284,7 @@ func envFloat(key string, def float64) float64 {
 	if env := os.Getenv(key); env != "" {
 		val, err := strconv.ParseFloat(env, 64)
 		if err != nil {
-			log.Error(err, "invalid env value, using default", "key", key, "val", os.Getenv(key), "default", def)
+			fmt.Fprintf(os.Stderr, "WARNING: invalid env value (%v): using default, key=%s, val=%q, default=%f\n", err, key, env, def)
 			return def
 		}
 		return val
@@ -208,7 +296,7 @@ func envDuration(key string, def time.Duration) time.Duration {
 	if env := os.Getenv(key); env != "" {
 		val, err := time.ParseDuration(env)
 		if err != nil {
-			log.Error(err, "invalid env value, using default", "key", key, "val", os.Getenv(key), "default", def)
+			fmt.Fprintf(os.Stderr, "WARNING: invalid env value (%v): using default, key=%s, val=%q, default=%d\n", err, key, env, def)
 			return def
 		}
 		return val
@@ -220,8 +308,7 @@ func setFlagDefaults() {
 	// Force logging to stderr (from glog).
 	stderrFlag := flag.Lookup("logtostderr")
 	if stderrFlag == nil {
-		fmt.Fprintf(os.Stderr, "ERROR: can't find flag 'logtostderr'\n")
+		handleError(false, "ERROR: can't find flag 'logtostderr'")
-		os.Exit(1)
 	}
 	stderrFlag.Value.Set("true")
 }
@@ -241,35 +328,33 @@ func main() {
 	setFlagDefaults()
 	flag.Parse()
 
+	var errorFile string
+	if *flErrorFile != "" {
+		errorFile = filepath.Join(*flRoot, *flErrorFile)
+	}
+	log = &customLogger{glogr.New(), errorFile}
+
 	if *flVer {
 		fmt.Println(version.VERSION)
 		os.Exit(0)
 	}
 
 	if *flRepo == "" {
-		fmt.Fprintf(os.Stderr, "ERROR: --repo must be specified\n")
+		handleError(true, "ERROR: --repo must be specified")
-		flag.Usage()
-		os.Exit(1)
 	}
 
 	if *flDepth < 0 { // 0 means "no limit"
-		fmt.Fprintf(os.Stderr, "ERROR: --depth must be greater than or equal to 0\n")
+		handleError(true, "ERROR: --depth must be greater than or equal to 0")
-		flag.Usage()
-		os.Exit(1)
 	}
 
 	switch *flSubmodules {
 	case submodulesRecursive, submodulesShallow, submodulesOff:
 	default:
-		fmt.Fprintf(os.Stderr, "ERROR: --submodules must be one of %q, %q, or %q", submodulesRecursive, submodulesShallow, submodulesOff)
+		handleError(true, "ERROR: --submodules must be one of %q, %q, or %q", submodulesRecursive, submodulesShallow, submodulesOff)
-		flag.Usage()
-		os.Exit(1)
 	}
 
 	if *flRoot == "" {
-		fmt.Fprintf(os.Stderr, "ERROR: --root must be specified\n")
+		handleError(true, "ERROR: --root must be specified")
-		flag.Usage()
-		os.Exit(1)
 	}
 
 	if *flDest == "" {
@@ -278,81 +363,59 @@ func main() {
 	}
 
 	if strings.Contains(*flDest, "/") {
-		fmt.Fprintf(os.Stderr, "ERROR: --dest must be a leaf name, not a path\n")
+		handleError(true, "ERROR: --dest must be a leaf name, not a path")
-		flag.Usage()
-		os.Exit(1)
 	}
 
 	if *flWait < 0 {
-		fmt.Fprintf(os.Stderr, "ERROR: --wait must be greater than or equal to 0\n")
+		handleError(true, "ERROR: --wait must be greater than or equal to 0")
-		flag.Usage()
-		os.Exit(1)
 	}
 
 	if *flSyncTimeout < 0 {
-		fmt.Fprintf(os.Stderr, "ERROR: --timeout must be greater than 0\n")
+		handleError(true, "ERROR: --timeout must be greater than 0")
-		flag.Usage()
-		os.Exit(1)
 	}
 
 	if *flWebhookURL != "" {
 		if *flWebhookStatusSuccess < -1 {
-			fmt.Fprintf(os.Stderr, "ERROR: --webhook-success-status must be a valid HTTP code or -1\n")
+			handleError(true, "ERROR: --webhook-success-status must be a valid HTTP code or -1")
-			flag.Usage()
-			os.Exit(1)
 		}
 		if *flWebhookTimeout < time.Second {
-			fmt.Fprintf(os.Stderr, "ERROR: --webhook-timeout must be at least 1s\n")
+			handleError(true, "ERROR: --webhook-timeout must be at least 1s")
-			flag.Usage()
-			os.Exit(1)
 		}
 		if *flWebhookBackoff < time.Second {
-			fmt.Fprintf(os.Stderr, "ERROR: --webhook-backoff must be at least 1s\n")
+			handleError(true, "ERROR: --webhook-backoff must be at least 1s")
-			flag.Usage()
-			os.Exit(1)
 		}
 	}
 
 	if _, err := exec.LookPath(*flGitCmd); err != nil {
-		fmt.Fprintf(os.Stderr, "ERROR: git executable %q not found: %v\n", *flGitCmd, err)
+		handleError(false, "ERROR: git executable %q not found: %v", *flGitCmd, err)
-		os.Exit(1)
 	}
 
 	if *flSSH {
 		if *flUsername != "" {
-			fmt.Fprintf(os.Stderr, "ERROR: only one of --ssh and --username may be specified\n")
+			handleError(false, "ERROR: only one of --ssh and --username may be specified")
-			os.Exit(1)
 		}
 		if *flPassword != "" {
-			fmt.Fprintf(os.Stderr, "ERROR: only one of --ssh and --password may be specified\n")
+			handleError(false, "ERROR: only one of --ssh and --password may be specified")
-			os.Exit(1)
 		}
 		if *flAskPassURL != "" {
-			fmt.Fprintf(os.Stderr, "ERROR: only one of --ssh and --askpass-url may be specified\n")
+			handleError(false, "ERROR: only one of --ssh and --askpass-url may be specified")
-			os.Exit(1)
 		}
 		if *flCookieFile {
-			fmt.Fprintf(os.Stderr, "ERROR: only one of --ssh and --cookie-file may be specified\n")
+			handleError(false, "ERROR: only one of --ssh and --cookie-file may be specified")
-			os.Exit(1)
 		}
 		if *flSSHKeyFile == "" {
-			fmt.Fprintf(os.Stderr, "ERROR: --ssh-key-file must be specified when --ssh is specified\n")
+			handleError(true, "ERROR: --ssh-key-file must be specified when --ssh is specified")
-			flag.Usage()
-			os.Exit(1)
 		}
 		if *flSSHKnownHosts {
 			if *flSSHKnownHostsFile == "" {
-				fmt.Fprintf(os.Stderr, "ERROR: --ssh-known-hosts-file must be specified when --ssh-known-hosts is specified\n")
+				handleError(true, "ERROR: --ssh-known-hosts-file must be specified when --ssh-known-hosts is specified")
-				flag.Usage()
-				os.Exit(1)
 			}
 		}
 	}
 
 	if *flAddUser {
 		if err := addUser(); err != nil {
-			fmt.Fprintf(os.Stderr, "ERROR: can't write to /etc/passwd: %v\n", err)
+			handleError(false, "ERROR: can't write to /etc/passwd: %v", err)
-			os.Exit(1)
 		}
 	}
 
@@ -362,30 +425,26 @@ func main() {
 
 	if *flUsername != "" && *flPassword != "" {
 		if err := setupGitAuth(ctx, *flUsername, *flPassword, *flRepo); err != nil {
-			fmt.Fprintf(os.Stderr, "ERROR: can't create .netrc file: %v\n", err)
+			handleError(false, "ERROR: can't create .netrc file: %v", err)
-			os.Exit(1)
 		}
 	}
 
 	if *flSSH {
 		if err := setupGitSSH(*flSSHKnownHosts); err != nil {
-			fmt.Fprintf(os.Stderr, "ERROR: can't configure SSH: %v\n", err)
+			handleError(false, "ERROR: can't configure SSH: %v", err)
-			os.Exit(1)
 		}
 	}
 
 	if *flCookieFile {
 		if err := setupGitCookieFile(ctx); err != nil {
-			fmt.Fprintf(os.Stderr, "ERROR: can't set git cookie file: %v\n", err)
+			handleError(false, "ERROR: can't set git cookie file: %v", err)
-			os.Exit(1)
 		}
 	}
 
 	if *flAskPassURL != "" {
 		if err := callGitAskPassURL(ctx, *flAskPassURL); err != nil {
 			askpassCount.WithLabelValues(metricKeyError).Inc()
-			fmt.Fprintf(os.Stderr, "ERROR: failed to call ASKPASS callback URL: %v\n", err)
+			handleError(false, "ERROR: failed to call ASKPASS callback URL: %v", err)
-			os.Exit(1)
 		}
 		askpassCount.WithLabelValues(metricKeySuccess).Inc()
 	}
@@ -404,8 +463,7 @@ func main() {
 	if *flHTTPBind != "" {
 		ln, err := net.Listen("tcp", *flHTTPBind)
 		if err != nil {
-			fmt.Fprintf(os.Stderr, "ERROR: unable to bind HTTP endpoint: %v\n", err)
+			handleError(false, "ERROR: unable to bind HTTP endpoint: %v", err)
-			os.Exit(1)
 		}
 		mux := http.NewServeMux()
 		go func() {
@@ -480,6 +538,7 @@ func main() {
 
 		if initialSync {
 			if *flOneTime {
+				log.deleteErrorFile()
 				os.Exit(0)
 			}
 			if isHash, err := revIsHash(ctx, *flRev, *flRoot); err != nil {
@@ -487,12 +546,14 @@ func main() {
 				os.Exit(1)
 			} else if isHash {
 				log.V(0).Info("rev appears to be a git hash, no further sync needed", "rev", *flRev)
+				log.deleteErrorFile()
 				sleepForever()
 			}
 			initialSync = false
 		}
 
 		failCount = 0
+		log.deleteErrorFile()
 		log.V(1).Info("next sync", "wait_time", waitTime(*flWait))
 		cancel()
 		time.Sleep(waitTime(*flWait))
@@ -517,6 +578,18 @@ func sleepForever() {
 	os.Exit(0)
 }
 
+// handleError prints the error to the standard error, prints the usage if the `printUsage` flag is true,
+// exports the error to the error file and exits the process with the exit code.
+func handleError(printUsage bool, format string, a ...interface{}) {
+	s := fmt.Sprintf(format, a...)
+	fmt.Fprintln(os.Stderr, s)
+	if printUsage {
+		flag.Usage()
+	}
+	log.exportError(s)
+	os.Exit(1)
+}
+
 // Put the current UID/GID into /etc/passwd so SSH can look it up.  This
 // assumes that we have the permissions to write to it.
 func addUser() error {

test_e2e.sh

@@ -59,6 +59,13 @@ function assert_file_eq() {
     fail "file $1 does not contain '$2': $(cat $1)"
 }
 
+function assert_file_contains() {
+    if grep -q "$2" "$1"; then
+        return
+    fi
+    fail "file $1 does not contain '$2': $(cat $1)"
+}
+
 # Helper: run a docker container.
 function docker_run() {
     docker run \
@@ -1226,3 +1233,43 @@ pass
 echo
 echo "cleaning up $DIR"
 rm -rf "$DIR"
+
+##############################################
+# Test export-error
+##############################################
+testcase "export-error"
+echo "$TESTCASE" > "$REPO"/file
+git -C "$REPO" commit -qam "$TESTCASE"
+(
+  set +o errexit
+  GIT_SYNC \
+      --repo="file://$REPO" \
+      --branch=does-not-exit \
+      --root="$ROOT" \
+      --dest="link" \
+      --error-file="error.json" \
+      > "$DIR"/log."$TESTCASE" 2>&1
+  RET=$?
+  if [[ "$RET" != 1 ]]; then
+      fail "expected exit code 1, got $RET"
+  fi
+  assert_file_absent "$ROOT"/link
+  assert_file_absent "$ROOT"/link/file
+  assert_file_contains "$ROOT"/error.json "Remote branch does-not-exit not found in upstream origin"
+)
+
+# the error.json file should be removed if sync succeeds.
+GIT_SYNC \
+    --one-time \
+    --repo="file://$REPO" \
+    --branch=e2e-branch \
+    --root="$ROOT" \
+    --dest="link" \
+    --error-file="error.json" \
+    > "$DIR"/log."$TESTCASE" 2>&1
+assert_link_exists "$ROOT"/link
+assert_file_exists "$ROOT"/link/file
+assert_file_eq "$ROOT"/link/file "$TESTCASE"
+assert_file_absent "$ROOT"/error.json
+# Wrap up
+pass