Repository: fortio/fortio
Pull request #626 (2022-09-18 23:40:07)

add connection times histogram
As you requested @howardjohn 


ex.:

```
% go run . load -a  -connection-reuse 4 -n 32 -c 4 -nocatchup -qps 4  https://httpbin.org/status/200
Fortio dev running at 4 queries per second, 8->8 procs, for 32 calls: https://httpbin.org/status/200
16:36:56 I httprunner.go:102> Starting http test for https://httpbin.org/status/200 with 4 threads at 4.0 qps and parallel warmup, with connection reuse [4, 4]
Starting at 4 qps with 4 thread(s) [gomax 8] : exactly 32, 8 calls each (total 32 + 0)
16:37:04 I periodic.go:808> T003 ended after 8.07513475s : 8 calls. qps=0.9906955422632421
16:37:04 I periodic.go:808> T001 ended after 8.075134834s : 8 calls. qps=0.9906955319577269
16:37:04 I periodic.go:808> T002 ended after 8.075261667s : 8 calls. qps=0.990679971732983
16:37:04 I periodic.go:808> T000 ended after 8.279228959s : 8 calls. qps=0.9662735551362592
Ended after 8.279327584s : 32 calls. qps=3.865
Sleep times : count 28 avg 0.96779572 +/- 0.1425 min 0.677604017 max 1.070371576 sum 27.09828
Aggregated Function Time : count 32 avg 0.16807453 +/- 0.138 min 0.07142125 max 0.465166625 sum 5.37838488
# range, mid point, percentile, count
>= 0.0714213 <= 0.08 , 0.0757106 , 65.62, 21
> 0.18 <= 0.2 , 0.19 , 68.75, 1
> 0.25 <= 0.3 , 0.275 , 75.00, 2
> 0.3 <= 0.35 , 0.325 , 87.50, 4
> 0.35 <= 0.4 , 0.375 , 90.62, 1
> 0.45 <= 0.465167 , 0.457583 , 100.00, 3
# target 50% 0.0778553
# target 75% 0.3
# target 90% 0.39
# target 99% 0.463549
# target 99.9% 0.465005
Error cases : no data
# Socket and IP used for each connection:
[0]   2 socket used, resolved to [18.207.88.57:443] connection timing : count 2 avg 0.24029735 +/- 0.0102 min 0.23009375 max 0.250500958 sum 0.480594708
[1]   2 socket used, resolved to [52.45.189.24:443 (1), 54.236.79.58:443 (1)] connection timing : count 2 avg 0.24741869 +/- 0.01099 min 0.236425167 max 0.258412209 sum 0.494837376
[2]   2 socket used, resolved to [44.207.168.240:443] connection timing : count 2 avg 0.24210123 +/- 0.01765 min 0.224453083 max 0.259749375 sum 0.484202458
[3]   2 socket used, resolved to [54.236.79.58:443 (1), 52.45.189.24:443 (1)] connection timing : count 2 avg 0.24513125 +/- 0.00845 min 0.236681084 max 0.253581417 sum 0.490262501
Connection time histogram (s) : count 8 avg 0.24373713 +/- 0.01263 min 0.224453083 max 0.259749375 sum 1.94989704
# range, mid point, percentile, count
>= 0.224453 <= 0.25 , 0.237227 , 50.00, 4
> 0.25 <= 0.259749 , 0.254875 , 100.00, 4
# target 50% 0.25
# target 75% 0.254875
# target 90% 0.2578
# target 99% 0.259554
# target 99.9% 0.25973
Sockets used: 8 (for perfect keepalive, would be 4)
Uniform: false, Jitter: false
IP addresses distribution:
54.236.79.58:443: 2
44.207.168.240:443: 2
18.207.88.57:443: 2
52.45.189.24:443: 2
Code 200 : 32 (100.0 %)
Response Header Sizes : count 32 avg 236 +/- 0 min 236 max 236 sum 7552
Response Body/Total Sizes : count 32 avg 236 +/- 0 min 236 max 236 sum 7552
All done 32 calls (plus 0 warmup) 168.075 ms avg, 3.9 qps
Successfully wrote 4003 bytes of Json data to 2022-09-18-163656_httpbin_org_status_200_MacBook_Air.json
```
You can see connection time min/avg/p50 is higher than total time min/avg/p50 (because we reuse each socket 4x so amortize down in this case)

```json
{
  "RunType": "HTTP",
  "Labels": "httpbin.org/status/200 , MacBook-Air",
  "StartTime": "2022-09-18T16:36:56.296767-07:00",
  "RequestedQPS": "4",
  "RequestedDuration": "exactly 32 calls",
  "ActualQPS": 3.865048178772485,
  "ActualDuration": 8279327584,
  "NumThreads": 4,
  "Version": "dev",
  "DurationHistogram": {
    "Count": 32,
    "Min": 0.07142125,
    "Max": 0.465166625,
    "Sum": 5.378384876,
    "Avg": 0.168074527375,
    "StdDev": 0.13797295167128187,
    "Data": [
      {
        "Start": 0.07142125,
        "End": 0.08,
        "Percent": 65.625,
        "Count": 21
      },
      {
        "Start": 0.18,
        "End": 0.2,
        "Percent": 68.75,
        "Count": 1
      },
      {
        "Start": 0.25,
        "End": 0.3,
        "Percent": 75,
        "Count": 2
      },
      {
        "Start": 0.3,
        "End": 0.35000000000000003,
        "Percent": 87.5,
        "Count": 4
      },
      {
        "Start": 0.35000000000000003,
        "End": 0.4,
        "Percent": 90.625,
        "Count": 1
      },
      {
        "Start": 0.45,
        "End": 0.465166625,
        "Percent": 100,
        "Count": 3
      }
    ],
    "Percentiles": [
      {
        "Percentile": 50,
        "Value": 0.0778553125
      },
      {
        "Percentile": 75,
        "Value": 0.3
      },
      {
        "Percentile": 90,
        "Value": 0.39
      },
      {
        "Percentile": 99,
        "Value": 0.46354885166666665
      },
      {
        "Percentile": 99.9,
        "Value": 0.46500484766666667
      }
    ]
  },
  "ErrorsDurationHistogram": {
    "Count": 0,
    "Min": 0,
    "Max": 0,
    "Sum": 0,
    "Avg": 0,
    "StdDev": 0,
    "Data": null
  },
  "Exactly": 32,
  "Jitter": false,
  "Uniform": false,
  "NoCatchUp": true,
  "RunID": 0,
  "AccessLoggerInfo": "",
  "ID": "2022-09-18-163656_httpbin_org_status_200_MacBook_Air",
  "RetCodes": {
    "200": 32
  },
  "IPCountMap": {
    "18.207.88.57:443": 2,
    "44.207.168.240:443": 2,
    "52.45.189.24:443": 2,
    "54.236.79.58:443": 2
  },
  "Insecure": false,
  "CACert": "",
  "Cert": "",
  "Key": "",
  "UnixDomainSocket": "",
  "URL": "https://httpbin.org/status/200",
  "NumConnections": 1,
  "Compression": false,
  "DisableFastClient": false,
  "HTTP10": false,
  "DisableKeepAlive": false,
  "AllowHalfClose": false,
  "FollowRedirects": false,
  "Resolve": "",
  "HTTPReqTimeOut": 3000000000,
  "UserCredentials": "",
  "ContentType": "",
  "Payload": "",
  "LogErrors": true,
  "SequentialWarmup": false,
  "ConnReuseRange": [
    4,
    4
  ],
  "NoResolveEachConn": false,
  "Offset": 0,
  "Resolution": 0.001,
  "Sizes": {
    "Count": 32,
    "Min": 236,
    "Max": 236,
    "Sum": 7552,
    "Avg": 236,
    "StdDev": 0,
    "Data": [
      {
        "Start": 236,
        "End": 236,
        "Percent": 100,
        "Count": 32
      }
    ]
  },
  "HeaderSizes": {
    "Count": 32,
    "Min": 236,
    "Max": 236,
    "Sum": 7552,
    "Avg": 236,
    "StdDev": 0,
    "Data": [
      {
        "Start": 236,
        "End": 236,
        "Percent": 100,
        "Count": 32
      }
    ]
  },
  "Sockets": [
    2,
    2,
    2,
    2
  ],
  "SocketCount": 8,
  "ConnectionStats": {
    "Count": 8,
    "Min": 0.224453083,
    "Max": 0.259749375,
    "Sum": 1.949897043,
    "Avg": 0.243737130375,
    "StdDev": 0.012627738138411356,
    "Data": [
      {
        "Start": 0.224453083,
        "End": 0.25,
        "Percent": 50,
        "Count": 4
      },
      {
        "Start": 0.25,
        "End": 0.259749375,
        "Percent": 100,
        "Count": 4
      }
    ],
    "Percentiles": [
      {
        "Percentile": 50,
        "Value": 0.25
      },
      {
        "Percentile": 75,
        "Value": 0.2548746875
      },
      {
        "Percentile": 90,
        "Value": 0.2577995
      },
      {
        "Percentile": 99,
        "Value": 0.2595543875
      },
      {
        "Percentile": 99.9,
        "Value": 0.25972987625
      }
    ]
  },
  "AbortOn": 0
}
```

codecov[bot]: # [Codecov](https://codecov.io/gh/fortio/fortio/pull/626?src=pr&el=h1&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=fortio) Report
Base: **88.4**% // Head: **88.5**% // Increases project coverage by **`+0.0%`** :tada:
> Coverage data is based on head [(`af8dd09`)](https://codecov.io/gh/fortio/fortio/pull/626?src=pr&el=desc&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=fortio) compared to base [(`0fa8982`)](https://codecov.io/gh/fortio/fortio/commit/0fa89821fab2d9451802ea6195b721d4a94d65a7?el=desc&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=fortio).
> Patch coverage: 92.3% of modified lines in pull request are covered.

<details><summary>Additional details and impacted files</summary>


```diff
@@          Coverage Diff           @@
##           master    #626   +/-   ##
======================================
  Coverage    88.4%   88.5%           
======================================
  Files          30      30           
  Lines        4320    4340   +20     
======================================
+ Hits         3821    3839   +18     
- Misses        335     336    +1     
- Partials      164     165    +1     
```


| [Impacted Files](https://codecov.io/gh/fortio/fortio/pull/626?src=pr&el=tree&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=fortio) | Coverage Δ | |
|---|---|---|
| [periodic/periodic.go](https://codecov.io/gh/fortio/fortio/pull/626/diff?src=pr&el=tree&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=fortio#diff-cGVyaW9kaWMvcGVyaW9kaWMuZ28=) | `93.6% <ø> (ø)` | |
| [stats/stats.go](https://codecov.io/gh/fortio/fortio/pull/626/diff?src=pr&el=tree&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=fortio#diff-c3RhdHMvc3RhdHMuZ28=) | `97.4% <ø> (ø)` | |
| [fhttp/httprunner.go](https://codecov.io/gh/fortio/fortio/pull/626/diff?src=pr&el=tree&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=fortio#diff-Zmh0dHAvaHR0cHJ1bm5lci5nbw==) | `88.0% <84.6%> (-0.5%)` | :arrow_down: |
| [fhttp/http\_client.go](https://codecov.io/gh/fortio/fortio/pull/626/diff?src=pr&el=tree&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=fortio#diff-Zmh0dHAvaHR0cF9jbGllbnQuZ28=) | `84.4% <100.0%> (+0.2%)` | :arrow_up: |

Help us with your feedback. Take ten seconds to tell us [how you rate us](https://about.codecov.io/nps?utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=fortio). Have a feature suggestion? [Share it here.](https://app.codecov.io/gh/feedback/?utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=fortio)

</details>

[:umbrella: View full report at Codecov](https://codecov.io/gh/fortio/fortio/pull/626?src=pr&el=continue&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=fortio).   
:loudspeaker: Do you have feedback about the report comment? [Let us know in this issue](https://about.codecov.io/codecov-pr-comment-feedback/?utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=fortio).

ldemailly: @howardjohn going to merge this and another MR to make 1.38.0 but do feel free to comment after the facts and I can do follow ups later as needed. Also was wondering for instance if the access log(s) should include the info.

Patch:
diff --git a/README.md b/README.md
index 39f946c..033f82c 100644
--- a/README.md
+++ b/README.md
@@ -52,13 +52,13 @@ You can install from source:
 The [releases](https://github.com/fortio/fortio/releases) page has binaries for many OS/architecture combinations (see assets).
 
 ```shell
-curl -L https://github.com/fortio/fortio/releases/download/v1.37.1/fortio-linux_amd64-1.37.1.tgz \
+curl -L https://github.com/fortio/fortio/releases/download/v1.38.0/fortio-linux_amd64-1.38.0.tgz \
  | sudo tar -C / -xvzpf -
 # or the debian package
-wget https://github.com/fortio/fortio/releases/download/v1.37.1/fortio_1.37.1_amd64.deb
-dpkg -i fortio_1.37.1_amd64.deb
+wget https://github.com/fortio/fortio/releases/download/v1.38.0/fortio_1.38.0_amd64.deb
+dpkg -i fortio_1.38.0_amd64.deb
 # or the rpm
-rpm -i https://github.com/fortio/fortio/releases/download/v1.37.1/fortio-1.37.1-1.x86_64.rpm
+rpm -i https://github.com/fortio/fortio/releases/download/v1.38.0/fortio-1.38.0-1.x86_64.rpm
 # and more, see assets in release page
 ```
 
@@ -68,7 +68,7 @@ On a MacOS you can also install Fortio using [Homebrew](https://brew.sh/):
 brew install fortio
 ```
 
-On Windows, download https://github.com/fortio/fortio/releases/download/v1.37.1/fortio_win_1.37.1.zip and extract `fortio.exe` to any location, then using the Windows Command Prompt:
+On Windows, download https://github.com/fortio/fortio/releases/download/v1.38.0/fortio_win_1.38.0.zip and extract `fortio.exe` to any location, then using the Windows Command Prompt:
 ```
 fortio.exe server
 ```
@@ -116,7 +116,7 @@ Full list of command line flags (`fortio help`):
 <details>
 <!-- use release/updateFlags.sh to update this section -->
 <pre>
-Φορτίο 1.37.1 usage:
+Φορτίο 1.38.0 usage:
     fortio command [flags] target
 where command is one of: load (load testing), server (starts ui, rest api,
  http-echo, redirect, proxies, tcp-echo and grpc ping servers), tcp-echo (only
diff --git a/fhttp/http_client.go b/fhttp/http_client.go
index f7b8559..321998f 100644
--- a/fhttp/http_client.go
+++ b/fhttp/http_client.go
@@ -45,9 +45,9 @@ type Fetcher interface {
 	Fetch() (int, []byte, int)
 	// Close() cleans up connections and state - must be paired with NewClient calls.
 	Close()
-	// GetIPAddress() returns the occurrence of ip address used by this client connection.
-	// and how many sockets have been used
-	GetIPAddress() (*stats.Occurrence, int)
+	// GetIPAddress() returns the occurrence of ip address used by this client connection,
+	// and the connection time histogram (which includes the count).
+	GetIPAddress() (*stats.Occurrence, *stats.Histogram)
 }
 
 const (
@@ -90,6 +90,9 @@ func (h *HTTPOptions) Init(url string) *HTTPOptions {
 		log.Warnf("Invalid timeout %v, setting to %v", h.HTTPReqTimeOut, HTTPReqTimeOutDefaultValue)
 		h.HTTPReqTimeOut = HTTPReqTimeOutDefaultValue
 	}
+	if h.Resolution <= 0 {
+		h.Resolution = 0.001
+	}
 	h.URLSchemeCheck()
 	return h
 }
@@ -185,6 +188,10 @@ type HTTPOptions struct {
 	ConnReuseRange   [2]int        // range of max number of connection to reuse for each thread.
 	// When false, re-resolve the DNS name when the connection breaks.
 	NoResolveEachConn bool
+	// Optional Offset Duration; to offset the histogram of the Connection duration
+	Offset time.Duration
+	// Optional resolution divider for the Connection duration histogram. In seconds. Defaults to 0.001 or 1 millisecond.
+	Resolution float64
 }
 
 // ResetHeaders resets all the headers, including the User-Agent: one (and the Host: logical special header).
@@ -354,8 +361,8 @@ type Client struct {
 	bodyContainsUUID     bool // if body contains the "{uuid}" pattern (lowercase)
 	logErrors            bool
 	id                   int
-	socketCount          int
 	ipAddrUsage          *stats.Occurrence
+	connectStats         *stats.Histogram
 }
 
 // Close cleans up any resources used by NewStdClient.
@@ -443,9 +450,9 @@ func (c *Client) Fetch() (int, []byte, int) {
 	return code, data, 0
 }
 
-// GetIPAddress get the ip address that DNS resolves to when using stdClient.
-func (c *Client) GetIPAddress() (*stats.Occurrence, int) {
-	return c.ipAddrUsage, c.socketCount
+// GetIPAddress get the ip address that DNS resolves to when using stdClient and connection stats.
+func (c *Client) GetIPAddress() (*stats.Occurrence, *stats.Histogram) {
+	return c.ipAddrUsage, c.connectStats
 }
 
 // NewClient creates either a standard or fast client (depending on
@@ -483,6 +490,8 @@ func NewStdClient(o *HTTPOptions) (*Client, error) {
 		id:          o.ID,
 		logErrors:   o.LogErrors,
 		ipAddrUsage: stats.NewOccurrence(),
+		// Keep track of timing for connection (re)establishment.
+		connectStats: stats.NewHistogram(o.Offset.Seconds(), o.Resolution),
 	}
 
 	tr := http.Transport{
@@ -497,10 +506,11 @@ func NewStdClient(o *HTTPOptions) (*Client, error) {
 				addr = o.Resolve + addr[strings.LastIndex(addr, ":"):]
 			}
 			var conn net.Conn
+			now := time.Now()
 			conn, err = (&net.Dialer{
 				Timeout: o.HTTPReqTimeOut,
 			}).DialContext(ctx, network, addr)
-
+			client.connectStats.Record(time.Since(now).Seconds())
 			if conn != nil {
 				newRemoteAddress := conn.RemoteAddr().String()
 				// No change when it wasn't set before (first time) and when the value isn't actually changing either.
@@ -508,10 +518,8 @@ func NewStdClient(o *HTTPOptions) (*Client, error) {
 					log.Infof("[%d] Standard client IP address changed from %s to %s", client.id, req.RemoteAddr, newRemoteAddress)
 				}
 				req.RemoteAddr = newRemoteAddress
-				client.socketCount++
 				client.ipAddrUsage.Record(req.RemoteAddr)
 			}
-
 			return conn, err
 		},
 		TLSHandshakeTimeout: o.HTTPReqTimeOut,
@@ -561,7 +569,7 @@ type FastClient struct {
 	req          []byte
 	dest         net.Addr
 	socket       net.Conn
-	socketCount  int
+	socketCount  int // number of sockets attempts, same as the new connectStats.Count() + DNS errors if any.
 	size         int
 	code         int
 	errorCount   int
@@ -588,11 +596,12 @@ type FastClient struct {
 	connReuseRange [2]int
 	connReuse      int
 	reuseCount     int
+	connectStats   *stats.Histogram
 }
 
-// GetIPAddress get ip address that DNS resolved to when using fast client.
-func (c *FastClient) GetIPAddress() (*stats.Occurrence, int) {
-	return c.ipAddrUsage, c.socketCount
+// GetIPAddress get ip address that DNS resolved to when using fast client and connection stats.
+func (c *FastClient) GetIPAddress() (*stats.Occurrence, *stats.Histogram) {
+	return c.ipAddrUsage, c.connectStats
 }
 
 // Close cleans up any resources used by FastClient.
@@ -657,6 +666,8 @@ func NewFastClient(o *HTTPOptions) (Fetcher, error) { //nolint:funlen
 		http10: o.HTTP10, halfClose: o.AllowHalfClose, logErrors: o.LogErrors, id: o.ID,
 		https: o.https, connReuseRange: o.ConnReuseRange, connReuse: connReuse,
 		resolve: o.Resolve, noResolveEachConn: o.NoResolveEachConn, ipAddrUsage: stats.NewOccurrence(),
+		// Keep track of timing for connection (re)establishment.
+		connectStats: stats.NewHistogram(o.Offset.Seconds(), o.Resolution),
 	}
 	if o.https {
 		bc.tlsConfig, err = o.TLSOptions.TLSClientConfig()
@@ -751,14 +762,17 @@ func (c *FastClient) connect() net.Conn {
 	}
 
 	d := &net.Dialer{Timeout: c.reqTimeout}
+	now := time.Now()
 	if c.https {
 		socket, err = tls.DialWithDialer(d, c.dest.Network(), c.dest.String(), c.tlsConfig)
+		c.connectStats.Record(time.Since(now).Seconds())
 		if err != nil {
 			log.Errf("[%d] Unable to TLS connect to %v : %v", c.id, c.dest, err)
 			return nil
 		}
 	} else {
 		socket, err = d.Dial(c.dest.Network(), c.dest.String())
+		c.connectStats.Record(time.Since(now).Seconds())
 		if err != nil {
 			log.Errf("[%d] Unable to connect to %v : %v", c.id, c.dest, err)
 			return nil
diff --git a/fhttp/httprunner.go b/fhttp/httprunner.go
index 06e5013..812c43a 100644
--- a/fhttp/httprunner.go
+++ b/fhttp/httprunner.go
@@ -45,8 +45,10 @@ type HTTPRunnerResults struct {
 	HTTPOptions
 	Sizes       *stats.HistogramData
 	HeaderSizes *stats.HistogramData
-	Sockets     []int
-	SocketCount int
+	Sockets     []int64
+	SocketCount int64
+	// Connection Time stats
+	ConnectionStats *stats.HistogramData
 	// http code to abort the run on (-1 for connection or other socket error)
 	AbortOn int
 	aborter *periodic.Aborter
@@ -85,7 +87,7 @@ type HTTPRunnerOptions struct {
 
 // RunHTTPTest runs an http test and returns the aggregated stats.
 //
-//nolint:funlen, gocognit, gocyclo
+//nolint:funlen, gocognit, gocyclo, maintidx
 func RunHTTPTest(o *HTTPRunnerOptions) (*HTTPRunnerResults, error) {
 	o.RunType = "HTTP"
 	warmupMode := "parallel"
@@ -100,6 +102,12 @@ func RunHTTPTest(o *HTTPRunnerOptions) (*HTTPRunnerResults, error) {
 	log.Infof("Starting http test for %s with %d threads at %.1f qps and %s warmup%s",
 		o.URL, o.NumThreads, o.QPS, warmupMode, connReuseMsg)
 	r := periodic.NewPeriodicRunner(&o.RunnerOptions)
+	if o.HTTPOptions.Resolution <= 0 {
+		// Set both connect histogram params when Resolution isn't set explicitly on the HTTP options
+		// (that way you can set the offet to 0 in connect and to something else for the call)
+		o.HTTPOptions.Resolution = r.Options().Resolution
+		o.HTTPOptions.Offset = r.Options().Offset
+	}
 	defer r.Options().Abort()
 	numThreads := r.Options().NumThreads // can change during run for c > 2 n
 	o.HTTPOptions.Init(o.URL)
@@ -188,6 +196,8 @@ func RunHTTPTest(o *HTTPRunnerOptions) (*HTTPRunnerResults, error) {
 		fm.Close()
 		_, _ = fmt.Fprintf(out, "Wrote profile data to %s.{cpu|mem}\n", o.Profiler)
 	}
+	// Connection stats, aggregated
+	connectionStats := stats.NewHistogram(o.HTTPOptions.Offset.Seconds(), o.HTTPOptions.Resolution)
 	// Numthreads may have reduced:
 	numThreads = total.RunnerResults.NumThreads
 	// But we also must cleanup all the created clients.
@@ -195,10 +205,11 @@ func RunHTTPTest(o *HTTPRunnerOptions) (*HTTPRunnerResults, error) {
 	fmt.Fprintf(out, "# Socket and IP used for each connection:\n")
 	for i := 0; i < numThreads; i++ {
 		// Get the report on the IP address each thread use to send traffic
-		occurrence, currentSocketUsed := httpstate[i].client.GetIPAddress()
+		occurrence, connStats := httpstate[i].client.GetIPAddress()
+		currentSocketUsed := connStats.Count
 		httpstate[i].client.Close()
-		fmt.Fprintf(out, "[%d] %3d socket used, resolved to %s\n", i, currentSocketUsed, occurrence.PrintAndAggregate(total.IPCountMap))
-
+		fmt.Fprintf(out, "[%d] %3d socket used, resolved to %s ", i, currentSocketUsed, occurrence.PrintAndAggregate(total.IPCountMap))
+		connStats.Counter.Print(out, "connection timing")
 		total.SocketCount += currentSocketUsed
 		total.Sockets = append(total.Sockets, currentSocketUsed)
 		// Q: is there some copying each time stats[i] is used?
@@ -210,6 +221,13 @@ func RunHTTPTest(o *HTTPRunnerOptions) (*HTTPRunnerResults, error) {
 		}
 		total.sizes.Transfer(httpstate[i].sizes)
 		total.headerSizes.Transfer(httpstate[i].headerSizes)
+		connectionStats.Transfer(connStats)
+	}
+	total.ConnectionStats = connectionStats.Export().CalcPercentiles(o.Percentiles)
+	if log.Log(log.Info) {
+		total.ConnectionStats.Print(out, "Connection time histogram (s)")
+	} else if log.Log(log.Warning) {
+		connectionStats.Counter.Print(out, "Connection time (s)")
 	}
 
 	// Sort the ip address form largest to smallest based on its usage count
diff --git a/periodic/periodic.go b/periodic/periodic.go
index 2cfb589..73581e9 100644
--- a/periodic/periodic.go
+++ b/periodic/periodic.go
@@ -171,9 +171,11 @@ type RunnerOptions struct {
 	// Note that this actually maps to gorountines and not actual threads
 	// but threads seems like a more familiar name to use for non go users
 	// and in a benchmarking context
-	NumThreads  int
+	NumThreads int
+	// List of percentiles to calculate.
 	Percentiles []float64
-	Resolution  float64
+	// Divider to apply to duration data in seconds. Defaults to 0.001 or 1 millisecond.
+	Resolution float64
 	// Where to write the textual version of the results, defaults to stdout
 	Out io.Writer `json:"-"`
 	// Extra data to be copied back to the results (to be saved/JSON serialized)
diff --git a/stats/stats.go b/stats/stats.go
index b80fbd4..1cf0f44 100644
--- a/stats/stats.go
+++ b/stats/stats.go
@@ -196,7 +196,7 @@ type HistogramData struct {
 	Avg         float64
 	StdDev      float64
 	Data        []Bucket
-	Percentiles []Percentile
+	Percentiles []Percentile `json:"Percentiles,omitempty"`
 }
 
 // NewHistogram creates a new histogram (sets up the buckets).


Test patch:
diff --git a/fhttp/http_loglevel_test.go b/fhttp/http_loglevel_test.go
index 2eda66a..156346d 100644
--- a/fhttp/http_loglevel_test.go
+++ b/fhttp/http_loglevel_test.go
@@ -32,3 +32,8 @@ func TestDebugMode(t *testing.T) {
 	TestNoFirstChunkSizeInitially(t)
 	TestFetchAndOnBehalfOf(t)
 }
+
+func TesWarningMode(t *testing.T) {
+	log.SetLogLevel(log.Warning)
+	TestHTTPRunner(t)
+}
diff --git a/fhttp/httprunner_test.go b/fhttp/httprunner_test.go
index a7d7409..4eda80f 100644
--- a/fhttp/httprunner_test.go
+++ b/fhttp/httprunner_test.go
@@ -58,7 +58,7 @@ func TestHTTPRunner(t *testing.T) {
 	if totalReq != httpOk {
 		t.Errorf("Mismatch between requests %d and ok %v", totalReq, res.RetCodes)
 	}
-	if res.SocketCount != res.RunnerResults.NumThreads {
+	if res.SocketCount != int64(res.RunnerResults.NumThreads) {
 		t.Errorf("%d socket used, expected same as thread# %d", res.SocketCount, res.RunnerResults.NumThreads)
 	}
 	count := getIPUsageCount(res.IPCountMap)
@@ -126,7 +126,7 @@ func testHTTPNotLeaking(t *testing.T, opts *HTTPRunnerOptions) {
 	if ngAfter > ngBefore2+8 {
 		t.Errorf("Goroutines after test %d, expected it to stay near %d", ngAfter, ngBefore2)
 	}
-	if res.SocketCount != res.RunnerResults.NumThreads {
+	if res.SocketCount != int64(res.RunnerResults.NumThreads) {
 		t.Errorf("%d socket used, expected same as thread# %d", res.SocketCount, res.RunnerResults.NumThreads)
 	}
 }
@@ -213,7 +213,7 @@ func testClosingAndSocketCount(t *testing.T, o *HTTPRunnerOptions) {
 	if totalReq != httpOk {
 		t.Errorf("Mismatch between requests %d and ok %v", totalReq, res.RetCodes)
 	}
-	if int64(res.SocketCount) != numReq {
+	if res.SocketCount != numReq {
 		t.Errorf("When closing, got %d while expected as many sockets as requests %d", res.SocketCount, numReq)
 	}
 }
@@ -502,14 +502,14 @@ func TestConnectionReuseRange(t *testing.T) {
 			t.Error(err)
 		}
 
-		if res.SocketCount != (int)(expectedSocketReuse) {
+		if res.SocketCount != (int64)(expectedSocketReuse) {
 			t.Errorf("Expecting %f socket to be used, got %d", expectedSocketReuse, res.SocketCount)
 		}
 	}
 
 	// Test when connection reuse range min != max.
 	// The actual socket count should always be 2 as the connection reuse range varies between 5 and 9.
-	expectedSocketReuse := 2
+	expectedSocketReuse := int64(2)
 	opts.ConnReuseRange = [2]int{5, 9}
 	// Check a few times that despite the range and random 2-9 we still always get 2 connections
 	for i := 0; i < 5; i++ {
diff --git a/rapi/restHandler_test.go b/rapi/restHandler_test.go
index fcdc6a6..7315a39 100644
--- a/rapi/restHandler_test.go
+++ b/rapi/restHandler_test.go
@@ -117,7 +117,7 @@ func TestHTTPRunnerRESTApi(t *testing.T) {
 	if totalReq != httpOk {
 		t.Errorf("Mismatch between requests %d and ok %v (%+v)", totalReq, res.RetCodes, res)
 	}
-	if res.SocketCount != res.RunnerResults.NumThreads {
+	if res.SocketCount != int64(res.RunnerResults.NumThreads) {
 		t.Errorf("%d socket used, expected same as thread# %d", res.SocketCount, res.RunnerResults.NumThreads)
 	}