TCP Connections not reused

[JudgeGregg]

I think the TCP connections are not reused with the current code:

package main

import (
    dac "github.com/xinsnake/go-http-digest-auth-client"
    "io"
    "io/ioutil"
)

const ENDPOINT = "https://foobar.com"
const USERNAME = "Foo"
const PASSWORD = "Bar"
const DBPATH = "Baz"

func main() {
    // create a new digest authentication request
    dr := dac.NewRequest(USERNAME, PASSWORD, "GET", ENDPOINT+"v1/documents/?uri="+DBPATH, "")
    resp, _ := dr.Execute()
    io.Copy(ioutil.Discard, resp.Body)
    resp.Body.Close()
    dr.UpdateRequest(USERNAME, PASSWORD, "GET", ENDPOINT+"v1/documents/?uri="+DBPATH, "")
    resp, _ = dr.Execute()
    io.Copy(ioutil.Discard, resp.Body)
    resp.Body.Close()
    dr = dac.NewRequest(USERNAME, PASSWORD, "GET", ENDPOINT+"v1/documents/?uri="+DBPATH, "")
    resp, _ = dr.Execute()
    io.Copy(ioutil.Discard, resp.Body)
    resp.Body.Close()
}

I patched the client according to: https://blog.golang.com/http-tracing

diff --git a/digest_auth_client.go b/digest_auth_client.go
index a2e69c4..9f0f7ba 100644
--- a/digest_auth_client.go
+++ b/digest_auth_client.go
@@ -4,7 +4,9 @@ import (
    "bytes"
    "crypto/tls"
    "fmt"
+   "log"
    "net/http"
+   "net/http/httptrace"
    "time"
 )

@@ -106,6 +108,12 @@ func (dr *DigestRequest) Execute() (resp *http.Response, err error) {
        return nil, err
    }
    req.Header = dr.Header
+   trace := &httptrace.ClientTrace{
+       GotConn: func(connInfo httptrace.GotConnInfo) {
+           log.Printf("Got Conn: %+v\n", connInfo)
+       },
+   }
+   req = req.WithContext(httptrace.WithClientTrace(req.Context(), trace))

    client := dr.getHTTPClient()

@@ -169,6 +177,13 @@ func (dr *DigestRequest) executeRequest(authString string) (resp *http.Response,
    req.Header = dr.Header
    req.Header.Add("Authorization", authString)

+   trace := &httptrace.ClientTrace{
+       GotConn: func(connInfo httptrace.GotConnInfo) {
+           log.Printf("Got Conn: %+v\n", connInfo)
+       },
+   }
+   req = req.WithContext(httptrace.WithClientTrace(req.Context(), trace))
+
    client := dr.getHTTPClient()
    return client.Do(req)
 }

And here's what I got:

Go/src/test via 🐹 v1.14.4 took 6s
[N] ➜ go run main.go
2020/07/03 15:08:58 Got Conn: {Conn:0xc000080380 Reused:false WasIdle:false IdleTime:0s}
2020/07/03 15:08:58 Got Conn: {Conn:0xc000600e00 Reused:false WasIdle:false IdleTime:0s}
2020/07/03 15:09:00 Got Conn: {Conn:0xc000601180 Reused:false WasIdle:false IdleTime:0s}
2020/07/03 15:09:02 Got Conn: {Conn:0xc000601880 Reused:false WasIdle:false IdleTime:0s}
2020/07/03 15:09:02 Got Conn: {Conn:0xc000580380 Reused:false WasIdle:false IdleTime:0s}

I believe the problem is twofold:

• First we create a transport for each request, which will cancel the benefit of caching requests:

https://golang.org/src/net/http/transport.go?h=http.Transport

// By default, Transport caches connections for future re-use.
// This may leave many open connections when accessing many hosts.
// This behavior can be managed using Transport's CloseIdleConnections method
// and the MaxIdleConnsPerHost and DisableKeepAlives fields.
//
// Transports should be reused instead of created as needed.
// Transports are safe for concurrent use by multiple goroutines.

By applying the following patch:

diff --git a/digest_auth_client.go b/digest_auth_client.go
index a2e69c4..13ff3c3 100644
--- a/digest_auth_client.go
+++ b/digest_auth_client.go
@@ -54,9 +56,9 @@ func (dr *DigestRequest) getHTTPClient() *http.Client {

    return &http.Client{
        Timeout: 30 * time.Second,
-       Transport: &http.Transport{
-           TLSClientConfig: &tlsConfig,
-       },
+       //Transport: &http.Transport{
+       //TLSClientConfig: &tlsConfig,
+       //},
    }
 }

we get the following:

Go/src/test via 🐹 v1.14.4 took 7s 
[N] ➜ go run main.go                                       
2020/07/03 15:13:06 Got Conn: {Conn:0xc000105880 Reused:false WasIdle:false IdleTime:0s}
2020/07/03 15:13:06 Got Conn: {Conn:0xc000104700 Reused:false WasIdle:false IdleTime:0s}
2020/07/03 15:13:06 Got Conn: {Conn:0xc000104700 Reused:true WasIdle:true IdleTime:221.992µs}
2020/07/03 15:13:06 Got Conn: {Conn:0xc000104700 Reused:true WasIdle:true IdleTime:115.194µs}
2020/07/03 15:13:06 Got Conn: {Conn:0xc000053500 Reused:false WasIdle:false IdleTime:0s}

• Second, we don't discard the body on the first request (authentication), which keeps the connection in a "waiting state": If we discard it:

  
  diff --git a/digest_auth_client.go b/digest_auth_client.go
  index a2e69c4..d97ad9a 100644
  --- a/digest_auth_client.go
  +++ b/digest_auth_client.go
  @@ -4,7 +4,11 @@ import (
  "bytes"
  "crypto/tls"
  "fmt"

• "io"
• "io/ioutil" "net/http" "time" )

@@ -129,6 +139,7 @@ func (dr DigestRequest) executeNewDigest(resp http.Response) (resp2 *http.Resp )

// body not required for authentication, closing

• io.Copy(ioutil.Discard, resp.Body) resp.Body.Close()

  if waString = resp.Header.Get("WWW-Authenticate"); waString == "" {

Then we get:

Go/src/test via 🐹 v1.14.4
[N] ➜ go run main.go
2020/07/03 15:17:59 Got Conn: {Conn:0xc000080380 Reused:false WasIdle:false IdleTime:0s}
2020/07/03 15:17:59 Got Conn: {Conn:0xc000080380 Reused:true WasIdle:true IdleTime:91.744µs}
2020/07/03 15:18:01 Got Conn: {Conn:0xc000080380 Reused:true WasIdle:true IdleTime:117.822µs}
2020/07/03 15:18:01 Got Conn: {Conn:0xc000080380 Reused:true WasIdle:true IdleTime:79.115µs}
2020/07/03 15:18:01 Got Conn: {Conn:0xc000080380 Reused:true WasIdle:true IdleTime:193.787µs}

The problem with hanging connections is that under a heavy load, the client can run out of TCP connections, since they're all in a TIME-WAIT state.

I think problem 2 is easy to solve (simply discard the resp.Body) I have no idea how to solve problem 1 while still keeping a configurable client, though.

Sorry for that long text, and thank you very much for your work on this useful library :)

[xinsnake]

Thanks @JudgeGregg for your analysis. I am not sure how necessary it is to patch this (maybe in some scenarios reusing existing connection is necessary, but I haven't personally built any system that run out of TCP connections) 😄 .

Let me spend some time investigate TCP connection reuse and I'll see what we can do here. Thanks for reporting this issue.

[xinsnake]

Thanks for your report. Due to time limit on my side I won't be able to maintain this package. Please consider using some other library like https://github.com/rkl-/digest. Thanks for your support!