e0148ca697c9617a36dc96d806720644c38f87a6

Author
Ayman Bagabas <ayman.bagabas@gmail.com>
Committer
GitHub <noreply@github.com>
Date

Message

fix(http): times out on large repositories (#428)

This was due to having a _set_ value of Read/Write http server timeout
values, and a faulty git gzip request handler. The server drops the
connection if there wasn't any read/write within 10 seconds.

Replace the read/write timeouts with idle timeout which will reset the
counter to _either_ read/write within 10 seconds. Idle timeout is only
used when keep-alive is enabled. That is the case by default.

Fix git by properly handling gzip and buffered git service responses.

Improve git http handler logging

Fixes: https://github.com/charmbracelet/soft-serve/issues/427

Diff

  1diff --git a/pkg/git/service.go b/pkg/git/service.go
  2index e0d6877b736c24aeef3754a7ab88c8a5ff8565d7..9608af999aefb07183369b6d37ef24f063a666af 100644
  3--- a/pkg/git/service.go
  4+++ b/pkg/git/service.go
  5@@ -149,6 +149,11 @@ func gitServiceHandler(ctx context.Context, svc Service, scmd ServiceCommand) er
  6 	if err != nil && errors.Is(err, os.ErrNotExist) {
  7 		return ErrInvalidRepo
  8 	} else if err != nil {
  9+		var exitErr *exec.ExitError
 10+		if errors.As(err, &exitErr) && len(exitErr.Stderr) > 0 {
 11+			return fmt.Errorf("%s: %s", exitErr, exitErr.Stderr)
 12+		}
 13+
 14 		return err
 15 	}
 16 
 17diff --git a/pkg/web/context.go b/pkg/web/context.go
 18index 6cb6c5428eb49bd9732c0d6d50ed5e96cba6bc88..e8aae8f7ea0286ebc659e30298e68e1f7f14d99b 100644
 19--- a/pkg/web/context.go
 20+++ b/pkg/web/context.go
 21@@ -24,7 +24,11 @@ func NewContextHandler(ctx context.Context) func(http.Handler) http.Handler {
 22 			ctx := r.Context()
 23 			ctx = config.WithContext(ctx, cfg)
 24 			ctx = backend.WithContext(ctx, be)
 25-			ctx = log.WithContext(ctx, logger)
 26+			ctx = log.WithContext(ctx, logger.With(
 27+				"method", r.Method,
 28+				"path", r.URL,
 29+				"addr", r.RemoteAddr,
 30+			))
 31 			ctx = db.WithContext(ctx, dbx)
 32 			ctx = store.WithContext(ctx, datastore)
 33 			r = r.WithContext(ctx)
 34diff --git a/pkg/web/git.go b/pkg/web/git.go
 35index e166b92afe49b21e50f73d583cd97f2e8755e880..364530f623e42c95d44e9c02c39ccc481ec61d10 100644
 36--- a/pkg/web/git.go
 37+++ b/pkg/web/git.go
 38@@ -413,12 +413,16 @@ func serviceRpc(w http.ResponseWriter, r *http.Request) {
 39 		}...)
 40 	}
 41 
 42+	var (
 43+		err    error
 44+		reader io.ReadCloser
 45+	)
 46+
 47 	// Handle gzip encoding
 48-	reader := r.Body
 49-	defer reader.Close() // nolint: errcheck
 50+	reader = r.Body
 51 	switch r.Header.Get("Content-Encoding") {
 52 	case "gzip":
 53-		reader, err := gzip.NewReader(reader)
 54+		reader, err = gzip.NewReader(reader)
 55 		if err != nil {
 56 			logger.Errorf("failed to create gzip reader: %v", err)
 57 			renderInternalServerError(w, r)
 58@@ -428,49 +432,51 @@ func serviceRpc(w http.ResponseWriter, r *http.Request) {
 59 	}
 60 
 61 	cmd.Stdin = reader
 62+	cmd.Stdout = &flushResponseWriter{w}
 63 
 64 	if err := service.Handler(ctx, cmd); err != nil {
 65-		if errors.Is(err, git.ErrInvalidRepo) {
 66-			renderNotFound(w, r)
 67-			return
 68-		}
 69-		renderInternalServerError(w, r)
 70+		logger.Errorf("failed to handle service: %v", err)
 71 		return
 72 	}
 73 
 74-	// Handle buffered output
 75-	// Useful when using proxies
 76-
 77-	// We know that `w` is an `http.ResponseWriter`.
 78-	flusher, ok := w.(http.Flusher)
 79-	if !ok {
 80-		logger.Errorf("expected http.ResponseWriter to be an http.Flusher, got %T", w)
 81-		return
 82+	if service == git.ReceivePackService {
 83+		if err := git.EnsureDefaultBranch(ctx, cmd); err != nil {
 84+			logger.Errorf("failed to ensure default branch: %s", err)
 85+		}
 86 	}
 87+}
 88 
 89+// Handle buffered output
 90+// Useful when using proxies
 91+type flushResponseWriter struct {
 92+	http.ResponseWriter
 93+}
 94+
 95+func (f *flushResponseWriter) ReadFrom(r io.Reader) (int64, error) {
 96+	flusher := http.NewResponseController(f.ResponseWriter) // nolint: bodyclose
 97+
 98+	var n int64
 99 	p := make([]byte, 1024)
100 	for {
101-		nRead, err := stdout.Read(p)
102+		nRead, err := r.Read(p)
103 		if err == io.EOF {
104 			break
105 		}
106-		nWrite, err := w.Write(p[:nRead])
107+		nWrite, err := f.ResponseWriter.Write(p[:nRead])
108 		if err != nil {
109-			logger.Errorf("failed to write data: %v", err)
110-			return
111+			return n, err
112 		}
113 		if nRead != nWrite {
114-			logger.Errorf("failed to write data: %d read, %d written", nRead, nWrite)
115-			return
116+			return n, err
117 		}
118-		flusher.Flush()
119-	}
120-
121-	if service == git.ReceivePackService {
122-		if err := git.EnsureDefaultBranch(ctx, cmd); err != nil {
123-			logger.Errorf("failed to ensure default branch: %s", err)
124+		n += int64(nRead)
125+		// ResponseWriter must support http.Flusher to handle buffered output.
126+		if err := flusher.Flush(); err != nil {
127+			return n, fmt.Errorf("%w: error while flush", err)
128 		}
129 	}
130+
131+	return n, nil
132 }
133 
134 func getInfoRefs(w http.ResponseWriter, r *http.Request) {
135diff --git a/pkg/web/http.go b/pkg/web/http.go
136index a9a61a1402e93b3326164a76900be17bfcd9aa7f..9e109a0e2b880bf60300f5ac8ecb0d40cbff5225 100644
137--- a/pkg/web/http.go
138+++ b/pkg/web/http.go
139@@ -19,7 +19,7 @@ type HTTPServer struct {
140 // NewHTTPServer creates a new HTTP server.
141 func NewHTTPServer(ctx context.Context) (*HTTPServer, error) {
142 	cfg := config.FromContext(ctx)
143-	logger := log.FromContext(ctx).WithPrefix("http")
144+	logger := log.FromContext(ctx)
145 	s := &HTTPServer{
146 		ctx: ctx,
147 		cfg: cfg,
148@@ -27,8 +27,7 @@ func NewHTTPServer(ctx context.Context) (*HTTPServer, error) {
149 			Addr:              cfg.HTTP.ListenAddr,
150 			Handler:           NewRouter(ctx),
151 			ReadHeaderTimeout: time.Second * 10,
152-			ReadTimeout:       time.Second * 10,
153-			WriteTimeout:      time.Second * 10,
154+			IdleTimeout:       time.Second * 10,
155 			MaxHeaderBytes:    http.DefaultMaxHeaderBytes,
156 			ErrorLog:          logger.StandardLog(log.StandardLogOptions{ForceLevel: log.ErrorLevel}),
157 		},
158diff --git a/pkg/web/logging.go b/pkg/web/logging.go
159index 40f187e0888defc2e7412ad35c576bfa0b98afbd..70a3671d5b8af8c1b90e143a40fd7861ab6a4a4a 100644
160--- a/pkg/web/logging.go
161+++ b/pkg/web/logging.go
162@@ -64,14 +64,13 @@ func (r *logWriter) Hijack() (net.Conn, *bufio.ReadWriter, error) {
163 }
164 
165 // NewLoggingMiddleware returns a new logging middleware.
166-func NewLoggingMiddleware(next http.Handler) http.Handler {
167+func NewLoggingMiddleware(next http.Handler, logger *log.Logger) http.Handler {
168 	return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
169-		logger := log.FromContext(r.Context())
170 		start := time.Now()
171 		writer := &logWriter{code: http.StatusOK, ResponseWriter: w}
172 		logger.Debug("request",
173 			"method", r.Method,
174-			"uri", r.RequestURI,
175+			"path", r.URL,
176 			"addr", r.RemoteAddr)
177 		next.ServeHTTP(writer, r)
178 		elapsed := time.Since(start)
179diff --git a/pkg/web/server.go b/pkg/web/server.go
180index 73921e68bf953491bc60f7f6252e38de2e8fcdf2..74a04f5b176bee7d1710f023643436119b181c97 100644
181--- a/pkg/web/server.go
182+++ b/pkg/web/server.go
183@@ -4,12 +4,14 @@ import (
184 	"context"
185 	"net/http"
186 
187+	"github.com/charmbracelet/log"
188 	"github.com/gorilla/handlers"
189 	"github.com/gorilla/mux"
190 )
191 
192 // NewRouter returns a new HTTP router.
193 func NewRouter(ctx context.Context) http.Handler {
194+	logger := log.FromContext(ctx).WithPrefix("http")
195 	router := mux.NewRouter()
196 
197 	// Git routes
198@@ -19,10 +21,10 @@ func NewRouter(ctx context.Context) http.Handler {
199 
200 	// Context handler
201 	// Adds context to the request
202-	h := NewContextHandler(ctx)(router)
203+	h := NewLoggingMiddleware(router, logger)
204+	h = NewContextHandler(ctx)(h)
205 	h = handlers.CompressHandler(h)
206 	h = handlers.RecoveryHandler()(h)
207-	h = NewLoggingMiddleware(h)
208 
209 	return h
210 }
211diff --git a/pkg/web/util.go b/pkg/web/util.go
212index 412d0e00ef14b545fc042462b63bf12626ea7cc5..0e00357a26d4d1239ddad6ba248136d003ae15c5 100644
213--- a/pkg/web/util.go
214+++ b/pkg/web/util.go
215@@ -8,7 +8,7 @@ import (
216 
217 func renderStatus(code int) http.HandlerFunc {
218 	return func(w http.ResponseWriter, _ *http.Request) {
219-		w.WriteHeader(code)
220 		io.WriteString(w, fmt.Sprintf("%d %s", code, http.StatusText(code))) // nolint: errcheck
221+		w.WriteHeader(code)
222 	}
223 }