diff --git a/README.md b/README.md index 5d7c2632..c63561ce 100644 --- a/README.md +++ b/README.md @@ -27,7 +27,7 @@ ## 核心特性 -- 网络协议：完整支持 HTTP(S)/1.1 和 HTTP/2，可扩展支持 WebSocket/TCP/RPC 等更多协议 +- 网络协议：完整支持 HTTP(S)/HTTP2/WebSocket，可扩展支持 TCP/UDP/RPC 等更多协议 - 多格式可选：测试用例支持 YAML/JSON/go test/pytest 格式，并且支持格式互相转换 - 双执行引擎：同时支持 golang/python 两个执行引擎，兼具 go 的高性能和 [pytest] 的丰富生态 - 录制 & 生成：可使用 [HAR]/Postman/Swagger/curl 等生成测试用例；基于链式调用的方法提示也可快速编写测试用例 diff --git a/docs/CHANGELOG.md b/docs/CHANGELOG.md index b6656601..adee1c8c 100644 --- a/docs/CHANGELOG.md +++ b/docs/CHANGELOG.md @@ -1,9 +1,10 @@ # Release History -## v4.0.0-beta2 (2022-05-03) +## v4.0.0 (2022-05-05) **go version** +- feat: stat HTTP request latencies (DNSLookup, TCP Connection and so on) - feat: add builtin function `environ`/`ENV` - fix: demo function compatibility - fix #1240: losing host port in har2case diff --git a/docs/cmd/hrp.md b/docs/cmd/hrp.md index ef528f9d..1b512dba 100644 --- a/docs/cmd/hrp.md +++ b/docs/cmd/hrp.md @@ -36,4 +36,4 @@ Copyright 2017 debugtalk * [hrp run](hrp_run.md) - run API test with go engine * [hrp startproject](hrp_startproject.md) - create a scaffold project -###### Auto generated by spf13/cobra on 3-May-2022 +###### Auto generated by spf13/cobra on 5-May-2022 diff --git a/docs/cmd/hrp_boom.md b/docs/cmd/hrp_boom.md index fe95ddab..dc049340 100644 --- a/docs/cmd/hrp_boom.md +++ b/docs/cmd/hrp_boom.md @@ -41,4 +41,4 @@ hrp boom [flags] * [hrp](hrp.md) - Next-Generation API Testing Solution. -###### Auto generated by spf13/cobra on 3-May-2022 +###### Auto generated by spf13/cobra on 5-May-2022 diff --git a/docs/cmd/hrp_convert.md b/docs/cmd/hrp_convert.md index 880bce0b..5366a607 100644 --- a/docs/cmd/hrp_convert.md +++ b/docs/cmd/hrp_convert.md @@ -18,4 +18,4 @@ hrp convert $path... [flags] * [hrp](hrp.md) - Next-Generation API Testing Solution. -###### Auto generated by spf13/cobra on 3-May-2022 +###### Auto generated by spf13/cobra on 5-May-2022 diff --git a/docs/cmd/hrp_har2case.md b/docs/cmd/hrp_har2case.md index d7b6e925..852c2bc2 100644 --- a/docs/cmd/hrp_har2case.md +++ b/docs/cmd/hrp_har2case.md @@ -24,4 +24,4 @@ hrp har2case $har_path... [flags] * [hrp](hrp.md) - Next-Generation API Testing Solution. -###### Auto generated by spf13/cobra on 3-May-2022 +###### Auto generated by spf13/cobra on 5-May-2022 diff --git a/docs/cmd/hrp_pytest.md b/docs/cmd/hrp_pytest.md index 5c59d217..6bc851e2 100644 --- a/docs/cmd/hrp_pytest.md +++ b/docs/cmd/hrp_pytest.md @@ -16,4 +16,4 @@ hrp pytest $path ... [flags] * [hrp](hrp.md) - Next-Generation API Testing Solution. -###### Auto generated by spf13/cobra on 3-May-2022 +###### Auto generated by spf13/cobra on 5-May-2022 diff --git a/docs/cmd/hrp_run.md b/docs/cmd/hrp_run.md index 6d2f8486..d0125914 100644 --- a/docs/cmd/hrp_run.md +++ b/docs/cmd/hrp_run.md @@ -24,6 +24,7 @@ hrp run $path... [flags] -c, --continue-on-failure continue running next step when failure occurs -g, --gen-html-report generate html report -h, --help help for run + --http-stat turn on HTTP latency stat (DNSLookup, TCP Connection, etc.) --log-plugin turn on plugin logging --log-requests-off turn off request & response details logging -p, --proxy-url string set proxy url @@ -34,4 +35,4 @@ hrp run $path... [flags] * [hrp](hrp.md) - Next-Generation API Testing Solution. -###### Auto generated by spf13/cobra on 3-May-2022 +###### Auto generated by spf13/cobra on 5-May-2022 diff --git a/docs/cmd/hrp_startproject.md b/docs/cmd/hrp_startproject.md index a8706619..d459b838 100644 --- a/docs/cmd/hrp_startproject.md +++ b/docs/cmd/hrp_startproject.md @@ -20,4 +20,4 @@ hrp startproject $project_name [flags] * [hrp](hrp.md) - Next-Generation API Testing Solution. -###### Auto generated by spf13/cobra on 3-May-2022 +###### Auto generated by spf13/cobra on 5-May-2022 diff --git a/examples/demo-with-go-plugin/plugin/go.mod b/examples/demo-with-go-plugin/plugin/go.mod index 941628d8..8dabb414 100644 --- a/examples/demo-with-go-plugin/plugin/go.mod +++ b/examples/demo-with-go-plugin/plugin/go.mod @@ -2,4 +2,4 @@ module plugin go 1.16 -require github.com/httprunner/funplugin v0.4.3 // indirect +require github.com/httprunner/funplugin v0.4.5 // indirect diff --git a/examples/demo-with-go-plugin/plugin/go.sum b/examples/demo-with-go-plugin/plugin/go.sum index 93a4421a..33c01bfb 100644 --- a/examples/demo-with-go-plugin/plugin/go.sum +++ b/examples/demo-with-go-plugin/plugin/go.sum @@ -58,8 +58,8 @@ github.com/hashicorp/go-plugin v1.4.3 h1:DXmvivbWD5qdiBts9TpBC7BYL1Aia5sxbRgQB+v github.com/hashicorp/go-plugin v1.4.3/go.mod h1:5fGEH17QVwTTcR0zV7yhDPLLmFX9YSZ38b18Udy6vYQ= github.com/hashicorp/yamux v0.0.0-20180604194846-3520598351bb h1:b5rjCoWHc7eqmAS4/qyk21ZsHyb6Mxv/jykxvNTkU4M= github.com/hashicorp/yamux v0.0.0-20180604194846-3520598351bb/go.mod h1:+NfK9FKeTrX5uv1uIXGdwYDTeHna2qgaIlx54MXqjAM= -github.com/httprunner/funplugin v0.4.3 h1:mxdxQh54NZLQnK/FXZxpZV0rhqZQzckrWKEnBW5w2Vg= -github.com/httprunner/funplugin v0.4.3/go.mod h1:vPyeJIfbpGe0epZZtAV0wCn16gLY9+imSw/zfxq0Lcc= +github.com/httprunner/funplugin v0.4.5 h1:2KCj5AZZA22OER6TN5P/PSBYFMiKpgTmCRbDmHB1tos= +github.com/httprunner/funplugin v0.4.5/go.mod h1:vPyeJIfbpGe0epZZtAV0wCn16gLY9+imSw/zfxq0Lcc= github.com/jhump/protoreflect v1.6.0/go.mod h1:eaTn3RZAmMBcV0fifFvlm6VHNz3wSkYyXYWUh7ymB74= github.com/json-iterator/go v1.1.12 h1:PV8peI4a0ysnczrg+LtxykD8LfKY9ML6u2jnxaEnrnM= github.com/json-iterator/go v1.1.12/go.mod h1:e30LSqwooZae/UwlEbR2852Gd8hjQvJoHmT4TnhNGBo= diff --git a/go.mod b/go.mod index 510515e6..dbe79c4c 100644 --- a/go.mod +++ b/go.mod @@ -5,10 +5,11 @@ 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 - github.com/httprunner/funplugin v0.4.4 + github.com/httprunner/funplugin v0.4.5 github.com/jinzhu/copier v0.3.2 github.com/jmespath/go-jmespath v0.4.0 github.com/json-iterator/go v1.1.12 diff --git a/go.sum b/go.sum index 24c26644..62502254 100644 --- a/go.sum +++ b/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= @@ -241,8 +242,8 @@ github.com/hashicorp/memberlist v0.1.3/go.mod h1:ajVTdAv/9Im8oMAAj5G31PhhMCZJV2p github.com/hashicorp/serf v0.8.2/go.mod h1:6hOLApaqBFA1NXqRQAsxw9QxuDEvNxSQRwA/JwenrHc= github.com/hashicorp/yamux v0.0.0-20180604194846-3520598351bb h1:b5rjCoWHc7eqmAS4/qyk21ZsHyb6Mxv/jykxvNTkU4M= github.com/hashicorp/yamux v0.0.0-20180604194846-3520598351bb/go.mod h1:+NfK9FKeTrX5uv1uIXGdwYDTeHna2qgaIlx54MXqjAM= -github.com/httprunner/funplugin v0.4.4 h1:IVt603Y57WfSbn6DZ0R4iLeGQJ1yj944gmYwEOSBzGo= -github.com/httprunner/funplugin v0.4.4/go.mod h1:vPyeJIfbpGe0epZZtAV0wCn16gLY9+imSw/zfxq0Lcc= +github.com/httprunner/funplugin v0.4.5 h1:2KCj5AZZA22OER6TN5P/PSBYFMiKpgTmCRbDmHB1tos= +github.com/httprunner/funplugin v0.4.5/go.mod h1:vPyeJIfbpGe0epZZtAV0wCn16gLY9+imSw/zfxq0Lcc= github.com/ianlancetaylor/demangle v0.0.0-20181102032728-5e5cf60278f6/go.mod h1:aSSvb/t6k1mPoxDqO4vJh6VOCGPwU4O0C2/Eqndh1Sc= github.com/ianlancetaylor/demangle v0.0.0-20200824232613-28f6c0f3b639/go.mod h1:aSSvb/t6k1mPoxDqO4vJh6VOCGPwU4O0C2/Eqndh1Sc= github.com/imkira/go-interpol v1.1.0/go.mod h1:z0h2/2T3XF8kyEPpRgJ3kmNv+C43p+I/CoI+jC3w2iA= @@ -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= diff --git a/hrp/cmd/run.go b/hrp/cmd/run.go index 17f54014..891563fd 100644 --- a/hrp/cmd/run.go +++ b/hrp/cmd/run.go @@ -35,6 +35,9 @@ var runCmd = &cobra.Command{ if !requestsLogOff { runner.SetRequestsLogOn() } + if httpStatOn { + runner.SetHTTPStatOn() + } if pluginLogOn { runner.SetPluginLogOn() } @@ -51,6 +54,7 @@ var runCmd = &cobra.Command{ var ( continueOnFailure bool requestsLogOff bool + httpStatOn bool pluginLogOn bool proxyUrl string saveTests bool @@ -61,6 +65,7 @@ func init() { rootCmd.AddCommand(runCmd) runCmd.Flags().BoolVarP(&continueOnFailure, "continue-on-failure", "c", false, "continue running next step when failure occurs") runCmd.Flags().BoolVar(&requestsLogOff, "log-requests-off", false, "turn off request & response details logging") + runCmd.Flags().BoolVar(&httpStatOn, "http-stat", false, "turn on HTTP latency stat (DNSLookup, TCP Connection, etc.)") runCmd.Flags().BoolVar(&pluginLogOn, "log-plugin", false, "turn on plugin logging") runCmd.Flags().StringVarP(&proxyUrl, "proxy-url", "p", "", "set proxy url") runCmd.Flags().BoolVarP(&saveTests, "save-tests", "s", false, "save tests summary") diff --git a/hrp/internal/httpstat/main.go b/hrp/internal/httpstat/main.go new file mode 100644 index 00000000..29bf464d --- /dev/null +++ b/hrp/internal/httpstat/main.go @@ -0,0 +1,268 @@ +// Package httpstat traces HTTP latency infomation (DNSLookup, TCP Connection and so on) on any golang HTTP request. +// It uses `httptrace` package. +// Inspired by https://github.com/tcnksm/go-httpstat and https://github.com/davecheney/httpstat +package httpstat + +import ( + "context" + "crypto/tls" + "fmt" + "net/http" + "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 + // DNSLookup => TCPConnection => TLSHandshake => ServerProcessing => ContentTransfer + DNSLookup time.Duration + TCPConnection time.Duration + TLSHandshake time.Duration + ServerProcessing time.Duration + ContentTransfer time.Duration // from the first response byte to tansfer done. + + // The followings are timeline of request + NameLookup time.Duration // = DNSLookup + Connect time.Duration // = DNSLookup + TCPConnection + Pretransfer time.Duration // = DNSLookup + TCPConnection + TLSHandshake + StartTransfer time.Duration // = DNSLookup + TCPConnection + TLSHandshake + ServerProcessing + Total time.Duration // = DNSLookup + TCPConnection + TLSHandshake + ServerProcessing + ContentTransfer + + // internal timelines, including start and finish timestamps of each phase + dnsStart time.Time + dnsDone time.Time + tcpStart time.Time + tcpDone time.Time + tlsStart time.Time + tlsDone time.Time + serverStart time.Time + serverDone time.Time + transferStart time.Time + transferDone time.Time // need to be provided from outside + + // isTLS is true when connection seems to use TLS + isTLS bool + + // isReused is true when connection is reused (keep-alive) + isReused bool + + // https or http + schema string + + // connected network info + network, addr string +} + +// Finish sets the time when reading response is done. +// This must be called after reading response body. +func (s *Stat) Finish() { + s.transferDone = time.Now() + + // This means result is empty (it does nothing). + // Skip setting value (contentTransfer and total will be zero). + if s.dnsStart.IsZero() { + return + } + + s.ContentTransfer = s.transferDone.Sub(s.transferStart) + s.Total = s.transferDone.Sub(s.dnsStart) +} + +// Durations returns all durations and timelines of request latencies +func (s *Stat) Durations() map[string]int64 { + return map[string]int64{ + "DNSLookup": s.DNSLookup.Milliseconds(), + "TCPConnection": s.TCPConnection.Milliseconds(), + "TLSHandshake": s.TLSHandshake.Milliseconds(), + "ServerProcessing": s.ServerProcessing.Milliseconds(), + "ContentTransfer": s.ContentTransfer.Milliseconds(), + "NameLookup": s.NameLookup.Milliseconds(), + "Connect": s.Connect.Milliseconds(), + "Pretransfer": s.Pretransfer.Milliseconds(), + "StartTransfer": s.StartTransfer.Milliseconds(), + "Total": s.Total.Milliseconds(), + } +} + +func (s *Stat) Print() { + if s.network != "" && s.addr != "" { + printf("\n%s %s: %s\n", + color.CyanString("Connected to"), + color.YellowString(s.network), + color.BlueString(s.addr), + ) + } + + switch s.schema { + case "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 + ) + case "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 + ) + } + 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(req *http.Request, s *Stat) context.Context { + s.schema = req.URL.Scheme + return httptrace.WithClientTrace(req.Context(), &httptrace.ClientTrace{ + DNSStart: func(i httptrace.DNSStartInfo) { + s.dnsStart = time.Now() + }, + + DNSDone: func(i httptrace.DNSDoneInfo) { + s.dnsDone = time.Now() + + s.DNSLookup = s.dnsDone.Sub(s.dnsStart) + s.NameLookup = s.DNSLookup + }, + + ConnectStart: func(network, addr string) { + s.network = network + s.addr = addr + + s.tcpStart = time.Now() + + // When connecting to IP (When no DNS lookup) + if s.dnsStart.IsZero() { + s.dnsStart = s.tcpStart + s.dnsDone = s.tcpStart + } + }, + + ConnectDone: func(network, addr string, err error) { + s.tcpDone = time.Now() + s.TCPConnection = s.tcpDone.Sub(s.tcpStart) + s.Connect = s.tcpDone.Sub(s.dnsStart) + }, + + TLSHandshakeStart: func() { + s.isTLS = true + s.tlsStart = time.Now() + }, + + TLSHandshakeDone: func(_ tls.ConnectionState, _ error) { + s.tlsDone = time.Now() + s.TLSHandshake = s.tlsDone.Sub(s.tlsStart) + s.Pretransfer = s.tlsDone.Sub(s.dnsStart) + }, + + GotConn: func(i httptrace.GotConnInfo) { + // Handle when keep alive is used and connection is reused. + // DNSStart(Done) and ConnectStart(Done) is skipped + if i.Reused { + s.isReused = true + } + }, + + WroteRequest: func(info httptrace.WroteRequestInfo) { + now := time.Now() + s.serverStart = now + + // When client doesn't use DialContext, DNS/TCP/TLS hook is not called. + if s.dnsStart.IsZero() && s.tcpStart.IsZero() { + s.dnsStart = now + s.dnsDone = now + s.tcpStart = now + s.tcpDone = now + } + + // When connection is re-used, DNS/TCP/TLS hook is not called. + if s.isReused { + s.dnsStart = now + s.dnsDone = now + s.tcpStart = now + s.tcpDone = now + s.tlsStart = now + s.tlsDone = now + } + + if s.isTLS { // https + return + } + + // http + s.TLSHandshake = 0 + s.Pretransfer = s.Connect + }, + + GotFirstResponseByte: func() { + s.serverDone = time.Now() + s.ServerProcessing = s.serverDone.Sub(s.serverStart) + s.StartTransfer = s.serverDone.Sub(s.dnsStart) + s.transferStart = s.serverDone + }, + }) +} diff --git a/hrp/internal/scaffold/main.go b/hrp/internal/scaffold/main.go index 98f5ffed..d655384d 100644 --- a/hrp/internal/scaffold/main.go +++ b/hrp/internal/scaffold/main.go @@ -185,7 +185,7 @@ func createPythonPlugin(projectName string) error { return errors.Wrap(err, "copy file failed") } - _, err = builtin.EnsurePython3Venv(fmt.Sprintf("funppy>=%s", shared.Version)) + _, err = builtin.EnsurePython3Venv("funppy") if err != nil { return err } diff --git a/hrp/runner.go b/hrp/runner.go index d21b8beb..74c463cd 100644 --- a/hrp/runner.go +++ b/hrp/runner.go @@ -54,6 +54,7 @@ func NewRunner(t *testing.T) *HRPRunner { type HRPRunner struct { t *testing.T failfast bool + httpStatOn bool requestsLogOn bool pluginLogOn bool saveTests bool @@ -100,6 +101,13 @@ func (r *HRPRunner) SetRequestsLogOn() *HRPRunner { return r } +// SetHTTPStatOn turns on HTTP latency stat. +func (r *HRPRunner) SetHTTPStatOn() *HRPRunner { + log.Info().Msg("[init] SetHTTPStatOn") + r.httpStatOn = true + return r +} + // SetPluginLogOn turns on plugin logging. func (r *HRPRunner) SetPluginLogOn() *HRPRunner { log.Info().Msg("[init] SetPluginLogOn") diff --git a/hrp/session.go b/hrp/session.go index 96710284..eae3b41a 100644 --- a/hrp/session.go +++ b/hrp/session.go @@ -42,6 +42,10 @@ func (r *SessionRunner) GetConfig() *TConfig { return r.parsedConfig } +func (r *SessionRunner) HTTPStatOn() bool { + return r.hrpRunner.httpStatOn +} + func (r *SessionRunner) LogOn() bool { return r.hrpRunner.requestsLogOn } diff --git a/hrp/step.go b/hrp/step.go index 242f9294..b4583852 100644 --- a/hrp/step.go +++ b/hrp/step.go @@ -17,6 +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,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 diff --git a/hrp/step_request.go b/hrp/step_request.go index 64994657..30c5988e 100644 --- a/hrp/step_request.go +++ b/hrp/step_request.go @@ -4,6 +4,7 @@ import ( "bytes" "compress/gzip" "compress/zlib" + "crypto/tls" "fmt" "io" "net/http" @@ -15,10 +16,12 @@ import ( "time" "github.com/andybalholm/brotli" + "github.com/fatih/color" "github.com/pkg/errors" "github.com/rs/zerolog/log" "github.com/httprunner/httprunner/hrp/internal/builtin" + "github.com/httprunner/httprunner/hrp/internal/httpstat" "github.com/httprunner/httprunner/hrp/internal/json" ) @@ -311,6 +314,13 @@ func runStepRequest(r *SessionRunner, step *TStep) (stepResult *StepResult, err } } + // stat HTTP request + var httpStat httpstat.Stat + if r.HTTPStatOn() { + ctx := httpstat.WithHTTPStat(rb.req, &httpStat) + rb.req = rb.req.WithContext(ctx) + } + // do request action start := time.Now() var resp *http.Response @@ -346,6 +356,13 @@ func runStepRequest(r *SessionRunner, step *TStep) (stepResult *StepResult, err return } + if r.HTTPStatOn() { + // resp.Body has been ReadAll + httpStat.Finish() + stepResult.HttpStat = httpStat.Durations() + httpStat.Print() + } + // add response object to step variables, could be used in teardown hooks stepVariables["hrp_step_response"] = respObj.respObjMeta @@ -408,8 +425,22 @@ func printRequest(req *http.Request) error { return nil } +func printf(format string, a ...interface{}) (n int, err error) { + return fmt.Fprintf(color.Output, format, a...) +} + func printResponse(resp *http.Response) error { fmt.Println("==================== response ====================") + connectedVia := "plaintext" + if resp.TLS != nil { + switch resp.TLS.Version { + case tls.VersionTLS12: + connectedVia = "TLSv1.2" + case tls.VersionTLS13: + connectedVia = "TLSv1.3" + } + } + printf("%s %s\n", color.CyanString("Connected via"), color.BlueString("%s", connectedVia)) respContentType := resp.Header.Get("Content-Type") printBody := shouldPrintBody(respContentType) respDump, err := httputil.DumpResponse(resp, printBody) diff --git a/hrp/step_request_test.go b/hrp/step_request_test.go index 234119f4..1076b31d 100644 --- a/hrp/step_request_test.go +++ b/hrp/step_request_test.go @@ -2,6 +2,8 @@ package hrp import ( "testing" + + "github.com/stretchr/testify/assert" ) var ( @@ -89,3 +91,84 @@ func TestRunRequestRun(t *testing.T) { t.Fatalf("stepPOSTData.Run() error: %v", err) } } + +func TestRunRequestStatOn(t *testing.T) { + testcase := &TestCase{ + Config: NewConfig("test").SetBaseURL("https://postman-echo.com"), + TestSteps: []IStep{stepGET, stepPOSTData}, + } + runner := NewRunner(t).SetHTTPStatOn() + sessionRunner, _ := runner.NewSessionRunner(testcase) + if err := sessionRunner.Start(nil); err != nil { + t.Fatal() + } + summary := sessionRunner.GetSummary() + + stat := summary.Records[0].HttpStat + if !assert.GreaterOrEqual(t, stat["DNSLookup"], int64(0)) { + t.Fatal() + } + if !assert.Greater(t, stat["TCPConnection"], int64(0)) { + t.Fatal() + } + if !assert.Greater(t, stat["TLSHandshake"], int64(0)) { + t.Fatal() + } + if !assert.Greater(t, stat["ServerProcessing"], int64(1)) { + t.Fatal() + } + if !assert.GreaterOrEqual(t, stat["ContentTransfer"], int64(0)) { + t.Fatal() + } + if !assert.GreaterOrEqual(t, stat["NameLookup"], int64(0)) { + t.Fatal() + } + if !assert.Greater(t, stat["Connect"], int64(0)) { + t.Fatal() + } + if !assert.Greater(t, stat["Pretransfer"], int64(0)) { + t.Fatal() + } + if !assert.Greater(t, stat["StartTransfer"], int64(0)) { + t.Fatal() + } + if !assert.Greater(t, stat["Total"], int64(5)) { + t.Fatal() + } + if !assert.Less(t, stat["Total"]-summary.Records[0].Elapsed, int64(3)) { + t.Fatal() + } + + // reuse connection + stat = summary.Records[1].HttpStat + if !assert.Equal(t, int64(0), stat["DNSLookup"]) { + t.Fatal() + } + if !assert.Equal(t, int64(0), stat["TCPConnection"]) { + t.Fatal() + } + if !assert.Equal(t, int64(0), stat["TLSHandshake"]) { + t.Fatal() + } + if !assert.Greater(t, stat["ServerProcessing"], int64(1)) { + t.Fatal() + } + if !assert.Equal(t, int64(0), stat["NameLookup"]) { + t.Fatal() + } + if !assert.Equal(t, int64(0), stat["Connect"]) { + t.Fatal() + } + if !assert.Equal(t, int64(0), stat["Pretransfer"]) { + t.Fatal() + } + if !assert.Greater(t, stat["StartTransfer"], int64(0)) { + t.Fatal() + } + if !assert.Greater(t, stat["Total"], int64(1)) { + t.Fatal() + } + if !assert.Less(t, stat["Total"]-summary.Records[0].Elapsed, int64(3)) { + t.Fatal() + } +}