printer.go

Documentation: github.com/henvic/httpretty

     1  package httpretty
     2  
     3  import (
     4  	"bufio"
     5  	"bytes"
     6  	"crypto/tls"
     7  	"crypto/x509"
     8  	"fmt"
     9  	"io"
    10  	"io/ioutil"
    11  	"mime"
    12  	"net"
    13  	"net/http"
    14  	"sort"
    15  	"strings"
    16  	"time"
    17  
    18  	"github.com/henvic/httpretty/internal/color"
    19  	"github.com/henvic/httpretty/internal/header"
    20  )
    21  
    22  func newPrinter(l *Logger) printer {
    23  	l.mu.Lock()
    24  	defer l.mu.Unlock()
    25  
    26  	return printer{
    27  		logger:  l,
    28  		flusher: l.flusher,
    29  	}
    30  }
    31  
    32  type printer struct {
    33  	flusher Flusher
    34  
    35  	logger *Logger
    36  	buf    bytes.Buffer
    37  }
    38  
    39  func (p *printer) maybeOnReady() {
    40  	if p.flusher == OnReady {
    41  		p.flush()
    42  	}
    43  }
    44  
    45  func (p *printer) flush() {
    46  	if p.flusher == NoBuffer {
    47  		return
    48  	}
    49  
    50  	p.logger.mu.Lock()
    51  	defer p.logger.mu.Unlock()
    52  	defer p.buf.Reset()
    53  	w := p.logger.getWriter()
    54  	fmt.Fprint(w, p.buf.String())
    55  }
    56  
    57  func (p *printer) print(a ...interface{}) {
    58  	p.logger.mu.Lock()
    59  	defer p.logger.mu.Unlock()
    60  	w := p.logger.getWriter()
    61  
    62  	if p.flusher == NoBuffer {
    63  		fmt.Fprint(w, a...)
    64  		return
    65  	}
    66  
    67  	fmt.Fprint(&p.buf, a...)
    68  }
    69  
    70  func (p *printer) println(a ...interface{}) {
    71  	p.logger.mu.Lock()
    72  	defer p.logger.mu.Unlock()
    73  	w := p.logger.getWriter()
    74  
    75  	if p.flusher == NoBuffer {
    76  		fmt.Fprintln(w, a...)
    77  		return
    78  	}
    79  
    80  	fmt.Fprintln(&p.buf, a...)
    81  }
    82  
    83  func (p *printer) printf(format string, a ...interface{}) {
    84  	p.logger.mu.Lock()
    85  	defer p.logger.mu.Unlock()
    86  	w := p.logger.getWriter()
    87  
    88  	if p.flusher == NoBuffer {
    89  		fmt.Fprintf(w, format, a...)
    90  		return
    91  	}
    92  
    93  	fmt.Fprintf(&p.buf, format, a...)
    94  }
    95  
    96  func (p *printer) printRequest(req *http.Request) {
    97  	if p.logger.RequestHeader {
    98  		p.printRequestHeader(req)
    99  		p.maybeOnReady()
   100  	}
   101  
   102  	if p.logger.RequestBody && req.Body != nil {
   103  		p.printRequestBody(req)
   104  		p.maybeOnReady()
   105  	}
   106  }
   107  
   108  func (p *printer) printRequestInfo(req *http.Request) {
   109  	to := req.URL.String()
   110  
   111  	// req.URL.Host is empty on the request received by a server
   112  	if req.URL.Host == "" {
   113  		to = req.Host + to
   114  		schema := "http://"
   115  
   116  		if req.TLS != nil {
   117  			schema = "https://"
   118  		}
   119  
   120  		to = schema + to
   121  	}
   122  
   123  	p.printf("* Request to %s\n", p.format(color.FgBlue, to))
   124  
   125  	if req.RemoteAddr != "" {
   126  		p.printf("* Request from %s\n", p.format(color.FgBlue, req.RemoteAddr))
   127  	}
   128  }
   129  
   130  // checkFilter checkes if the request is filtered and if the Request value is nil.
   131  func (p *printer) checkFilter(req *http.Request) (skip bool) {
   132  	filter := p.logger.getFilter()
   133  
   134  	if req == nil {
   135  		p.printf("> %s\n", p.format(color.FgRed, "error: null request"))
   136  		return true
   137  	}
   138  
   139  	if filter == nil {
   140  		return false
   141  	}
   142  
   143  	ok, err := safeFilter(filter, req)
   144  
   145  	if err != nil {
   146  		p.printf("* cannot filter request: %s: %s\n", p.format(color.FgBlue, fmt.Sprintf("%s %s", req.Method, req.URL)), p.format(color.FgRed, err.Error()))
   147  		return false // never filter out the request if the filter errored
   148  	}
   149  
   150  	return ok
   151  }
   152  
   153  func safeFilter(filter Filter, req *http.Request) (skip bool, err error) {
   154  	defer func() {
   155  		if e := recover(); e != nil {
   156  			err = fmt.Errorf("panic: %v", e)
   157  		}
   158  	}()
   159  	return filter(req)
   160  }
   161  
   162  func (p *printer) printResponse(resp *http.Response) {
   163  	if resp == nil {
   164  		p.printf("< %s\n", p.format(color.FgRed, "error: null response"))
   165  		p.maybeOnReady()
   166  		return
   167  	}
   168  
   169  	if p.logger.ResponseHeader {
   170  		p.printResponseHeader(resp.Proto, resp.Status, resp.Header)
   171  		p.maybeOnReady()
   172  	}
   173  
   174  	if p.logger.ResponseBody && resp.Body != nil && (resp.Request == nil || resp.Request.Method != http.MethodHead) {
   175  		p.printResponseBodyOut(resp)
   176  		p.maybeOnReady()
   177  	}
   178  
   179  }
   180  
   181  func (p *printer) checkBodyFiltered(h http.Header) (skip bool, err error) {
   182  	if f := p.logger.getBodyFilter(); f != nil {
   183  		defer func() {
   184  			if e := recover(); e != nil {
   185  				p.printf("* panic while filtering body: %v\n", e)
   186  			}
   187  		}()
   188  		return f(h)
   189  	}
   190  	return false, nil
   191  }
   192  
   193  func (p *printer) printResponseBodyOut(resp *http.Response) {
   194  	if resp.ContentLength == 0 {
   195  		return
   196  	}
   197  
   198  	skip, err := p.checkBodyFiltered(resp.Header)
   199  
   200  	if err != nil {
   201  		p.printf("* %s\n", p.format(color.FgRed, "error on response body filter: ", err.Error()))
   202  	}
   203  
   204  	if skip {
   205  		return
   206  	}
   207  
   208  	if contentType := resp.Header.Get("Content-Type"); contentType != "" && isBinaryMediatype(contentType) {
   209  		p.println("* body contains binary data")
   210  		return
   211  	}
   212  
   213  	if p.logger.MaxResponseBody > 0 && resp.ContentLength > p.logger.MaxResponseBody {
   214  		p.printf("* body is too long (%d bytes) to print, skipping (longer than %d bytes)\n", resp.ContentLength, p.logger.MaxResponseBody)
   215  		return
   216  	}
   217  
   218  	contentType := resp.Header.Get("Content-Type")
   219  
   220  	if resp.ContentLength == -1 {
   221  		if newBody := p.printBodyUnknownLength(contentType, p.logger.MaxResponseBody, resp.Body); newBody != nil {
   222  			resp.Body = newBody
   223  		}
   224  
   225  		return
   226  	}
   227  
   228  	var buf bytes.Buffer
   229  	tee := io.TeeReader(resp.Body, &buf)
   230  	defer resp.Body.Close()
   231  
   232  	defer func() {
   233  		resp.Body = ioutil.NopCloser(&buf)
   234  	}()
   235  
   236  	p.printBodyReader(contentType, tee)
   237  }
   238  
   239  // isBinary uses heuristics to guess if file is binary (actually, "printable" in the terminal).
   240  // See discussion at https://groups.google.com/forum/#!topic/golang-nuts/YeLL7L7SwWs
   241  func isBinary(body []byte) bool {
   242  	if len(body) > 512 {
   243  		body = body[512:]
   244  	}
   245  
   246  	// If file contains UTF-8 OR UTF-16 BOM, consider it non-binary.
   247  	// Reference: https://tools.ietf.org/html/draft-ietf-websec-mime-sniff-03#section-5
   248  	if len(body) >= 3 && (bytes.Equal(body[:2], []byte{0xFE, 0xFF}) || // UTF-16BE BOM
   249  		bytes.Equal(body[:2], []byte{0xFF, 0xFE}) || // UTF-16LE BOM
   250  		bytes.Equal(body[:3], []byte{0xEF, 0xBB, 0xBF})) { // UTF-8 BOM
   251  		return false
   252  	}
   253  
   254  	// If all of the first n octets are binary data octets, consider it binary.
   255  	// Reference: https://github.com/golang/go/blob/349e7df2c3d0f9b5429e7c86121499c137faac7e/src/net/http/sniff.go#L297-L309
   256  	// c.f. section 5, step 4.
   257  	for _, b := range body {
   258  		switch {
   259  		case b <= 0x08,
   260  			b == 0x0B,
   261  			0x0E <= b && b <= 0x1A,
   262  			0x1C <= b && b <= 0x1F:
   263  			return true
   264  		}
   265  	}
   266  
   267  	// Otherwise, check against a white list of binary mimetypes.
   268  	mediatype, _, err := mime.ParseMediaType(http.DetectContentType(body))
   269  	if err != nil {
   270  		return false
   271  	}
   272  
   273  	return isBinaryMediatype(mediatype)
   274  }
   275  
   276  var binaryMediatypes = map[string]struct{}{
   277  	"application/pdf":               struct{}{},
   278  	"application/postscript":        struct{}{},
   279  	"image":                         struct{}{}, // for practical reasons, any image (including SVG) is considered binary data
   280  	"audio":                         struct{}{},
   281  	"application/ogg":               struct{}{},
   282  	"video":                         struct{}{},
   283  	"application/vnd.ms-fontobject": struct{}{},
   284  	"font":                          struct{}{},
   285  	"application/x-gzip":            struct{}{},
   286  	"application/zip":               struct{}{},
   287  	"application/x-rar-compressed":  struct{}{},
   288  	"application/wasm":              struct{}{},
   289  }
   290  
   291  func isBinaryMediatype(mediatype string) bool {
   292  	if _, ok := binaryMediatypes[mediatype]; ok {
   293  		return true
   294  	}
   295  
   296  	if parts := strings.SplitN(mediatype, "/", 2); len(parts) == 2 {
   297  		if _, ok := binaryMediatypes[parts[0]]; ok {
   298  			return true
   299  		}
   300  	}
   301  
   302  	return false
   303  }
   304  
   305  const maxDefaultUnknownReadable = 4096 // bytes
   306  
   307  func (p *printer) printBodyUnknownLength(contentType string, maxLength int64, r io.ReadCloser) (newBody io.ReadCloser) {
   308  	shortReader := bufio.NewReader(r)
   309  
   310  	if maxLength == 0 {
   311  		maxLength = maxDefaultUnknownReadable
   312  	}
   313  
   314  	pb := make([]byte, maxLength+1) // read one extra bit to assure the length is longer than acceptable
   315  	n, err := io.ReadFull(shortReader, pb)
   316  	pb = pb[0:n] // trim any nil symbols left after writing in the byte slice.
   317  	buf := bytes.NewReader(pb)
   318  	newBody = newBodyReaderBuf(buf, r)
   319  
   320  	switch {
   321  	// Server requests always return req.Body != nil, but the Reader returns io.EOF immediately.
   322  	// Avoiding returning early to mitigate any risk of bad reader implementations that might
   323  	// send something even after returning io.EOF if read again.
   324  	case err == io.EOF && n == 0:
   325  	case err == nil && int64(n) > maxLength:
   326  		p.printf("* body is too long, skipping (contains more than %d bytes)\n", n-1)
   327  	case err == io.ErrUnexpectedEOF || err == nil:
   328  		// cannot pass same bytes reader below because we only read it once.
   329  		p.printBodyReader(contentType, bytes.NewReader(pb))
   330  	default:
   331  		p.printf("* cannot read body: %v (%d bytes read)\n", err, n)
   332  	}
   333  	return
   334  }
   335  
   336  func findPeerCertificate(hostname string, state *tls.ConnectionState) (cert *x509.Certificate) {
   337  	if chains := state.VerifiedChains; chains != nil && chains[0] != nil && chains[0][0] != nil {
   338  		return chains[0][0]
   339  	}
   340  
   341  	if hostname == "" && len(state.PeerCertificates) > 0 {
   342  		// skip finding a match for a given hostname if hostname is not available (e.g., a client certificate)
   343  		return state.PeerCertificates[0]
   344  	}
   345  
   346  	// the chain is not created when tls.Config.InsecureSkipVerify is set, then let's try to find a match to display
   347  	for _, cert := range state.PeerCertificates {
   348  		if err := cert.VerifyHostname(hostname); err == nil {
   349  			return cert
   350  		}
   351  	}
   352  
   353  	return nil
   354  }
   355  
   356  func (p *printer) printTLSInfo(state *tls.ConnectionState, skipVerifyChains bool) {
   357  	if state == nil {
   358  		return
   359  	}
   360  
   361  	protocol := tlsProtocolVersions[state.Version]
   362  
   363  	if protocol == "" {
   364  		protocol = fmt.Sprintf("%#v", state.Version)
   365  	}
   366  
   367  	cipher := tlsCiphers[state.CipherSuite]
   368  
   369  	if cipher == "" {
   370  		cipher = fmt.Sprintf("%#v", state.CipherSuite)
   371  	}
   372  
   373  	p.printf("* TLS connection using %s / %s", p.format(color.FgBlue, protocol), p.format(color.FgBlue, cipher))
   374  
   375  	if !skipVerifyChains && state.VerifiedChains == nil {
   376  		p.print(" (insecure=true)")
   377  	}
   378  
   379  	p.println()
   380  
   381  	if state.NegotiatedProtocol != "" {
   382  		p.printf("* ALPN: %v accepted\n", p.format(color.FgBlue, state.NegotiatedProtocol))
   383  	}
   384  }
   385  
   386  func (p *printer) printOutgoingClientTLS(config *tls.Config) {
   387  	if config == nil || len(config.Certificates) == 0 {
   388  		return
   389  	}
   390  
   391  	p.println("* Client certificate:")
   392  	cert := config.Certificates[0].Leaf
   393  
   394  	if cert == nil {
   395  		// Please notice tls.Config.BuildNameToCertificate() doesn't store the certificate Leaf field.
   396  		// You need to explicitly parse and store it with something such as:
   397  		// cert.Leaf, err = x509.ParseCertificate(cert.Certificate)
   398  		p.println(`** unparsed certificate found, skipping`)
   399  		return
   400  	}
   401  
   402  	p.printCertificate("", cert)
   403  }
   404  
   405  func (p *printer) printIncomingClientTLS(state *tls.ConnectionState) {
   406  	// if no TLS state is null or no client TLS certificate is found, return early.
   407  	if state == nil || len(state.PeerCertificates) == 0 {
   408  		return
   409  	}
   410  
   411  	p.println("* Client certificate:")
   412  	cert := findPeerCertificate("", state)
   413  
   414  	if cert == nil {
   415  		p.println(p.format(color.FgRed, "** No valid certificate was found"))
   416  		return
   417  	}
   418  
   419  	p.printCertificate("", cert)
   420  }
   421  
   422  func (p *printer) printTLSServer(host string, state *tls.ConnectionState) {
   423  	if state == nil {
   424  		return
   425  	}
   426  
   427  	hostname, _, err := net.SplitHostPort(host)
   428  
   429  	if err != nil {
   430  		// assume the error is due to "missing port in address"
   431  		hostname = host
   432  	}
   433  
   434  	p.println("* Server certificate:")
   435  	cert := findPeerCertificate(hostname, state)
   436  
   437  	if cert == nil {
   438  		p.println(p.format(color.FgRed, "** No valid certificate was found"))
   439  		return
   440  	}
   441  
   442  	// server certificate messages are slightly similar to how "curl -v" shows
   443  	p.printCertificate(hostname, cert)
   444  }
   445  
   446  func (p *printer) printCertificate(hostname string, cert *x509.Certificate) {
   447  	p.printf(`*  subject: %v
   448  *  start date: %v
   449  *  expire date: %v
   450  *  issuer: %v
   451  `,
   452  		p.format(color.FgBlue, cert.Subject),
   453  		p.format(color.FgBlue, cert.NotBefore.Format(time.UnixDate)),
   454  		p.format(color.FgBlue, cert.NotAfter.Format(time.UnixDate)),
   455  		p.format(color.FgBlue, cert.Issuer),
   456  	)
   457  
   458  	if hostname == "" {
   459  		return
   460  	}
   461  
   462  	if err := cert.VerifyHostname(hostname); err != nil {
   463  		p.printf("*  %s\n", p.format(color.FgRed, err.Error()))
   464  		return
   465  	}
   466  
   467  	p.println("*  TLS certificate verify ok.")
   468  }
   469  
   470  func (p *printer) printServerResponse(req *http.Request, rec *responseRecorder) {
   471  	if p.logger.ResponseHeader {
   472  		// TODO(henvic): see how httptest.ResponseRecorder adds extra headers due to Content-Type detection
   473  		// and other stuff (Date). It would be interesting to show them here too (either as default or opt-in).
   474  		p.printResponseHeader(req.Proto, fmt.Sprintf("%d %s", rec.statusCode, http.StatusText(rec.statusCode)), rec.Header())
   475  	}
   476  
   477  	if !p.logger.ResponseBody || rec.size == 0 {
   478  		return
   479  	}
   480  
   481  	skip, err := p.checkBodyFiltered(rec.Header())
   482  
   483  	if err != nil {
   484  		p.printf("* %s\n", p.format(color.FgRed, "error on response body filter: ", err.Error()))
   485  	}
   486  
   487  	if skip {
   488  		return
   489  	}
   490  
   491  	if mediatype := req.Header.Get("Content-Type"); mediatype != "" && isBinaryMediatype(mediatype) {
   492  		p.println("* body contains binary data")
   493  		return
   494  	}
   495  
   496  	if p.logger.MaxResponseBody > 0 && rec.size > p.logger.MaxResponseBody {
   497  		p.printf("* body is too long (%d bytes) to print, skipping (longer than %d bytes)\n", rec.size, p.logger.MaxResponseBody)
   498  		return
   499  	}
   500  
   501  	p.printBodyReader(rec.Header().Get("Content-Type"), rec.buf)
   502  }
   503  
   504  func (p *printer) printResponseHeader(proto, status string, h http.Header) {
   505  	p.printf("< %s %s\n",
   506  		p.format(color.FgBlue, color.Bold, proto),
   507  		p.format(color.FgRed, status))
   508  
   509  	p.printHeaders('<', h)
   510  	p.println()
   511  }
   512  
   513  func (p *printer) printBodyReader(contentType string, r io.Reader) {
   514  	mediatype, _, _ := mime.ParseMediaType(contentType)
   515  	body, err := ioutil.ReadAll(r)
   516  
   517  	if err != nil {
   518  		p.printf("* cannot read body: %v\n", p.format(color.FgRed, err.Error()))
   519  		return
   520  	}
   521  
   522  	if isBinary(body) {
   523  		p.println("* body contains binary data")
   524  		return
   525  	}
   526  
   527  	for _, f := range p.logger.Formatters {
   528  		if ok := p.safeBodyMatch(f, mediatype); !ok {
   529  			continue
   530  		}
   531  
   532  		var formatted bytes.Buffer
   533  		switch err := p.safeBodyFormat(f, &formatted, body); {
   534  		case err != nil:
   535  			p.printf("* body cannot be formatted: %v\n%s\n", p.format(color.FgRed, err.Error()), string(body))
   536  		default:
   537  			p.println(formatted.String())
   538  		}
   539  		return
   540  	}
   541  
   542  	p.println(string(body))
   543  }
   544  
   545  func (p *printer) safeBodyMatch(f Formatter, mediatype string) bool {
   546  	defer func() {
   547  		if e := recover(); e != nil {
   548  			p.printf("* panic while testing body format: %v\n", e)
   549  		}
   550  	}()
   551  
   552  	return f.Match(mediatype)
   553  }
   554  
   555  func (p *printer) safeBodyFormat(f Formatter, w io.Writer, src []byte) (err error) {
   556  	defer func() {
   557  		// should not return panic as error because we want to try the next formatter
   558  		if e := recover(); e != nil {
   559  			err = fmt.Errorf("panic: %v", e)
   560  		}
   561  	}()
   562  
   563  	return f.Format(w, src)
   564  }
   565  
   566  func (p *printer) format(s ...interface{}) string {
   567  	if p.logger.Colors {
   568  		return color.Format(s...)
   569  	}
   570  
   571  	return color.StripAttributes(s...)
   572  }
   573  
   574  func (p *printer) printHeaders(prefix rune, h http.Header) {
   575  	if !p.logger.SkipSanitize {
   576  		h = header.Sanitize(header.DefaultSanitizers, h)
   577  	}
   578  
   579  	skipped := p.logger.cloneSkipHeader()
   580  
   581  	for _, key := range sortHeaderKeys(h) {
   582  		for _, v := range h[key] {
   583  			if _, skip := skipped[key]; skip {
   584  				continue
   585  			}
   586  			p.printf("%c %s%s %s\n", prefix,
   587  				p.format(color.FgBlue, color.Bold, key),
   588  				p.format(color.FgRed, ":"),
   589  				p.format(color.FgYellow, v))
   590  		}
   591  	}
   592  }
   593  
   594  func sortHeaderKeys(h http.Header) []string {
   595  	keys := make([]string, 0, len(h))
   596  
   597  	for key := range h {
   598  		keys = append(keys, key)
   599  	}
   600  
   601  	sort.Strings(keys)
   602  
   603  	return keys
   604  }
   605  
   606  func (p *printer) printRequestHeader(req *http.Request) {
   607  	p.printf("> %s %s %s\n",
   608  		p.format(color.FgBlue, color.Bold, req.Method),
   609  		p.format(color.FgYellow, req.URL.RequestURI()),
   610  		p.format(color.FgBlue, req.Proto))
   611  
   612  	host := req.Host
   613  
   614  	if host == "" {
   615  		host = req.URL.Host
   616  	}
   617  
   618  	if host != "" {
   619  		p.printf("> %s%s %s\n",
   620  			p.format(color.FgBlue, color.Bold, "Host"),
   621  			p.format(color.FgRed, ":"),
   622  			p.format(color.FgYellow, host),
   623  		)
   624  	}
   625  
   626  	p.printHeaders('>', req.Header)
   627  	p.println()
   628  }
   629  
   630  func (p *printer) printRequestBody(req *http.Request) {
   631  	// For client requests, a request with zero content-length and no body is also treated as unknown.
   632  	if req.Body == nil {
   633  		return
   634  	}
   635  
   636  	skip, err := p.checkBodyFiltered(req.Header)
   637  
   638  	if err != nil {
   639  		p.printf("* %s\n", p.format(color.FgRed, "error on request body filter: ", err.Error()))
   640  	}
   641  
   642  	if skip {
   643  		return
   644  	}
   645  
   646  	if mediatype := req.Header.Get("Content-Type"); mediatype != "" && isBinaryMediatype(mediatype) {
   647  		p.println("* body contains binary data")
   648  		return
   649  	}
   650  
   651  	// TODO(henvic): add support for printing multipart/formdata information as body (to responses too).
   652  	if p.logger.MaxRequestBody > 0 && req.ContentLength > p.logger.MaxRequestBody {
   653  		p.printf("* body is too long (%d bytes) to print, skipping (longer than %d bytes)\n",
   654  			req.ContentLength, p.logger.MaxRequestBody)
   655  		return
   656  	}
   657  
   658  	contentType := req.Header.Get("Content-Type")
   659  
   660  	if req.ContentLength > 0 {
   661  		var buf bytes.Buffer
   662  		tee := io.TeeReader(req.Body, &buf)
   663  		defer req.Body.Close()
   664  
   665  		defer func() {
   666  			req.Body = ioutil.NopCloser(&buf)
   667  		}()
   668  
   669  		p.printBodyReader(contentType, tee)
   670  		return
   671  	}
   672  
   673  	if newBody := p.printBodyUnknownLength(contentType, p.logger.MaxRequestBody, req.Body); newBody != nil {
   674  		req.Body = newBody
   675  	}
   676  }
   677  
   678  func (p *printer) printTimeRequest() (end func()) {
   679  	startRequest := time.Now()
   680  
   681  	p.printf("* Request at %v\n", startRequest)
   682  
   683  	return func() {
   684  		p.printf("* Request took %v\n", time.Since(startRequest))
   685  	}
   686  }
   687
View as plain text