golift.io/starr@v1.0.0/debuglog/roundtripper.go (about)

     1  // Package debuglog provides a RoundTripper you can put into
     2  // an HTTP client Transport to log requests made with that client.
     3  // This has been proven useful for finding starr app API payloads,
     4  // and as a general debug log wrapper for an integrating application.
     5  package debuglog
     6  
     7  import (
     8  	"bytes"
     9  	"fmt"
    10  	"io"
    11  	"log"
    12  	"net/http"
    13  	"strings"
    14  )
    15  
    16  // Config is the input data for the logger.
    17  type Config struct {
    18  	// Limit logged JSON payloads to this many bytes. 0=unlimited
    19  	MaxBody int
    20  	// This is where logs go. If not set they go to log.Printf.
    21  	Debugf func(string, ...interface{})
    22  	// This can be used for byte counters, but is optional otherwise.
    23  	Caller Caller
    24  	// Any strings in this list are replaced with <recated> in the log output.
    25  	// Useful for hiding api keys and passwords from debug logs. String must be 4+ chars.
    26  	Redact []string
    27  }
    28  
    29  const minRedactChars = 4
    30  
    31  // Caller is a callback function you may use to collect statistics.
    32  type Caller func(status, method string, sentBytes, rcvdBytes int, err error)
    33  
    34  // LoggingRoundTripper allows us to use a datacounter to log http request data.
    35  type LoggingRoundTripper struct {
    36  	next   http.RoundTripper // The next Transport to call after logging.
    37  	config *Config
    38  }
    39  
    40  type fakeCloser struct {
    41  	io.Reader
    42  	CloseFn func() error
    43  	Body    *bytes.Buffer
    44  	Sent    *bytes.Buffer
    45  	Method  string
    46  	URL     string
    47  	Status  string
    48  	Header  http.Header
    49  	*Config
    50  }
    51  
    52  // NewLoggingRoundTripper returns a round tripper to log requests counts and response sizes.
    53  func NewLoggingRoundTripper(config Config, next http.RoundTripper) *LoggingRoundTripper {
    54  	if next == nil {
    55  		next = http.DefaultTransport
    56  	}
    57  
    58  	if config.Debugf == nil {
    59  		config.Debugf = log.Printf
    60  	}
    61  
    62  	return &LoggingRoundTripper{
    63  		next:   next,
    64  		config: &config,
    65  	}
    66  }
    67  
    68  // RoundTrip satisfies the http.RoundTripper interface.
    69  func (rt *LoggingRoundTripper) RoundTrip(req *http.Request) (*http.Response, error) {
    70  	buf := bytes.Buffer{}
    71  	if req.Body != nil {
    72  		sent := io.TeeReader(req.Body, &buf)
    73  		req.Body = io.NopCloser(sent)
    74  
    75  		defer req.Body.Close()
    76  	}
    77  
    78  	resp, err := rt.next.RoundTrip(req)
    79  	if err != nil {
    80  		if rt.config.Caller != nil {
    81  			// Send this report now since .Close() will never be called.
    82  			rt.config.Caller("000 Failed", req.Method, buf.Len(), 0, err)
    83  		}
    84  
    85  		return resp, err //nolint:wrapcheck
    86  	}
    87  
    88  	resp.Body = rt.newFakeCloser(resp, &buf)
    89  
    90  	return resp, nil
    91  }
    92  
    93  func (rt *LoggingRoundTripper) newFakeCloser(resp *http.Response, sent *bytes.Buffer) io.ReadCloser {
    94  	var buf bytes.Buffer
    95  
    96  	return &fakeCloser{
    97  		CloseFn: resp.Body.Close,
    98  		Reader:  io.TeeReader(resp.Body, &buf),
    99  		Body:    &buf,
   100  		Method:  resp.Request.Method,
   101  		Status:  resp.Status,
   102  		URL:     resp.Request.URL.String(),
   103  		Sent:    sent,
   104  		Header:  resp.Header,
   105  		Config:  rt.config,
   106  	}
   107  }
   108  
   109  // Close closes the response Body, logs the request, and fires the call back.
   110  func (f *fakeCloser) Close() error {
   111  	sentBytes, rcvdBytes := f.logRequest()
   112  	if f.Caller != nil {
   113  		f.Caller(f.Status, f.Method, sentBytes, rcvdBytes, nil)
   114  	}
   115  
   116  	return f.CloseFn()
   117  }
   118  
   119  func (f *fakeCloser) logRequest() (int, int) {
   120  	var (
   121  		sentBytes = f.Sent.Len()
   122  		rcvdBytes = f.Body.Len()
   123  		sent      = f.Sent.String()
   124  		rcvd      = f.Body.String()
   125  	)
   126  
   127  	if f.MaxBody > 0 && len(sent) > f.MaxBody {
   128  		sent = sent[:f.MaxBody] + " <data truncated>"
   129  	}
   130  
   131  	switch ctype := f.Header.Get("content-type"); {
   132  	case !strings.Contains(ctype, "json"):
   133  		// We only log JSON. Need something else? Ask!
   134  		rcvd = "<data not logged, content-type: " + ctype + ">"
   135  	case f.MaxBody > 0 && len(rcvd) > f.MaxBody:
   136  		rcvd = rcvd[:f.MaxBody] + " <body truncated>"
   137  	}
   138  
   139  	if sentBytes > 0 {
   140  		f.redactLog("Sent (%s) %d bytes to %s: %s\n Response: %s %d bytes\n%s%s)",
   141  			f.Method, sentBytes, f.URL, sent, f.Status, rcvdBytes, f.headers(), rcvd)
   142  	} else {
   143  		f.redactLog("Sent (%s) to %s, Response: %s %d bytes\n%s%s",
   144  			f.Method, f.URL, f.Status, rcvdBytes, f.headers(), rcvd)
   145  	}
   146  
   147  	return sentBytes, rcvdBytes
   148  }
   149  
   150  func (f *fakeCloser) headers() string {
   151  	var headers string
   152  
   153  	for header, values := range f.Header {
   154  		for _, value := range values {
   155  			headers += header + ": " + value + "\n"
   156  		}
   157  	}
   158  
   159  	return headers
   160  }
   161  
   162  func (f *fakeCloser) redactLog(msg string, format ...interface{}) {
   163  	msg = fmt.Sprintf(msg, format...)
   164  
   165  	for _, redact := range f.Redact {
   166  		if len(redact) >= minRedactChars {
   167  			msg = strings.ReplaceAll(msg, redact, "<redacted>")
   168  		}
   169  	}
   170  
   171  	f.Debugf(msg)
   172  }