1 files changed, 70 insertions, 10 deletions

diff --git a/cmd/git-lfs-authenticate/main.go b/cmd/git-lfs-authenticate/main.go
index 56b9d78..e4fa67d 100644
--- a/cmd/git-lfs-authenticate/main.go
+++ b/cmd/git-lfs-authenticate/main.go
@@ -7,14 +7,57 @@ import (
         "encoding/json"
         "errors"
         "fmt"
+        "io"
         "os"
         "os/exec"
         "strings"
+        "sync"
+        "sync/atomic"
         "time"
 
         "github.com/golang-jwt/jwt/v5"
+        "github.com/rs/xid"
 )
 
+type logger struct {
+        reqID string
+        time  time.Time
+        m     sync.Mutex
+        // Contained value must implement io.WriteCloser
+        wc atomic.Value
+}
+
+func newLogger(reqID string) *logger {
+        return &logger{reqID: reqID, time: time.Now()}
+}
+
+func (l *logger) writer() io.WriteCloser {
+        w := l.wc.Load()
+        if w == nil {
+                l.m.Lock()
+                if l.wc.Load() == nil {
+                        os.MkdirAll(".gitolfs3/logs/", 0o600) // drw-------
+                        path := fmt.Sprintf(".gitolfs3/logs/gitolfs3-%s-%s.log", l.time, l.reqID)
+                        var err error
+                        if w, err = os.Create(path); err == nil {
+                                l.wc.Store(w)
+                        }
+                }
+                l.m.Unlock()
+        }
+        return w.(io.WriteCloser)
+}
+
+func (l *logger) logf(msg string, args ...any) {
+        fmt.Fprintf(l.writer(), msg, args...)
+}
+
+func (l *logger) close() {
+        if wc := l.wc.Load(); wc != nil {
+                wc.(io.Closer).Close()
+        }
+}
+
 func die(msg string, args ...any) {
         fmt.Fprint(os.Stderr, "Error: ")
         fmt.Fprintf(os.Stderr, msg, args...)
@@ -22,14 +65,22 @@ func die(msg string, args ...any) {
         os.Exit(1)
 }
 
-func getGitoliteAccess(path, user, gitolitePerm string) bool {
+func dieReqID(reqID string, msg string, args ...any) {
+        fmt.Fprint(os.Stderr, "Error: ")
+        fmt.Fprintf(os.Stderr, msg, args...)
+        fmt.Fprintf(os.Stderr, "(request ID: %s)\n", reqID)
+        os.Exit(1)
+}
+
+func getGitoliteAccess(logger *logger, reqID, path, user, gitolitePerm string) bool {
         // gitolite access -q: returns only exit code
         cmd := exec.Command("gitolite", "access", "-q", path, user, gitolitePerm)
         err := cmd.Run()
         permGranted := err == nil
         var exitErr *exec.ExitError
         if err != nil && !errors.As(err, &exitErr) {
-                die("failed to query access information")
+                logger.logf("Failed to query access information (%s): %s", cmd, err)
+                dieReqID(reqID, "failed to query access information")
         }
         return permGranted
 }
@@ -66,6 +117,9 @@ func main() {
         // code and print the error message in plain text to standard error. See
         // https://github.com/git-lfs/git-lfs/blob/baf40ac99850a62fe98515175d52df5c513463ec/lfshttp/ssh.go#L76-L117
 
+        reqID := xid.New().String()
+        logger := newLogger(reqID)
+
         if len(os.Args) != 3 {
                 die("expected 2 arguments (path, operation), got %d", len(os.Args)-1)
         }
@@ -78,35 +132,40 @@ func main() {
 
         user := os.Getenv("GL_USER")
         if user == "" {
-                die("internal error")
+                logger.logf("Environment variable GL_USER is not set")
+                dieReqID(reqID, "internal error")
         }
         keyPath := os.Getenv("GITOLFS3_KEY_PATH")
         if keyPath == "" {
-                die("internal error")
+                logger.logf("Environment variable GITOLFS3_KEY_PATH is not set")
+                dieReqID(reqID, "internal error")
         }
         keyStr, err := os.ReadFile(keyPath)
         if err != nil {
-                die("internal error")
+                logger.logf("Cannot read key in GITOLFS3_KEY_PATH: %s", err)
+                dieReqID(reqID, "internal error")
         }
         keyStr = bytes.TrimSpace(keyStr)
         defer wipe(keyStr)
 
         if hex.DecodedLen(len(keyStr)) != ed25519.SeedSize {
-                die("internal error")
+                logger.logf("Fatal: provided private key (seed) is invalid: does not have expected length")
+                dieReqID(reqID, "internal error")
         }
 
         seed := make([]byte, ed25519.SeedSize)
         defer wipe(seed)
         if _, err = hex.Decode(seed, keyStr); err != nil {
-                die("internal error")
+                logger.logf("Fatal: cannot decode provided private key (seed): %s", err)
+                dieReqID(reqID, "internal error")
         }
         privateKey := ed25519.NewKeyFromSeed(seed)
 
-        if !getGitoliteAccess(path, user, "R") {
+        if !getGitoliteAccess(logger, reqID, path, user, "R") {
                 die("repository not found")
         }
-        if operation == "upload" && !getGitoliteAccess(path, user, "W") {
-                // User has read access but not write access
+        if operation == "upload" && !getGitoliteAccess(logger, reqID, path, user, "W") {
+                // User has read access but no write access
                 die("forbidden")
         }
 
@@ -126,6 +185,7 @@ func main() {
         token := jwt.NewWithClaims(jwt.SigningMethodEdDSA, claims)
         ss, err := token.SignedString(privateKey)
         if err != nil {
+                logger.logf("Fatal: failed to generate JWT: %s", err)
                 die("failed to generate token")
         }