Golang TLS server and client, avoiding high memory usage on client on reconnect

Question

According to the examples here and here here I setup a server and a client that uses TLS with custom certificates. Analyzing the memory usage over times with pprof shows that the number of allocs increases each time the TLS client connects. Looking at the logs a lot of these entries do exist:

    #   0x5827cb    math/big.nat.make+0x93b                     /usr/local/go/src/math/big/nat.go:68
    #   0x58267e    math/big.nat.mul+0x7ee                      /usr/local/go/src/math/big/nat.go:428
    #   0x5780b8    math/big.(*Int).Mul+0x118                   /usr/local/go/src/math/big/int.go:168
    #   0x72d57b    crypto/elliptic.(*CurveParams).addJacobian+0xf5b        /usr/local/go/src/crypto/elliptic/elliptic.go:145
    #   0x72ebe2    crypto/elliptic.(*CurveParams).ScalarMult+0x1c2         /usr/local/go/src/crypto/elliptic/elliptic.go:260
    #   0x7c5934    crypto/tls.(*nistParameters).SharedKey+0xd4         /usr/local/go/src/crypto/tls/key_schedule.go:171
    #   0x7c3d09    crypto/tls.(*ecdheKeyAgreement).processServerKeyExchange+0x1d9  /usr/local/go/src/crypto/tls/key_agreement.go:266
    #   0x7a43e1    crypto/tls.(*clientHandshakeState).doFullHandshake+0x471    /usr/local/go/src/crypto/tls/handshake_client.go:503
    #   0x7a3b9a    crypto/tls.(*clientHandshakeState).handshake+0x3fa      /usr/local/go/src/crypto/tls/handshake_client.go:399
    #   0x7a21ec    crypto/tls.(*Conn).clientHandshake+0x2cc            /usr/local/go/src/crypto/tls/handshake_client.go:208
    #   0x7a07fe    crypto/tls.(*Conn).Handshake+0xee               /usr/local/go/src/crypto/tls/conn.go:1343
    #   0x7ca570    crypto/tls.DialWithDialer+0x220                 /usr/local/go/src/crypto/tls/tls.go:156
    #   0x8f2578    crypto/tls.Dial+0x1a8                       /usr/local/go/src/crypto/tls/tls.go:180
    #   0x8f2518    main.(*TCPSSLClient).Open+0x148                 /home/audinate/vcx/tcpSslClient.go:39

And also these:

#   0x58364a    math/big.nat.make+0x2ca                     /usr/local/go/src/math/big/nat.go:68
#   0x583507    math/big.nat.sqr+0x187                      /usr/local/go/src/math/big/nat.go:570
#   0x578015    math/big.(*Int).Mul+0x75                    /usr/local/go/src/math/big/int.go:164
#   0x72e0e0    crypto/elliptic.(*CurveParams).doubleJacobian+0xe0      /usr/local/go/src/crypto/elliptic/elliptic.go:197
#   0x72eb7c    crypto/elliptic.(*CurveParams).ScalarMult+0x15c         /usr/local/go/src/crypto/elliptic/elliptic.go:258
#   0x7c5934    crypto/tls.(*nistParameters).SharedKey+0xd4         /usr/local/go/src/crypto/tls/key_schedule.go:171
#   0x7c3d09    crypto/tls.(*ecdheKeyAgreement).processServerKeyExchange+0x1d9  /usr/local/go/src/crypto/tls/key_agreement.go:266
#   0x7a43e1    crypto/tls.(*clientHandshakeState).doFullHandshake+0x471    /usr/local/go/src/crypto/tls/handshake_client.go:503
#   0x7a3b9a    crypto/tls.(*clientHandshakeState).handshake+0x3fa      /usr/local/go/src/crypto/tls/handshake_client.go:399
#   0x7a21ec    crypto/tls.(*Conn).clientHandshake+0x2cc            /usr/local/go/src/crypto/tls/handshake_client.go:208
#   0x7a07fe    crypto/tls.(*Conn).Handshake+0xee               /usr/local/go/src/crypto/tls/conn.go:1343
#   0x7ca570    crypto/tls.DialWithDialer+0x220                 /usr/local/go/src/crypto/tls/tls.go:156
#   0x8f2578    crypto/tls.Dial+0x1a8                       /usr/local/go/src/crypto/tls/tls.go:180
#   0x8f2518    main.(*TCPSSLClient).Open+0x148                 /home/audinate/vcx/tcpSslClient.go:39

Doing a go tool pprof http://localhost:6060/debug/pprof/allocs and a top hows that it counts up highly.

Type: alloc_space
Time: Jul 19, 2019 at 3:03pm (CEST)
Entering interactive mode (type "help" for commands, "o" for options)
(pprof) top
Showing nodes accounting for 124.23MB, 96.13% of 129.23MB total
Dropped 34 nodes (cum <= 0.65MB)
Showing top 10 nodes out of 78
      flat  flat%   sum%        cum   cum%
  110.03MB 85.14% 85.14%   110.03MB 85.14%  math/big.nat.make
    3.53MB  2.73% 87.87%     6.47MB  5.00%  compress/flate.NewWriter
       2MB  1.55% 89.41%        2MB  1.55%  math/big.basicSqr
    1.80MB  1.39% 90.81%     2.94MB  2.28%  compress/flate.(*compressor).init
    1.50MB  1.16% 91.97%     1.50MB  1.16%  encoding/pem.removeWhitespace
    1.50MB  1.16% 93.13%    61.51MB 47.60%  crypto/elliptic.(*CurveParams).doubleJacobian
    1.14MB  0.88% 94.01%     1.14MB  0.88%  compress/flate.newDeflateFast
       1MB  0.77% 94.79%        1MB  0.77%  reflect.unsafe_NewArray
       1MB  0.77% 95.56%        1MB  0.77%  reflect.(*structType).Field
    0.73MB  0.57% 96.13%     0.73MB  0.57%  main.NewConmon
(pprof)

My Code on the client side is fairly simple: (not showing the timers to reconnect..)

   ....... 
   config := &tls.Config{Certificates: certificates, RootCAs: cas, SessionTicketsDisabled: true}


    conn, err := tls.Dial("tcp", addr, config)
    if err != nil {
        ...
        return
    }
    ....
    conn.Close()
    ....

Falda

What's your question? Are you surprised that a TLS handshake requires memory allocations? I'm not. – Shallow

I am not surprised that it requires memory, but I am surprised that it allocates memory each time it connects and GC does not collect the allocated memory on math/big.nat – Falda

pprof is telling you about allocations, not usage. What makes you say GC is not collecting the memory? – Timothytimour

pprof shows a running counter of many bytes have been allocated, nothing more, nothing less. This doesn't mean that the GC hasn't reclaimed space. // "I am surprised that it allocates memory each time it connects." How is this surprising? Doing fancy math with big numbers requires memory. I don't understand how that's not obvious. – Shallow

Maybe the question is not clear. My program does acquire more and m ore memory over time (looking to "top" on linux). So going step by step backwards I figured out that it allocates more and more memory every time the client connects. The values in the line : "110.03MB 85.14% 85.14% 110.03MB 85.14% math/big.nat.make" are growing fast. GC should trash this "BIG" numbers when they are not referenced anymore, no? – Falda

Your are looking at total allocations (Type: alloc_space). You need to look at memory in use. Try the -inuse_space or -inuse_objects options to pprof. – Sterilization

It looks like you're not using a defer in conn.Close(), do you ever just return before calling conn.Close? That could be the cause of the connection leak. Try adding a defer and testing again. – Dumps