feat: print http stat with color

This commit is contained in:
debugtalk
2022-05-05 14:24:48 +08:00
parent aa926d53cf
commit 95ab8b1851
6 changed files with 106 additions and 18 deletions

1
go.mod
View File

@@ -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

4
go.sum
View File

@@ -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=

View File

@@ -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

View File

@@ -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

View File

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

View File

@@ -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)) {