feat: print http stat with color

go.mod

@@ -5,6 +5,7 @@ go 1.16
 require (
 	github.com/andybalholm/brotli v1.0.4
 	github.com/denisbrodbeck/machineid v1.0.1
+	github.com/fatih/color v1.13.0
 	github.com/getsentry/sentry-go v0.13.0
 	github.com/google/uuid v1.3.0
 	github.com/gorilla/websocket v1.4.1

go.sum

@@ -106,8 +106,9 @@ github.com/envoyproxy/go-control-plane v0.9.9-0.20210217033140-668b12f5399d/go.m
 github.com/envoyproxy/go-control-plane v0.9.10-0.20210907150352-cf90f659a021/go.mod h1:AFq3mo9L8Lqqiid3OhADV3RfLJnjiw63cSpi+fDTRC0=
 github.com/envoyproxy/protoc-gen-validate v0.1.0/go.mod h1:iSmxcyjqTsJpI2R4NaDN7+kN2VEUnK/pcBlmesArF7c=
 github.com/etcd-io/bbolt v1.3.3/go.mod h1:ZF2nL25h33cCyBtcyWeZ2/I3HQOfTP+0PIEvHjkjCrw=
-github.com/fatih/color v1.7.0 h1:DkWD4oS2D8LGGgTQ6IvwJJXSL5Vp2ffcQg58nFV38Ys=
 github.com/fatih/color v1.7.0/go.mod h1:Zm6kSWBoL9eyXnKyktHP6abPY2pDugNf5KwzbycvMj4=
+github.com/fatih/color v1.13.0 h1:8LOYc1KYPPmyKMuN8QV2DNRWNbLo6LZ0iLs8+mlH53w=
+github.com/fatih/color v1.13.0/go.mod h1:kLAiJbzzSOZDVNGyDpeOxJ47H46qBXwg5ILebYFFOfk=
 github.com/fatih/structs v1.1.0/go.mod h1:9NiDSp5zOcgEDl+j00MP/WkGVPOlPRLejGD8Ga6PJ7M=
 github.com/fsnotify/fsnotify v1.4.7/go.mod h1:jwhsz4b93w/PPRr/qN1Yymfu8t87LnFCMoQvtojpjFo=
 github.com/fsnotify/fsnotify v1.4.9/go.mod h1:znqG4EE+3YCdAaPaxE2ZRY/06pZUdp0tY4IgpuI1SZQ=
@@ -303,6 +304,7 @@ github.com/mattn/go-colorable v0.0.9/go.mod h1:9vuHe8Xs5qXnSaW/c/ABM9alt+Vo+STaO
 github.com/mattn/go-colorable v0.1.2/go.mod h1:U0ppj6V5qS13XJ6of8GYAs25YV2eR4EVcfRqFIhoBtE=
 github.com/mattn/go-colorable v0.1.4/go.mod h1:U0ppj6V5qS13XJ6of8GYAs25YV2eR4EVcfRqFIhoBtE=
 github.com/mattn/go-colorable v0.1.8/go.mod h1:u6P/XSegPjTcexA+o6vUJrdnUu04hMope9wVRipJSqc=
+github.com/mattn/go-colorable v0.1.9/go.mod h1:u6P/XSegPjTcexA+o6vUJrdnUu04hMope9wVRipJSqc=
 github.com/mattn/go-colorable v0.1.11 h1:nQ+aFkoE2TMGc0b68U2OKSexC+eq46+XwZzWXHRmPYs=
 github.com/mattn/go-colorable v0.1.11/go.mod h1:u5H1YNBxpqRaxsYJYSkiCWKzEfiAb1Gb520KVy5xxl4=
 github.com/mattn/go-isatty v0.0.3/go.mod h1:M+lRXTBqGeGNdLjl/ufCoiOlB5xdOkqRJdNxMWT7Zi4=

hrp/internal/httpstat/main.go

@@ -1,15 +1,64 @@
 // Package httpstat traces HTTP latency infomation (DNSLookup, TCP Connection and so on) on any golang HTTP request.
 // It uses `httptrace` package.
-// Forked from https://github.com/tcnksm/go-httpstat
+// Inspired by https://github.com/tcnksm/go-httpstat and https://github.com/davecheney/httpstat
 package httpstat
 
 import (
 	"context"
 	"crypto/tls"
+	"fmt"
 	"net/http/httptrace"
+	"strconv"
+	"strings"
 	"time"
+
+	"github.com/fatih/color"
+	"github.com/rs/zerolog/log"
 )
 
+const (
+	httpsTemplate = "\n" +
+		`  DNS Lookup   TCP Connection   TLS Handshake   Server Processing   Content Transfer` + "\n" +
+		`[%s  |     %s  |    %s  |        %s  |       %s  ]` + "\n" +
+		`            |                |               |                   |                  |` + "\n" +
+		`   namelookup:%s      |               |                   |                  |` + "\n" +
+		`                       connect:%s     |                   |                  |` + "\n" +
+		`                                   pretransfer:%s         |                  |` + "\n" +
+		`                                                     starttransfer:%s        |` + "\n" +
+		`                                                                                total:%s` + "\n\n"
+
+	httpTemplate = "\n" +
+		`   DNS Lookup   TCP Connection   Server Processing   Content Transfer` + "\n" +
+		`[ %s  |     %s  |        %s  |       %s  ]` + "\n" +
+		`             |                |                   |                  |` + "\n" +
+		`    namelookup:%s      |                   |                  |` + "\n" +
+		`                        connect:%s         |                  |` + "\n" +
+		`                                      starttransfer:%s        |` + "\n" +
+		`                                                                 total:%s` + "\n\n"
+)
+
+func fmta(d time.Duration) string {
+	return color.BlueString("%7dms", int(d.Milliseconds()))
+}
+
+func fmtb(d time.Duration) string {
+	return color.MagentaString("%-9s", strconv.Itoa(int(d.Milliseconds()))+"ms")
+}
+
+func grayscale(code color.Attribute) func(string, ...interface{}) string {
+	return color.New(code + 232).SprintfFunc()
+}
+
+func colorize(s string) string {
+	v := strings.Split(s, "\n")
+	v[0] = grayscale(16)(v[0])
+	return strings.Join(v, "\n")
+}
+
+func printf(format string, a ...interface{}) (n int, err error) {
+	return fmt.Fprintf(color.Output, format, a...)
+}
+
 // Stat stores httpstat info.
 type Stat struct {
 	// The following are duration for each phase
@@ -61,6 +110,11 @@ func (s *Stat) Finish() {
 	s.Total = s.transferDone.Sub(s.dnsStart)
 }
 
+func (s *Stat) assertSchemaHTTP() bool {
+	// HTTP other than HTTPS
+	return s.dnsStart.IsZero() && s.tcpStart.IsZero()
+}
+
 // Durations returns all durations and timelines of request latencies
 func (s *Stat) Durations() map[string]int64 {
 	return map[string]int64{
@@ -71,12 +125,45 @@ func (s *Stat) Durations() map[string]int64 {
 		"ContentTransfer":  s.ContentTransfer.Milliseconds(),
 		"NameLookup":       s.NameLookup.Milliseconds(),
 		"Connect":          s.Connect.Milliseconds(),
-		"Pretransfer":      s.Connect.Milliseconds(),
+		"Pretransfer":      s.Pretransfer.Milliseconds(),
 		"StartTransfer":    s.StartTransfer.Milliseconds(),
 		"Total":            s.Total.Milliseconds(),
 	}
 }
 
+func (s *Stat) Print() {
+	if s.assertSchemaHTTP() {
+		// http
+		printf(colorize(httpTemplate),
+			fmta(s.DNSLookup),        // dns lookup
+			fmta(s.TCPConnection),    // tcp connection
+			fmta(s.ServerProcessing), // server processing
+			fmta(s.ContentTransfer),  // content transfer
+			fmtb(s.NameLookup),       // namelookup
+			fmtb(s.Connect),          // connect
+			fmtb(s.StartTransfer),    // starttransfer
+			fmtb(s.Total),            // total
+		)
+	} else {
+		// https
+		printf(colorize(httpsTemplate),
+			fmta(s.DNSLookup),        // dns lookup
+			fmta(s.TCPConnection),    // tcp connection
+			fmta(s.TLSHandshake),     // tls handshake
+			fmta(s.ServerProcessing), // server processing
+			fmta(s.ContentTransfer),  // content transfer
+			fmtb(s.NameLookup),       // namelookup
+			fmtb(s.Connect),          // connect
+			fmtb(s.Pretransfer),      // pretransfer
+			fmtb(s.StartTransfer),    // starttransfer
+			fmtb(s.Total),            // total
+		)
+	}
+	log.Info().
+		Interface("httpstat(ms)", s.Durations()).
+		Msg("HTTP latency statistics")
+}
+
 // WithHTTPStat is a wrapper of httptrace.WithClientTrace.
 // It records the time of each httptrace hooks.
 func WithHTTPStat(ctx context.Context, s *Stat) context.Context {
@@ -132,7 +219,7 @@ func WithHTTPStat(ctx context.Context, s *Stat) context.Context {
 
 			// When client doesn't use DialContext or using old (before go1.7) `net`
 			// package, DNS/TCP/TLS hook is not called.
-			if s.dnsStart.IsZero() && s.tcpStart.IsZero() {
+			if s.assertSchemaHTTP() {
 				now := s.serverStart
 				s.dnsStart = now
 				s.dnsDone = now

hrp/step.go

@@ -17,7 +17,7 @@ type StepResult struct {
 	StepType    StepType               `json:"step_type" yaml:"step_type"`                         // step type, testcase/request/transaction/rendezvous
 	Success     bool                   `json:"success" yaml:"success"`                             // step execution result
 	Elapsed     int64                  `json:"elapsed_ms" yaml:"elapsed_ms"`                       // step execution time in millisecond(ms)
-	HttpStat    map[string]int64       `json:"httpstat" yaml:"httpstat"`                           // httpstat in millisecond(ms)
+	HttpStat    map[string]int64       `json:"httpstat,omitempty" yaml:"httpstat,omitempty"`       // httpstat in millisecond(ms)
 	Data        interface{}            `json:"data,omitempty" yaml:"data,omitempty"`               // session data or slice of step data
 	ContentSize int64                  `json:"content_size" yaml:"content_size"`                   // response body length
 	ExportVars  map[string]interface{} `json:"export_vars,omitempty" yaml:"export_vars,omitempty"` // extract variables

hrp/step_request.go

@@ -350,9 +350,7 @@ func runStepRequest(r *SessionRunner, step *TStep) (stepResult *StepResult, err
 	if r.HTTPStatOn() {
 		httpStat.Finish()
 		stepResult.HttpStat = httpStat.Durations()
-		log.Info().
+		httpStat.Print()
-			Interface("httpstat(ms)", httpStat.Durations()).
-			Msg("HTTP latency statistics")
 	}
 
 	// new response object

hrp/step_request_test.go

@@ -105,31 +105,31 @@ func TestRunRequestStatOn(t *testing.T) {
 	summary := sessionRunner.GetSummary()
 
 	stat := summary.Records[0].HttpStat
-	if !assert.Greater(t, stat["DNSLookup"], int64(1)) {
+	if !assert.Greater(t, stat["DNSLookup"], int64(0)) {
 		t.Fatal()
 	}
-	if !assert.Greater(t, stat["TCPConnection"], int64(1)) {
+	if !assert.Greater(t, stat["TCPConnection"], int64(0)) {
 		t.Fatal()
 	}
-	if !assert.Greater(t, stat["TLSHandshake"], int64(1)) {
+	if !assert.Greater(t, stat["TLSHandshake"], int64(0)) {
 		t.Fatal()
 	}
-	if !assert.Greater(t, stat["ServerProcessing"], int64(1)) {
+	if !assert.Greater(t, stat["ServerProcessing"], int64(10)) {
 		t.Fatal()
 	}
 	if !assert.GreaterOrEqual(t, stat["ContentTransfer"], int64(0)) {
 		t.Fatal()
 	}
-	if !assert.Greater(t, stat["NameLookup"], int64(1)) {
+	if !assert.Greater(t, stat["NameLookup"], int64(0)) {
 		t.Fatal()
 	}
-	if !assert.Greater(t, stat["Connect"], int64(1)) {
+	if !assert.Greater(t, stat["Connect"], int64(0)) {
 		t.Fatal()
 	}
-	if !assert.Greater(t, stat["Pretransfer"], int64(1)) {
+	if !assert.Greater(t, stat["Pretransfer"], int64(0)) {
 		t.Fatal()
 	}
-	if !assert.Greater(t, stat["StartTransfer"], int64(1)) {
+	if !assert.Greater(t, stat["StartTransfer"], int64(0)) {
 		t.Fatal()
 	}
 	if !assert.Greater(t, stat["Total"], int64(10)) {
@@ -150,7 +150,7 @@ func TestRunRequestStatOn(t *testing.T) {
 	if !assert.Equal(t, stat["TLSHandshake"], int64(0)) {
 		t.Fatal()
 	}
-	if !assert.Greater(t, stat["ServerProcessing"], int64(1)) {
+	if !assert.Greater(t, stat["ServerProcessing"], int64(10)) {
 		t.Fatal()
 	}
 	if !assert.Equal(t, stat["ContentTransfer"], int64(0)) {
@@ -165,7 +165,7 @@ func TestRunRequestStatOn(t *testing.T) {
 	if !assert.Equal(t, stat["Pretransfer"], int64(0)) {
 		t.Fatal()
 	}
-	if !assert.Greater(t, stat["StartTransfer"], int64(10)) {
+	if !assert.Greater(t, stat["StartTransfer"], int64(0)) {
 		t.Fatal()
 	}
 	if !assert.Greater(t, stat["Total"], int64(10)) {