Make http servers obey --dump headers,bodies

fs/fshttp/fshttpdump/fshttpdump.go

@@ -0,0 +1,97 @@
+package fshttpdump
+
+import (
+	"bytes"
+	"net/http"
+	"net/http/httputil"
+	"sync"
+
+	"github.com/rclone/rclone/fs"
+)
+
+const (
+	separatorReq  = ">>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>"
+	separatorResp = "<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<"
+)
+
+var (
+	logMutex sync.Mutex
+)
+
+// cleanAuth gets rid of one authBuf header within the first 4k
+func cleanAuth(buf, authBuf []byte) []byte {
+	// Find how much buffer to check
+	n := 4096
+	if len(buf) < n {
+		n = len(buf)
+	}
+	// See if there is an Authorization: header
+	i := bytes.Index(buf[:n], authBuf)
+	if i < 0 {
+		return buf
+	}
+	i += len(authBuf)
+	// Overwrite the next 4 chars with 'X'
+	for j := 0; i < len(buf) && j < 4; j++ {
+		if buf[i] == '\n' {
+			break
+		}
+		buf[i] = 'X'
+		i++
+	}
+	// Snip out to the next '\n'
+	j := bytes.IndexByte(buf[i:], '\n')
+	if j < 0 {
+		return buf[:i]
+	}
+	n = copy(buf[i:], buf[i+j:])
+	return buf[:i+n]
+}
+
+var authBufs = [][]byte{
+	[]byte("Authorization: "),
+	[]byte("X-Auth-Token: "),
+}
+
+// cleanAuths gets rid of all the possible Auth headers
+func cleanAuths(buf []byte) []byte {
+	for _, authBuf := range authBufs {
+		buf = cleanAuth(buf, authBuf)
+	}
+	return buf
+}
+
+func DumpRequest(req *http.Request, dump fs.DumpFlags, client bool) {
+	if dump&(fs.DumpHeaders|fs.DumpBodies|fs.DumpAuth|fs.DumpRequests|fs.DumpResponses) != 0 {
+		dumper := httputil.DumpRequestOut
+		if !client {
+			dumper = httputil.DumpRequest
+		}
+		buf, _ := dumper(req, dump&(fs.DumpBodies|fs.DumpRequests) != 0)
+		if dump&fs.DumpAuth == 0 {
+			buf = cleanAuths(buf)
+		}
+		logMutex.Lock()
+		fs.Debugf(nil, "%s", separatorReq)
+		fs.Debugf(nil, "%s (req %p)", "HTTP REQUEST", req)
+		fs.Debugf(nil, "%s", string(buf))
+		fs.Debugf(nil, "%s", separatorReq)
+		logMutex.Unlock()
+	}
+}
+
+func DumpResponse(resp *http.Response, req *http.Request, err error, dump fs.DumpFlags) {
+	if dump&(fs.DumpHeaders|fs.DumpBodies|fs.DumpAuth|fs.DumpRequests|fs.DumpResponses) != 0 {
+		logMutex.Lock()
+		fs.Debugf(nil, "%s", separatorResp)
+		fs.Debugf(nil, "%s (req %p)", "HTTP RESPONSE", req)
+		if err != nil {
+			fs.Debugf(nil, "Error: %v", err)
+		} else {
+			buf, _ := httputil.DumpResponse(resp, dump&(fs.DumpBodies|fs.DumpResponses) != 0)
+			fs.Debugf(nil, "%s", string(buf))
+		}
+		fs.Debugf(nil, "%s", separatorResp)
+		logMutex.Unlock()
+	}
+}

fs/fshttp/fshttpdump/fshttpdump_test.go

@@ -1,4 +1,4 @@
-package fshttp
+package fshttpdump
 
 import (
 	"testing"

fs/fshttp/http.go

@@ -2,7 +2,6 @@
 package fshttp
 
 import (
-	"bytes"
 	"context"
 	"crypto/tls"
 	"crypto/x509"
@@ -10,27 +9,21 @@ import (
 	"net"
 	"net/http"
 	"net/http/cookiejar"
-	"net/http/httputil"
 	"os"
 	"sync"
 	"time"
 
 	"github.com/rclone/rclone/fs"
 	"github.com/rclone/rclone/fs/accounting"
+	"github.com/rclone/rclone/fs/fshttp/fshttpdump"
 	"github.com/rclone/rclone/lib/structs"
 	"golang.org/x/net/publicsuffix"
 )
 
-const (
-	separatorReq  = ">>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>"
-	separatorResp = "<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<"
-)
-
 var (
 	transport    http.RoundTripper
 	noTransport  = new(sync.Once)
 	cookieJar, _ = cookiejar.New(&cookiejar.Options{PublicSuffixList: publicsuffix.List})
-	logMutex     sync.Mutex
 )
 
 // ResetTransport resets the existing transport, allowing it to take new settings.
@@ -204,49 +197,6 @@ func checkServerTime(req *http.Request, resp *http.Response) {
 	checkedHostMu.Unlock()
 }
 
-// cleanAuth gets rid of one authBuf header within the first 4k
-func cleanAuth(buf, authBuf []byte) []byte {
-	// Find how much buffer to check
-	n := 4096
-	if len(buf) < n {
-		n = len(buf)
-	}
-	// See if there is an Authorization: header
-	i := bytes.Index(buf[:n], authBuf)
-	if i < 0 {
-		return buf
-	}
-	i += len(authBuf)
-	// Overwrite the next 4 chars with 'X'
-	for j := 0; i < len(buf) && j < 4; j++ {
-		if buf[i] == '\n' {
-			break
-		}
-		buf[i] = 'X'
-		i++
-	}
-	// Snip out to the next '\n'
-	j := bytes.IndexByte(buf[i:], '\n')
-	if j < 0 {
-		return buf[:i]
-	}
-	n = copy(buf[i:], buf[i+j:])
-	return buf[:i+n]
-}
-
-var authBufs = [][]byte{
-	[]byte("Authorization: "),
-	[]byte("X-Auth-Token: "),
-}
-
-// cleanAuths gets rid of all the possible Auth headers
-func cleanAuths(buf []byte) []byte {
-	for _, authBuf := range authBufs {
-		buf = cleanAuth(buf, authBuf)
-	}
-	return buf
-}
-
 // RoundTrip implements the RoundTripper interface.
 func (t *Transport) RoundTrip(req *http.Request) (resp *http.Response, err error) {
 	// Limit transactions per second if required
@@ -262,34 +212,11 @@ func (t *Transport) RoundTrip(req *http.Request) (resp *http.Response, err error
 		t.filterRequest(req)
 	}
 	// Logf request
-	if t.dump&(fs.DumpHeaders|fs.DumpBodies|fs.DumpAuth|fs.DumpRequests|fs.DumpResponses) != 0 {
+	fshttpdump.DumpRequest(req, t.dump, true)
-		buf, _ := httputil.DumpRequestOut(req, t.dump&(fs.DumpBodies|fs.DumpRequests) != 0)
-		if t.dump&fs.DumpAuth == 0 {
-			buf = cleanAuths(buf)
-		}
-		logMutex.Lock()
-		fs.Debugf(nil, "%s", separatorReq)
-		fs.Debugf(nil, "%s (req %p)", "HTTP REQUEST", req)
-		fs.Debugf(nil, "%s", string(buf))
-		fs.Debugf(nil, "%s", separatorReq)
-		logMutex.Unlock()
-	}
 	// Do round trip
 	resp, err = t.Transport.RoundTrip(req)
 	// Logf response
-	if t.dump&(fs.DumpHeaders|fs.DumpBodies|fs.DumpAuth|fs.DumpRequests|fs.DumpResponses) != 0 {
+	fshttpdump.DumpResponse(resp, req, err, t.dump)
-		logMutex.Lock()
-		fs.Debugf(nil, "%s", separatorResp)
-		fs.Debugf(nil, "%s (req %p)", "HTTP RESPONSE", req)
-		if err != nil {
-			fs.Debugf(nil, "Error: %v", err)
-		} else {
-			buf, _ := httputil.DumpResponse(resp, t.dump&(fs.DumpBodies|fs.DumpResponses) != 0)
-			fs.Debugf(nil, "%s", string(buf))
-		}
-		fs.Debugf(nil, "%s", separatorResp)
-		logMutex.Unlock()
-	}
 	// Update metrics
 	t.metrics.onResponse(req, resp)
 

lib/http/middleware.go

@@ -1,15 +1,18 @@
 package http
 
 import (
+	"bytes"
 	"context"
 	"encoding/base64"
 	"fmt"
+	"io"
 	"net/http"
 	"strings"
 	"sync"
 
 	goauth "github.com/abbot/go-http-auth"
 	"github.com/rclone/rclone/fs"
+	"github.com/rclone/rclone/fs/fshttp/fshttpdump"
 )
 
 // parseAuthorization parses the Authorization header into user, pass
@@ -195,3 +198,79 @@ func MiddlewareStripPrefix(prefix string) Middleware {
 		return http.StripPrefix(prefix, next)
 	}
 }
+
+type dumpWriter struct {
+	w        http.ResponseWriter
+	resp     http.Response
+	buf      bytes.Buffer
+	out      io.Writer
+	dump     fs.DumpFlags
+	dumpBody bool
+}
+
+func newDumpWriter(w http.ResponseWriter, req *http.Request, dump fs.DumpFlags) *dumpWriter {
+	d := &dumpWriter{
+		w: w,
+		resp: http.Response{
+			Status:     "200 probably OK",
+			StatusCode: 200,
+			Proto:      req.Proto,
+			ProtoMajor: req.ProtoMajor,
+			ProtoMinor: req.ProtoMinor,
+		},
+		dump:     dump,
+		dumpBody: dump&(fs.DumpBodies|fs.DumpResponses) != 0,
+	}
+	if d.dumpBody {
+		d.out = io.MultiWriter(w, &d.buf)
+	}
+	return d
+}
+
+// Header returns the header map that will be sent by WriteHeader.
+func (d *dumpWriter) Header() http.Header {
+	return d.w.Header()
+}
+
+// Write writes the data to the connection as part of an HTTP reply.
+func (d *dumpWriter) Write(buf []byte) (int, error) {
+	if d.dumpBody {
+		return d.out.Write(buf)
+	}
+	return d.w.Write(buf)
+}
+
+// WriteHeader sends an HTTP response header with the provided status
+// code.
+func (d *dumpWriter) WriteHeader(statusCode int) {
+	d.resp.StatusCode = statusCode
+	d.w.WriteHeader(statusCode)
+}
+
+// dump the recorded contents.
+func (d *dumpWriter) dumpResponse(req *http.Request) {
+	d.resp.Header = d.w.Header()
+	if d.dumpBody {
+		d.resp.Body = io.NopCloser(bytes.NewBuffer(d.buf.Bytes()))
+	}
+	fshttpdump.DumpResponse(&d.resp, req, nil, d.dump)
+}
+
+// MiddlewareDump dumps requests and responses to the log
+func MiddlewareDump(dump fs.DumpFlags) Middleware {
+	return func(next http.Handler) http.Handler {
+		return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
+			// First dump the incoming request
+			fshttpdump.DumpRequest(r, dump, false)
+
+			// Now intercept the body write
+			d := newDumpWriter(w, r, dump)
+
+			// Do the request
+			next.ServeHTTP(d, r)
+
+			// Now dump the contents
+			d.dumpResponse(r)
+		})
+	}
+}

lib/http/server.go

@@ -19,6 +19,7 @@ import (
 	"time"
 
 	"github.com/go-chi/chi/v5"
+	"github.com/rclone/rclone/fs"
 	"github.com/rclone/rclone/fs/config/flags"
 	"github.com/rclone/rclone/lib/atexit"
 	"github.com/spf13/pflag"
@@ -240,6 +241,13 @@ func NewServer(ctx context.Context, options ...Option) (*Server, error) {
 
 	s.mux.Use(MiddlewareCORS(s.cfg.AllowOrigin))
 
+	// Put this one last for dumping requests / responses
+	ci := fs.GetConfig(context.Background())
+	dump := ci.Dump
+	if dump != 0 {
+		s.mux.Use(MiddlewareDump(dump))
+	}
+
 	s.initAuth()
 
 	for _, addr := range s.cfg.ListenAddr {